00000001:02000400:2.0F:1787756060.741264:0:3305:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg130-server.virtnet: executing set_hostid
00000001:02000400:1.0F:1787756076.635448:0:3526:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg130-server.virtnet: executing load_modules_local
00000001:01000000:0.0F:1787756077.878951:0:3587:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm adler32 speed = 1307 MB/s
00000001:01000000:0.0:1787756078.129133:0:3587:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm crc32 speed = 1459 MB/s
00000001:01000000:0.0:1787756078.378964:0:3587:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm crc32c speed = 10223 MB/s
00000020:02000000:3.0F:1787756078.734249:0:3619:0:(class_obd.c:771:obdclass_init()) Lustre: Build Version: 2.17.57_110_g6beee0e
00000400:02000000:3.0:1787756079.202935:0:3634:0:(api-ni.c:2823:lnet_startup_lndni()) Added LNI 192.168.201.130@tcp [8/256/0/180]
00008000:02000000:1.0:1787756081.835896:0:3783:0:(echo_client.c:2574:obdecho_init()) Echo OBD driver; http://www.lustre.org/
00000001:02000400:0.0:1787756115.779141:0:5747:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg130-server.virtnet: executing load_modules_local
00000020:01000004:1.0:1787756120.630113:0:6495:0:(obd_mount.c:923:lmd_print())   mount data:
00000020:01000004:1.0:1787756120.630119:0:6495:0:(obd_mount.c:926:lmd_print()) device:  /dev/mapper/mds1_flakey
00000020:01000004:1.0:1787756120.630121:0:6495:0:(obd_mount.c:929:lmd_print()) options: user_xattr,errors=remount-ro
00000080:01200004:1.0:1787756120.630271:0:6495:0:(super25.c:131:lustre_fill_super()) VFS Op: sb 000000008bc99b09
00000080:02000400:1.0:1787756120.630281:0:6495:0:(super25.c:149:lustre_fill_super()) lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt'
00000020:01000004:1.0:1787756120.633951:0:6495:0:(tgt_mount.c:2500:osd_start()) Attempting to start lustre-MDT0000, type=osd-ldiskfs, lsifl=200065, mountfl=0
00000020:01000004:1.0:1787756120.633961:0:6495:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD lustre-MDT0000-osd (typ=osd-ldiskfs)
00000020:00000080:1.0:1787756120.633984:0:6495:0:(genops.c:413:class_newdev()) Allocate new device lustre-MDT0000-osd (00000000011d35b2)
00000020:00000080:1.0:1787756120.633997:0:6495:0:(obd_config.c:720:class_attach_name()) OBD: dev 0 attached type osd-ldiskfs with refcount 2
00100000:10000000:1.0:1787756120.655797:0:6495:0:(scrub.c:230:scrub_file_store()) lustre-MDT0000: store scrub file: rc = 0
00100000:10000000:1.0:1787756120.655858:0:6495:0:(scrub.c:230:scrub_file_store()) lustre-MDT0000: store scrub file: rc = 0
00080000:01000000:1.0:1787756120.667165:0:6495:0:(osd_lproc.c:911:osd_procfs_init()) lustre-MDT0000: register osd-ldiskfs tunable parameters
00000020:00000080:1.0:1787756120.667373:0:6495:0:(obd_config.c:826:class_setup()) finished setup of obd lustre-MDT0000-osd (uuid lustre-MDT0000-osd_UUID)
00080000:01000000:1.0:1787756120.667382:0:6495:0:(osd_handler.c:8895:osd_obd_connect()) connect #0
00000020:00000080:1.0:1787756120.667393:0:6495:0:(genops.c:1385:class_connect()) connect: client lustre-MDT0000-osd_UUID, cookie 0x612e228bfecd355e
00000020:01000004:1.0:1787756120.667399:0:6495:0:(tgt_mount.c:2585:server_fill_super()) Found service lustre-MDT0000 on device /dev/mapper/mds1_flakey
00000020:01000000:1.0:1787756120.667404:0:6495:0:(tgt_mount.c:219:server_start_mgs()) Start MGS service MGS
00000020:01000004:1.0:1787756120.667409:0:6495:0:(tgt_mount.c:101:server_register_mount()) register mount 000000008bc99b09 from MGS
00000020:01000004:1.0:1787756120.667414:0:6495:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MGS (typ=mgs)
00000020:00000080:1.0:1787756120.667423:0:6495:0:(genops.c:413:class_newdev()) Allocate new device MGS (00000000049f53a5)
00000020:00000080:1.0:1787756120.667436:0:6495:0:(obd_config.c:720:class_attach_name()) OBD: dev 1 attached type mgs with refcount 2
00000020:01000004:1.0:1787756120.667492:0:6495:0:(tgt_mount.c:153:server_get_mount()) get mount 000000008bc99b09 from MGS, refs=2
00080000:01000000:1.0:1787756120.667497:0:6495:0:(osd_handler.c:8895:osd_obd_connect()) connect #1
00000020:00000080:1.0:1787756120.667501:0:6495:0:(genops.c:1385:class_connect()) connect: client lustre-MDT0000-osd_UUID, cookie 0x612e228bfecd356c
00000100:00100000:1.0:1787756120.667614:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) ldlm_cbd: allocate 1 new 8192-byte reqbufs (0/1 left), rc = 0
00000100:00100000:1.0:1787756120.667786:0:6495:0:(service.c:3462:ptlrpc_start_thread()) ldlm_cbd[0] started 0 min 2 max 56
00000100:00100000:1.0:1787756120.667793:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cb00_000'
00000100:00100000:1.0:1787756120.668631:0:6495:0:(service.c:3462:ptlrpc_start_thread()) ldlm_cbd[0] started 1 min 2 max 56
00000100:00100000:1.0:1787756120.668639:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cb00_001'
00000100:00100000:1.0:1787756120.669463:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) ldlm_canceld: allocate 64 new 8192-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756120.669651:0:6495:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 0 min 3 max 56
00000100:00100000:1.0:1787756120.669657:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_000'
00000100:00100000:0.0:1787756120.670539:0:6495:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 1 min 3 max 56
00000100:00100000:0.0:1787756120.670548:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_001'
00000100:00100000:1.0:1787756120.670912:0:6495:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 2 min 3 max 56
00000100:00100000:1.0:1787756120.670920:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_002'
00010000:00010000:0.0:1787756120.671445:0:6506:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1787756120.671449:0:6506:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1787756120.671451:0:6506:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1787756120.671650:0:6507:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1787756120.671654:0:6507:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1787756120.671656:0:6507:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:1.0:1787756120.672322:0:6495:0:(ldlm_pool.c:923:ldlm_pool_init()) Lock pool ldlm-pool-MGS-0 is initialized
00010000:00010000:0.0:1787756120.681798:0:6506:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000001:01000000:1.0:1787756120.921840:0:6495:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10ip512 speed = 6607 MB/s
00000001:01000000:1.0:1787756121.171871:0:6495:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10ip4K speed = 7855 MB/s
00000001:01000000:1.0:1787756121.422331:0:6495:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10crc512 speed = 1439 MB/s
00000001:01000000:1.0:1787756121.671925:0:6495:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10crc4K speed = 1771 MB/s
00080000:10000000:1.0:1787756121.675427:0:6495:0:(osd_handler.c:5551:osd_index_try()) lustre-MDT0000: index object [0x200000003:0x2:0x0] (8/32) registered
00000040:01000000:1.0:1787756121.681577:0:6495:0:(llog_obd.c:197:llog_setup()) obd MGS ctxt 0 is initialized
10000000:01000000:1.0:1787756121.682063:0:6510:0:(mgc_request.c:68:mgc_name2resid()) log params to resid 0x736d61726170/0x2 (params)
20000000:01000000:2.0:1787756121.682083:0:6495:0:(mgs_nids.c:666:mgs_nidtbl_init_fs()) IR: current version is 2
20000000:01000000:2.0:1787756121.682133:0:6495:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
00000040:00080000:2.0:1787756121.682346:0:6495:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
20000000:01000000:2.0:1787756121.682373:0:6495:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
00000100:00100000:2.0:1787756121.682765:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mgs: allocate 64 new 8192-byte reqbufs (0/64 left), rc = 0
00000100:00100000:2.0:1787756121.682974:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 0 min 3 max 32
00000100:00100000:2.0:1787756121.682981:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0000'
00000100:00100000:2.0:1787756121.683545:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 1 min 3 max 32
00000100:00100000:2.0:1787756121.683553:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0001'
00000100:00100000:2.0:1787756121.683868:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 2 min 3 max 32
00000100:00100000:2.0:1787756121.683874:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0002'
00000100:00080000:1.0:1787756121.684301:0:6515:0:(pinger.c:466:ping_evictor_main()) Starting Ping Evictor
00000020:00000080:2.0:1787756121.684332:0:6495:0:(obd_config.c:826:class_setup()) finished setup of obd MGS (uuid MGS)
00000020:01000004:2.0:1787756121.684352:0:6495:0:(obd_mount.c:411:lustre_start_mgc()) Start MGC 'MGC192.168.201.130@tcp'
00000020:01000004:2.0:1787756121.684354:0:6495:0:(obd_mount.c:420:lustre_start_mgc()) mgs NIDs (null).
00000020:01000004:2.0:1787756121.684403:0:6495:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MGC192.168.201.130@tcp (typ=mgc)
00000020:00000080:2.0:1787756121.684423:0:6495:0:(genops.c:413:class_newdev()) Allocate new device MGC192.168.201.130@tcp (0000000093b89ec2)
00000020:00000080:2.0:1787756121.684444:0:6495:0:(obd_config.c:720:class_attach_name()) OBD: dev 2 attached type mgc with refcount 2
00010000:00080000:2.0:1787756121.684621:0:6495:0:(ldlm_lib.c:102:import_set_conn()) imp 00000000470caecc@MGC192.168.201.130@tcp: add connection 192.168.201.130@tcp at head
00010000:00010000:2.0:1787756121.684808:0:6495:0:(ldlm_pool.c:923:ldlm_pool_init()) Lock pool ldlm-pool-MGC192.168.201.130@tcp-0 is initialized
00000040:01000000:2.0:1787756121.684814:0:6495:0:(llog_obd.c:197:llog_setup()) obd MGC192.168.201.130@tcp ctxt 1 is initialized
10000000:01000000:1.0:1787756121.685234:0:6516:0:(mgc_request.c:631:mgc_requeue_thread()) Starting requeue thread
00000020:00000080:2.0:1787756121.685275:0:6495:0:(obd_config.c:826:class_setup()) finished setup of obd MGC192.168.201.130@tcp (uuid 4ba41538-425d-410f-ae90-32a55a630de3)
00000020:00000080:2.0:1787756121.685294:0:6495:0:(genops.c:1385:class_connect()) connect: client 4ba41538-425d-410f-ae90-32a55a630de3, cookie 0x612e228bfecd357a
00000100:00080000:2.0:1787756121.685303:0:6495:0:(import.c:510:import_select_connection()) MGC192.168.201.130@tcp: connect to NID 0@lo last attempt 0
00000100:00080000:2.0:1787756121.685308:0:6495:0:(import.c:624:import_select_connection()) MGC192.168.201.130@tcp: import 00000000470caecc using connection 192.168.201.130@tcp/0@lo
00000100:00100000:2.0:1787756121.685337:0:6495:0:(import.c:826:ptlrpc_connect_import_locked()) @@@ (re)connect request (timeout 5)  req@000000003e173977 x1874598118293632/t0(0) o250->MGC192.168.201.130@tcp@0@lo:26/25 lens 520/544 e 0 to 0 dl 0 ref 1 fl New:NQU/0/ffffffff rc 0/-1 job:'' uid:4294967295 gid:4294967295 projid:4294967295
00000100:00100000:2.0:1787756121.685447:0:3649:0:(client.c:1919:ptlrpc_send_new_req()) Sending RPC req@000000003e173977 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_rcv:4ba41538-425d-410f-ae90-32a55a630de3:3649:1874598118293632:0@lo:250:
00000100:00100000:2.0:1787756121.685547:0:3649:0:(events.c:340:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1787756121.685597:0:6511:0:(service.c:2301:ptlrpc_server_handle_req_in()) unwrap req x1874598118293632
00000100:00100000:1.0:1787756121.685604:0:6511:0:(service.c:2366:ptlrpc_server_handle_req_in()) got req x1874598118293632
00000100:00080000:2.0:1787756121.685627:0:6495:0:(pinger.c:373:ptlrpc_pinger_add_import()) adding pingable import 4ba41538-425d-410f-ae90-32a55a630de3->MGS
00000100:00100000:1.0:1787756121.685650:0:6511:0:(nrs_fifo.c:152:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 0
00000020:01000004:2.0:1787756121.685654:0:6495:0:(tgt_mount.c:1809:server_start_targets()) starting target lustre-MDT0000
00000020:01000004:2.0:1787756121.685659:0:6495:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MDS (typ=mds)
00000100:00100000:1.0:1787756121.685660:0:6511:0:(service.c:2552:ptlrpc_server_handle_request()) Handling RPC req@00000000ae613bec pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:0+-99:3649:x1874598118293632:12345-0@lo:250:
00000020:00000080:2.0:1787756121.685675:0:6495:0:(genops.c:413:class_newdev()) Allocate new device MDS (0000000081ca295c)
00010000:00080000:1.0:1787756121.685686:0:6511:0:(ldlm_lib.c:1482:target_handle_connect()) MGS: connection from 4ba41538-425d-410f-ae90-32a55a630de3@0@lo t0 exp 0000000000000000 cur 112 last 0
00000020:00000080:2.0:1787756121.685689:0:6495:0:(obd_config.c:720:class_attach_name()) OBD: dev 3 attached type mds with refcount 2
00000020:00000080:1.0:1787756121.685756:0:6511:0:(genops.c:1385:class_connect()) connect: client 4ba41538-425d-410f-ae90-32a55a630de3, cookie 0x612e228bfecd3588
00000100:00080000:1.0:1787756121.685998:0:6511:0:(import.c:65:import_set_state_nolock()) 0000000077da0168 : changing import state from RECOVER to FULL
00000100:00100000:1.0:1787756121.686081:0:6511:0:(service.c:2610:ptlrpc_server_handle_request()) Handled RPC req@00000000ae613bec pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:4ba41538-425d-410f-ae90-32a55a630de3+5:3649:x1874598118293632:12345-0@lo:250: Request processed in 420us (536us total) trans 0 rc 0/0
00000100:00100000:1.0:1787756121.686090:0:6511:0:(nrs_fifo.c:211:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 0
00000100:00100000:2.0:1787756121.686126:0:3649:0:(client.c:3125:ptlrpc_free_committed()) MGC192.168.201.130@tcp: committing for last_committed 0 gen 1
00000100:00080000:2.0:1787756121.686134:0:3649:0:(import.c:1132:ptlrpc_connect_interpret()) MGC192.168.201.130@tcp: connect to target with instance 0
00000100:00080000:2.0:1787756121.686141:0:3649:0:(import.c:956:ptlrpc_connect_set_flags()) MGC192.168.201.130@tcp: Resetting ns_connect_flags to server flags: 0xa000011001002060
10000000:01000000:2.0:1787756121.686145:0:3649:0:(mgc_request.c:1168:mgc_import_event()) import event 0x808005
00000100:00080000:2.0:1787756121.686149:0:3649:0:(import.c:65:import_set_state_nolock()) 00000000470caecc MGS: changing import state from CONNECTING to FULL
10000000:01000000:2.0:1787756121.686153:0:3649:0:(mgc_request.c:1168:mgc_import_event()) import event 0x808004
00000100:00080000:2.0:1787756121.686165:0:3649:0:(pinger.c:186:ptlrpc_pinger_ir_up()) IR up
00000100:00100000:2.0:1787756121.686175:0:3649:0:(client.c:2414:ptlrpc_check_set()) Completed RPC req@000000003e173977 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_rcv:4ba41538-425d-410f-ae90-32a55a630de3:3649:1874598118293632:0@lo:250:
00010000:00010000:1.0:1787756121.689782:0:6507:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:2.0:1787756121.695902:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt: allocate 64 new 262144-byte reqbufs (0/64 left), rc = 0
00000100:00100000:2.0:1787756121.696193:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 0 min 3 max 116
00000100:00100000:2.0:1787756121.696201:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_000'
00000100:00100000:2.0:1787756121.698108:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 1 min 3 max 116
00000100:00100000:2.0:1787756121.698129:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_001'
00000100:00100000:1.0:1787756121.698709:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 2 min 3 max 116
00000100:00100000:1.0:1787756121.698751:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_002'
00000100:00100000:1.0:1787756121.699555:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_readpage: allocate 64 new 8192-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.699800:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_readpage[0] started 0 min 2 max 80
00000100:00100000:1.0:1787756121.699805:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_rdpg00_000'
00000100:00100000:1.0:1787756121.700192:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_readpage[0] started 1 min 2 max 80
00000100:00100000:1.0:1787756121.700200:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_rdpg00_001'
00000100:00100000:1.0:1787756121.727495:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_out: allocate 64 new 1048576-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.727693:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_out[0] started 0 min 2 max 116
00000100:00100000:1.0:1787756121.727700:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_out00_000'
00000100:00100000:1.0:1787756121.728653:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_out[0] started 1 min 2 max 116
00000100:00100000:1.0:1787756121.728662:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_out00_001'
00000100:00100000:1.0:1787756121.729133:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_seqs: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.729274:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqs[-1] started 0 min 2 max 256
00000100:00100000:1.0:1787756121.729285:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqs_0000'
00000100:00100000:1.0:1787756121.729641:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqs[-1] started 1 min 2 max 256
00000100:00100000:1.0:1787756121.729647:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqs_0001'
00000100:00100000:1.0:1787756121.730454:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_seqm: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.730586:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqm[-1] started 0 min 2 max 256
00000100:00100000:1.0:1787756121.730590:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqm_0000'
00000100:00100000:2.0:1787756121.731030:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqm[-1] started 1 min 2 max 256
00000100:00100000:2.0:1787756121.731043:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqm_0001'
00000100:00100000:1.0:1787756121.731585:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_fld: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.731696:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_fld[-1] started 0 min 2 max 256
00000100:00100000:1.0:1787756121.731701:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_fld_0000'
00000100:00100000:1.0:1787756121.732067:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_fld[-1] started 1 min 2 max 256
00000100:00100000:1.0:1787756121.732073:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_fld_0001'
00000100:00100000:1.0:1787756121.742177:0:6495:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_io: allocate 64 new 524288-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756121.742400:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 0 min 3 max 116
00000100:00100000:1.0:1787756121.742405:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_000'
00000100:00100000:1.0:1787756121.745213:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 1 min 3 max 116
00000100:00100000:1.0:1787756121.745227:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_001'
00000100:00100000:1.0:1787756121.746258:0:6495:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 2 min 3 max 116
00000100:00100000:1.0:1787756121.746273:0:6495:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_002'
00000020:00000080:1.0:1787756121.747220:0:6495:0:(obd_config.c:826:class_setup()) finished setup of obd MDS (uuid MDS_uuid)
00000020:01000004:1.0:1787756121.747253:0:6495:0:(tgt_mount.c:280:server_mgc_set_fs()) Set mgc disk for /dev/mapper/mds1_flakey
10000000:01000000:1.0:1787756121.747259:0:6495:0:(mgc_request_server.c:89:mgc_fs_setup()) MGC192.168.201.130@tcp: cl_mgc_mutex lustre-MDT0000-osd for locked: rc = 0
00000040:01000000:1.0:1787756121.747352:0:6495:0:(llog_obd.c:197:llog_setup()) obd MGC192.168.201.130@tcp ctxt 0 is initialized
00000020:01000004:1.0:1787756121.747384:0:6495:0:(tgt_mount.c:1418:server_register_target()) Registration lustre-MDT0000, fs=lustre, 192.168.201.130@tcp, index=0000, flags=0x20065
00000020:01000004:1.0:1787756121.747388:0:6495:0:(tgt_mount.c:1175:server_mti_print()) mti - server_register_target
00000020:01000004:1.0:1787756121.747393:0:6495:0:(tgt_mount.c:1176:server_mti_print()) server: lustre-MDT0000
00000020:01000004:1.0:1787756121.747394:0:6495:0:(tgt_mount.c:1177:server_mti_print()) fs:     lustre
00000020:01000004:1.0:1787756121.747395:0:6495:0:(tgt_mount.c:1178:server_mti_print()) uuid:   
00000020:01000004:1.0:1787756121.747396:0:6495:0:(tgt_mount.c:1179:server_mti_print()) ver:    0
00000020:01000004:1.0:1787756121.747403:0:6495:0:(tgt_mount.c:1180:server_mti_print()) flags:
00000020:01000004:1.0:1787756121.747404:0:6495:0:(tgt_mount.c:1182:server_mti_print()) 	 LDD_F_SV_TYPE_MDT
00000020:01000004:1.0:1787756121.747405:0:6495:0:(tgt_mount.c:1186:server_mti_print()) 	 LDD_F_SV_TYPE_MGS
00000020:01000004:1.0:1787756121.747407:0:6495:0:(tgt_mount.c:1192:server_mti_print()) 	 LDD_F_VIRIGIN
00000020:01000004:1.0:1787756121.747408:0:6495:0:(tgt_mount.c:1194:server_mti_print()) 	 LDD_F_UPDATE
00000020:01000004:1.0:1787756121.747409:0:6495:0:(tgt_mount.c:1214:server_mti_print()) 	 LDD_F_LARGE_NID
00000020:01000004:1.0:1787756121.747410:0:6495:0:(tgt_mount.c:1216:server_mti_print()) 	 LDD_F_OPC_REG
10000000:01000000:1.0:1787756121.747412:0:6495:0:(mgc_request_server.c:451:mgc_set_info_async_server()) register_target lustre-MDT0000 0x10020065
00000020:01000004:1.0:1787756121.747414:0:6495:0:(tgt_mount.c:1175:server_mti_print()) mti - mgc_target_register: req
00000020:01000004:1.0:1787756121.747415:0:6495:0:(tgt_mount.c:1176:server_mti_print()) server: lustre-MDT0000
00000020:01000004:1.0:1787756121.747416:0:6495:0:(tgt_mount.c:1177:server_mti_print()) fs:     lustre
00000020:01000004:1.0:1787756121.747417:0:6495:0:(tgt_mount.c:1178:server_mti_print()) uuid:   
00000020:01000004:1.0:1787756121.747417:0:6495:0:(tgt_mount.c:1179:server_mti_print()) ver:    0
00000020:01000004:1.0:1787756121.747418:0:6495:0:(tgt_mount.c:1180:server_mti_print()) flags:
00000020:01000004:1.0:1787756121.747419:0:6495:0:(tgt_mount.c:1182:server_mti_print()) 	 LDD_F_SV_TYPE_MDT
00000020:01000004:1.0:1787756121.747420:0:6495:0:(tgt_mount.c:1186:server_mti_print()) 	 LDD_F_SV_TYPE_MGS
00000020:01000004:1.0:1787756121.747420:0:6495:0:(tgt_mount.c:1192:server_mti_print()) 	 LDD_F_VIRIGIN
00000020:01000004:1.0:1787756121.747421:0:6495:0:(tgt_mount.c:1194:server_mti_print()) 	 LDD_F_UPDATE
00000020:01000004:1.0:1787756121.747426:0:6495:0:(tgt_mount.c:1214:server_mti_print()) 	 LDD_F_LARGE_NID
00000020:01000004:1.0:1787756121.747427:0:6495:0:(tgt_mount.c:1216:server_mti_print()) 	 LDD_F_OPC_REG
10000000:01000000:1.0:1787756121.747448:0:6495:0:(mgc_request_server.c:281:mgc_target_register()) register lustre-MDT0000
00000100:00100000:1.0:1787756121.747464:0:6495:0:(client.c:1919:ptlrpc_send_new_req()) Sending RPC req@00000000dfd28f0b pname:cluuid:pid:xid:nid:opc:job mount.lustre:4ba41538-425d-410f-ae90-32a55a630de3:6495:1874598118293760:0@lo:253:
00000100:00100000:1.0:1787756121.747526:0:6495:0:(events.c:340:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:2.0:1787756121.747586:0:6514:0:(service.c:2301:ptlrpc_server_handle_req_in()) unwrap req x1874598118293760
00000100:00100000:2.0:1787756121.747593:0:6514:0:(service.c:2366:ptlrpc_server_handle_req_in()) got req x1874598118293760
00000100:00100000:1.0:1787756121.747599:0:6495:0:(client.c:2715:ptlrpc_set_wait()) set 00000000e0a46bf3 going to sleep for 11 seconds
00000100:00100000:2.0:1787756121.747643:0:6514:0:(nrs_fifo.c:152:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 1
00000100:00100000:2.0:1787756121.747653:0:6514:0:(service.c:2552:ptlrpc_server_handle_request()) Handling RPC req@000000004404c2d7 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0002:4ba41538-425d-410f-ae90-32a55a630de3+5:6495:x1874598118293760:12345-0@lo:253:
20000000:01000000:2.0:1787756121.747698:0:6514:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
20000000:01000000:2.0:1787756121.747701:0:6514:0:(mgs_handler.c:479:mgs_target_reg()) fs: lustre index: 0 is registered to MGS.
10000000:01000000:2.0:1787756121.747927:0:6534:0:(mgc_request.c:68:mgc_name2resid()) log lustre to resid 0x65727473756c/0x2 (lustre)
20000000:01000000:1.0:1787756121.747954:0:6514:0:(mgs_nids.c:666:mgs_nidtbl_init_fs()) IR: current version is 2
00000040:00080000:1.0:1787756121.748208:0:6514:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:2.0:1787756121.749024:0:6535:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 64768 count 1
20000000:01000000:1.0:1787756121.749135:0:6514:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
20000000:01000000:1.0:1787756121.749139:0:6514:0:(mgs_handler.c:599:mgs_target_reg()) updating lustre-MDT0000, index=0
20000000:01000000:1.0:1787756121.749143:0:6514:0:(mgs_llog.c:869:mgs_set_index()) Set index for lustre-MDT0000 to 0
20000000:01000000:1.0:1787756121.749146:0:6514:0:(mgs_llog.c:3612:mgs_write_log_mdt()) writing new mdt lustre-MDT0000
20000000:01000000:1.0:1787756121.749157:0:6514:0:(mgs_llog.c:3172:mgs_write_log_lov()) Writing lov(lustre-MDT0000-mdtlov) log for lustre-MDT0000
00000040:00080000:1.0:1787756121.749273:0:6514:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:1.0:1787756121.749388:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].1, 224 off8416
20000000:01000000:1.0:1787756121.749402:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdtlov 0xcf001 lov lustre-MDT0000-mdtlov_UUID (null) (null)
00000040:00080000:1.0:1787756121.749424:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].2, 136 off8552
00000040:00080000:1.0:1787756121.749439:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].3, 176 off8728
00000040:00080000:1.0:1787756121.749447:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].4, 224 off8952
00000040:00080000:1.0:1787756121.749477:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].5, 224 off9176
20000000:01000000:1.0:1787756121.749482:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000 0xcf001 mdt lustre-MDT0000_UUID (null) (null)
00000040:00080000:1.0:1787756121.749489:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].6, 120 off9296
20000000:01000000:1.0:1787756121.749492:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf007 lustre-MDT0000 lustre-MDT0000-mdtlov (null) (null)
00000040:00080000:1.0:1787756121.749498:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].7, 112 off9408
20000000:01000000:1.0:1787756121.749501:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000 0xcf003 lustre-MDT0000_UUID 0 lustre-MDT0000-mdtlov f
00000040:00080000:1.0:1787756121.749507:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].8, 160 off9568
00000040:00080000:1.0:1787756121.749514:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].9, 224 off9792
00000040:00080000:1.0:1787756121.749526:0:6514:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
20000000:01000000:1.0:1787756121.749529:0:6514:0:(mgs_llog.c:3172:mgs_write_log_lov()) Writing lov(lustre-clilov) log for lustre-client
00000040:00080000:1.0:1787756121.749533:0:6514:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:1.0:1787756121.749610:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].1, 224 off8416
20000000:01000000:1.0:1787756121.749617:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilov 0xcf001 lov lustre-clilov_UUID (null) (null)
00000040:00080000:1.0:1787756121.749626:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].2, 120 off8536
00000040:00080000:1.0:1787756121.749633:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].3, 168 off8704
00000040:00080000:1.0:1787756121.749641:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].4, 224 off8928
20000000:01000000:1.0:1787756121.749646:0:6514:0:(mgs_llog.c:3129:mgs_write_log_lmv()) Writing lmv(lustre-clilmv) log for lustre-client
00000040:00080000:1.0:1787756121.749659:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].5, 224 off9152
20000000:01000000:1.0:1787756121.749663:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilmv 0xcf001 lmv lustre-clilmv_UUID (null) (null)
00000040:00080000:1.0:1787756121.749669:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].6, 120 off9272
00000040:00080000:1.0:1787756121.749676:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].7, 168 off9440
00000040:00080000:1.0:1787756121.749684:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].8, 224 off9664
20000000:01000000:1.0:1787756121.749688:0:6514:0:(mgs_llog.c:3094:mgs_write_log_mount_opt()) Writing mount options log for lustre-client
00000040:00080000:1.0:1787756121.749698:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].9, 224 off9888
20000000:01000000:1.0:1787756121.749702:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf007 lustre-client lustre-clilov lustre-clilmv (null)
00000040:00080000:1.0:1787756121.749709:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].10, 120 off10008
00000040:00080000:1.0:1787756121.749739:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].11, 224 off10232
00000040:00080000:1.0:1787756121.749789:0:6514:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 12 count 12
20000000:01000000:1.0:1787756121.749810:0:6514:0:(mgs_llog.c:3309:mgs_write_log_mdc_to_lmv()) adding mdc for lustre-MDT0000 to log lustre-client:lmv(lustre-clilmv)
20000000:01000000:1.0:1787756121.749822:0:6514:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-client/lustre-MDT0000/add mdc fl=4
00000040:00080000:2.0:1787756121.750030:0:6536:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 12 count 12
00000040:00080000:1.0:1787756121.750083:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].12, 224 off10456
20000000:01000000:1.0:1787756121.750095:0:6514:0:(mgs_llog.c:3355:mgs_write_log_mdc_to_lmv()) add nid 192.168.201.130@tcp for mdt
20000000:01000000:1.0:1787756121.750097:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf005 192.168.201.130@tcp (null) (null) (null)
00000040:00080000:1.0:1787756121.750104:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].13, 88 off10544
20000000:01000000:1.0:1787756121.750109:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdc 0xcf001 mdc lustre-clilmv_UUID (null) (null)
00000040:00080000:1.0:1787756121.750120:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].14, 128 off10672
20000000:01000000:1.0:1787756121.750125:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdc 0xcf003 lustre-MDT0000_UUID 192.168.201.130@tcp (null) (null)
00000040:00080000:1.0:1787756121.750136:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].15, 144 off10816
20000000:01000000:1.0:1787756121.750142:0:6514:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilmv 0xcf014 lustre-MDT0000_UUID 0 1 lustre-MDT0000-mdc_UUID
00000040:00080000:1.0:1787756121.750154:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].16, 160 off10976
00000040:00080000:1.0:1787756121.750181:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].17, 224 off11200
20000000:01000000:1.0:1787756121.750208:0:6514:0:(mgs_llog.c:5252:mgs_write_log_target()) remaining string: ' mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity ', param: 'sys.timeout=20'
20000000:01000000:1.0:1787756121.750210:0:6514:0:(mgs_llog.c:4748:mgs_write_log_param()) next param 'sys.timeout=20'
20000000:01000000:1.0:1787756121.750213:0:6514:0:(mgs_llog.c:4181:mgs_write_log_sys()) global 'sys.timeout=20' val=20
20000000:01000000:1.0:1787756121.750254:0:6514:0:(mgs_llog.c:2550:mgs_write_log_direct_all()) Changing log lustre-client
20000000:01000000:1.0:1787756121.750255:0:6514:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-client/lustre/sys.timeout fl=4
00000040:00080000:2.0:1787756121.750452:0:6537:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 18 count 18
00000040:00080000:1.0:1787756121.750507:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].18, 224 off11424
00000040:00080000:1.0:1787756121.750519:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].19, 80 off11504
00000040:00080000:1.0:1787756121.750527:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].20, 224 off11728
20000000:01000000:1.0:1787756121.750531:0:6514:0:(mgs_llog.c:2550:mgs_write_log_direct_all()) Changing log lustre-MDT0000
20000000:01000000:1.0:1787756121.750532:0:6514:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-MDT0000/lustre/sys.timeout fl=4
00000040:00080000:2.0:1787756121.750706:0:6538:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x4:0x0] index 10 count 10
00000040:00080000:1.0:1787756121.750801:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].10, 224 off10016
00000040:00080000:1.0:1787756121.750815:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].11, 80 off10096
00000040:00080000:1.0:1787756121.750824:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].12, 224 off10320
00000020:00000080:1.0:1787756121.750832:0:6514:0:(obd_config.c:1472:class_process_config()) processing cmd: cf009
00000020:00000080:1.0:1787756121.750835:0:6514:0:(obd_config.c:1537:class_process_config()) changing lustre timeout from 100 to 20
20000000:01000000:1.0:1787756121.750838:0:6514:0:(mgs_llog.c:5252:mgs_write_log_target()) remaining string: ' ', param: 'mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity'
20000000:01000000:1.0:1787756121.750840:0:6514:0:(mgs_llog.c:4748:mgs_write_log_param()) next param 'mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity'
20000000:01000000:1.0:1787756121.750844:0:6514:0:(mgs_llog.c:5072:mgs_write_log_param()) mdt param identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity
20000000:01000000:1.0:1787756121.750848:0:6514:0:(mgs_llog.c:1379:mgs_modify_param()) modify lustre-MDT0000/lustre-MDT0000/mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity del=0
00000040:00080000:3.0:1787756121.751083:0:6539:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x4:0x0] index 13 count 13
20000000:02000000:1.0:1787756121.751133:0:6514:0:(mgs_llog.c:4120:mgs_wlp_lcfg()) Setting parameter lustre-MDT0000.mdt.identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity in log lustre-MDT0000
00000040:00080000:0.0:1787756121.754080:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].13, 224 off10544
00000040:00080000:0.0:1787756121.754109:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].14, 160 off10704
00000040:00080000:0.0:1787756121.754124:0:6514:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].15, 224 off10928
10000000:01000000:0.0:1787756121.754141:0:6514:0:(mgc_request.c:68:mgc_name2resid()) log lustre to resid 0x65727473756c/0x0 (lustre)
00010000:00010000:0.0:1787756121.754157:0:6514:0:(ldlm_lock.c:775:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(EX) ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 3/0,1 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754172:0:6514:0:(ldlm_lock.c:1072:ldlm_granted_list_add_lock()) ### About to add lock: ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 3/0,1 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x50210000000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754181:0:6514:0:(ldlm_lock.c:954:ldlm_lock_decref_and_cancel()) ### ldlm_lock_decref(EX) ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 4/0,1 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40210000000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754187:0:6514:0:(ldlm_lock.c:829:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(EX) ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 4/0,1 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754193:0:6514:0:(ldlm_lock.c:887:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 3/0,0 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x50210400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754198:0:6514:0:(ldlm_lockd.c:1907:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 4/0,0 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754205:0:6514:0:(ldlm_lockd.c:1921:ldlm_handle_bl_callback()) Lock 00000000182e982c already unused, calling callback (00000000254105b0)
00010000:00010000:0.0:1787756121.754212:0:6514:0:(ldlm_request.c:378:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 4/0,0 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40210400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754218:0:6514:0:(ldlm_request.c:1416:ldlm_cli_cancel_local()) ### server-side local cancel ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 5/0,0 mode: EX/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40218400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754226:0:6514:0:(ldlm_lockd.c:1933:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 3/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754231:0:6514:0:(ldlm_request.c:557:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 1/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:0.0:1787756121.754234:0:6514:0:(ldlm_lock.c:193:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: MGS lock: 00000000182e982c/0x612e228bfecd358f lrc: 0/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6514 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
20000000:01000000:0.0:1787756121.754246:0:6514:0:(mgs_handler.c:637:mgs_target_reg()) replying with lustre-MDT0000, index=0, rc=0
Debug log: 288 lines, 288 kept, 0 dropped, 0 bad.