Project

General

Profile

Bug #59394 » MDS-Small3.log

Brian Woods, 05/09/2023 07:47 PM

 
debug 2023-05-09T18:53:03.454+0000 7fb2e883f700 10 MDSAuthCap is_capable inode(path /Pool-ErasurePool/MediaStore/UserName/USB-Drive owner 11002:12101 mode 042770) by caller 0:0 mask 1 new 0:0 cap: MDSAuthCaps[allow *]
debug 2023-05-09T18:53:03.454+0000 7fb2e883f700 20 mds.0.bal hit_dir 0 pop is 1, frag * size 20 [pop IRD:[C 1.00e+00] IWR:[C 0.00e+00] RDR:[C 2.00e+01] FET:[C 0.00e+00] STR:[C 0.00e+00] *LOAD:21.0]

debug 2023-05-09T18:53:03.454+0000 7fb2e883f700 10 mds.0.server reply to stat on client_request(client.61004462:1474231706 getattr Fa #0x1000067f7ef 2023-05-09T18:53:03.458639+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server respond_to_request batch head request(client.61004462:1474231706 nref=3 cr=0x55e0a0ece840)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 respond: responding to batch ops with result=0: [batch front=request(client.61004462:1474231706 nref=3 cr=0x55e0a0ece840)]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.server reply_client_request 0 ((0) Success) client_request(client.61004462:1474231706 getattr Fa #0x1000067f7ef 2023-05-09T18:53:03.458639+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server apply_allocated_inos 0x0 / [] / 0x0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server lat 0.000643
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server set_trace_dist snapid head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server set_trace_dist snaprealm snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} past_parent_snaps= 0x55e077abe400) len=48
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.cache.ino(0x1000067f7ef) pfile 1 pauth 1 plink 1 pxattr 1 plocal 0 ctime 2022-11-15T13:08:59.082506+0000 valid=1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) encode_inodestat issuing pAsLsXsFsx seq 13
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) encode_inodestat caps pAsLsXsFsx seq 13 mseq 0 xattrv 0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server set_trace_dist added in [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.17360 send_message_client client.61004462 192.168.10.250:0/2668832115 client_reply(???:1474231706 = 0 (0) Success) v1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache request_finish request(client.61004462:1474231706 nref=3 cr=0x55e0a0ece840)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache request_cleanup request(client.61004462:1474231706 nref=3 cr=0x55e0a0ece840)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=27) on [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=27) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=4) on [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=4) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) auth_unpin by 0x55e0c13e1000 on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00] now 0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7df) adjust_nested_auth_pins -1 on [dir 0x1000067f7df /Pool-ErasurePool/MediaStore/UserName/ [2,head] auth v=154678 cv=154678/154678 REP state=1074003969|complete f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148362=136530+11832) hs=20+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e0790a8000] by 0x55e0c13e1000 count now 0/0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 4 mds.0.server handle_client_request client_request(client.61004462:1474231707 getattr Fa #0x1000067f7df 2023-05-09T18:53:03.459932+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.server oldest_client_tid=1474231707
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache request_start request(client.61004462:1474231707 nref=2 cr=0x55e19c4a22c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.server dispatch_client_request client_request(client.61004462:1474231707 getattr Fa #0x1000067f7df 2023-05-09T18:53:03.459932+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache traverse: opening base ino 0x1000067f7df snap head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server rdlock_path_pin_ref request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0) #0x1000067f7df
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache traverse: opening base ino 0x1000067f7df snap head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker try_rdlock_snap_layout request(client.61004462:1474231707 nref=4 cr=0x55e19c4a22c0) [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=1 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=1 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=5) [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=5) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=28) [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=28) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server ref is [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=1 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7df) auth_pin by 0x55e0e0f6f400 on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 ap=1 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1021} | dirtyscattered=0 request=1 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=1 0x55e078f69080] now 1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7de) adjust_nested_auth_pins 1 on [dir 0x1000067f7de /Pool-ErasurePool/MediaStore/ [2,head] auth v=1200330 cv=1200330/1200330 REP ap=0+1 state=1074003969|complete f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240205=1174006+66199) hs=29+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e077c19180] by 0x55e078f69080 count now 0/1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker acquire_locks request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 Session check_access path /Pool-ErasurePool/MediaStore/UserName
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 MDSAuthCap is_capable inode(path /Pool-ErasurePool/MediaStore/UserName owner 11002:12101 mode 042770) by caller 0:0 mask 1 new 0:0 cap: MDSAuthCaps[allow *]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.bal hit_dir 0 pop is 1.99834, frag * size 29 [pop IRD:[C 2.00e+00] IWR:[C 0.00e+00] RDR:[C 0.00e+00] FET:[C 0.00e+00] STR:[C 0.00e+00] *LOAD:2.0]

debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server reply to stat on client_request(client.61004462:1474231707 getattr Fa #0x1000067f7df 2023-05-09T18:53:03.459932+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server respond_to_request batch head request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 respond: responding to batch ops with result=0: [batch front=request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0)]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.server reply_client_request 0 ((0) Success) client_request(client.61004462:1474231707 getattr Fa #0x1000067f7df 2023-05-09T18:53:03.459932+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server apply_allocated_inos 0x0 / [] / 0x0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server lat 0.000665
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server set_trace_dist snapid head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server set_trace_dist snaprealm snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} past_parent_snaps= 0x55e077abe400) len=48
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.cache.ino(0x1000067f7df) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 2022-12-15T04:35:54.407540+0000 valid=1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7df) encode_inodestat issuing pAsLsXsFs seq 1022
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7df) encode_inodestat caps pAsLsXsFs seq 1022 mseq 0 xattrv 0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.server set_trace_dist added in [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 ap=1 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=1 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=1 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.17360 send_message_client client.61004462 192.168.10.250:0/2668832115 client_reply(???:1474231707 = 0 (0) Success) v1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache request_finish request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache request_cleanup request(client.61004462:1474231707 nref=3 cr=0x55e19c4a22c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=27) on [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=27) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=4) on [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=4) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 ap=1 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=1 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=1 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 ap=1 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=1 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=1 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7df) auth_unpin by 0x55e0e0f6f400 on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=1 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080] now 0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7de) adjust_nested_auth_pins -1 on [dir 0x1000067f7de /Pool-ErasurePool/MediaStore/ [2,head] auth v=1200330 cv=1200330/1200330 REP state=1074003969|complete f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240205=1174006+66199) hs=29+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e077c19180] by 0x55e0e0f6f400 count now 0/0
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 4 mds.0.server handle_client_request client_request(client.61004462:1474231708 readdir #0x1000067f7ef 2023-05-09T18:53:03.461186+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.server oldest_client_tid=1474231708
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache request_start request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.server dispatch_client_request client_request(client.61004462:1474231708 readdir #0x1000067f7ef 2023-05-09T18:53:03.461186+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server rdlock_path_pin_ref request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0) #0x1000067f7ef
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.cache traverse: opening base ino 0x1000067f7ef snap head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker try_rdlock_snap_layout request(client.61004462:1474231708 nref=3 cr=0x55e0a782a2c0) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=0 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=0 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=5) [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=5) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=28) [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=28) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.server ref is [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=0 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker acquire_locks request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0)
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker must rdlock (ifile excl) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker must rdlock (idft sync) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker must authpin [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker auth_pinning [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) auth_pin by 0x55e0b4fd3800 on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00] now 1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7df) adjust_nested_auth_pins 1 on [dir 0x1000067f7df /Pool-ErasurePool/MediaStore/UserName/ [2,head] auth v=154678 cv=154678/154678 REP ap=0+1 state=1074003969|complete f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148362=136530+11832) hs=20+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e0790a8000] by 0x55e079f48c00 count now 0/1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_start on (ifile excl) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker simple_sync on (ifile excl) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker get_allowed_caps loner client.61004462 allowed=pAsLsXsFscr, xlocker allowed=pAsLsXsFscr, others allowed=pAsLsXs on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFsx/-@13},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.locker client.61004462 pending pAsLsXsFsx allowed pAsLsXsFs wanted -
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker sending MClientCaps to client.61004462 seq 14 new pending pAsLsXsFs was pAsLsXsFsx
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 20 mds.0.cache.ino(0x1000067f7ef) encode_cap_message pfile 1 pauth 0 plink 0 pxattr 0 ctime 2022-11-15T13:08:59.082506+0000
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.17360 send_message_client_counted client.61004462 seq 32066591 client_caps(revoke ino 0x1000067f7ef 138485445 seq 14 caps=pAsLsXsFs dirty=- wanted=- follows 0 size 0/0 ts 1/18446744073709551615 mtime 2022-01-26T19:23:09.000000+0000 tws 2) v11
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) auth_pin by 0x55e079f48f10 on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/pAsLsXsFsx/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00] now 2
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7df) adjust_nested_auth_pins 1 on [dir 0x1000067f7df /Pool-ErasurePool/MediaStore/UserName/ [2,head] auth v=154678 cv=154678/154678 REP ap=0+2 state=1074003969|complete f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148362=136530+11832) hs=20+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e0790a8000] by 0x55e079f48c00 count now 0/2
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 7 mds.0.locker rdlock_start waiting on (ifile excl->sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/pAsLsXsFsx/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) add_waiter tag 2000000040000000 0x55e0a8777640 !ambig 1 !frozen 1 !freezing 1
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 15 mds.0.cache.ino(0x1000067f7ef) taking waiter here
debug 2023-05-09T18:53:03.458+0000 7fb2e883f700 10 mds.0.locker nudge_log (ifile excl->sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/pAsLsXsFsx/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker handle_client_caps on 0x1000067f7ef tid 0 follows 0 op update flags 0x0
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker head inode [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/pAsLsXsFsx/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker follows 0 retains pAsLsXsFs dirty - on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker _do_cap_update dirty - issued pAsLsXsFs wanted - on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker eval 3648 [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker eval_gather (ifile excl->sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker next state is sync issued/allows loner s/scrl xlocker /scrl other /scrl
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker eval_gather finished gather on (ifile excl->sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=2 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl->sync) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) auth_unpin by 0x55e079f48f10 on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=1 authpin=1 0x55e079f48c00] now 1
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7df) adjust_nested_auth_pins -1 on [dir 0x1000067f7df /Pool-ErasurePool/MediaStore/UserName/ [2,head] auth v=154678 cv=154678/154678 REP ap=0+1 state=1074003969|complete f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148362=136530+11832) hs=20+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e0790a8000] by 0x55e079f48f10 count now 0/1
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker file_eval stable, bump to loner (ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker file_excl (ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker simple_eval (iauth sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker simple_eval (ilink sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker simple_eval (ixattr sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 MDSContext::complete: 18C_MDS_RetryRequest
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.server dispatch_client_request client_request(client.61004462:1474231708 readdir #0x1000067f7ef 2023-05-09T18:53:03.461186+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.server rdlock_path_pin_ref request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0) #0x1000067f7ef
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker acquire_locks request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0)
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 mds.0.locker must rdlock (ifile excl) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 mds.0.locker must rdlock (idft sync) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker must authpin [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker already auth_pinned [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker rdlock_start on (ifile excl) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker simple_sync on (ifile excl) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker get_allowed_caps loner client.61004462 allowed=pAsLsXsFscrl, xlocker allowed=pAsLsXsFscrl, others allowed=pAsLsXsFscrl on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 mds.0.locker client.61004462 pending pAsLsXsFs allowed pAsLsXsFs wanted -
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker got rdlock on (ifile sync r=1) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=2 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 7 mds.0.locker rdlock_start on (idft sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=2 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.locker got rdlock on (idft sync r=1) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (idft sync r=1) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@14},l=61004462 | request=1 lock=3 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 20 Session check_access path /Pool-ErasurePool/MediaStore/UserName/USB-Drive
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 MDSAuthCap is_capable inode(path /Pool-ErasurePool/MediaStore/UserName/USB-Drive owner 11002:12101 mode 042770) by caller 0:0 mask 1 new 0:0 cap: MDSAuthCaps[allow *]
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.server frag * offset '' offset_hash 0 flags 1
debug 2023-05-09T18:53:03.462+0000 7fb2e883f700 10 mds.0.server handle_client_readdir on [dir 0x1000067f7ef /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ [2,head] auth v=24685 cv=24685/24685 state=1074003969|complete f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71242=66511+4731) hs=3+0,ss=0+0 | child=1 waiter=0 authpin=0 0x55e0f0dfcd80]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.server snapid head
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including dn [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada12 state=1073741824 | request=0 lock=0 inodepin=1 authpin=0 0x55e0f0ece500]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.locker issue_client_lease no/null lease on [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada12 state=1073741824 | request=0 lock=0 inodepin=1 authpin=0 0x55e0f0ece500]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including inode [inode 0x100006ada12 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download/ auth v24651 f(v0 m2022-11-15T13:12:16.389934+0000 103=14+89) n(v1376 rc2022-11-15T16:02:07.438227+0000 b295230152010 55940=51886+4054) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@27},l=61004462 | request=0 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e0f0eca580]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.cache.ino(0x100006ada12) pfile 1 pauth 1 plink 1 pxattr 1 plocal 0 ctime 2022-11-15T13:12:16.393934+0000 valid=1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada12) encode_inodestat issuing pAsLsXsFsx seq 28
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada12) encode_inodestat caps pAsLsXsFsx seq 28 mseq 0 xattrv 0
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including dn [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Configuration [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada11 state=1073741824 0x55e1677cbb80]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.locker issue_client_lease no/null lease on [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Configuration [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada11 state=1073741824 0x55e1677cbb80]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including inode [inode 0x100006ada11 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Configuration/ auth v103 f() n(v0 rc2016-12-08T14:57:23.000000+0000 1=0+1) (ifile excl) (iversion lock) 0x55e1646abb80]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.cache.ino(0x100006ada11) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 2022-11-15T13:08:59.082506+0000 valid=1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada11) add_client_cap first cap, joining realm snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} past_parent_snaps= 0x55e077abe400)
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada11) encode_inodestat issuing pAsLsXsFsx seq 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada11) encode_inodestat caps pAsLsXsFsx seq 1 mseq 0 xattrv 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada11) including xattrs version 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including dn [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Public [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada13 state=1073741824 | request=0 lock=0 inodepin=1 authpin=0 0x55e0f0ece000]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.locker issue_client_lease no/null lease on [dentry #0x1/Pool-ErasurePool/MediaStore/UserName/USB-Drive/Public [2,head] auth (dversion lock) pv=0 v=24685 ino=0x100006ada13 state=1073741824 | request=0 lock=0 inodepin=1 authpin=0 0x55e0f0ece000]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 12 mds.0.server including inode [inode 0x100006ada13 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Public/ auth v24679 f(v0 m2022-11-15T16:01:38.570897+0000 11=0+11) n(v303 rc2022-11-15T16:37:16.649338+0000 b40783383091 15301=14625+676) (inest lock) (ifile excl) (iversion lock) | request=0 lock=0 dirfrag=1 caps=0 waiter=0 authpin=0 0x55e0f0eca000]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.cache.ino(0x100006ada13) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 2022-11-15T16:01:38.570897+0000 valid=1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada13) add_client_cap first cap, joining realm snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} past_parent_snaps= 0x55e077abe400)
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada13) encode_inodestat issuing pAsLsXsFsx seq 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada13) encode_inodestat caps pAsLsXsFsx seq 1 mseq 0 xattrv 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada13) including xattrs version 1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.server reply to client_request(client.61004462:1474231708 readdir #0x1000067f7ef 2023-05-09T18:53:03.461186+0000 caller_uid=0, caller_gid=0{0,}) v5 readdir num=3 bytes=1097 start=1 end=1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.bal hit_dir 2 pop is 3, frag * size 3 [pop IRD:[C 0.00e+00] IWR:[C 0.00e+00] RDR:[C 3.00e+00] FET:[C 0.00e+00] STR:[C 0.00e+00] *LOAD:3.0]

debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.server reply_client_request 0 ((0) Success) client_request(client.61004462:1474231708 readdir #0x1000067f7ef 2023-05-09T18:53:03.461186+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.server apply_allocated_inos 0x0 / [] / 0x0
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.server lat 0.006462
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.server set_trace_dist snapid head
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.server set_trace_dist snaprealm snaprealm(0x1 seq 1 lc 0 cr 0 cps 1 snaps={} past_parent_snaps= 0x55e077abe400) len=48
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.cache.ino(0x1000067f7ef) pfile 1 pauth 1 plink 1 pxattr 1 plocal 0 ctime 2022-11-15T13:08:59.082506+0000 valid=1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) encode_inodestat issuing pAsLsXsFs seq 15
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) encode_inodestat caps pAsLsXsFs seq 15 mseq 0 xattrv 0
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.server set_trace_dist added in [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (idft sync r=1) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=3 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.17360 send_message_client client.61004462 192.168.10.250:0/2668832115 client_reply(???:1474231708 = 0 (0) Success) v1
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.cache request_finish request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0)
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 15 mds.0.cache request_cleanup request(client.61004462:1474231708 nref=2 cr=0x55e0a782a2c0)
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=27) on [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=27) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync r=4) on [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=4) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=0 lock=0 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (idft sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=2 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.locker scatter_eval (idft sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile sync r=1) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=2 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker file_eval stable, bump to loner (ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker file_excl (ifile sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker get_allowed_caps loner client.61004462 allowed=pAsLsXsFsxcrwb, xlocker allowed=pAsLsXsFsxcrwb, others allowed=pAsLsXs on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 ap=1 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.locker client.61004462 pending pAsLsXsFs allowed pAsLsXsFsxwb wanted -
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.cache.ino(0x1000067f7ef) auth_unpin by 0x55e0b4fd3800 on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00] now 0
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7df) adjust_nested_auth_pins -1 on [dir 0x1000067f7df /Pool-ErasurePool/MediaStore/UserName/ [2,head] auth v=154678 cv=154678/154678 REP state=1074003969|complete f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148362=136530+11832) hs=20+0,ss=0+0 | child=1 dirty=0 waiter=0 authpin=0 0x55e0790a8000] by 0x55e0b4fd3800 count now 0/0
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 7 mds.0.locker get_allowed_caps loner client.61004462 allowed=pAsLsXsFsxcrwb, xlocker allowed=pAsLsXsFsxcrwb, others allowed=pAsLsXs on [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=0 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 20 mds.0.locker client.61004462 pending pAsLsXsFs allowed pAsLsXsFsxwb wanted -
debug 2023-05-09T18:53:03.466+0000 7fb2e883f700 10 mds.0.locker eval done
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 4 mds.0.server handle_client_request client_request(client.61004462:1474231709 getattr Fa #0x100006ada12 2023-05-09T18:53:03.472189+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.17360 get_session have 0x55e084f0c000 client.61004462 192.168.10.250:0/2668832115 state open
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 15 mds.0.server oldest_client_tid=1474231709
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 7 mds.0.cache request_start request(client.61004462:1474231709 nref=2 cr=0x55e18fbc6000)
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 7 mds.0.server dispatch_client_request client_request(client.61004462:1474231709 getattr Fa #0x100006ada12 2023-05-09T18:53:03.472189+0000 caller_uid=0, caller_gid=0{0,}) v5
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 7 mds.0.cache traverse: opening base ino 0x100006ada12 snap head
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.server rdlock_path_pin_ref request(client.61004462:1474231709 nref=3 cr=0x55e18fbc6000) #0x100006ada12
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 7 mds.0.cache traverse: opening base ino 0x100006ada12 snap head
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.locker try_rdlock_snap_layout request(client.61004462:1474231709 nref=4 cr=0x55e18fbc6000) [inode 0x100006ada12 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download/ auth v24651 f(v0 m2022-11-15T13:12:16.389934+0000 103=14+89) n(v1376 rc2022-11-15T16:02:07.438227+0000 b295230152010 55940=51886+4054) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@28},l=61004462 | request=1 lock=0 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e0f0eca580]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x100006ada12 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download/ auth v24651 f(v0 m2022-11-15T13:12:16.389934+0000 103=14+89) n(v1376 rc2022-11-15T16:02:07.438227+0000 b295230152010 55940=51886+4054) (isnap sync r=1) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@28},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e0f0eca580]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7ef [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ auth v32663 f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71243=66511+4732) (isnap sync r=1) (inest lock) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFs/-@15},l=61004462 | request=0 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e079f48c00]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7df [...12,head] /Pool-ErasurePool/MediaStore/UserName/ auth v1195138 f(v0 m2022-12-15T04:35:54.407540+0000 20=3+17) n(v8046 rc2023-04-13T04:19:48.516951+0000 b5374507909557 148363=136530+11833) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={61004462=pAsLsXsFs/-@1022} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 dirty=0 waiter=0 authpin=0 0x55e078f69080]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1000067f7de [...12,head] /Pool-ErasurePool/MediaStore/ auth v8697367 f(v0 m2023-03-30T21:28:52.366466+0000 29=15+14) n(v46239 rc2023-05-01T02:03:23.317694+0000 b20900279453794 1240206=1174006+66200) old_inodes=1 (isnap sync r=1) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@15,61004462=pAsLsXsFs/-@583} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 dirtyrstat=0 dirty=0 waiter=0 authpin=0 0x55e077b1b700]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=5) [inode 0x1000067ce00 [...12,head] /Pool-ErasurePool/ auth v47901672 f(v0 m2022-12-17T00:20:39.355818+0000 5=1+4) n(v422761 rc2106-02-05T15:12:36.000000+0000 b51098455054354 3802944=3652045+150899) old_inodes=1 (isnap sync r=5) (inest lock) (ipolicy sync r=3) (iversion lock) caps={57639090=pAsLsXsFs/-@5,61004462=pAsLsXsFs/-@237,61955650=pAsLsXsFs/-@76} | dirtyscattered=0 request=0 lock=2 dirfrag=1 caps=1 dirtyrstat=0 dirty=1 authpin=0 0x55e077c49180]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 mds.0.locker got rdlock on (isnap sync r=28) [inode 0x1 [...12,head] / auth v17033349 snaprealm=0x55e077abe400 f(v0 m2023-04-12T23:56:18.959056+0000 6=0+6) n(v2923901 rc2106-02-05T15:12:36.000000+0000 b51585737737600 3913194=3735815+177379)/n(v0 rc2022-10-01T02:52:43.139958+0000 1=0+1) old_inodes=13 (isnap sync r=28) (inest lock) (iversion lock) caps={57639090=pAsLsXsFs/-@367,61004462=pAsLsXsFs/-@898,61955650=pAsLsXsFs/-@375,63467652=pAsLsXsFs/-@8} | dirtyscattered=0 request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 waiter=0 authpin=0 0x55e077abab00]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.server ref is [inode 0x100006ada12 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download/ auth v24651 f(v0 m2022-11-15T13:12:16.389934+0000 103=14+89) n(v1376 rc2022-11-15T16:02:07.438227+0000 b295230152010 55940=51886+4054) (isnap sync r=1) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@28},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=0 0x55e0f0eca580]
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.cache.ino(0x100006ada12) auth_pin by 0x55e1ae5c7400 on [inode 0x100006ada12 [...2,head] /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download/ auth v24651 ap=1 f(v0 m2022-11-15T13:12:16.389934+0000 103=14+89) n(v1376 rc2022-11-15T16:02:07.438227+0000 b295230152010 55940=51886+4054) (isnap sync r=1) (ifile excl) (iversion lock) caps={61004462=pAsLsXsFsx/-@28},l=61004462 | request=1 lock=1 dirfrag=1 caps=1 waiter=0 authpin=1 0x55e0f0eca580] now 1
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 15 mds.0.cache.dir(0x1000067f7ef) adjust_nested_auth_pins 1 on [dir 0x1000067f7ef /Pool-ErasurePool/MediaStore/UserName/USB-Drive/ [2,head] auth v=24685 cv=24685/24685 ap=0+1 state=1074003969|complete f(v0 m2022-11-15T13:08:59.082506+0000 3=0+3) n(v1588 rc2022-11-15T16:37:16.649338+0000 b336013535101 71242=66511+4731) hs=3+0,ss=0+0 | child=1 waiter=0 authpin=0 0x55e0f0dfcd80] by 0x55e0f0eca580 count now 0/1
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 10 mds.0.locker acquire_locks request(client.61004462:1474231709 nref=3 cr=0x55e18fbc6000)
debug 2023-05-09T18:53:03.470+0000 7fb2e883f700 20 Session check_access path /Pool-ErasurePool/MediaStore/UserName/USB-Drive/Download
(2-2/2)