00010000:00010000:2.0F:1776205339.367577:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0F:1776205340.393036:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0F:1776205341.423232:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:0.0:1776205342.442868:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000488b21de pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263895744:0@lo:13:osp-pre-1-0.0
00000100:00100000:0.0:1776205342.442936:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205342.443025:0:127846:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263895744
00000100:00100000:0.0:1776205342.443066:0:127846:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 300
00000100:00100000:0.0:1776205342.443072:0:127846:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000059bb41fe pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263895744:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:0.0:1776205342.443123:0:127846:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:0.0:1776205342.443158:0:127846:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000059bb41fe pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263895744:12345-0@lo:13:osp-pre-1-0.0 Request processed in 86us (223us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205342.443165:0:127846:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 300
00000100:00100000:1.0:1776205342.448671:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000488b21de pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263895744:0@lo:13:osp-pre-1-0.0
00010000:00010000:2.0:1776205342.451639:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:1.0:1776205342.960231:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:1.0:1776205342.960278:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:1.0:1776205342.960320:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572672
00000100:00100000:1.0:1776205342.960374:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 57
00000100:00100000:1.0:1776205342.960381:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000002c4ec7f4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572672:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.960448:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000002c4ec7f4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572672:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 68us (171us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205342.960456:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 57
00000100:00100000:3.0F:1776205342.960538:0:138505:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572608
00000100:00100000:3.0:1776205342.960588:0:138505:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 89
00000100:00100000:3.0:1776205342.960592:0:138505:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000204b9c3c pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0002:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572608:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:3.0:1776205342.960620:0:138505:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000204b9c3c pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0002:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572608:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 27us (396us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205342.960627:0:138505:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 89
00000100:00100000:1.0:1776205342.961431:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000353b1ef4 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263895808:0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.961474:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205342.964856:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0000_UUID:3020:1862480263895872:0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205342.964922:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205342.964998:0:3020:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [3->2]
00000100:00100000:0.0:1776205342.965005:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000005b38f38 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0001_UUID:3020:1862480263895936:0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205342.965027:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205342.965146:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263895872
00000100:00100000:0.0:1776205342.965186:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263895936
00000100:00100000:0.0:1776205342.965204:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 58
00000100:00100000:0.0:1776205342.965209:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000f36187a4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3020:x1862480263895872:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205342.965252:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000f36187a4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3020:x1862480263895872:12345-0@lo:400:kworker/u8:0.0 Request processed in 43us (332us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205342.965259:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 58
00000100:00100000:0.0:1776205342.965274:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 59
00000100:00100000:0.0:1776205342.965277:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000000e702c31 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0001_UUID+5:3020:x1862480263895936:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205342.965297:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000000e702c31 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0001_UUID+5:3020:x1862480263895936:12345-0@lo:400:kworker/u8:0.0 Request processed in 19us (270us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205342.965302:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 59
00000100:00100000:0.0:1776205342.965346:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000005b38f38 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0001_UUID:3020:1862480263895936:0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205342.965355:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0000_UUID:3020:1862480263895872:0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.965627:0:3019:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [0->1]
00000100:00100000:1.0:1776205342.965635:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000035d6a614 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263896000:0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.965664:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205342.965694:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263895808
00000100:00100000:1.0:1776205342.965731:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 90
00000100:00100000:1.0:1776205342.965735:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000a20a87a4 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263895808:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.965768:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000a20a87a4 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263895808:12345-0@lo:400:kworker/u8:0.0 Request processed in 32us (4294us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205342.965774:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 90
00000100:00100000:1.0:1776205342.965808:0:128059:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896000
00000100:00100000:1.0:1776205342.965832:0:128059:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 507
00000100:00100000:1.0:1776205342.965836:0:128059:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000000a867b18 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263896000:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.965862:0:128059:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000000a867b18 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263896000:12345-0@lo:400:kworker/u8:0.0 Request processed in 25us (197us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205342.965877:0:128059:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 507
00000100:00100000:1.0:1776205342.965905:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000035d6a614 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263896000:0@lo:400:kworker/u8:0.0
00000100:00100000:1.0:1776205342.965914:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000353b1ef4 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263895808:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205342.969279:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000353b1ef4 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263896064:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205342.969343:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205342.969390:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896064
00000100:00100000:3.0:1776205342.969422:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 60
00000100:00100000:3.0:1776205342.969427:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000035d6a614 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263896064:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205342.969466:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000035d6a614 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263896064:12345-0@lo:400:kworker/u8:0.0 Request processed in 39us (125us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205342.969473:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 60
00000100:00100000:3.0:1776205342.969505:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000353b1ef4 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263896064:0@lo:400:kworker/u8:0.0
00010000:00010000:2.0:1776205343.463084:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1776205344.494370:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205345.521185:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205346.537460:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1776205347.559786:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:2.0:1776205347.561090:0:3021:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [2->3]
00000100:00100000:2.0:1776205347.561113:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000488b21de pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263896128:0@lo:13:osp-pre-1-0.0
00000100:00100000:2.0:1776205347.561181:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205347.562709:0:134295:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896128
00000100:00100000:0.0:1776205347.562761:0:134295:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 301
00000100:00100000:0.0:1776205347.562766:0:134295:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000c389476b pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263896128:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:0.0:1776205347.562904:0:134295:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:0.0:1776205347.563156:0:134295:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000c389476b pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263896128:12345-0@lo:13:osp-pre-1-0.0 Request processed in 388us (1977us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205347.563162:0:134295:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 301
00000100:00100000:3.0:1776205347.563254:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000488b21de pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263896128:0@lo:13:osp-pre-1-0.0
00000100:00100000:0.0:1776205348.071628:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000009edd5009 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0000_UUID:3018:1862480263896256:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205348.071715:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205348.071756:0:3018:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0]
00000100:00100000:0.0:1776205348.071762:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263896320:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205348.071782:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205348.071846:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896256
00000100:00100000:2.0:1776205348.071907:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896320
00000100:00100000:2.0:1776205348.071928:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 61
00000100:00100000:2.0:1776205348.071933:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000488b21de pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0000_UUID+5:3018:x1862480263896256:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205348.072004:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000488b21de pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0000_UUID+5:3018:x1862480263896256:12345-0@lo:400:kworker/u8:1.0 Request processed in 70us (290us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205348.072011:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 61
00000100:00100000:2.0:1776205348.072029:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 62
00000100:00100000:2.0:1776205348.072033:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000ae931035 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263896320:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205348.072055:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000ae931035 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263896320:12345-0@lo:400:kworker/u8:1.0 Request processed in 22us (274us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205348.072061:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 62
00000100:00100000:2.0:1776205348.072099:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263896320:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205348.072110:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000009edd5009 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0000_UUID:3018:1862480263896256:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.073150:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000bf62f96f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263896384:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.073197:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205348.073221:0:3020:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [3->2]
00000100:00100000:1.0:1776205348.073227:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000c67f3508 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3020:1862480263896192:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.073250:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205348.073309:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000008cbdc148 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-MDT0000_UUID:3020:1862480263896448:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.073332:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205348.073371:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896448
00000100:00100000:1.0:1776205348.073402:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 63
00000100:00100000:1.0:1776205348.073407:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000459164e6 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-MDT0000_UUID+5:3020:x1862480263896448:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.073444:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000459164e6 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-MDT0000_UUID+5:3020:x1862480263896448:12345-0@lo:400:kworker/u8:1.0 Request processed in 37us (112us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205348.073449:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 63
00000100:00100000:1.0:1776205348.073480:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000008cbdc148 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-MDT0000_UUID:3020:1862480263896448:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205348.073538:0:127844:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896384
00000100:00100000:0.0:1776205348.073571:0:127844:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 508
00000100:00100000:0.0:1776205348.073575:0:127844:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000985b9809 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263896384:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205348.073603:0:127844:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000985b9809 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263896384:12345-0@lo:400:kworker/u8:1.0 Request processed in 28us (407us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205348.073608:0:127844:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 508
00000100:00100000:1.0:1776205348.077507:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000bf62f96f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263896384:0@lo:400:kworker/u8:1.0
00000100:00100000:3.0:1776205348.080035:0:3012:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:3.0:1776205348.080086:0:3012:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:3.0:1776205348.080129:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572800
00000100:00100000:3.0:1776205348.080176:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 64
00000100:00100000:3.0:1776205348.080183:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000353b1ef4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572800:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:3.0:1776205348.080254:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000353b1ef4 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572800:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 70us (170us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205348.080280:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 64
00000100:00100000:1.0:1776205348.081966:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896192
00000100:00100000:1.0:1776205348.082008:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572736
00000100:00100000:1.0:1776205348.082022:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 91
00000100:00100000:1.0:1776205348.082027:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000adb487b0 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3020:x1862480263896192:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205348.082101:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000adb487b0 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3020:x1862480263896192:12345-0@lo:400:kworker/u8:1.0 Request processed in 73us (8850us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205348.082108:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 91
00000100:00100000:1.0:1776205348.082132:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 92
00000100:00100000:1.0:1776205348.082136:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000069cd3c8e pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572736:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:1.0:1776205348.082160:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000069cd3c8e pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572736:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 24us (2136us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205348.082166:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 92
00000100:00100000:1.0:1776205348.082308:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000c67f3508 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3020:1862480263896192:0@lo:400:kworker/u8:1.0
00010000:00010000:3.0:1776205348.583080:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205349.608781:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205350.631151:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205351.655322:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:3.0:1776205352.680172:0:3019:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [0->1]
00000100:00100000:3.0:1776205352.680195:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263896512:0@lo:13:osp-pre-1-0.0
00000100:00100000:3.0:1776205352.680291:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205352.680338:0:134295:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896512
00000100:00100000:3.0:1776205352.680379:0:134295:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 302
00000100:00100000:3.0:1776205352.680385:0:134295:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000005b38f38 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263896512:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:3.0:1776205352.680416:0:134295:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:3.0:1776205352.680453:0:134295:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000005b38f38 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263896512:12345-0@lo:13:osp-pre-1-0.0 Request processed in 67us (163us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205352.680460:0:134295:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 302
00000100:00100000:3.0:1776205352.680503:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263896512:0@lo:13:osp-pre-1-0.0
00010000:00010000:2.0:1776205352.693164:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000400:00000080:1.0:1776205353.113202:0:140979:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648
00000001:02000400:1.0:1776205353.113207:0:140979: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:00100000:3.0:1776205353.193260:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000006a91ab6f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0001_UUID:3021:1862480263896704:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193324:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.193353:0:3021:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [2->3]
00000100:00100000:3.0:1776205353.193359:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000be5c8371 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263896640:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193380:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.193392:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000ab69255d pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-MDT0000_UUID:3021:1862480263896896:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193411:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.193443:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896704
00000100:00100000:3.0:1776205353.193482:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896640
00000100:00100000:3.0:1776205353.193504:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896896
00000100:00100000:3.0:1776205353.193515:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 65
00000100:00100000:3.0:1776205353.193520:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000d101fdb9 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-OST0001_UUID+5:3021:x1862480263896704:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193562:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000d101fdb9 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-OST0001_UUID+5:3021:x1862480263896704:12345-0@lo:400:kworker/u8:0.0 Request processed in 41us (239us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.193568:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 65
00000100:00100000:3.0:1776205353.193582:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 66
00000100:00100000:3.0:1776205353.193584:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000053398608 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263896640:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193603:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000053398608 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263896640:12345-0@lo:400:kworker/u8:0.0 Request processed in 18us (223us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.193608:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 66
00000100:00100000:3.0:1776205353.193632:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 67
00000100:00100000:3.0:1776205353.193635:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000e398f55a pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-MDT0000_UUID+5:3021:x1862480263896896:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193656:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000e398f55a pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:lustre-MDT0000-lwp-MDT0000_UUID+5:3021:x1862480263896896:12345-0@lo:400:kworker/u8:0.0 Request processed in 21us (245us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.193661:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 67
00000100:00100000:3.0:1776205353.193692:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000be5c8371 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263896640:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193700:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000ab69255d pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-MDT0000_UUID:3021:1862480263896896:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193707:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000006a91ab6f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0001_UUID:3021:1862480263896704:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193748:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000060b5a5d5 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263896768:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193826:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.193844:0:3018:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [1->0]
00000100:00100000:3.0:1776205353.193849:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3018:1862480263896576:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193874:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.193895:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000001451b77 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263896832:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.193915:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:3.0:1776205353.195371:0:128059:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896768
00000100:00100000:3.0:1776205353.195419:0:128059:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896832
00000100:00100000:3.0:1776205353.195438:0:128059:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 509
00000100:00100000:3.0:1776205353.195443:0:128059:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000006a91ab6f pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263896768:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.195507:0:128059:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000006a91ab6f pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263896768:12345-0@lo:400:kworker/u8:0.0 Request processed in 64us (1681us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.195514:0:128059:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 509
00000100:00100000:3.0:1776205353.195527:0:128059:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 510
00000100:00100000:3.0:1776205353.195530:0:128059:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000ab69255d pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263896832:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.195555:0:128059:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000ab69255d pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_003:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263896832:12345-0@lo:400:kworker/u8:0.0 Request processed in 24us (1640us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.195561:0:128059:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 510
00000100:00100000:3.0:1776205353.195600:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000001451b77 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263896832:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.195611:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000060b5a5d5 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263896768:0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.195663:0:138503:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896576
00000100:00100000:3.0:1776205353.195690:0:138503:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 93
00000100:00100000:3.0:1776205353.195694:0:138503:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000033727224 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3018:x1862480263896576:12345-0@lo:400:kworker/u8:0.0
00000100:00100000:3.0:1776205353.195724:0:138503:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000033727224 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3018:x1862480263896576:12345-0@lo:400:kworker/u8:0.0 Request processed in 30us (1851us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.195730:0:138503:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 93
00000100:00100000:3.0:1776205353.195762:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000d888af04 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3018:1862480263896576:0@lo:400:kworker/u8:0.0
00000100:00100000:0.0:1776205353.207644:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205353.207700:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205353.207739:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572928
00000100:00100000:0.0:1776205353.207792:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 68
00000100:00100000:0.0:1776205353.207799:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000014b80d2b pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572928:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:0.0:1776205353.207881:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000014b80d2b pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268572928:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 82us (181us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205353.207890:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 68
00000100:00100000:3.0:1776205353.211873:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572864
00000100:00100000:3.0:1776205353.211986:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 94
00000100:00100000:3.0:1776205353.211994:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000008c2d2478 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572864:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:3.0:1776205353.212072:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000008c2d2478 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268572864:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 78us (4438us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205353.212080:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 94
00010000:00010000:1.0:1776205353.703271:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205354.733743:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205355.752392:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205356.775865:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:2.0:1776205357.799481:0:3020:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [3->2]
00000100:00100000:2.0:1776205357.799513:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000060b5a5d5 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263896960:0@lo:13:osp-pre-1-0.0
00000100:00100000:2.0:1776205357.799613:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00010000:00010000:0.0:1776205357.799916:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:3.0:1776205357.801812:0:127846:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263896960
00000100:00100000:3.0:1776205357.801914:0:127846:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 303
00000100:00100000:3.0:1776205357.801926:0:127846:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000009edd5009 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263896960:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:3.0:1776205357.802021:0:127846:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:3.0:1776205357.802140:0:127846:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000009edd5009 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263896960:12345-0@lo:13:osp-pre-1-0.0 Request processed in 217us (2529us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205357.802148:0:127846:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 303
00000100:00100000:2.0:1776205357.802671:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000060b5a5d5 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263896960:0@lo:13:osp-pre-1-0.0
00000100:00100000:1.0:1776205358.311861:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0001_UUID:3020:1862480263897152:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.311928:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205358.311988:0:3020:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [3->2]
00000100:00100000:1.0:1776205358.311994:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897216:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312019:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205358.312057:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897152
00000100:00100000:1.0:1776205358.312114:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 69
00000100:00100000:1.0:1776205358.312120:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000f23ed8bb pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0001_UUID+5:3020:x1862480263897152:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312166:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000f23ed8bb pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0001_UUID+5:3020:x1862480263897152:12345-0@lo:400:kworker/u8:1.0 Request processed in 45us (238us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.312172:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 69
00000100:00100000:1.0:1776205358.312196:0:128060:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897216
00000100:00100000:1.0:1776205358.312236:0:128060:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 511
00000100:00100000:1.0:1776205358.312239:0:128060:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000fb8f44d1 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897216:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312269:0:128060:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000fb8f44d1 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897216:12345-0@lo:400:kworker/u8:1.0 Request processed in 28us (250us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.312275:0:128060:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 511
00000100:00100000:1.0:1776205358.312314:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897216:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312324:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-lwp-OST0001_UUID:3020:1862480263897152:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312489:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-OST0000_UUID:3019:1862480263897088:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312518:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205358.312540:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263897344:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312560:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205358.312586:0:3019:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [0->1]
00000100:00100000:0.0:1776205358.312591:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000b2a99e6f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263897024:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312614:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205358.312628:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263897280:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312645:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205358.312664:0:138503:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897024
00000100:00100000:0.0:1776205358.312686:0:138503:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 95
00000100:00100000:0.0:1776205358.312690:0:138503:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000777eebeb pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263897024:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.312718:0:138503:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000777eebeb pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263897024:12345-0@lo:400:kworker/u8:1.0 Request processed in 28us (104us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205358.312725:0:138503:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 95
00000100:00100000:0.0:1776205358.312756:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000b2a99e6f pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263897024:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312816:0:127844:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897280
00000100:00100000:1.0:1776205358.312889:0:127844:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 512
00000100:00100000:1.0:1776205358.312893:0:127844:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000756828d4 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263897280:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.312932:0:127844:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000756828d4 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263897280:12345-0@lo:400:kworker/u8:1.0 Request processed in 38us (286us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.312938:0:127844:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 512
00000100:00100000:1.0:1776205358.313042:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897088
00000100:00100000:1.0:1776205358.313213:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897344
00000100:00100000:1.0:1776205358.313377:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 70
00000100:00100000:1.0:1776205358.313382:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000002b334ae8 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3019:x1862480263897088:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.313414:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000002b334ae8 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3019:x1862480263897088:12345-0@lo:400:kworker/u8:1.0 Request processed in 32us (897us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.313420:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 70
00000100:00100000:1.0:1776205358.313431:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 71
00000100:00100000:1.0:1776205358.313434:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000faa0a5d0 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263897344:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.313457:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000faa0a5d0 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263897344:12345-0@lo:400:kworker/u8:1.0 Request processed in 23us (897us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.313462:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 71
00000100:00100000:1.0:1776205358.313859:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263897280:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.313872:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-OST0000_UUID:3019:1862480263897088:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205358.313880:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263897344:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205358.314049:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205358.314321:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:1.0:1776205358.317661:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268572992
00000100:00100000:1.0:1776205358.317723:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 96
00000100:00100000:1.0:1776205358.317730:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000006007dd58 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2217:x1862480268572992:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:1.0:1776205358.317800:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000006007dd58 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2217:x1862480268572992:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 71us (3481us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205358.317807:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 96
00000100:00100000:2.0:1776205358.319846:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573056
00000100:00100000:2.0:1776205358.319974:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 72
00000100:00100000:2.0:1776205358.319980:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000f27116da pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:2784e426-5469-4962-abdd-5d421f2f60e1+14:2217:x1862480268573056:12345-192.168.202.23@tcp:400:kworker/u8:0.0
00000100:00100000:2.0:1776205358.320053:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000f27116da pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:2784e426-5469-4962-abdd-5d421f2f60e1+14:2217:x1862480268573056:12345-192.168.202.23@tcp:400:kworker/u8:0.0 Request processed in 72us (6004us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205358.320060:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 72
00010000:00010000:0.0:1776205358.829826:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205359.855006:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000400:00000080:0.0:1776205360.443080:0:141320:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648
00000001:02000400:0.0:1776205360.443086:0:141320:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: setting create_count to 100200:
00010000:00010000:0.0:1776205360.872961:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205361.903357:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000400:00000080:2.0:1776205362.058455:0:141368:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648
00000001:02000400:2.0:1776205362.058462:0:141368:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: -result- count: 9984 with max: 20000, expecting: 9984
00010000:00010000:2.0:1776205362.922744:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:2.0:1776205362.922760:0:3021:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [2->3]
00000100:00100000:2.0:1776205362.922779:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263897408:0@lo:13:osp-pre-1-0.0
00000100:00100000:2.0:1776205362.922847:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205362.922901:0:134295:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897408
00000100:00100000:2.0:1776205362.922963:0:134295:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 304
00000100:00100000:2.0:1776205362.922969:0:134295:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000017d5dd63 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263897408:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:2.0:1776205362.923014:0:134295:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:2.0:1776205362.923337:0:134295:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000017d5dd63 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263897408:12345-0@lo:13:osp-pre-1-0.0 Request processed in 366us (490us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205362.923345:0:134295:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 304
00000100:00100000:2.0:1776205362.923387:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263897408:0@lo:13:osp-pre-1-0.0
00000100:00100000:1.0:1776205363.432162:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0000_UUID:3018:1862480263897536:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432232:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205363.432256:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000edd25d12 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-MDT0000_UUID:3018:1862480263897792:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432276:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205363.432298:0:3018:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0]
00000100:00100000:1.0:1776205363.432304:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263897600:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432326:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205363.432358:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897536
00000100:00100000:1.0:1776205363.432396:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897792
00000100:00100000:1.0:1776205363.432404:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897600
00000100:00100000:1.0:1776205363.432416:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 73
00000100:00100000:1.0:1776205363.432420:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000950d6278 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3018:x1862480263897536:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432464:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000950d6278 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0000_UUID+5:3018:x1862480263897536:12345-0@lo:400:kworker/u8:1.0 Request processed in 43us (233us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205363.432470:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 73
00000100:00100000:1.0:1776205363.432499:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 74
00000100:00100000:1.0:1776205363.432502:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000003df7bff pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3018:x1862480263897792:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432538:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000003df7bff pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3018:x1862480263897792:12345-0@lo:400:kworker/u8:1.0 Request processed in 35us (261us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205363.432543:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 74
00000100:00100000:1.0:1776205363.432553:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 75
00000100:00100000:1.0:1776205363.432557:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000b2a99e6f pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263897600:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432580:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000b2a99e6f pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263897600:12345-0@lo:400:kworker/u8:1.0 Request processed in 22us (254us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205363.432598:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 75
00000100:00100000:1.0:1776205363.432636:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263897600:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432645:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0000_UUID:3018:1862480263897536:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.432652:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000edd25d12 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-MDT0000_UUID:3018:1862480263897792:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.432730:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897664:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.432760:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205363.432787:0:3020:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [3->2]
00000100:00100000:0.0:1776205363.432792:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3020:1862480263897472:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.432817:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205363.432828:0:3020:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897728:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.432844:0:3020:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205363.432868:0:128060:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897664
00000100:00100000:0.0:1776205363.432891:0:128060:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897728
00000100:00100000:0.0:1776205363.432907:0:128060:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 513
00000100:00100000:0.0:1776205363.432910:0:128060:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000baa187f7 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897664:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.432962:0:128060:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000baa187f7 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897664:12345-0@lo:400:kworker/u8:1.0 Request processed in 28us (179us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205363.432968:0:128060:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 513
00000100:00100000:0.0:1776205363.432980:0:128060:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 514
00000100:00100000:0.0:1776205363.432983:0:128060:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000000a674be0 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897728:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.433006:0:128060:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000000a674be0 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3020:x1862480263897728:12345-0@lo:400:kworker/u8:1.0 Request processed in 22us (161us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205363.433012:0:128060:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 514
00000100:00100000:0.0:1776205363.433039:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897728:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.433046:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:lustre-MDT0000-mdtlov_UUID:3020:1862480263897664:0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.434757:0:138503:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897472
00000100:00100000:1.0:1776205363.434825:0:138503:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 97
00000100:00100000:1.0:1776205363.434831:0:138503:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000a55b92db pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3020:x1862480263897472:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:1.0:1776205363.434912:0:138503:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000a55b92db pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3020:x1862480263897472:12345-0@lo:400:kworker/u8:1.0 Request processed in 80us (2094us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205363.434919:0:138503:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 97
00000100:00100000:2.0:1776205363.435050:0:3020:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_02:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3020:1862480263897472:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205363.450009:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205363.450034:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205363.450069:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573120
00000100:00100000:0.0:1776205363.450104:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 98
00000100:00100000:0.0:1776205363.450109:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000004806c9b9 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268573120:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:0.0:1776205363.450157:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000004806c9b9 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268573120:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 48us (156us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205363.450162:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 98
00000100:00100000:3.0:1776205363.451005:0:138512:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573184
00000100:00100000:3.0:1776205363.451046:0:138512:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 76
00000100:00100000:3.0:1776205363.451051:0:138512:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000ebb38ac0 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268573184:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:3.0:1776205363.451100:0:138512:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000ebb38ac0 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_000:2784e426-5469-4962-abdd-5d421f2f60e1+14:2219:x1862480268573184:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 49us (1065us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205363.451108:0:138512:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 76
00010000:00010000:3.0:1776205363.945220:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205364.973976:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1776205365.991146:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205367.017066:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1776205368.041145:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:0.0:1776205368.041184:0:3018:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0]
00000100:00100000:0.0:1776205368.041205:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263897856:0@lo:13:osp-pre-1-0.0
00000100:00100000:0.0:1776205368.041271:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.041341:0:127846:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897856
00000100:00100000:2.0:1776205368.041379:0:127846:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 305
00000100:00100000:2.0:1776205368.041383:0:127846:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000b9682ab6 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263897856:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:2.0:1776205368.041411:0:127846:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:2.0:1776205368.041451:0:127846:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000b9682ab6 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263897856:12345-0@lo:13:osp-pre-1-0.0 Request processed in 67us (182us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.041457:0:127846:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 305
00000100:00100000:2.0:1776205368.041652:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263897856:0@lo:13:osp-pre-1-0.0
00000100:00100000:2.0:1776205368.552690:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000005c48185e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263897984:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.552757:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.552781:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000c67f3508 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-MDT0000_UUID:3021:1862480263898240:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.552804:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.552826:0:3021:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 2 async RPCs [2->3]
00000100:00100000:2.0:1776205368.552832:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3021:1862480263897920:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.552860:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.552875:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000027de7507 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263898176:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.552899:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.552922:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000b3b01d6c pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263898048:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.552969:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.552990:0:3018:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [1->0]
00000100:00100000:2.0:1776205368.552996:0:3018:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000e178a1ec pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263898112:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553034:0:3018:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1776205368.553081:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897984
00000100:00100000:2.0:1776205368.553118:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898240
00000100:00100000:2.0:1776205368.553128:0:138514:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898048
00000100:00100000:2.0:1776205368.553139:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 77
00000100:00100000:2.0:1776205368.553144:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000bf62f96f pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263897984:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553189:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000bf62f96f pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263897984:12345-0@lo:400:kworker/u8:1.0 Request processed in 44us (433us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553206:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 77
00000100:00100000:2.0:1776205368.553223:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 78
00000100:00100000:2.0:1776205368.553226:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000008cbdc148 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-MDT0000_UUID+5:3021:x1862480263898240:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553252:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000008cbdc148 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-MDT0000_UUID+5:3021:x1862480263898240:12345-0@lo:400:kworker/u8:1.0 Request processed in 25us (448us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553257:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 78
00000100:00100000:2.0:1776205368.553267:0:138514:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 79
00000100:00100000:2.0:1776205368.553270:0:138514:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000047ff5268 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263898048:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553296:0:138514:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000047ff5268 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_002:lustre-MDT0000-lwp-OST0001_UUID+5:3018:x1862480263898048:12345-0@lo:400:kworker/u8:1.0 Request processed in 26us (329us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553302:0:138514:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 79
00000100:00100000:2.0:1776205368.553322:0:138503:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263897920
00000100:00100000:2.0:1776205368.553346:0:138503:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 99
00000100:00100000:2.0:1776205368.553349:0:138503:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000008cad106d pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3021:x1862480263897920:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553379:0:138503:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000008cad106d pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3021:x1862480263897920:12345-0@lo:400:kworker/u8:1.0 Request processed in 28us (519us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553385:0:138503:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 99
00000100:00100000:2.0:1776205368.553412:0:127844:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898176
00000100:00100000:2.0:1776205368.553436:0:127844:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898112
00000100:00100000:2.0:1776205368.553453:0:127844:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 515
00000100:00100000:2.0:1776205368.553457:0:127844:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000053fe1d81 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263898176:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553499:0:127844:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000053fe1d81 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3021:x1862480263898176:12345-0@lo:400:kworker/u8:1.0 Request processed in 42us (600us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553505:0:127844:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 515
00000100:00100000:2.0:1776205368.553529:0:127844:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 516
00000100:00100000:2.0:1776205368.553539:0:127844:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000b2c6c8a4 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263898112:12345-0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553569:0:127844:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000b2c6c8a4 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_002:lustre-MDT0000-mdtlov_UUID+5:3018:x1862480263898112:12345-0@lo:400:kworker/u8:1.0 Request processed in 30us (536us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.553574:0:127844:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 516
00000100:00100000:2.0:1776205368.553628:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000e178a1ec pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-mdtlov_UUID:3018:1862480263898112:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553640:0:3018:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000b3b01d6c pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_00:lustre-MDT0000-lwp-OST0001_UUID:3018:1862480263898048:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553668:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000a9a412dd pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3021:1862480263897920:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553695:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000027de7507 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-mdtlov_UUID:3021:1862480263898176:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553703:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000005c48185e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263897984:0@lo:400:kworker/u8:1.0
00000100:00100000:2.0:1776205368.553710:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000c67f3508 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-MDT0000_UUID:3021:1862480263898240:0@lo:400:kworker/u8:1.0
00000100:00100000:0.0:1776205368.556222:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205368.556276:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:2.0:1776205368.556389:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573312
00000100:00100000:2.0:1776205368.556444:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 80
00000100:00100000:2.0:1776205368.556450:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000640e41d3 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:2217:x1862480268573312:12345-192.168.202.23@tcp:400:kworker/u8:2.0
00000100:00100000:2.0:1776205368.556540:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000640e41d3 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:2217:x1862480268573312:12345-192.168.202.23@tcp:400:kworker/u8:2.0 Request processed in 89us (338us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205368.556548:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 80
00000100:00100000:3.0:1776205368.558606:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573248
00000100:00100000:3.0:1776205368.558670:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 100
00000100:00100000:3.0:1776205368.558677:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000b907ac00 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2217:x1862480268573248:12345-192.168.202.23@tcp:400:kworker/u8:2.0
00000100:00100000:3.0:1776205368.558755:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000b907ac00 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2217:x1862480268573248:12345-192.168.202.23@tcp:400:kworker/u8:2.0 Request processed in 78us (2480us total) trans 0 rc 0/0
00000100:00100000:3.0:1776205368.558776:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 100
00010000:00010000:2.0:1776205369.063275:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205370.087302:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1776205371.112692:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000400:00000080:1.0:1776205371.169768:0:141661:0:(module.c:221:libcfs_ioctl()) libcfs ioctl cmd 3221775648
00000001:02000400:1.0:1776205371.169774:0:141661:0:(debug.c:702:libcfs_debug_mark_buffer()) DEBUG MARKER: == sanity test 831: throttling unlink/setattr queuing on OSP ========================================================== 18:22:49 (1776205369)
00000100:00100000:3.0:1776205372.081269:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:3.0:1776205372.081392:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573376
00000100:00100000:3.0:1776205372.081457:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 29
00000100:00100000:3.0:1776205372.081465:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000001451b77 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+14:183775:x1862480268573376:12345-192.168.202.23@tcp:101:lfs.0
00010000:00010000:3.0:1776205372.081488:0:138513:0:(ldlm_lockd.c:1248:ldlm_handle_enqueue0()) ### server-side enqueue handler START
00010000:00010000:3.0:1776205372.081508:0:138513:0:(ldlm_lockd.c:1318:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 0000000003498852/0xb8d734e6f36e391b lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0xc31d44e5847febab expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081564:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 4 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081579:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081592:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081606:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081613:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081620:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081694:0:138513:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081709:0:138513:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 2/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081716:0:138513:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081723:0:138513:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 00000000dd95444f already unused, calling callback (0000000077bc9909)
00010000:00010000:3.0:1776205372.081726:0:138513:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081734:0:138513:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 4/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081745:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:3.0:1776205372.081748:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:3.0:1776205372.081753:0:138513:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081759:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000dd95444f/0xb8d734e6f36e3922 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081770:0:138513:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081777:0:138513:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081783:0:138513:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081799:0:138513:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000000cb623d1 already unused, calling callback (0000000077bc9909)
00010000:00010000:3.0:1776205372.081802:0:138513:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081807:0:138513:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 4/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081816:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x7a6a6e09 (0000000019127486)
00010000:00010000:3.0:1776205372.081819:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:3.0:1776205372.081821:0:138513:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 2/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081827:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000000cb623d1/0xb8d734e6f36e3929 lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081862:0:138513:0:(ldlm_lockd.c:1484:ldlm_handle_enqueue0()) ### server-side enqueue handler, sending reply (err=301, rc=0) ns: mdt-lustre-MDT0000_UUID lock: 0000000003498852/0xb8d734e6f36e391b lrc: 1/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febab expref: 15 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081869:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 0000000003498852/0xb8d734e6f36e391b lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febab expref: 15 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.081879:0:138513:0:(ldlm_lockd.c:1565:ldlm_handle_enqueue0()) ### server-side enqueue handler END (lock 0000000003498852, rc 0)
00000100:00100000:3.0:1776205372.081933:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000001451b77 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+14:183775:x1862480268573376:12345-192.168.202.23@tcp:101:lfs.0 Request processed in 468us (672us total) trans 0 rc 301/301
00000100:00100000:3.0:1776205372.081961:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 29
00000100:00100000:2.0:1776205372.085468:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:2.0:1776205372.085510:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573440
00000100:00100000:2.0:1776205372.085556:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 30
00000100:00100000:2.0:1776205372.085561:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000c67f3508 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:183775:x1862480268573440:12345-192.168.202.23@tcp:101:lfs.0
00010000:00010000:2.0:1776205372.085580:0:139561:0:(ldlm_lockd.c:1248:ldlm_handle_enqueue0()) ### server-side enqueue handler START
00010000:00010000:2.0:1776205372.085601:0:139561:0:(ldlm_lockd.c:1318:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3930 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0xc31d44e5847febb2 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085645:0:139561:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 4 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085655:0:139561:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085662:0:139561:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085670:0:139561:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085674:0:139561:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085678:0:139561:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085733:0:139561:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085737:0:139561:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 2/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085741:0:139561:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085745:0:139561:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000003dce4d22 already unused, calling callback (0000000077bc9909)
00010000:00010000:2.0:1776205372.085753:0:139561:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085758:0:139561:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 4/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085766:0:139561:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:2.0:1776205372.085768:0:139561:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:2.0:1776205372.085771:0:139561:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085774:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000003dce4d22/0xb8d734e6f36e3937 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085781:0:139561:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085783:0:139561:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085787:0:139561:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085790:0:139561:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 0000000009d16bb3 already unused, calling callback (0000000077bc9909)
00010000:00010000:2.0:1776205372.085791:0:139561:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085794:0:139561:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 4/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085797:0:139561:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x7a6a6e09 (0000000040927752)
00010000:00010000:2.0:1776205372.085802:0:139561:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:2.0:1776205372.085804:0:139561:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 2/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085807:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e393e lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085833:0:139561:0:(ldlm_lockd.c:1484:ldlm_handle_enqueue0()) ### server-side enqueue handler, sending reply (err=301, rc=0) ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3930 lrc: 1/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febb2 expref: 15 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085837:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3930 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febb2 expref: 15 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.085843:0:139561:0:(ldlm_lockd.c:1565:ldlm_handle_enqueue0()) ### server-side enqueue handler END (lock 000000001ffe81a5, rc 0)
00000100:00100000:2.0:1776205372.085884:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000c67f3508 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+14:183775:x1862480268573440:12345-192.168.202.23@tcp:101:lfs.0 Request processed in 321us (422us total) trans 0 rc 301/301
00000100:00100000:2.0:1776205372.085890:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 30
00000100:00100000:2.0:1776205372.087420:0:3012:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:2.0:1776205372.088552:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573504
00000100:00100000:2.0:1776205372.088664:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 31
00000100:00100000:2.0:1776205372.088670:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000005c48185e pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+14:183775:x1862480268573504:12345-192.168.202.23@tcp:101:lfs.0
00010000:00010000:2.0:1776205372.088700:0:138513:0:(ldlm_lockd.c:1248:ldlm_handle_enqueue0()) ### server-side enqueue handler START
00010000:00010000:2.0:1776205372.088718:0:138513:0:(ldlm_lockd.c:1318:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e3945 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0xc31d44e5847febb9 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.088778:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 3/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 4 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.088791:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.088814:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00000004:00200000:2.0:1776205372.088874:0:138513:0:(mdt_handler.c:912:mdt_pack_attr2body()) [0x200000007:0x1:0x0]: returning size 25088
00000004:00200000:2.0:1776205372.088878:0:138513:0:(mdt_handler.c:1523:mdt_getattr_internal()) dirent count 112 stripe count 1 MDT count 1
00000004:00010000:2.0:1776205372.088980:0:138513:0:(mdt_handler.c:2353:mdt_getattr_name_lock()) ### Returning lock to client ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.089003:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e3945 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febb9 expref: 16 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.089017:0:138513:0:(ldlm_lockd.c:1484:ldlm_handle_enqueue0()) ### server-side enqueue handler, sending reply (err=0, rc=0) ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 3 type: IBT gid 0 flags: 0x40200000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febb9 expref: 15 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.089024:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:2.0:1776205372.089027:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 13
00010000:00010000:2.0:1776205372.089030:0:138513:0:(ldlm_lockd.c:1565:ldlm_handle_enqueue0()) ### server-side enqueue handler END (lock 00000000af25c130, rc 0)
00000100:00100000:2.0:1776205372.089079:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000005c48185e pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+15:183775:x1862480268573504:12345-192.168.202.23@tcp:101:lfs.0 Request processed in 409us (1665us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205372.089086:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 31
00000100:00100000:3.0:1776205372.096559:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:2.0:1776205372.096870:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573632
00000100:00100000:2.0:1776205372.097233:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 32
00000100:00100000:2.0:1776205372.097241:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000be5c8371 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+15:183775:x1862480268573632:12345-192.168.202.23@tcp:36:lfs.0
00010000:00010000:2.0:1776205372.097298:0:138513:0:(ldlm_lockd.c:1720:ldlm_request_cancel()) ### server-side cancel handler START: 1 locks, starting at 0
00010000:00010000:2.0:1776205372.097324:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e394c lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x0 bits 0x13/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a01000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febb9 expref: 15 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097349:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:2.0:1776205372.097354:0:138513:0:(ldlm_lockd.c:1782:ldlm_request_cancel()) ### server-side cancel handler END
00010000:00010000:2.0:1776205372.097446:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CW) ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,1 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097461:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,1 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097471:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,1 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097485:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PW) ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,1 mode: --/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097492:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,1 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.097497:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,1 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00000004:00200000:2.0:1776205372.098242:0:138513:0:(mdt_handler.c:912:mdt_pack_attr2body()) [0x200002b11:0xe62:0x0]: returning size 512
00010000:00010000:2.0:1776205372.098252:0:138513:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CW) ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,1 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098261:0:138513:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 2/0,0 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098268:0:138513:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,0 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098285:0:138513:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000001ffe81a5 already unused, calling callback (0000000077bc9909)
00010000:00010000:2.0:1776205372.098289:0:138513:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 3/0,0 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098296:0:138513:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 4/0,0 mode: CW/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098307:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:2.0:1776205372.098310:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:2.0:1776205372.098313:0:138513:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 2/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.098319:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3953 lrc: 0/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 3 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00000004:00010000:2.0:1776205372.098331:0:138513:0:(mdt_handler.c:3992:mdt_save_lock()) ### save lock request 00000000be5c8371 reply state 00000000a659cd35 transno 34359738375
 ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,1 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00000100:00100000:2.0:1776205372.098432:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000be5c8371 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+16:183775:x1862480268573632:12345-192.168.202.23@tcp:36:lfs.0 Request processed in 1189us (1881us total) trans 34359738375 rc 0/0
00000100:00100000:2.0:1776205372.098451:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 32
00010000:00010000:3.0:1776205372.100612:0:3005:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PW) ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,1 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100637:0:3005:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 2/0,0 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100644:0:3005:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,0 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100650:0:3005:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 0000000009d16bb3 already unused, calling callback (0000000077bc9909)
00010000:00010000:3.0:1776205372.100654:0:3005:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 3/0,0 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100662:0:3005:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 4/0,0 mode: PW/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100676:0:3005:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x7a6a6e09 (0000000040927752)
00010000:00010000:3.0:1776205372.100679:0:3005:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:3.0:1776205372.100695:0:3005:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 2/0,0 mode: --/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.100701:0:3005:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 0000000009d16bb3/0xb8d734e6f36e395a lrc: 0/0,0 mode: --/PW res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.135194:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:3.0:1776205372.156314:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:2.0:1776205372.157053:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573760
00000100:00100000:2.0:1776205372.157123:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 33
00000100:00100000:2.0:1776205372.157131:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000009243099c pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+15:183776:x1862480268573760:12345-192.168.202.23@tcp:101:lfs.0
00010000:00010000:2.0:1776205372.157158:0:138513:0:(ldlm_lockd.c:1248:ldlm_handle_enqueue0()) ### server-side enqueue handler START
00010000:00010000:2.0:1776205372.157180:0:138513:0:(ldlm_lockd.c:1318:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3961 lrc: 2/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0xc31d44e5847febc0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157343:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 4 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157358:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157370:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157384:0:138513:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157391:0:138513:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157398:0:138513:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00000004:00200000:2.0:1776205372.157482:0:138513:0:(mdt_handler.c:912:mdt_pack_attr2body()) [0x200002b11:0xe62:0x0]: returning size 512
00010000:00010000:2.0:1776205372.157496:0:138513:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157503:0:138513:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 2/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157509:0:138513:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157515:0:138513:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 00000000af25c130 already unused, calling callback (0000000077bc9909)
00010000:00010000:2.0:1776205372.157526:0:138513:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157533:0:138513:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 4/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157545:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:2.0:1776205372.157548:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:2.0:1776205372.157552:0:138513:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157558:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000af25c130/0xb8d734e6f36e3968 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157570:0:138513:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157575:0:138513:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157580:0:138513:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157585:0:138513:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 0000000060ab3ca7 already unused, calling callback (0000000077bc9909)
00010000:00010000:2.0:1776205372.157587:0:138513:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157592:0:138513:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 4/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157598:0:138513:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x7a6a6e09 (00000000b4cd42a4)
00010000:00010000:2.0:1776205372.157605:0:138513:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:2.0:1776205372.157608:0:138513:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 2/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157614:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 0000000060ab3ca7/0xb8d734e6f36e396f lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157645:0:138513:0:(ldlm_lockd.c:1484:ldlm_handle_enqueue0()) ### server-side enqueue handler, sending reply (err=301, rc=0) ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3961 lrc: 1/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febc0 expref: 16 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157653:0:138513:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000001ffe81a5/0xb8d734e6f36e3961 lrc: 0/0,0 mode: --/CW res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febc0 expref: 16 pid: 138513 timeout: 0 lvb_type: 0
00010000:00010000:2.0:1776205372.157662:0:138513:0:(ldlm_lockd.c:1565:ldlm_handle_enqueue0()) ### server-side enqueue handler END (lock 000000001ffe81a5, rc 0)
00000100:00100000:2.0:1776205372.157723:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000009243099c pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+15:183776:x1862480268573760:12345-192.168.202.23@tcp:101:lfs.0 Request processed in 591us (1416us total) trans 0 rc 301/301
00000100:00100000:2.0:1776205372.157730:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 33
00000100:00100000:0.0:1776205372.187450:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205372.187498:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268573888
00000100:00100000:0.0:1776205372.187547:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 34
00000100:00100000:0.0:1776205372.187555:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000c4ce3f7c pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+15:183776:x1862480268573888:12345-192.168.202.23@tcp:101:lfs.0
00010000:00010000:0.0:1776205372.187575:0:139561:0:(ldlm_lockd.c:1248:ldlm_handle_enqueue0()) ### server-side enqueue handler START
00010000:00010000:0.0:1776205372.187594:0:139561:0:(ldlm_lockd.c:1318:ldlm_handle_enqueue0()) ### server-side enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000ca033c5d/0xb8d734e6f36e3976 lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 3 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0xc31d44e5847febc7 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187663:0:139561:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/1,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x0/0x0 rrc: 4 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187688:0:139561:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187698:0:139561:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187711:0:139561:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PR) ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/1,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187718:0:139561:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.187723:0:139561:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00000004:00200000:0.0:1776205372.190206:0:139561:0:(mdt_handler.c:912:mdt_pack_attr2body()) [0x200002b11:0xe62:0x0]: returning size 512
00010000:00010000:0.0:1776205372.190321:0:139561:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(CR) ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/1,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190337:0:139561:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 2/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190346:0:139561:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190352:0:139561:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 00000000e83923e5 already unused, calling callback (0000000077bc9909)
00010000:00010000:0.0:1776205372.190356:0:139561:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 3/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190364:0:139561:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 4/0,0 mode: CR/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190387:0:139561:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x0 (0000000017c0d237)
00010000:00010000:0.0:1776205372.190390:0:139561:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:0.0:1776205372.190394:0:139561:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 2/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190401:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000e83923e5/0xb8d734e6f36e397d lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x2/0x0 rrc: 4 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190412:0:139561:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PR) ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/1,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190417:0:139561:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 2/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190423:0:139561:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190428:0:139561:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 000000001739aa59 already unused, calling callback (0000000077bc9909)
00010000:00010000:0.0:1776205372.190430:0:139561:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 3/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190446:0:139561:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 4/0,0 mode: PR/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190453:0:139561:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200000007:0x1:0x0].0x7a6a6e09 (0000000053b6d812)
00010000:00010000:0.0:1776205372.190455:0:139561:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 2
00010000:00010000:0.0:1776205372.190457:0:139561:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 2/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190473:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 000000001739aa59/0xb8d734e6f36e3984 lrc: 0/0,0 mode: --/PR res: [0x200000007:0x1:0x0].0x7a6a6e09 bits 0x2/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190511:0:139561:0:(ldlm_lockd.c:1484:ldlm_handle_enqueue0()) ### server-side enqueue handler, sending reply (err=301, rc=0) ns: mdt-lustre-MDT0000_UUID lock: 00000000ca033c5d/0xb8d734e6f36e3976 lrc: 1/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febc7 expref: 17 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190519:0:139561:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000ca033c5d/0xb8d734e6f36e3976 lrc: 0/0,0 mode: --/CR res: [0x200000007:0x1:0x0].0x0 bits 0x1/0x0 rrc: 3 type: IBT gid 0 flags: 0x44000000000000 nid: 192.168.202.23@tcp remote: 0xc31d44e5847febc7 expref: 17 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.190529:0:139561:0:(ldlm_lockd.c:1565:ldlm_handle_enqueue0()) ### server-side enqueue handler END (lock 00000000ca033c5d, rc 0)
00000100:00100000:0.0:1776205372.190606:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000c4ce3f7c pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+16:183776:x1862480268573888:12345-192.168.202.23@tcp:101:lfs.0 Request processed in 3049us (3169us total) trans 34359738376 rc 301/301
00000100:00100000:0.0:1776205372.190615:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 34
00000100:00100000:3.0:1776205372.197419:0:3012:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205372.197657:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268574016
00000100:00100000:0.0:1776205372.197713:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 35
00000100:00100000:0.0:1776205372.197719:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000fa665197 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+16:183776:x1862480268574016:12345-192.168.202.23@tcp:36:lfs.0
00010000:00010000:0.0:1776205372.197813:0:139561:0:(ldlm_lock.c:766:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(PW) ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,1 mode: --/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x0/0x0 rrc: 2 type: IBT gid 0 flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.197831:0:139561:0:(ldlm_lock.c:1064:ldlm_granted_list_add_lock()) ### About to add lock: ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,1 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:0.0:1776205372.197844:0:139561:0:(ldlm_request.c:528:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,1 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00000004:00010000:0.0:1776205372.198074:0:139561:0:(mdt_handler.c:3992:mdt_save_lock()) ### save lock request 00000000fa665197 reply state 00000000c0b2db7d transno 34359738377
 ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,1 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00000004:00200000:0.0:1776205372.198108:0:139561:0:(mdt_handler.c:912:mdt_pack_attr2body()) [0x200002b11:0xe62:0x0]: returning size 512
00000100:00100000:0.0:1776205372.198187:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000fa665197 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:2784e426-5469-4962-abdd-5d421f2f60e1+18:183776:x1862480268574016:12345-192.168.202.23@tcp:36:lfs.0 Request processed in 467us (779us total) trans 34359738377 rc 0/0
00000100:00100000:0.0:1776205372.198194:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 35
00000100:00100000:1.0:1776205372.211838:0:3013:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205372.211906:0:138515:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268574144
00000100:00100000:0.0:1776205372.211984:0:138515:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 3
00000100:00100000:0.0:1776205372.211991:0:138515:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000edd25d12 pname:cluuid+ref:pid:xid:nid:opc:job mdt_rdpg00_000:2784e426-5469-4962-abdd-5d421f2f60e1+18:183776:x1862480268574144:12345-192.168.202.23@tcp:35:lfs.0
00000100:00100000:0.0:1776205372.212231:0:138515:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000edd25d12 pname:cluuid+ref:pid:xid:nid:opc:job mdt_rdpg00_000:2784e426-5469-4962-abdd-5d421f2f60e1+19:183776:x1862480268574144:12345-192.168.202.23@tcp:35:lfs.0 Request processed in 239us (402us total) trans 34359738378 rc 0/0
00000100:00100000:0.0:1776205372.212239:0:138515:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 3
00010000:00010000:3.0:1776205372.215736:0:3004:0:(ldlm_lock.c:820:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(PW) ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,1 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215755:0:3004:0:(ldlm_lock.c:879:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 2/0,0 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215785:0:3004:0:(ldlm_lockd.c:1879:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,0 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215792:0:3004:0:(ldlm_lockd.c:1893:ldlm_handle_bl_callback()) Lock 00000000de310c01 already unused, calling callback (0000000077bc9909)
00010000:00010000:3.0:1776205372.215795:0:3004:0:(ldlm_request.c:364:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 3/0,0 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215803:0:3004:0:(ldlm_request.c:1257:ldlm_cli_cancel_local()) ### server-side local cancel ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 4/0,0 mode: PW/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215818:0:3004:0:(ldlm_inodebits.c:94:ldlm_reprocess_inodebits_queue()) --- Reprocess resource [0x200002b11:0xe62:0x0].0x0 (000000007deccafc)
00010000:00010000:3.0:1776205372.215821:0:3004:0:(ldlm_inodebits.c:96:ldlm_reprocess_inodebits_queue()) Hint 20
00010000:00010000:3.0:1776205372.215825:0:3004:0:(ldlm_lockd.c:1903:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 2/0,0 mode: --/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00010000:00010000:3.0:1776205372.215831:0:3004:0:(ldlm_lock.c:216:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: mdt-lustre-MDT0000_UUID lock: 00000000de310c01/0xb8d734e6f36e3992 lrc: 0/0,0 mode: --/PW res: [0x200002b11:0xe62:0x0].0x0 bits 0x20/0x0 rrc: 2 type: IBT gid 0 flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 139561 timeout: 0 lvb_type: 0
00000100:00100000:2.0:1776205373.160567:0:3019:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [0->1]
00000100:00100000:2.0:1776205373.160590:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@0000000027de7507 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263898304:0@lo:13:osp-pre-1-0.0
00000100:00100000:2.0:1776205373.160660:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00010000:00010000:3.0:1776205373.163011:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:0.0:1776205373.164022:0:134295:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898304
00000100:00100000:0.0:1776205373.164072:0:134295:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 306
00000100:00100000:0.0:1776205373.164077:0:134295:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000a9a412dd pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263898304:12345-0@lo:13:osp-pre-1-0.0
00002000:00000024:0.0:1776205373.164115:0:134295:0:(ofd_obd.c:740:ofd_statfs()) blocks cached 0 granted 40566784 pending 0 free 3848273920 avail 3846176768
00000100:00100000:0.0:1776205373.164185:0:134295:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000a9a412dd pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_create00:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263898304:12345-0@lo:13:osp-pre-1-0.0 Request processed in 107us (3525us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205373.164192:0:134295:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 306
00000100:00100000:0.0:1776205373.164639:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@0000000027de7507 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263898304:0@lo:13:osp-pre-1-0.0
00000100:00100000:0.0:1776205373.671172:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:0.0:1776205373.671220:0:3011:0:(events.c:361:request_in_callback()) peer: 12345-192.168.202.23@tcp (source: 12345-192.168.202.23@tcp)
00000100:00100000:1.0:1776205373.672141:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268574272
00000100:00100000:1.0:1776205373.672212:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 81
00000100:00100000:1.0:1776205373.672228:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000005f3251bf pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+18:2219:x1862480268574272:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:1.0:1776205373.672309:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000005f3251bf pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:2784e426-5469-4962-abdd-5d421f2f60e1+18:2219:x1862480268574272:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 82us (1089us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205373.672317:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 81
00000100:00100000:2.0:1776205373.672930:0:138504:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480268574208
00000100:00100000:2.0:1776205373.673028:0:138504:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-192.168.202.23@tcp, seq: 101
00000100:00100000:2.0:1776205373.673034:0:138504:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000002ad9a69 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268574208:12345-192.168.202.23@tcp:400:kworker/u8:4.0
00000100:00100000:2.0:1776205373.673075:0:138504:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000002ad9a69 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0001:e87161b9-77a0-4aa2-8a8c-e8cc5bcd510c+9:2219:x1862480268574208:12345-192.168.202.23@tcp:400:kworker/u8:4.0 Request processed in 40us (1922us total) trans 0 rc 0/0
00000100:00100000:2.0:1776205373.673081:0:138504:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-192.168.202.23@tcp, seq: 101
00000100:00100000:1.0:1776205373.673971:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0001_UUID:3021:1862480263898496:0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.674033:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205373.674057:0:3021:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [2->3]
00000100:00100000:1.0:1776205373.674063:0:3021:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263898432:0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.674087:0:3021:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1776205373.674129:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898496
00000100:00100000:1.0:1776205373.674161:0:138513:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898432
00000100:00100000:1.0:1776205373.674179:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 82
00000100:00100000:1.0:1776205373.674183:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000007a25dba6 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0001_UUID+5:3021:x1862480263898496:12345-0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.674236:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000007a25dba6 pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0001_UUID+5:3021:x1862480263898496:12345-0@lo:400:kworker/u8:2.0 Request processed in 52us (204us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205373.674242:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 82
00000100:00100000:1.0:1776205373.674258:0:138513:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 83
00000100:00100000:1.0:1776205373.674261:0:138513:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000c1576a6d pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263898432:12345-0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.674285:0:138513:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000c1576a6d pname:cluuid+ref:pid:xid:nid:opc:job mdt00_001:lustre-MDT0000-lwp-OST0000_UUID+5:3021:x1862480263898432:12345-0@lo:400:kworker/u8:2.0 Request processed in 23us (199us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205373.674290:0:138513:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 83
00000100:00100000:1.0:1776205373.674330:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000abf51baf pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0000_UUID:3021:1862480263898432:0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.674339:0:3021:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@000000002184727e pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_03:lustre-MDT0000-lwp-OST0001_UUID:3021:1862480263898496:0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.674986:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263898368:0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675039:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205373.675062:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263898624:0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675096:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205373.675113:0:3019:0:(ptlrpcd.c:415:ptlrpcd_check()) transfer 1 async RPCs [0->1]
00000100:00100000:0.0:1776205373.675119:0:3019:0:(client.c:1733:ptlrpc_send_new_req()) Sending RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263898560:0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675140:0:3019:0:(events.c:361:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1776205373.675172:0:128060:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898560
00000100:00100000:0.0:1776205373.675214:0:128060:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 517
00000100:00100000:0.0:1776205373.675218:0:128060:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@00000000c36836bd pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263898560:12345-0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675254:0:128060:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@00000000c36836bd pname:cluuid+ref:pid:xid:nid:opc:job ll_ost00_004:lustre-MDT0000-mdtlov_UUID+5:3019:x1862480263898560:12345-0@lo:400:kworker/u8:2.0 Request processed in 35us (113us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205373.675260:0:128060:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 517
00000100:00100000:0.0:1776205373.675284:0:139561:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898624
00000100:00100000:0.0:1776205373.675304:0:139561:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 84
00000100:00100000:0.0:1776205373.675308:0:139561:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@0000000015e5563e pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263898624:12345-0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675335:0:139561:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@0000000015e5563e pname:cluuid+ref:pid:xid:nid:opc:job mdt00_003:lustre-MDT0000-lwp-MDT0000_UUID+5:3019:x1862480263898624:12345-0@lo:400:kworker/u8:2.0 Request processed in 26us (240us total) trans 0 rc 0/0
00000100:00100000:0.0:1776205373.675341:0:139561:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 84
00000100:00100000:0.0:1776205373.675369:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000b962ceb2 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-mdtlov_UUID:3019:1862480263898560:0@lo:400:kworker/u8:2.0
00000100:00100000:0.0:1776205373.675377:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000509be9fa pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:lustre-MDT0000-lwp-MDT0000_UUID:3019:1862480263898624:0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.676670:0:138503:0:(service.c:2152:ptlrpc_server_handle_req_in()) got req x1862480263898368
00000100:00100000:1.0:1776205373.676721:0:138503:0:(nrs_fifo.c:179:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 102
00000100:00100000:1.0:1776205373.676726:0:138503:0:(service.c:2324:ptlrpc_server_handle_request()) Handling RPC req@000000002c3889ee pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263898368:12345-0@lo:400:kworker/u8:2.0
00000100:00100000:1.0:1776205373.676785:0:138503:0:(service.c:2372:ptlrpc_server_handle_request()) Handled RPC req@000000002c3889ee pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97+18:3019:x1862480263898368:12345-0@lo:400:kworker/u8:2.0 Request processed in 59us (1747us total) trans 0 rc 0/0
00000100:00100000:1.0:1776205373.676792:0:138503:0:(nrs_fifo.c:241:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 102
00000100:00100000:0.0:1776205373.677347:0:3019:0:(client.c:2215:ptlrpc_check_set()) Completed RPC req@00000000291671ca pname:cluuid:pid:xid:nid:opc:job ptlrpcd_00_01:67b478c9-4a7a-4db2-a1bd-e4af8cf85e97:3019:1862480263898368:0@lo:400:kworker/u8:2.0
00010000:00010000:1.0:1776205374.189047:0:130741:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000001:00080000:0.0:1776205374.289345:0:138546:0:(tgt_lastrcvd.c:913:tgt_cb_last_committed()) lustre-MDT0000: transno 34359738378 is committed
00010000:00010000:2.0:1776205375.207162:0:127084:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:3.0:1776205376.231277:0:127083:0:(ldlm_lockd.c:2792:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
Debug log: 759 lines, 759 kept, 0 dropped, 0 bad.