00010000:00010000:1.0F:1776205339.288098:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:3.0F:1776205340.314115:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0F:1776205341.335960:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0F:1776205342.389537:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00080000:2.0:1776205342.873603:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205342.873610:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:2.0:1776205342.873612:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205342.873615:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:3.0:1776205342.873789:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572608:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:3.0:1776205342.873927:0:2219:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:3.0:1776205342.873934:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572672:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:2.0:1776205342.886870:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572672:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:2.0:1776205342.886896:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572608:192.168.202.123@tcp:400:kworker/u8:0.0 00010000:00010000:2.0:1776205343.447996:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205344.472008:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205345.495866:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205346.519862:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205347.543969:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00100000:3.0:1776205347.992491:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572736:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:3.0:1776205348.000268:0:2219:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:3.0:1776205348.000288:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572800:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00080000:2.0:1776205348.000958:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205348.000963:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:2.0:1776205348.000965:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205348.000968:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:2.0:1776205348.009458:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572800:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:2.0:1776205348.009475:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572736:192.168.202.123@tcp:400:kworker/u8:0.0 00010000:00010000:0.0:1776205348.568137:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205349.592194:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205350.616809:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205351.641893:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205352.666421:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000400:00000080:2.0:1776205353.005946:0:182840:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648 00000001:02000400:2.0:1776205353.005953:0:182840:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: == sanity test 823: Setting create_count > OST_MAX_PRECREATE is lowered to maximum ========================================================== 18:22:30 (1776205350) 00000100:00080000:2.0:1776205353.118803:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205353.118810:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:2.0:1776205353.118827:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205353.118829:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:2.0:1776205353.118865:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572864:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205353.118947:0:2219:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:2.0:1776205353.118954:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572928:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205353.146959:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268572928:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205353.146979:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268572864:192.168.202.123@tcp:400:kworker/u8:4.0 00010000:00010000:1.0:1776205353.687900:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205354.711935:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205355.737194:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205356.761002:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205357.787180:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00080000:0.0:1776205358.231985:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:0.0:1776205358.231992:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:0.0:1776205358.231994:0:182578:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:0.0:1776205358.232008:0:182578:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:0.0:1776205358.232037:0:2217:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000000d20f609 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:2784e426-5469-4962-abdd-5d421f2f60e1:2217:1862480268573056:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:0.0:1776205358.232146:0:2217:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:0.0:1776205358.232152:0:2217:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000448dcb47 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2217:1862480268572992:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:1.0:1776205358.245338:0:2217:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000448dcb47 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2217:1862480268572992:192.168.202.123@tcp:400:kworker/u8:0.0 00000100:00100000:1.0:1776205358.245361:0:2217:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000000d20f609 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:2784e426-5469-4962-abdd-5d421f2f60e1:2217:1862480268573056:192.168.202.123@tcp:400:kworker/u8:0.0 00010000:00010000:0.0:1776205358.821204:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205359.833493:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000400:00000080:3.0:1776205360.379643:0:183033:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648 00000001:02000400:3.0:1776205360.379648:0:183033:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: setting create_count to 100200: 00010000:00010000:0.0:1776205360.856806:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205361.880146:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000400:00000080:3.0:1776205362.089508:0:183169:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648 00000001:02000400:3.0:1776205362.089515:0:183169:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: -result- count: 9984 with max: 20000, expecting: 9984 00010000:00010000:0.0:1776205362.903922:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00080000:2.0:1776205363.370268:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205363.370274:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:2.0:1776205363.370276:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205363.370278:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:2.0:1776205363.370337:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268573120:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205363.370438:0:2219:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:2.0:1776205363.370445:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268573184:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205363.373212:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268573120:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205363.382556:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268573184:192.168.202.123@tcp:400:kworker/u8:4.0 00010000:00010000:1.0:1776205363.928814:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:3.0:1776205364.952206:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205365.977478:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205367.001670:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:0.0:1776205368.025528:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00080000:1.0:1776205368.473152:0:131101:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:1.0:1776205368.473158:0:131101:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:1.0:1776205368.473160:0:131101:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:1.0:1776205368.473163:0:131101:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:1.0:1776205368.473185:0:2217:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000ee2eac5d pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:2784e426-5469-4962-abdd-5d421f2f60e1:2217:1862480268573312:192.168.202.123@tcp:400:kworker/u8:2.0 00000100:00100000:1.0:1776205368.473272:0:2217:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:1.0:1776205368.473278:0:2217:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000492daa43 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2217:1862480268573248:192.168.202.123@tcp:400:kworker/u8:2.0 00000100:00100000:1.0:1776205368.482274:0:2217:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000ee2eac5d pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:2784e426-5469-4962-abdd-5d421f2f60e1:2217:1862480268573312:192.168.202.123@tcp:400:kworker/u8:2.0 00000100:00100000:1.0:1776205368.482797:0:2217:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000492daa43 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2217:1862480268573248:192.168.202.123@tcp:400:kworker/u8:2.0 00010000:00010000:1.0:1776205369.047952:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205370.075179:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000400:00000080:3.0:1776205370.927269:0:183751:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648 00000001:02000400:3.0:1776205370.927274:0:183751:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: == sanity test 831: throttling unlink/setattr queuing on OSP ========================================================== 18:22:49 (1776205369) 00010000:00010000:1.0:1776205371.098593:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000080:00200000:0.0:1776205371.987155:0:183775:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205371.987182:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:0.0:1776205371.987199:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205371.987213:0:183775:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:0.0:1776205371.987239:0:183775:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205371.987242:0:183775:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:0.0:1776205371.987296:0:183775:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 0000000091e264d9 00010000:00010000:0.0:1776205371.987300:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205371.987308:0:183775:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205371.987322:0:183775:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 1 00000080:00200000:0.0:1776205371.987335:0:183775:0:(namei.c:1111:ll_lookup_nd()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), flags=13 00000080:00200000:0.0:1776205371.987340:0:183775:0:(namei.c:833:ll_lookup_it()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), intent=getattr 00000002:00010000:0.0:1776205371.987351:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: d831.sanity,[0x0:0x0:0x0]) in obj [0x200000007:0x1:0x0], intent: getattr flags 0 00010000:00010000:0.0:1776205371.987392:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205371.987399:0:183775:0:(ldlm_request.c:1026:ldlm_cli_enqueue()) ### client-side enqueue START, flags 0x1000 ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205371.988522:0:183775:0:(ldlm_request.c:1114:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000100:00100000:0.0:1776205371.988553:0:183775:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573376:192.168.202.123@tcp:101:lfs.0 00000100:00100000:0.0:1776205371.988667:0:183775:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:0.0:1776205372.005530:0:183775:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573376:192.168.202.123@tcp:101:lfs.0 00010000:00010000:0.0:1776205372.005551:0:183775:0:(ldlm_request.c:641:ldlm_cli_enqueue_fini()) ### client-side enqueue END (ABORTED) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005578:0:183775:0:(ldlm_request.c:562:failed_lock_cleanup()) ### setting FL_LOCAL_ONLY | LDLM_FL_FAILED | LDLM_FL_ATOMIC_CB | LDLM_FL_CBPENDING ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005584:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005590:0:183775:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005597:0:183775:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005603:0:183775:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 00000000dd454cc5 already unused, calling callback (00000000bc2b7da8) 00010000:00010000:0.0:1776205372.005607:0:183775:0:(ldlm_request.c:1546:ldlm_cli_convert()) ### client lock convert START ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005613:0:183775:0:(ldlm_request.c:1556:ldlm_cli_convert()) ### client lock convert END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005621:0:183775:0:(ldlm_request.c:1232:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 5/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x20e400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005627:0:183775:0:(ldlm_request.c:1248:ldlm_cli_cancel_local()) not sending request (at caller's instruction) 00010000:00010000:0.0:1776205372.005633:0:183775:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005637:0:183775:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000dd454cc5/0xc31d44e5847febab lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000002:00100000:0.0:1776205372.005658:0:183775:0:(mdc_locks.c:743:mdc_finish_enqueue()) @@@ op=8 disposition=7, status=0 req@000000005f5c2807 x1862480268573376/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 584/640 e 0 to 0 dl 1776205413 ref 1 fl Complete:RQU/0/0 rc 301/301 job:'lfs.0' 00010000:00010000:0.0:1776205372.005684:0:183775:0:(ldlm_lock.c:1511:ldlm_lock_match_with_skip()) ### not matched ns 000000001c22f413 type 13 mode 30 res 8589934599/1 (0 0) 00000080:00200000:0.0:1776205372.005804:0:183775:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205372.005814:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:0.0:1776205372.005819:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005825:0:183775:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:0.0:1776205372.005830:0:183775:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205372.005832:0:183775:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:0.0:1776205372.005836:0:183775:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 00000000c5b5e51a 00010000:00010000:0.0:1776205372.005837:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005841:0:183775:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205372.005850:0:183775:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 1 00000080:00200000:0.0:1776205372.005858:0:183775:0:(namei.c:1111:ll_lookup_nd()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), flags=16392 00000080:00200000:0.0:1776205372.005861:0:183775:0:(namei.c:833:ll_lookup_it()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), intent=getattr 00000002:00010000:0.0:1776205372.005876:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: d831.sanity,[0x0:0x0:0x0]) in obj [0x200000007:0x1:0x0], intent: getattr flags 0 00010000:00010000:0.0:1776205372.005912:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005929:0:183775:0:(ldlm_request.c:1026:ldlm_cli_enqueue()) ### client-side enqueue START, flags 0x1000 ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.005947:0:183775:0:(ldlm_request.c:1114:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000100:00100000:0.0:1776205372.005966:0:183775:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573440:192.168.202.123@tcp:101:lfs.0 00000100:00100000:0.0:1776205372.006068:0:183775:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:0.0:1776205372.009098:0:183775:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573440:192.168.202.123@tcp:101:lfs.0 00010000:00010000:0.0:1776205372.009118:0:183775:0:(ldlm_request.c:641:ldlm_cli_enqueue_fini()) ### client-side enqueue END (ABORTED) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009128:0:183775:0:(ldlm_request.c:562:failed_lock_cleanup()) ### setting FL_LOCAL_ONLY | LDLM_FL_FAILED | LDLM_FL_ATOMIC_CB | LDLM_FL_CBPENDING ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009133:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009137:0:183775:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009141:0:183775:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009145:0:183775:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000009829edf1 already unused, calling callback (00000000bc2b7da8) 00010000:00010000:0.0:1776205372.009147:0:183775:0:(ldlm_request.c:1546:ldlm_cli_convert()) ### client lock convert START ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009166:0:183775:0:(ldlm_request.c:1556:ldlm_cli_convert()) ### client lock convert END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009171:0:183775:0:(ldlm_request.c:1232:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 5/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x20e400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009175:0:183775:0:(ldlm_request.c:1248:ldlm_cli_cancel_local()) not sending request (at caller's instruction) 00010000:00010000:0.0:1776205372.009178:0:183775:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009182:0:183775:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000009829edf1/0xc31d44e5847febb2 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x2 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000002:00100000:0.0:1776205372.009193:0:183775:0:(mdc_locks.c:743:mdc_finish_enqueue()) @@@ op=8 disposition=7, status=0 req@000000005f5c2807 x1862480268573440/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 584/640 e 0 to 0 dl 1776205414 ref 1 fl Complete:RQU/0/0 rc 301/301 job:'lfs.0' 00010000:00010000:0.0:1776205372.009216:0:183775:0:(ldlm_lock.c:1511:ldlm_lock_match_with_skip()) ### not matched ns 000000001c22f413 type 13 mode 30 res 8589934599/1 (0 0) 00000080:00200000:0.0:1776205372.009274:0:183775:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205372.009284:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: getattr flags 0 00010000:00010000:0.0:1776205372.009289:0:183775:0:(ldlm_lock.c:1511:ldlm_lock_match_with_skip()) ### not matched ns 000000001c22f413 type 13 mode 30 res 8589934599/1 (0 0) 00010000:00010000:0.0:1776205372.009324:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009330:0:183775:0:(ldlm_request.c:1026:ldlm_cli_enqueue()) ### client-side enqueue START, flags 0x1000 ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.009340:0:183775:0:(ldlm_request.c:1114:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000100:00100000:0.0:1776205372.009356:0:183775:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573504:192.168.202.123@tcp:101:lfs.0 00000100:00100000:0.0:1776205372.009453:0:183775:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:0.0:1776205372.014695:0:183775:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573504:192.168.202.123@tcp:101:lfs.0 00010000:00010000:0.0:1776205372.014738:0:183775:0:(ldlm_request.c:714:ldlm_cli_enqueue_fini()) ### server returned different mode PR ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014750:0:183775:0:(ldlm_request.c:742:ldlm_cli_enqueue_fini()) ### client-side enqueue, new policy data ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 4/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014760:0:183775:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 4/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014769:0:183775:0:(ldlm_request.c:796:ldlm_cli_enqueue_fini()) ### client-side enqueue END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 4/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014779:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 5/2,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014786:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 5/2,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014792:0:183775:0:(ldlm_lock.c:909:ldlm_lock_decref_internal()) ### do not add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 4/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000002:00100000:0.0:1776205372.014800:0:183775:0:(mdc_locks.c:743:mdc_finish_enqueue()) @@@ op=8 disposition=b, status=0 req@000000005f5c2807 x1862480268573504/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 576/688 e 0 to 0 dl 1776205414 ref 1 fl Complete:RQU/0/0 rc 0/0 job:'lfs.0' 00000002:00010000:0.0:1776205372.014814:0:183775:0:(mdc_locks.c:1179:mdc_finish_intent_lock()) ### matching against this ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014825:0:183775:0:(ldlm_lock.c:1511:ldlm_lock_match_with_skip()) ### not matched ns 000000001c22f413 type 13 mode 4 res 8589934599/1 (0 0) 00000080:00200000:0.0:1776205372.014865:0:183775:0:(llite_lib.c:2760:ll_update_inode()) inode=[0x200000007:0x1:0x0], updating i_size 25088 00000080:00010000:0.0:1776205372.014872:0:183775:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847febb9 00000080:00010000:0.0:1776205372.014878:0:183775:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205372.014880:0:183775:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847febb9 from it 000000000d9a1196 00010000:00010000:0.0:1776205372.014882:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.014890:0:183775:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205372.016811:0:183775:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205372.016833:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: getattr flags 0 00010000:00010000:0.0:1776205372.016847:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.016859:0:183775:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000080:00010000:0.0:1776205372.016880:0:183775:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205372.016883:0:183775:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847febb9 00000080:00010000:0.0:1776205372.016889:0:183775:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847febb9 from it 000000000d9a1196 00010000:00010000:0.0:1776205372.016891:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.016899:0:183775:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205372.017029:0:183775:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205372.017036:0:183775:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:0.0:1776205372.017045:0:183775:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 4 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.017052:0:183775:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:0.0:1776205372.017060:0:183775:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205372.017062:0:183775:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:0.0:1776205372.017065:0:183775:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 00000000fa8b17d5 00010000:00010000:0.0:1776205372.017067:0:183775:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.017073:0:183775:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205372.017081:0:183775:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 44 00000080:00200000:0.0:1776205372.017088:0:183775:0:(file.c:837:ll_file_open()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), flags 300000 00000080:00200000:0.0:1776205372.017104:0:183775:0:(dir.c:1423:ll_dir_ioctl()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), cmd=0xc03066f0 00000080:00200000:0.0:1776205372.017114:0:183775:0:(dir.c:475:ll_dir_setdirstripe()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394) name d831.sanity stripe_offset 0, stripe_count: 0 00010000:00010000:0.0:1776205372.017133:0:183775:0:(ldlm_request.c:1232:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x8400000000 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.017146:0:183775:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 4 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.017186:0:183775:0:(ldlm_request.c:1279:__ldlm_pack_lock()) ### packing ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 1/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x4809400000020 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.017192:0:183775:0:(ldlm_request.c:1325:ldlm_cancel_pack()) 1 locks packed 00010000:00010000:0.0:1776205372.017194:0:183775:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febb9 lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x4809400000020 nid: local remote: 0xb8d734e6f36e394c expref: -99 pid: 183775 timeout: 0 lvb_type: 0 00000020:00100000:0.0:1776205372.017219:0:183775:0:(genops.c:2339:obd_get_mod_rpc_slot()) lustre-MDT0000-mdc-ffff961f51c5c800: modify RPC slot 1 is allocated opc 36, max 7 00000100:00100000:0.0:1776205372.017228:0:183775:0:(client.c:742:ptlrpc_reassign_next_xid()) @@@ reassign xid req@000000005f5c2807 x1862480268573632/t0(0) o36->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 560/448 e 0 to 0 dl 0 ref 1 fl New:QU/0/ffffffff rc 0/-1 job:'' 00000100:00100000:0.0:1776205372.017250:0:183775:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573632:192.168.202.123@tcp:36:lfs.0 00000100:00100000:0.0:1776205372.017768:0:183775:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:0.0:1776205372.022958:0:183775:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000005f5c2807 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183775:1862480268573632:192.168.202.123@tcp:36:lfs.0 00000080:00200000:0.0:1776205372.023177:0:183775:0:(llite_lib.c:2838:ll_read_inode2()) VFS Op:inode=[0x200002b11:0xe62:0x0](0000000084bcb99c) 00000080:00200000:0.0:1776205372.023184:0:183775:0:(llite_lib.c:2760:ll_update_inode()) inode=[0x200002b11:0xe62:0x0], updating i_size 512 00000080:00200000:0.0:1776205372.023213:0:183775:0:(file.c:410:ll_file_release()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394) 00000080:00200000:1.0:1776205372.065678:0:183776:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:1.0:1776205372.065702:0:183776:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:1.0:1776205372.066850:0:183776:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.067124:0:183776:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:1.0:1776205372.067145:0:183776:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:1.0:1776205372.067149:0:183776:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:1.0:1776205372.067160:0:183776:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 000000000e934d0c 00010000:00010000:1.0:1776205372.067163:0:183776:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.067172:0:183776:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:1.0:1776205372.067403:0:183776:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 1 00000080:00200000:1.0:1776205372.067427:0:183776:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:1.0:1776205372.067438:0:183776:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:1.0:1776205372.067444:0:183776:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.067452:0:183776:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:1.0:1776205372.067459:0:183776:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:1.0:1776205372.067462:0:183776:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:1.0:1776205372.067465:0:183776:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 0000000058d1addb 00010000:00010000:1.0:1776205372.067467:0:183776:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.067473:0:183776:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:1.0:1776205372.067489:0:183776:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 3 00000080:00200000:1.0:1776205372.067494:0:183776:0:(namei.c:1183:ll_atomic_open()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), file 0000000048fa2ae7, open_flags a141, mode 81b6 opened 0 00000080:00200000:1.0:1776205372.067503:0:183776:0:(namei.c:833:ll_lookup_it()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), intent=open|creat 00000002:00010000:1.0:1776205372.067522:0:183776:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: d831.sanity,[0x200002b11:0xe63:0x0]) in obj [0x200000007:0x1:0x0], intent: open|creat flags 0120502 00010000:00010000:1.0:1776205372.067576:0:183776:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CW) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 3/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.067583:0:183776:0:(ldlm_request.c:1026:ldlm_cli_enqueue()) ### client-side enqueue START, flags 0x1000 ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 3/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000020:00100000:1.0:1776205372.067629:0:183776:0:(genops.c:2339:obd_get_mod_rpc_slot()) lustre-MDT0000-mdc-ffff961f51c5c800: modify RPC slot 1 is allocated opc 101, max 7 00000100:00100000:1.0:1776205372.067641:0:183776:0:(client.c:742:ptlrpc_reassign_next_xid()) @@@ reassign xid req@00000000492daa43 x1862480268573760/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/66264 e 0 to 0 dl 0 ref 1 fl New:PQU/0/ffffffff rc 0/-1 job:'' 00010000:00010000:1.0:1776205372.067649:0:183776:0:(ldlm_request.c:1114:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 3/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000100:00100000:1.0:1776205372.067672:0:183776:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000492daa43 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268573760:192.168.202.123@tcp:101:lfs.0 00000100:00100000:1.0:1776205372.075438:0:183776:0:(client.c:2500:ptlrpc_set_wait()) set 00000000c6ee0c97 going to sleep for 41 seconds 00000100:00100000:1.0:1776205372.087879:0:183776:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000492daa43 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268573760:192.168.202.123@tcp:101:lfs.0 00010000:00010000:1.0:1776205372.087906:0:183776:0:(ldlm_request.c:641:ldlm_cli_enqueue_fini()) ### client-side enqueue END (ABORTED) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.087920:0:183776:0:(ldlm_request.c:562:failed_lock_cleanup()) ### setting FL_LOCAL_ONLY | LDLM_FL_FAILED | LDLM_FL_ATOMIC_CB | LDLM_FL_CBPENDING ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.087927:0:183776:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CW) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.087958:0:183776:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 3/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.087966:0:183776:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.087973:0:183776:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000006e4e45e9 already unused, calling callback (00000000bc2b7da8) 00010000:00010000:1.0:1776205372.092370:0:183776:0:(ldlm_request.c:1546:ldlm_cli_convert()) ### client lock convert START ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.092393:0:183776:0:(ldlm_request.c:1556:ldlm_cli_convert()) ### client lock convert END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 4/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.092403:0:183776:0:(ldlm_request.c:1232:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 5/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x20e400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.092412:0:183776:0:(ldlm_request.c:1248:ldlm_cli_cancel_local()) not sending request (at caller's instruction) 00010000:00010000:1.0:1776205372.092421:0:183776:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 3/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:1.0:1776205372.092428:0:183776:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000006e4e45e9/0xc31d44e5847febc0 lrc: 0/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000002:00100000:1.0:1776205372.092459:0:183776:0:(mdc_locks.c:743:mdc_finish_enqueue()) @@@ op=3 disposition=b, status=-21 req@00000000492daa43 x1862480268573760/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 1 fl Complete:RQU/0/0 rc 301/301 job:'lfs.0' 00000080:00200000:0.0:1776205372.092791:0:183776:0:(file.c:5227:ll_inode_revalidate()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394),name=/ 00000002:00010000:0.0:1776205372.092808:0:183776:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: ,[0x200000007:0x1:0x0]) in obj [0x200000007:0x1:0x0], intent: lookup flags 0 00010000:00010000:0.0:1776205372.092822:0:183776:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.092832:0:183776:0:(ldlm_lock.c:1494:ldlm_lock_match_with_skip()) ### matched (0 0) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00010000:0.0:1776205372.092841:0:183776:0:(dcache.c:293:ll_lookup_finish_locks()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) 00000080:00010000:0.0:1776205372.092844:0:183776:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200000007:0x1:0x0](0000000094dcd394) for lock 0xc31d44e5847feb7a 00000080:00010000:0.0:1776205372.092850:0:183776:0:(dcache.c:193:ll_intent_drop_lock()) releasing lock with cookie 0xc31d44e5847feb7a from it 000000000e934d0c 00010000:00010000:0.0:1776205372.092852:0:183776:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.092859:0:183776:0:(ldlm_lock.c:902:ldlm_lock_decref_internal()) ### add lock into lru list ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 00000000ead1bf2a/0xc31d44e5847feb7a lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x11/0x0 rrc: 2 type: IBT gid 0 flags: 0x0 nid: local remote: 0xb8d734e6f36e38a4 expref: -99 pid: 180647 timeout: 0 lvb_type: 0 00000080:00200000:0.0:1776205372.092899:0:183776:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200000007:0x1:0x0](0000000094dcd394), inode mode 41ff mask 1 00000080:00200000:0.0:1776205372.092912:0:183776:0:(namei.c:1183:ll_atomic_open()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), file 00000000fe1e147f, open_flags 1a100, mode 0 opened 0 00000080:00200000:0.0:1776205372.092918:0:183776:0:(namei.c:833:ll_lookup_it()) VFS Op:name=d831.sanity, dir=[0x200000007:0x1:0x0](0000000094dcd394), intent=open 00000002:00010000:0.0:1776205372.092930:0:183776:0:(mdc_locks.c:1328:mdc_intent_lock()) (name: d831.sanity,[0x0:0x0:0x0]) in obj [0x200000007:0x1:0x0], intent: open flags 0320401 00010000:00010000:0.0:1776205372.092997:0:183776:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x10000000000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.093004:0:183776:0:(ldlm_request.c:1026:ldlm_cli_enqueue()) ### client-side enqueue START, flags 0x1000 ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000020:00100000:0.0:1776205372.093016:0:183776:0:(genops.c:2339:obd_get_mod_rpc_slot()) lustre-MDT0000-mdc-ffff961f51c5c800: modify RPC slot 1 is allocated opc 101, max 7 00000100:00100000:0.0:1776205372.093022:0:183776:0:(client.c:742:ptlrpc_reassign_next_xid()) @@@ reassign xid req@000000004b171ca1 x1862480268573888/t0(0) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/131800 e 0 to 0 dl 0 ref 1 fl New:PQU/0/ffffffff rc 0/-1 job:'' 00010000:00010000:0.0:1776205372.093029:0:183776:0:(ldlm_request.c:1114:ldlm_cli_enqueue()) ### sending request ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000100:00100000:0.0:1776205372.093051:0:183776:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000004b171ca1 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268573888:192.168.202.123@tcp:101:lfs.0 00000100:00100000:0.0:1776205372.093214:0:183776:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:0.0:1776205372.117187:0:183776:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000004b171ca1 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268573888:192.168.202.123@tcp:101:lfs.0 00010000:00010000:0.0:1776205372.117209:0:183776:0:(ldlm_request.c:641:ldlm_cli_enqueue_fini()) ### client-side enqueue END (ABORTED) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x0 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117223:0:183776:0:(ldlm_request.c:562:failed_lock_cleanup()) ### setting FL_LOCAL_ONLY | LDLM_FL_FAILED | LDLM_FL_ATOMIC_CB | LDLM_FL_CBPENDING ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117230:0:183776:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117253:0:183776:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x10206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117261:0:183776:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117267:0:183776:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000000ae864f3 already unused, calling callback (00000000bc2b7da8) 00010000:00010000:0.0:1776205372.117271:0:183776:0:(ldlm_request.c:1546:ldlm_cli_convert()) ### client lock convert START ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117277:0:183776:0:(ldlm_request.c:1556:ldlm_cli_convert()) ### client lock convert END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 4/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x206400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117283:0:183776:0:(ldlm_request.c:1232:ldlm_cli_cancel_local()) ### client-side cancel ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 5/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x20e400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117290:0:183776:0:(ldlm_request.c:1248:ldlm_cli_cancel_local()) not sending request (at caller's instruction) 00010000:00010000:0.0:1776205372.117295:0:183776:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 3/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00010000:00010000:0.0:1776205372.117301:0:183776:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: lustre-MDT0000-mdc-ffff961f51c5c800 lock: 000000000ae864f3/0xc31d44e5847febc7 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x1 rrc: 3 type: IBT gid 0 flags: 0x4a0f400000000 nid: local remote: 0x0 expref: -99 pid: 183776 timeout: 0 lvb_type: 0 00000002:00100000:0.0:1776205372.117320:0:183776:0:(mdc_locks.c:743:mdc_finish_enqueue()) @@@ op=1 disposition=2b, status=0 req@000000004b171ca1 x1862480268573888/t34359738376(34359738376) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 2 fl Complete:RPQU/4/0 rc 301/301 job:'lfs.0' 00000002:00100000:0.0:1776205372.117334:0:183776:0:(mdc_request.c:833:mdc_set_open_replay_data()) @@@ Set up open replay data req@000000004b171ca1 x1862480268573888/t34359738376(34359738376) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 2 fl Complete:RPQU/4/0 rc 301/301 job:'lfs.0' 00000080:00200000:0.0:1776205372.117363:0:183776:0:(llite_lib.c:2760:ll_update_inode()) inode=[0x200002b11:0xe62:0x0], updating i_size 512 00000080:00200000:0.0:1776205372.117372:0:183776:0:(namei.c:157:ll_iget()) got inode: [0x200002b11:0xe62:0x0](0000000084bcb99c): rc = 0 00000080:00010000:0.0:1776205372.117378:0:183776:0:(llite_internal.h:1711:ll_set_lock_data()) setting l_data to inode [0x200002b11:0xe62:0x0](0000000084bcb99c) for lock 0x0 00000080:00200000:0.0:1776205372.117400:0:183776:0:(file.c:837:ll_file_open()) VFS Op:inode=[0x200002b11:0xe62:0x0](0000000084bcb99c), flags 320400 00000002:00100000:0.0:1776205372.117417:0:183776:0:(mdc_request.c:833:mdc_set_open_replay_data()) @@@ Set up open replay data req@000000004b171ca1 x1862480268573888/t34359738376(34359738376) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 2 fl Complete:RPQU/4/0 rc 301/301 job:'lfs.0' 00000080:00200000:0.0:1776205372.117518:0:183776:0:(file.c:5661:ll_inode_permission()) VFS Op:inode=[0x200002b11:0xe62:0x0](0000000084bcb99c), inode mode 41ed mask 44 00000080:00200000:0.0:1776205372.117553:0:183776:0:(dir.c:1423:ll_dir_ioctl()) VFS Op:inode=[0x200002b11:0xe62:0x0](0000000084bcb99c), cmd=0x4008669a 00000020:00100000:0.0:1776205372.117596:0:183776:0:(genops.c:2339:obd_get_mod_rpc_slot()) lustre-MDT0000-mdc-ffff961f51c5c800: modify RPC slot 1 is allocated opc 36, max 7 00000100:00100000:0.0:1776205372.117602:0:183776:0:(client.c:742:ptlrpc_reassign_next_xid()) @@@ reassign xid req@000000003e39b9a7 x1862480268574016/t0(0) o36->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 520/512 e 0 to 0 dl 0 ref 1 fl New:QU/0/ffffffff rc 0/-1 job:'' 00000100:00100000:0.0:1776205372.117620:0:183776:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000003e39b9a7 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268574016:192.168.202.123@tcp:36:lfs.0 00000100:00100000:0.0:1776205372.117770:0:183776:0:(client.c:2500:ptlrpc_set_wait()) set 0000000061aeae49 going to sleep for 41 seconds 00000100:00100000:2.0:1776205372.123143:0:183776:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000003e39b9a7 pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268574016:192.168.202.123@tcp:36:lfs.0 00000080:00200000:2.0:1776205372.123214:0:183776:0:(file.c:410:ll_file_release()) VFS Op:inode=[0x200002b11:0xe62:0x0](0000000084bcb99c) 00000002:00100000:2.0:1776205372.123263:0:183776:0:(mdc_request.c:944:mdc_close()) @@@ matched open req@000000004b171ca1 x1862480268573888/t34359738376(34359738376) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 1 fl Complete:RPQU/4/ffffffff rc 301/-1 job:'lfs.0' 00000020:00100000:2.0:1776205372.123291:0:183776:0:(genops.c:2339:obd_get_mod_rpc_slot()) lustre-MDT0000-mdc-ffff961f51c5c800: modify RPC slot 1 is allocated opc 35, max 7 00000100:00100000:2.0:1776205372.123297:0:183776:0:(client.c:742:ptlrpc_reassign_next_xid()) @@@ reassign xid req@0000000012c6369e x1862480268574144/t0(0) o35->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:23/10 lens 392/624 e 0 to 0 dl 0 ref 1 fl New:QU/0/ffffffff rc 0/-1 job:'' 00000100:00100000:2.0:1776205372.123317:0:183776:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268574144:192.168.202.123@tcp:35:lfs.0 00000100:00100000:2.0:1776205372.123375:0:183776:0:(client.c:2500:ptlrpc_set_wait()) set 000000009372ec9a going to sleep for 6 seconds 00010000:00010000:1.0:1776205372.132434:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00100000:2.0:1776205372.136436:0:183776:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job lfs:2784e426-5469-4962-abdd-5d421f2f60e1:183776:1862480268574144:192.168.202.123@tcp:35:lfs.0 00000002:00100000:2.0:1776205372.136468:0:183776:0:(mdc_request.c:854:mdc_free_open()) @@@ free open request, rq_replay=0 req@000000004b171ca1 x1862480268573888/t34359738376(34359738376) o101->lustre-MDT0000-mdc-ffff961f51c5c800@192.168.202.123@tcp:12/10 lens 528/600 e 0 to 0 dl 1776205414 ref 1 fl Complete:RQU/4/ffffffff rc 301/-1 job:'lfs.0' 00010000:00010000:2.0:1776205373.144560:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00000100:00080000:2.0:1776205373.592141:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205373.592147:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0000_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00080000:2.0:1776205373.592149:0:469:0:(pinger.c:251:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: level IDLE/11 force 0 force_next 0 deactive 0 pingable 1 suppress 0 00000100:00080000:2.0:1776205373.592151:0:469:0:(pinger.c:265:ptlrpc_pinger_process_import()) 2784e426-5469-4962-abdd-5d421f2f60e1->lustre-OST0001_UUID: not pinging (in recovery or recovery disabled: IDLE) 00000100:00100000:3.0:1776205373.592253:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268574208:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:3.0:1776205373.592369:0:2219:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0] 00000100:00100000:3.0:1776205373.592375:0:2219:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268574272:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205373.598430:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000cc73f843 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:2784e426-5469-4962-abdd-5d421f2f60e1:2219:1862480268574272:192.168.202.123@tcp:400:kworker/u8:4.0 00000100:00100000:2.0:1776205373.615146:0:2219:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000012c6369e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_01_00:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c:2219:1862480268574208:192.168.202.123@tcp:400:kworker/u8:4.0 00010000:00010000:1.0:1776205374.184992:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:2.0:1776205375.196114:0:163235:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) 00010000:00010000:1.0:1776205376.220933:0:163234:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue) Debug log: 333 lines, 333 kept, 0 dropped, 0 bad.