00000001:02000400:2.0F:1787756049.096374:0:3293:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg159-server.virtnet: executing set_hostid
00000001:02000400:0.0F:1787756061.290824:0:3496:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg159-server.virtnet: executing load_modules_local
00000001:01000000:3.0F:1787756062.726167:0:3559:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm adler32 speed = 843 MB/s
00000001:01000000:3.0:1787756062.976028:0:3559:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm crc32 speed = 1263 MB/s
00000001:01000000:1.0F:1787756063.226007:0:3559:0:(lnet-crypto.c:359:cfs_crypto_performance_test()) Crypto hash algorithm crc32c speed = 5563 MB/s
00000020:02000000:3.0:1787756063.908702:0:3588:0:(class_obd.c:771:obdclass_init()) Lustre: Build Version: 2.17.57_110_g6beee0e
00000400:02000000:2.0:1787756064.677514:0:3603:0:(api-ni.c:2823:lnet_startup_lndni()) Added LNI 192.168.201.159@tcp [8/256/0/180]
00008000:02000000:1.0:1787756067.729366:0:3753:0:(echo_client.c:2574:obdecho_init()) Echo OBD driver; http://www.lustre.org/
00000001:02000400:0.0:1787756104.412579:0:5717:0:(debug.c:653:libcfs_debug_mark_buffer()) DEBUG MARKER: oleg159-server.virtnet: executing load_modules_local
00000020:01000004:3.0:1787756111.930278:0:6466:0:(obd_mount.c:923:lmd_print())   mount data:
00000020:01000004:3.0:1787756111.930288:0:6466:0:(obd_mount.c:926:lmd_print()) device:  /dev/mapper/mds1_flakey
00000020:01000004:3.0:1787756111.930290:0:6466:0:(obd_mount.c:929:lmd_print()) options: user_xattr,errors=remount-ro
00000080:01200004:3.0:1787756111.930455:0:6466:0:(super25.c:131:lustre_fill_super()) VFS Op: sb 00000000b4e8d5f3
00000080:02000400:3.0:1787756111.930470:0:6466:0:(super25.c:149:lustre_fill_super()) lustre-MDT0000: mounting server target with '-t lustre' deprecated, use '-t lustre_tgt'
00000020:01000004:3.0:1787756111.935963:0:6466:0:(tgt_mount.c:2500:osd_start()) Attempting to start lustre-MDT0000, type=osd-ldiskfs, lsifl=200065, mountfl=0
00000020:01000004:3.0:1787756111.935976:0:6466:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD lustre-MDT0000-osd (typ=osd-ldiskfs)
00000020:00000080:1.0:1787756111.936060:0:6466:0:(genops.c:413:class_newdev()) Allocate new device lustre-MDT0000-osd (00000000c3c97fcd)
00000020:00000080:1.0:1787756111.936091:0:6466:0:(obd_config.c:720:class_attach_name()) OBD: dev 0 attached type osd-ldiskfs with refcount 2
00100000:10000000:0.0:1787756111.967063:0:6466:0:(scrub.c:230:scrub_file_store()) lustre-MDT0000: store scrub file: rc = 0
00100000:10000000:0.0:1787756111.967169:0:6466:0:(scrub.c:230:scrub_file_store()) lustre-MDT0000: store scrub file: rc = 0
00080000:01000000:0.0:1787756111.978192:0:6466:0:(osd_lproc.c:911:osd_procfs_init()) lustre-MDT0000: register osd-ldiskfs tunable parameters
00000020:00000080:0.0:1787756111.978451:0:6466:0:(obd_config.c:826:class_setup()) finished setup of obd lustre-MDT0000-osd (uuid lustre-MDT0000-osd_UUID)
00080000:01000000:0.0:1787756111.978460:0:6466:0:(osd_handler.c:8895:osd_obd_connect()) connect #0
00000020:00000080:0.0:1787756111.978472:0:6466:0:(genops.c:1385:class_connect()) connect: client lustre-MDT0000-osd_UUID, cookie 0xb3b030e9d319e854
00000020:01000004:0.0:1787756111.978479:0:6466:0:(tgt_mount.c:2585:server_fill_super()) Found service lustre-MDT0000 on device /dev/mapper/mds1_flakey
00000020:01000000:0.0:1787756111.978485:0:6466:0:(tgt_mount.c:219:server_start_mgs()) Start MGS service MGS
00000020:01000004:0.0:1787756111.978490:0:6466:0:(tgt_mount.c:101:server_register_mount()) register mount 00000000b4e8d5f3 from MGS
00000020:01000004:0.0:1787756111.978495:0:6466:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MGS (typ=mgs)
00000020:00000080:0.0:1787756111.978514:0:6466:0:(genops.c:413:class_newdev()) Allocate new device MGS (000000005c12ceef)
00000020:00000080:0.0:1787756111.978525:0:6466:0:(obd_config.c:720:class_attach_name()) OBD: dev 1 attached type mgs with refcount 2
00000020:01000004:0.0:1787756111.978619:0:6466:0:(tgt_mount.c:153:server_get_mount()) get mount 00000000b4e8d5f3 from MGS, refs=2
00080000:01000000:0.0:1787756111.978624:0:6466:0:(osd_handler.c:8895:osd_obd_connect()) connect #1
00000020:00000080:0.0:1787756111.978628:0:6466:0:(genops.c:1385:class_connect()) connect: client lustre-MDT0000-osd_UUID, cookie 0xb3b030e9d319e862
00000100:00100000:0.0:1787756111.978736:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) ldlm_cbd: allocate 1 new 8192-byte reqbufs (0/1 left), rc = 0
00000100:00100000:0.0:1787756111.978972:0:6466:0:(service.c:3462:ptlrpc_start_thread()) ldlm_cbd[0] started 0 min 2 max 56
00000100:00100000:0.0:1787756111.978978:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cb00_000'
00000100:00100000:1.0:1787756111.979382:0:6466:0:(service.c:3462:ptlrpc_start_thread()) ldlm_cbd[0] started 1 min 2 max 56
00000100:00100000:1.0:1787756111.979387:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cb00_001'
00000100:00100000:1.0:1787756111.980064:0:6466: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:1787756111.980210:0:6466:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 0 min 3 max 56
00000100:00100000:1.0:1787756111.980213:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_000'
00000100:00100000:0.0:1787756111.980692:0:6466:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 1 min 3 max 56
00000100:00100000:0.0:1787756111.980700:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_001'
00000100:00100000:0.0:1787756111.981503:0:6466:0:(service.c:3462:ptlrpc_start_thread()) ldlm_canceld[0] started 2 min 3 max 56
00000100:00100000:0.0:1787756111.981510:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'ldlm_cn00_002'
00010000:00010000:2.0:1787756111.981867:0:6477:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1787756111.981871:0:6477:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1787756111.981881:0:6477:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1787756111.982247:0:6478:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1787756111.982250:0:6478:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:2.0:1787756111.982251:0:6478:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00010000:00010000:0.0:1787756111.982561:0:6466:0:(ldlm_pool.c:923:ldlm_pool_init()) Lock pool ldlm-pool-MGS-0 is initialized
00010000:00010000:2.0:1787756111.984065:0:6477:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000001:01000000:2.0:1787756112.231887:0:6466:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10ip512 speed = 5567 MB/s
00000001:01000000:2.0:1787756112.482050:0:6466:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10ip4K speed = 7203 MB/s
00000001:01000000:2.0:1787756112.732343:0:6466:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10crc512 speed = 1383 MB/s
00000001:01000000:2.0:1787756112.982295:0:6466:0:(integrity.c:236:obd_t10_performance_test()) MGS: T10 checksum algorithm t10crc4K speed = 1743 MB/s
00080000:10000000:2.0:1787756112.986485:0:6466:0:(osd_handler.c:5551:osd_index_try()) lustre-MDT0000: index object [0x200000003:0x2:0x0] (8/32) registered
00000040:01000000:2.0:1787756112.993648:0:6466:0:(llog_obd.c:197:llog_setup()) obd MGS ctxt 0 is initialized
10000000:01000000:2.0:1787756112.996398:0:6480:0:(mgc_request.c:68:mgc_name2resid()) log params to resid 0x736d61726170/0x2 (params)
20000000:01000000:1.0:1787756112.996460:0:6466:0:(mgs_nids.c:666:mgs_nidtbl_init_fs()) IR: current version is 2
20000000:01000000:1.0:1787756112.996536:0:6466:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
00000040:00080000:1.0:1787756112.997011:0:6466:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
20000000:01000000:1.0:1787756112.997052:0:6466:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
00000100:00100000:1.0:1787756112.997550:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mgs: allocate 64 new 8192-byte reqbufs (0/64 left), rc = 0
00000100:00100000:1.0:1787756112.997809:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 0 min 3 max 32
00000100:00100000:1.0:1787756112.997817:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0000'
00000100:00100000:1.0:1787756112.998822:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 1 min 3 max 32
00000100:00100000:1.0:1787756112.998879:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0001'
00000100:00100000:1.0:1787756112.999342:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mgs[-1] started 2 min 3 max 32
00000100:00100000:1.0:1787756112.999350:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'll_mgs_0002'
00000100:00080000:0.0:1787756113.000048:0:6485:0:(pinger.c:466:ping_evictor_main()) Starting Ping Evictor
00000020:00000080:1.0:1787756113.000125:0:6466:0:(obd_config.c:826:class_setup()) finished setup of obd MGS (uuid MGS)
00000020:01000004:1.0:1787756113.000153:0:6466:0:(obd_mount.c:411:lustre_start_mgc()) Start MGC 'MGC192.168.201.159@tcp'
00000020:01000004:1.0:1787756113.000155:0:6466:0:(obd_mount.c:420:lustre_start_mgc()) mgs NIDs (null).
00000020:01000004:1.0:1787756113.000232:0:6466:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MGC192.168.201.159@tcp (typ=mgc)
00000020:00000080:1.0:1787756113.000248:0:6466:0:(genops.c:413:class_newdev()) Allocate new device MGC192.168.201.159@tcp (000000000f77974e)
00000020:00000080:1.0:1787756113.000272:0:6466:0:(obd_config.c:720:class_attach_name()) OBD: dev 2 attached type mgc with refcount 2
00010000:00080000:1.0:1787756113.000383:0:6466:0:(ldlm_lib.c:102:import_set_conn()) imp 000000006eb217c6@MGC192.168.201.159@tcp: add connection 192.168.201.159@tcp at head
00010000:00010000:1.0:1787756113.000578:0:6466:0:(ldlm_pool.c:923:ldlm_pool_init()) Lock pool ldlm-pool-MGC192.168.201.159@tcp-0 is initialized
00000040:01000000:1.0:1787756113.000586:0:6466:0:(llog_obd.c:197:llog_setup()) obd MGC192.168.201.159@tcp ctxt 1 is initialized
10000000:01000000:3.0:1787756113.001083:0:6486:0:(mgc_request.c:631:mgc_requeue_thread()) Starting requeue thread
00000020:00000080:0.0:1787756113.001236:0:6466:0:(obd_config.c:826:class_setup()) finished setup of obd MGC192.168.201.159@tcp (uuid 38734e35-8c92-4405-b7c0-57579bb9a076)
00000020:00000080:0.0:1787756113.001265:0:6466:0:(genops.c:1385:class_connect()) connect: client 38734e35-8c92-4405-b7c0-57579bb9a076, cookie 0xb3b030e9d319e870
00000100:00080000:0.0:1787756113.001279:0:6466:0:(import.c:510:import_select_connection()) MGC192.168.201.159@tcp: connect to NID 0@lo last attempt 0
00000100:00080000:0.0:1787756113.001345:0:6466:0:(import.c:624:import_select_connection()) MGC192.168.201.159@tcp: import 000000006eb217c6 using connection 192.168.201.159@tcp/0@lo
00000100:00100000:0.0:1787756113.001384:0:6466:0:(import.c:826:ptlrpc_connect_import_locked()) @@@ (re)connect request (timeout 5)  req@00000000c0706432 x1874598102564992/t0(0) o250->MGC192.168.201.159@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:00080000:0.0:1787756113.001408:0:6466:0:(pinger.c:373:ptlrpc_pinger_add_import()) adding pingable import 38734e35-8c92-4405-b7c0-57579bb9a076->MGS
00000020:01000004:0.0:1787756113.001444:0:6466:0:(tgt_mount.c:1809:server_start_targets()) starting target lustre-MDT0000
00000020:01000004:0.0:1787756113.001450:0:6466:0:(obd_mount.c:230:lustre_start_simple()) Starting OBD MDS (typ=mds)
00000020:00000080:0.0:1787756113.001464:0:6466:0:(genops.c:413:class_newdev()) Allocate new device MDS (0000000057387b13)
00000020:00000080:0.0:1787756113.001484:0:6466:0:(obd_config.c:720:class_attach_name()) OBD: dev 3 attached type mds with refcount 2
00000100:00100000:3.0:1787756113.005068:0:3618:0:(client.c:1919:ptlrpc_send_new_req()) Sending RPC req@00000000c0706432 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_rcv:38734e35-8c92-4405-b7c0-57579bb9a076:3618:1874598102564992:0@lo:250:
00000100:00100000:3.0:1787756113.005145:0:3618:0:(events.c:340:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:1.0:1787756113.005218:0:6482:0:(service.c:2301:ptlrpc_server_handle_req_in()) unwrap req x1874598102564992
00000100:00100000:1.0:1787756113.005225:0:6482:0:(service.c:2366:ptlrpc_server_handle_req_in()) got req x1874598102564992
00000100:00100000:1.0:1787756113.005257:0:6482:0:(nrs_fifo.c:152:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 0
00000100:00100000:1.0:1787756113.005262:0:6482:0:(service.c:2552:ptlrpc_server_handle_request()) Handling RPC req@00000000d4089712 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:0+-99:3618:x1874598102564992:12345-0@lo:250:
00010000:00080000:1.0:1787756113.005294:0:6482:0:(ldlm_lib.c:1482:target_handle_connect()) MGS: connection from 38734e35-8c92-4405-b7c0-57579bb9a076@0@lo t0 exp 0000000000000000 cur 109 last 0
00000020:00000080:1.0:1787756113.005335:0:6482:0:(genops.c:1385:class_connect()) connect: client 38734e35-8c92-4405-b7c0-57579bb9a076, cookie 0xb3b030e9d319e87e
00000100:00080000:1.0:1787756113.005446:0:6482:0:(import.c:65:import_set_state_nolock()) 000000008a2811f3 : changing import state from RECOVER to FULL
00000100:00100000:1.0:1787756113.005529:0:6482:0:(service.c:2610:ptlrpc_server_handle_request()) Handled RPC req@00000000d4089712 pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0000:38734e35-8c92-4405-b7c0-57579bb9a076+5:3618:x1874598102564992:12345-0@lo:250: Request processed in 265us (384us total) trans 0 rc 0/0
00000100:00100000:1.0:1787756113.005536:0:6482:0:(nrs_fifo.c:211:nrs_fifo_req_stop()) NRS stop fifo request from 12345-0@lo, seq: 0
00000100:00100000:3.0:1787756113.005562:0:3618:0:(client.c:3125:ptlrpc_free_committed()) MGC192.168.201.159@tcp: committing for last_committed 0 gen 1
00000100:00080000:3.0:1787756113.005571:0:3618:0:(import.c:1132:ptlrpc_connect_interpret()) MGC192.168.201.159@tcp: connect to target with instance 0
00000100:00080000:3.0:1787756113.005579:0:3618:0:(import.c:956:ptlrpc_connect_set_flags()) MGC192.168.201.159@tcp: Resetting ns_connect_flags to server flags: 0xa000011001002060
10000000:01000000:3.0:1787756113.005586:0:3618:0:(mgc_request.c:1168:mgc_import_event()) import event 0x808005
00000100:00080000:3.0:1787756113.005591:0:3618:0:(import.c:65:import_set_state_nolock()) 000000006eb217c6 MGS: changing import state from CONNECTING to FULL
10000000:01000000:3.0:1787756113.005595:0:3618:0:(mgc_request.c:1168:mgc_import_event()) import event 0x808004
00000100:00080000:3.0:1787756113.005610:0:3618:0:(pinger.c:186:ptlrpc_pinger_ir_up()) IR up
00000100:00100000:3.0:1787756113.005616:0:3618:0:(client.c:2414:ptlrpc_check_set()) Completed RPC req@00000000c0706432 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_rcv:38734e35-8c92-4405-b7c0-57579bb9a076:3618:1874598102564992:0@lo:250:
00000100:00100000:0.0:1787756113.008404:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt: allocate 64 new 262144-byte reqbufs (0/64 left), rc = 0
00000100:00100000:0.0:1787756113.008663:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 0 min 3 max 116
00000100:00100000:0.0:1787756113.008670:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_000'
00000100:00100000:0.0:1787756113.009501:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 1 min 3 max 116
00000100:00100000:0.0:1787756113.009509:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_001'
00000100:00100000:1.0:1787756113.010598:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt[0] started 2 min 3 max 116
00000100:00100000:1.0:1787756113.010610:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt00_002'
00000100:00100000:2.0:1787756113.012037:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_readpage: allocate 64 new 8192-byte reqbufs (0/64 left), rc = 0
00000100:00100000:2.0:1787756113.012410:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_readpage[0] started 0 min 2 max 80
00000100:00100000:2.0:1787756113.012417:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_rdpg00_000'
00000100:00100000:2.0:1787756113.013138:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_readpage[0] started 1 min 2 max 80
00000100:00100000:2.0:1787756113.013147:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_rdpg00_001'
00000100:00100000:2.0:1787756113.037074:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_out: allocate 64 new 1048576-byte reqbufs (0/64 left), rc = 0
00000100:00100000:2.0:1787756113.037270:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_out[0] started 0 min 2 max 116
00000100:00100000:2.0:1787756113.037276:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_out00_000'
00000100:00100000:2.0:1787756113.038142:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_out[0] started 1 min 2 max 116
00000100:00100000:2.0:1787756113.038150:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_out00_001'
00000100:00100000:3.0:1787756113.038702:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_seqs: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:3.0:1787756113.038942:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqs[-1] started 0 min 2 max 256
00000100:00100000:3.0:1787756113.038948:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqs_0000'
00000100:00100000:3.0:1787756113.039358:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqs[-1] started 1 min 2 max 256
00000100:00100000:3.0:1787756113.039365:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqs_0001'
00010000:00010000:1.0:1787756113.039404:0:6478:0:(ldlm_lockd.c:2804:ldlm_bl_get_work()) No blwi found in queue (no bl locks in queue)
00000100:00100000:3.0:1787756113.039769:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_seqm: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:3.0:1787756113.040153:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqm[-1] started 0 min 2 max 256
00000100:00100000:3.0:1787756113.040157:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqm_0000'
00000100:00100000:3.0:1787756113.040451:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_seqm[-1] started 1 min 2 max 256
00000100:00100000:3.0:1787756113.040457:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_seqm_0001'
00000100:00100000:3.0:1787756113.040787:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_fld: allocate 64 new 4096-byte reqbufs (0/64 left), rc = 0
00000100:00100000:3.0:1787756113.041011:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_fld[-1] started 0 min 2 max 256
00000100:00100000:3.0:1787756113.041016:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_fld_0000'
00000100:00100000:3.0:1787756113.041419:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_fld[-1] started 1 min 2 max 256
00000100:00100000:3.0:1787756113.041425:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_fld_0001'
00000100:00100000:3.0:1787756113.052678:0:6466:0:(service.c:155:ptlrpc_grow_req_bufs()) mdt_io: allocate 64 new 524288-byte reqbufs (0/64 left), rc = 0
00000100:00100000:3.0:1787756113.052819:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 0 min 3 max 116
00000100:00100000:3.0:1787756113.052823:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_000'
00000100:00100000:3.0:1787756113.054176:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 1 min 3 max 116
00000100:00100000:3.0:1787756113.054186:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_001'
00000100:00100000:3.0:1787756113.055398:0:6466:0:(service.c:3462:ptlrpc_start_thread()) mdt_io[0] started 2 min 3 max 116
00000100:00100000:3.0:1787756113.055407:0:6466:0:(service.c:3521:ptlrpc_start_thread()) starting thread 'mdt_io00_002'
00000020:00000080:3.0:1787756113.056436:0:6466:0:(obd_config.c:826:class_setup()) finished setup of obd MDS (uuid MDS_uuid)
00000020:01000004:3.0:1787756113.056467:0:6466:0:(tgt_mount.c:280:server_mgc_set_fs()) Set mgc disk for /dev/mapper/mds1_flakey
10000000:01000000:3.0:1787756113.056473:0:6466:0:(mgc_request_server.c:89:mgc_fs_setup()) MGC192.168.201.159@tcp: cl_mgc_mutex lustre-MDT0000-osd for locked: rc = 0
00000040:01000000:3.0:1787756113.056585:0:6466:0:(llog_obd.c:197:llog_setup()) obd MGC192.168.201.159@tcp ctxt 0 is initialized
00000020:01000004:3.0:1787756113.056614:0:6466:0:(tgt_mount.c:1418:server_register_target()) Registration lustre-MDT0000, fs=lustre, 192.168.201.159@tcp, index=0000, flags=0x20065
00000020:01000004:3.0:1787756113.056618:0:6466:0:(tgt_mount.c:1175:server_mti_print()) mti - server_register_target
00000020:01000004:3.0:1787756113.056620:0:6466:0:(tgt_mount.c:1176:server_mti_print()) server: lustre-MDT0000
00000020:01000004:3.0:1787756113.056621:0:6466:0:(tgt_mount.c:1177:server_mti_print()) fs:     lustre
00000020:01000004:3.0:1787756113.056622:0:6466:0:(tgt_mount.c:1178:server_mti_print()) uuid:   
00000020:01000004:3.0:1787756113.056623:0:6466:0:(tgt_mount.c:1179:server_mti_print()) ver:    0
00000020:01000004:3.0:1787756113.056624:0:6466:0:(tgt_mount.c:1180:server_mti_print()) flags:
00000020:01000004:3.0:1787756113.056626:0:6466:0:(tgt_mount.c:1182:server_mti_print()) 	 LDD_F_SV_TYPE_MDT
00000020:01000004:3.0:1787756113.056627:0:6466:0:(tgt_mount.c:1186:server_mti_print()) 	 LDD_F_SV_TYPE_MGS
00000020:01000004:3.0:1787756113.056628:0:6466:0:(tgt_mount.c:1192:server_mti_print()) 	 LDD_F_VIRIGIN
00000020:01000004:3.0:1787756113.056629:0:6466:0:(tgt_mount.c:1194:server_mti_print()) 	 LDD_F_UPDATE
00000020:01000004:3.0:1787756113.056631:0:6466:0:(tgt_mount.c:1214:server_mti_print()) 	 LDD_F_LARGE_NID
00000020:01000004:3.0:1787756113.056632:0:6466:0:(tgt_mount.c:1216:server_mti_print()) 	 LDD_F_OPC_REG
10000000:01000000:3.0:1787756113.056634:0:6466:0:(mgc_request_server.c:451:mgc_set_info_async_server()) register_target lustre-MDT0000 0x10020065
00000020:01000004:3.0:1787756113.056637:0:6466:0:(tgt_mount.c:1175:server_mti_print()) mti - mgc_target_register: req
00000020:01000004:3.0:1787756113.056638:0:6466:0:(tgt_mount.c:1176:server_mti_print()) server: lustre-MDT0000
00000020:01000004:3.0:1787756113.056639:0:6466:0:(tgt_mount.c:1177:server_mti_print()) fs:     lustre
00000020:01000004:3.0:1787756113.056640:0:6466:0:(tgt_mount.c:1178:server_mti_print()) uuid:   
00000020:01000004:3.0:1787756113.056641:0:6466:0:(tgt_mount.c:1179:server_mti_print()) ver:    0
00000020:01000004:3.0:1787756113.056643:0:6466:0:(tgt_mount.c:1180:server_mti_print()) flags:
00000020:01000004:3.0:1787756113.056643:0:6466:0:(tgt_mount.c:1182:server_mti_print()) 	 LDD_F_SV_TYPE_MDT
00000020:01000004:3.0:1787756113.056644:0:6466:0:(tgt_mount.c:1186:server_mti_print()) 	 LDD_F_SV_TYPE_MGS
00000020:01000004:3.0:1787756113.056650:0:6466:0:(tgt_mount.c:1192:server_mti_print()) 	 LDD_F_VIRIGIN
00000020:01000004:3.0:1787756113.056651:0:6466:0:(tgt_mount.c:1194:server_mti_print()) 	 LDD_F_UPDATE
00000020:01000004:3.0:1787756113.056652:0:6466:0:(tgt_mount.c:1214:server_mti_print()) 	 LDD_F_LARGE_NID
00000020:01000004:3.0:1787756113.056652:0:6466:0:(tgt_mount.c:1216:server_mti_print()) 	 LDD_F_OPC_REG
10000000:01000000:3.0:1787756113.056800:0:6466:0:(mgc_request_server.c:281:mgc_target_register()) register lustre-MDT0000
00000100:00100000:3.0:1787756113.056816:0:6466:0:(client.c:1919:ptlrpc_send_new_req()) Sending RPC req@00000000d085c6b7 pname:cluuid:pid:xid:nid:opc:job mount.lustre:38734e35-8c92-4405-b7c0-57579bb9a076:6466:1874598102565120:0@lo:253:
00000100:00100000:3.0:1787756113.056905:0:6466:0:(events.c:340:request_in_callback()) peer: 12345-0@lo (source: 12345-0@lo)
00000100:00100000:0.0:1787756113.056931:0:6484:0:(service.c:2301:ptlrpc_server_handle_req_in()) unwrap req x1874598102565120
00000100:00100000:0.0:1787756113.056939:0:6484:0:(service.c:2366:ptlrpc_server_handle_req_in()) got req x1874598102565120
00000100:00100000:3.0:1787756113.056961:0:6466:0:(client.c:2715:ptlrpc_set_wait()) set 00000000292d2516 going to sleep for 11 seconds
00000100:00100000:0.0:1787756113.056990:0:6484:0:(nrs_fifo.c:152:nrs_fifo_req_get()) NRS start fifo request from 12345-0@lo, seq: 1
00000100:00100000:0.0:1787756113.057000:0:6484:0:(service.c:2552:ptlrpc_server_handle_request()) Handling RPC req@0000000030df639a pname:cluuid+ref:pid:xid:nid:opc:job ll_mgs_0002:38734e35-8c92-4405-b7c0-57579bb9a076+5:6466:x1874598102565120:12345-0@lo:253:
20000000:01000000:0.0:1787756113.057041:0:6484:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
20000000:01000000:0.0:1787756113.057044:0:6484:0:(mgs_handler.c:479:mgs_target_reg()) fs: lustre index: 0 is registered to MGS.
10000000:01000000:0.0:1787756113.057289:0:6505:0:(mgc_request.c:68:mgc_name2resid()) log lustre to resid 0x65727473756c/0x2 (lustre)
20000000:01000000:2.0:1787756113.057317:0:6484:0:(mgs_nids.c:666:mgs_nidtbl_init_fs()) IR: current version is 2
00000040:00080000:2.0:1787756113.057560:0:6484:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:0.0:1787756113.058218:0:6506:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 64768 count 1
20000000:01000000:2.0:1787756113.058369:0:6484:0:(mgs_llog.c:684:mgs_find_or_make_fsdb_nolock()) Created new db: rc = 0
20000000:01000000:2.0:1787756113.058372:0:6484:0:(mgs_handler.c:599:mgs_target_reg()) updating lustre-MDT0000, index=0
20000000:01000000:2.0:1787756113.058376:0:6484:0:(mgs_llog.c:869:mgs_set_index()) Set index for lustre-MDT0000 to 0
20000000:01000000:2.0:1787756113.058378:0:6484:0:(mgs_llog.c:3612:mgs_write_log_mdt()) writing new mdt lustre-MDT0000
20000000:01000000:2.0:1787756113.058385:0:6484:0:(mgs_llog.c:3172:mgs_write_log_lov()) Writing lov(lustre-MDT0000-mdtlov) log for lustre-MDT0000
00000040:00080000:2.0:1787756113.058453:0:6484:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:2.0:1787756113.058608:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].1, 224 off8416
20000000:01000000:2.0:1787756113.058618:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdtlov 0xcf001 lov lustre-MDT0000-mdtlov_UUID (null) (null)
00000040:00080000:2.0:1787756113.058629:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].2, 136 off8552
00000040:00080000:2.0:1787756113.058637:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].3, 176 off8728
00000040:00080000:2.0:1787756113.058654:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].4, 224 off8952
00000040:00080000:2.0:1787756113.058695:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].5, 224 off9176
20000000:01000000:2.0:1787756113.058703:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000 0xcf001 mdt lustre-MDT0000_UUID (null) (null)
00000040:00080000:2.0:1787756113.058716:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].6, 120 off9296
20000000:01000000:2.0:1787756113.058721:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf007 lustre-MDT0000 lustre-MDT0000-mdtlov (null) (null)
00000040:00080000:2.0:1787756113.058731:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].7, 112 off9408
20000000:01000000:2.0:1787756113.058734:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000 0xcf003 lustre-MDT0000_UUID 0 lustre-MDT0000-mdtlov f
00000040:00080000:2.0:1787756113.058740:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].8, 160 off9568
00000040:00080000:2.0:1787756113.058747:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].9, 224 off9792
00000040:00080000:2.0:1787756113.058764:0:6484:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
20000000:01000000:2.0:1787756113.058766:0:6484:0:(mgs_llog.c:3172:mgs_write_log_lov()) Writing lov(lustre-clilov) log for lustre-client
00000040:00080000:2.0:1787756113.058770:0:6484:0:(llog_osd.c:211:llog_osd_read_header()) not reading header from 0-byte log
00000040:00080000:2.0:1787756113.058888:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].1, 224 off8416
20000000:01000000:2.0:1787756113.058899:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilov 0xcf001 lov lustre-clilov_UUID (null) (null)
00000040:00080000:2.0:1787756113.058911:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].2, 120 off8536
00000040:00080000:2.0:1787756113.058919:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].3, 168 off8704
00000040:00080000:2.0:1787756113.058926:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].4, 224 off8928
20000000:01000000:2.0:1787756113.058930:0:6484:0:(mgs_llog.c:3129:mgs_write_log_lmv()) Writing lmv(lustre-clilmv) log for lustre-client
00000040:00080000:2.0:1787756113.058944:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].5, 224 off9152
20000000:01000000:2.0:1787756113.058948:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilmv 0xcf001 lmv lustre-clilmv_UUID (null) (null)
00000040:00080000:2.0:1787756113.058954:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].6, 120 off9272
00000040:00080000:2.0:1787756113.058961:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].7, 168 off9440
00000040:00080000:2.0:1787756113.058968:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].8, 224 off9664
20000000:01000000:2.0:1787756113.058972:0:6484:0:(mgs_llog.c:3094:mgs_write_log_mount_opt()) Writing mount options log for lustre-client
00000040:00080000:2.0:1787756113.058983:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].9, 224 off9888
20000000:01000000:2.0:1787756113.058986:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf007 lustre-client lustre-clilov lustre-clilmv (null)
00000040:00080000:2.0:1787756113.058992:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].10, 120 off10008
00000040:00080000:2.0:1787756113.059011:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].11, 224 off10232
00000040:00080000:2.0:1787756113.059065:0:6484:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 12 count 12
20000000:01000000:2.0:1787756113.059083:0:6484: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:2.0:1787756113.059089:0:6484:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-client/lustre-MDT0000/add mdc fl=4
00000040:00080000:0.0:1787756113.059365:0:6507:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 12 count 12
00000040:00080000:2.0:1787756113.059470:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].12, 224 off10456
20000000:01000000:2.0:1787756113.059487:0:6484:0:(mgs_llog.c:3355:mgs_write_log_mdc_to_lmv()) add nid 192.168.201.159@tcp for mdt
20000000:01000000:2.0:1787756113.059489:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg (null) 0xcf005 192.168.201.159@tcp (null) (null) (null)
00000040:00080000:2.0:1787756113.059503:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].13, 88 off10544
20000000:01000000:2.0:1787756113.059509:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdc 0xcf001 mdc lustre-clilmv_UUID (null) (null)
00000040:00080000:2.0:1787756113.059523:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].14, 128 off10672
20000000:01000000:2.0:1787756113.059528:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-MDT0000-mdc 0xcf003 lustre-MDT0000_UUID 192.168.201.159@tcp (null) (null)
00000040:00080000:2.0:1787756113.059541:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].15, 144 off10816
20000000:01000000:2.0:1787756113.059548:0:6484:0:(mgs_llog.c:1539:record_base_raw()) lcfg lustre-clilmv 0xcf014 lustre-MDT0000_UUID 0 1 lustre-MDT0000-mdc_UUID
00000040:00080000:2.0:1787756113.059561:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].16, 160 off10976
00000040:00080000:2.0:1787756113.059577:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].17, 224 off11200
20000000:01000000:2.0:1787756113.059603:0:6484: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:2.0:1787756113.059606:0:6484:0:(mgs_llog.c:4748:mgs_write_log_param()) next param 'sys.timeout=20'
20000000:01000000:2.0:1787756113.059609:0:6484:0:(mgs_llog.c:4181:mgs_write_log_sys()) global 'sys.timeout=20' val=20
20000000:01000000:2.0:1787756113.059649:0:6484:0:(mgs_llog.c:2550:mgs_write_log_direct_all()) Changing log lustre-client
20000000:01000000:2.0:1787756113.059651:0:6484:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-client/lustre/sys.timeout fl=4
00000040:00080000:0.0:1787756113.059904:0:6508:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x3:0x0] index 18 count 18
00000040:00080000:2.0:1787756113.059977:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].18, 224 off11424
00000040:00080000:2.0:1787756113.059997:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].19, 80 off11504
00000040:00080000:2.0:1787756113.060012:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x3:0x0].20, 224 off11728
20000000:01000000:2.0:1787756113.060019:0:6484:0:(mgs_llog.c:2550:mgs_write_log_direct_all()) Changing log lustre-MDT0000
20000000:01000000:2.0:1787756113.060020:0:6484:0:(mgs_llog.c:1109:mgs_modify()) modify lustre-MDT0000/lustre/sys.timeout fl=4
00000040:00080000:0.0:1787756113.060209:0:6509:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x4:0x0] index 10 count 10
00000040:00080000:2.0:1787756113.060276:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].10, 224 off10016
00000040:00080000:2.0:1787756113.060296:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].11, 80 off10096
00000040:00080000:2.0:1787756113.060312:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].12, 224 off10320
00000020:00000080:2.0:1787756113.060321:0:6484:0:(obd_config.c:1472:class_process_config()) processing cmd: cf009
00000020:00000080:2.0:1787756113.060324:0:6484:0:(obd_config.c:1537:class_process_config()) changing lustre timeout from 100 to 20
20000000:01000000:2.0:1787756113.060326:0:6484: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:2.0:1787756113.060329:0:6484: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:2.0:1787756113.060338:0:6484:0:(mgs_llog.c:5072:mgs_write_log_param()) mdt param identity_upcall=/home/green/git/lustre-release/lustre/utils/l_getidentity
20000000:01000000:2.0:1787756113.060344:0:6484: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:0.0:1787756113.060623:0:6510:0:(llog.c:862:llog_process_thread()) stop processing plain [0xa:0x4:0x0] index 13 count 13
20000000:02000000:2.0:1787756113.060666:0:6484: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:2.0:1787756113.064017:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].13, 224 off10544
00000040:00080000:2.0:1787756113.064040:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].14, 160 off10704
00000040:00080000:2.0:1787756113.064049:0:6484:0:(llog_osd.c:725:llog_osd_write_rec()) added record [0xa:0x4:0x0].15, 224 off10928
10000000:01000000:2.0:1787756113.064063:0:6484:0:(mgc_request.c:68:mgc_name2resid()) log lustre to resid 0x65727473756c/0x0 (lustre)
00010000:00010000:2.0:1787756113.064080:0:6484:0:(ldlm_lock.c:775:ldlm_lock_addref_internal_nolock()) ### ldlm_lock_addref(EX) ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 lrc: 3/0,1 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x40000000000000 nid: local remote: 0x0 expref: -99 pid: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064092:0:6484:0:(ldlm_lock.c:1072:ldlm_granted_list_add_lock()) ### About to add lock: ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064100:0:6484:0:(ldlm_lock.c:954:ldlm_lock_decref_and_cancel()) ### ldlm_lock_decref(EX) ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064103:0:6484:0:(ldlm_lock.c:829:ldlm_lock_decref_internal_nolock()) ### ldlm_lock_decref(EX) ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064107:0:6484:0:(ldlm_lock.c:887:ldlm_lock_decref_internal()) ### final decref done on CBPENDING lock ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064111:0:6484:0:(ldlm_lockd.c:1907:ldlm_handle_bl_callback()) ### client blocking AST callback handler ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064114:0:6484:0:(ldlm_lockd.c:1921:ldlm_handle_bl_callback()) Lock 000000003dd1efe9 already unused, calling callback (000000008b0cffb9)
00010000:00010000:2.0:1787756113.064117:0:6484:0:(ldlm_request.c:378:ldlm_blocking_ast_nocheck()) ### already unused, calling ldlm_cli_cancel ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064122:0:6484:0:(ldlm_request.c:1416:ldlm_cli_cancel_local()) ### server-side local cancel ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 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: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064152:0:6484:0:(ldlm_lockd.c:1933:ldlm_handle_bl_callback()) ### client blocking callback handler END ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 lrc: 3/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064159:0:6484:0:(ldlm_request.c:557:ldlm_cli_enqueue_local()) ### client-side local enqueue handler, new lock created ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 lrc: 1/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
00010000:00010000:2.0:1787756113.064165:0:6484:0:(ldlm_lock.c:193:ldlm_lock_put()) ### final lock_put on destroyed lock, freeing it. ns: MGS lock: 000000003dd1efe9/0xb3b030e9d319e885 lrc: 0/0,0 mode: --/EX res: [0x65727473756c:0x0:0x0].0x0 rrc: 2 type: PLN flags: 0x44a19400000000 nid: local remote: 0x0 expref: -99 pid: 6484 timeout: 0 lvb_type: 0 lru_score: 0 lru_type: 0
20000000:01000000:2.0:1787756113.064181:0:6484: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.