Here, we enable mds debug logging into stdout
ceph tell mds.gml-okd-cephfs-a config set debug_mds 20/0
...
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.server reply to stat on client_request(client.66426408:170 lookup #0x10000000001/csi-vol-91510028-3e45-11ec-9461-0a580a82014a 2023-02-16T09:49:56.266338+0000 caller_uid=0, caller_gid=0{}) v5
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server respond_to_request batch head request(client.66426408:170 nref=3 cr=0x558f9a150580)
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 respond: responding to batch ops with result=0: [batch front=request(client.66426408:170 nref=3 cr=0x558f9a150580)]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.server reply_client_request 0 ((0) Success) client_request(client.66426408:170 lookup #0x10000000001/csi-vol-91510028-3e45-11ec-9461-0a580a82014a 2023-02-16T09:49:56.266338+0000 caller_uid=0, caller_gid=0{}) v5
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.server apply_allocated_inos 0x0 / [] / 0x0
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server lat 0.000551
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server set_trace_dist snapid head
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.server set_trace_dist snaprealm snaprealm(0x10001be180e seq 1 lc 0 cr 1 cps 2 snaps={} past_parent_snaps= 0x558f9982a200) len=96
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.cache.ino(0x10000000001) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 2022-12-26T14:29:05.859667+0000 valid=1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10000000001) encode_inodestat issuing pAsLsXsFs seq 56
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10000000001) encode_inodestat caps pAsLsXsFs seq 56 mseq 0 xattrv 0
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server set_trace_dist added diri [inode 0x10000000001 [...c,head] /volumes/csi/ auth v119902405 f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549126=1354219+194907) old_inodes=1 (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@56} | request=0 lock=1 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801600]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server set_trace_dist added dir [dir 0x10000000001 /volumes/csi/ [2,head] auth v=400540078 cv=400540078/400540078 ap=0+2 state=1074003969|complete f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549125=1354219+194906) hs=125+0,ss=0+0 | child=1 waiter=0 authpin=0 0x558f9aa22d80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.locker issue_client_lease no/null lease on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a [2,head] auth (dn sync r=1) (dversion lock) pv=0 v=400540078 ap=1 ino=0x10001be180e state=1073741824 | request=1 lock=1 inodepin=1 authpin=1 0x558f99828780]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server set_trace_dist added dn head [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a [2,head] auth (dn sync r=1) (dversion lock) pv=0 v=400540078 ap=1 ino=0x10001be180e state=1073741824 | request=1 lock=1 inodepin=1 authpin=1 0x558f99828780]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.cache.ino(0x10001be180e) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 2021-11-05T14:35:05.441183+0000 valid=1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10001be180e) add_client_cap first cap, joining realm snaprealm(0x10001be180e seq 1 lc 0 cr 1 cps 2 snaps={} past_parent_snaps= 0x558f9982a200)
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10001be180e) encode_inodestat issuing pAsLsXsFs seq 1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10001be180e) encode_inodestat caps pAsLsXsFs seq 1 mseq 0 xattrv 1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10001be180e) including xattrs version 1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 20 mds.0.server set_trace_dist added in [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (iauth sync r=1) (ilink sync r=1) (isnap sync r=1) (ifile sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=5 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.350627 send_message_client client.66426408 10.25.1.17:0/1669277120 client_reply(???:170 = 0 (0) Success) v1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.cache request_finish request(client.66426408:170 nref=3 cr=0x558f9a150580)
debug 2023-02-16T09:49:56.265+0000 7f0462329700 15 mds.0.cache request_cleanup request(client.66426408:170 nref=3 cr=0x558f9a150580)
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x1 [...2,head] / auth v5 snaprealm=0x558f9859d800 f(v1 m2021-07-31T21:13:24.403917+0000 3=0+3) n(v3 rc2023-01-03T22:32:29.158670+0000 b264347801454 1549251=1354337+194914)/n() (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=0 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 authpin=0 0x558f99800b00]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x1 [...2,head] / auth v5 snaprealm=0x558f9859d800 f(v1 m2021-07-31T21:13:24.403917+0000 3=0+3) n(v3 rc2023-01-03T22:32:29.158670+0000 b264347801454 1549251=1354337+194914)/n() (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=0 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 authpin=0 0x558f99800b00]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x10000000000 [...c,head] /volumes/ auth v94872546 f(v0 m2022-12-26T14:29:06.030099+0000 119=116+3) n(v8702956 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549246=1354335+194911) old_inodes=1 (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=0 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801080]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x10000000000 [...c,head] /volumes/ auth v94872546 f(v0 m2022-12-26T14:29:06.030099+0000 119=116+3) n(v8702956 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549246=1354335+194911) old_inodes=1 (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=0 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801080]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x10000000001 [...c,head] /volumes/csi/ auth v119902405 f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549126=1354219+194907) old_inodes=1 (iversion lock) caps={66426408=pAsLsXsFs/-@56} | request=0 lock=0 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801600]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x10000000001 [...c,head] /volumes/csi/ auth v119902405 f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549126=1354219+194907) old_inodes=1 (iversion lock) caps={66426408=pAsLsXsFs/-@56} | request=0 lock=0 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801600]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (iauth sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (ilink sync r=1) (isnap sync r=1) (ifile sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=4 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (iauth sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (ilink sync r=1) (isnap sync r=1) (ifile sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=4 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (ilink sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (ifile sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=3 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (ilink sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (ifile sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=3 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (ifile sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=2 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (ixattr sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=2 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (ixattr sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=1 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (ixattr sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=1 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (isnap sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=0 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (isnap sync) on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 ap=1 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=0 dirfrag=1 caps=1 openingsnapparents=0 authpin=1 0x558f99825b80]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 7 mds.0.locker rdlock_finish on (dn sync) on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a [2,head] auth (dversion lock) pv=0 v=400540078 ap=1 ino=0x10001be180e state=1073741824 | request=1 lock=0 inodepin=1 authpin=1 0x558f99828780]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.locker simple_eval (dn sync) on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a [2,head] auth (dversion lock) pv=0 v=400540078 ap=1 ino=0x10001be180e state=1073741824 | request=1 lock=0 inodepin=1 authpin=1 0x558f99828780]
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.ino(0x10001be180e) auth_unpin by 0x558f9aa3fc00 on [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=1 lock=0 dirfrag=1 caps=1 openingsnapparents=0 authpin=0 0x558f99825b80] now 0
debug 2023-02-16T09:49:56.265+0000 7f0462329700 15 mds.0.cache.dir(0x10000000001) adjust_nested_auth_pins -1 on [dir 0x10000000001 /volumes/csi/ [2,head] auth v=400540078 cv=400540078/400540078 ap=0+1 state=1074003969|complete f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549125=1354219+194906) hs=125+0,ss=0+0 | child=1 waiter=0 authpin=0 0x558f9aa22d80] by 0x558f9aa3fc00 count now 0/1
debug 2023-02-16T09:49:56.265+0000 7f0462329700 10 mds.0.cache.den(0x10000000001 csi-vol-91510028-3e45-11ec-9461-0a580a82014a) auth_unpin by 0x558f9aa3fc00 on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a [2,head] auth (dversion lock) pv=0 v=400540078 ino=0x10001be180e state=1073741824 | request=1 lock=0 inodepin=1 authpin=0 0x558f99828780] now 0
debug 2023-02-16T09:49:56.265+0000 7f0462329700 15 mds.0.cache.dir(0x10000000001) adjust_nested_auth_pins -1 on [dir 0x10000000001 /volumes/csi/ [2,head] auth v=400540078 cv=400540078/400540078 state=1074003969|complete f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549125=1354219+194906) hs=125+0,ss=0+0 | child=1 waiter=0 authpin=0 0x558f9aa22d80] by 0x558f9aa3fc00 count now 0/0
debug 2023-02-16T09:49:56.266+0000 7f0462329700 4 mds.0.server handle_client_request client_request(client.66426408:171 lookup #0x10001be180e/.meta 2023-02-16T09:49:56.268272+0000 caller_uid=0, caller_gid=0{}) v5
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.350627 get_session have 0x558f98893900 client.66426408 10.25.1.17:0/1669277120 state open
debug 2023-02-16T09:49:56.266+0000 7f0462329700 15 mds.0.server oldest_client_tid=170
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.cache request_start request(client.66426408:171 nref=2 cr=0x558f9a150840)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.server dispatch_client_request client_request(client.66426408:171 lookup #0x10001be180e/.meta 2023-02-16T09:49:56.268272+0000 caller_uid=0, caller_gid=0{}) v5
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.cache traverse: opening base ino 0x10001be180e snap head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 12 mds.0.cache traverse: path seg depth 0 '.meta' snapid head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.cache.dir(0x10001be180e) lookup (head, '.meta')
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.cache.dir(0x10001be180e) hit -> (.meta,head)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.server rdlock_path_pin_ref request(client.66426408:171 nref=3 cr=0x558f9a150840) #0x10001be180e/.meta
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.cache traverse: opening base ino 0x10001be180e snap head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker try_rdlock_snap_layout request(client.66426408:171 nref=4 cr=0x558f9a150840) [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=0 lock=0 dirfrag=1 caps=1 openingsnapparents=0 authpin=0 0x558f99825b80]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x10001be180e [...2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ auth v388627147 snaprealm=0x558f9982a200 f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 36=24+12) (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@1} | request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 authpin=0 0x558f99825b80]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x10000000001 [...c,head] /volumes/csi/ auth v119902405 f(v0 m2022-12-26T14:29:05.859667+0000 125=3+122) n(v9165118 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549126=1354219+194907) old_inodes=1 (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@56} | request=0 lock=1 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x10000000000 [...c,head] /volumes/ auth v94872546 f(v0 m2022-12-26T14:29:06.030099+0000 119=116+3) n(v8702956 rc2023-01-03T22:32:29.158670+0000 b264347773624 1549246=1354335+194911) old_inodes=1 (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=1 dirfrag=1 caps=1 dirty=1 authpin=0 0x558f99801080]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x1 [...2,head] / auth v5 snaprealm=0x558f9859d800 f(v1 m2021-07-31T21:13:24.403917+0000 3=0+3) n(v3 rc2023-01-03T22:32:29.158670+0000 b264347801454 1549251=1354337+194914)/n() (isnap sync r=1) (iversion lock) caps={66426408=pAsLsXsFs/-@2} | request=0 lock=1 dirfrag=1 caps=1 openingsnapparents=0 dirty=1 authpin=0 0x558f99800b00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 12 mds.0.cache traverse: path seg depth 0 '.meta' snapid head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.cache.dir(0x10001be180e) lookup (head, '.meta')
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.cache.dir(0x10001be180e) hit -> (.meta,head)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker acquire_locks request(client.66426408:171 nref=4 cr=0x558f9a150840)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker must rdlock (dn sync) [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dversion lock) pv=0 v=192774 ino=0x10001be1810 state=1073741824 | request=1 lock=0 inodepin=0 authpin=0 0x558f988d2a00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker must authpin [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dversion lock) pv=0 v=192774 ino=0x10001be1810 state=1073741824 | request=1 lock=0 inodepin=0 authpin=0 0x558f988d2a00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker auth_pinning [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dversion lock) pv=0 v=192774 ino=0x10001be1810 state=1073741824 | request=1 lock=0 inodepin=0 authpin=0 0x558f988d2a00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.cache.den(0x10001be180e .meta) auth_pin by 0x558f9aa38000 on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dversion lock) pv=0 v=192774 ap=1 ino=0x10001be1810 state=1073741824 | request=1 lock=0 inodepin=0 authpin=1 0x558f988d2a00] now 1
debug 2023-02-16T09:49:56.266+0000 7f0462329700 15 mds.0.cache.dir(0x10001be180e) adjust_nested_auth_pins 1 on [dir 0x10001be180e /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ [2,head] auth v=192774 cv=192774/192774 ap=0+1 state=1073741825|complete f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 35=24+11) hs=2+0,ss=0+0 | child=1 waiter=0 authpin=0 0x558f98722480] by 0x558f9aa38000 count now 0/1
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.locker rdlock_start on (dn sync) on [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dversion lock) pv=0 v=192774 ap=1 ino=0x10001be1810 state=1073741824 | request=1 lock=0 inodepin=0 authpin=1 0x558f988d2a00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker got rdlock on (dn sync r=1) [dentry #0x1/volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta [2,head] auth (dn sync r=1) (dversion lock) pv=0 v=192774 ap=1 ino=0x10001be1810 state=1073741824 | request=1 lock=1 inodepin=0 authpin=1 0x558f988d2a00]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker acquire_locks request(client.66426408:171 nref=4 cr=0x558f9a150840)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker must rdlock (isnap sync) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker must authpin [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker auth_pinning [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.cache.ino(0x10001be1810) auth_pin by 0x558f9aa38000 on [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=0 lock=0 caps=0 authpin=1 0x558f988cf600] now 1
debug 2023-02-16T09:49:56.266+0000 7f0462329700 15 mds.0.cache.dir(0x10001be180e) adjust_nested_auth_pins 1 on [dir 0x10001be180e /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/ [2,head] auth v=192774 cv=192774/192774 ap=0+2 state=1073741825|complete f(v0 m2021-11-05T14:35:05.441183+0000 2=1+1) n(v29796 rc2022-12-21T19:28:27.124662+0000 b57179 35=24+11) hs=2+0,ss=0+0 | child=1 waiter=0 authpin=0 0x558f98722480] by 0x558f988cf600 count now 0/2
debug 2023-02-16T09:49:56.266+0000 7f0462329700 7 mds.0.locker rdlock_start on (isnap sync) on [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=0 lock=0 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker got rdlock on (isnap sync r=1) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=0 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.cache path_traverse finish on snapid head
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.server ref is [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=0 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker acquire_locks request(client.66426408:171 nref=3 cr=0x558f9a150840)
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker must rdlock (iauth sync) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=1 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 20 mds.0.locker must rdlock (ifile sync) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=1 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.266+0000 7f0462329700 10 mds.0.locker must authpin [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=1 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 10 mds.0.locker already auth_pinned [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=1 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 7 mds.0.locker rdlock_start on (ifile sync) on [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iversion lock) | request=1 lock=1 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 10 mds.0.locker got rdlock on (ifile sync r=1) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (ifile sync r=1) (iversion lock) | request=1 lock=2 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 7 mds.0.locker rdlock_start on (iauth sync) on [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (ifile sync r=1) (iversion lock) | request=1 lock=2 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 10 mds.0.locker got rdlock on (iauth sync r=1) [inode 0x10001be1810 [2,head] /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta auth v12 ap=1 s=158 n(v0 rc2021-11-05T14:35:05.443099+0000 b158 1=1+0) (iauth sync r=1) (ifile sync r=1) (iversion lock) | request=1 lock=3 caps=0 authpin=1 0x558f988cf600]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 20 Session check_access path /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta
debug 2023-02-16T09:49:56.267+0000 7f0462329700 10 MDSAuthCap is_capable inode(path /volumes/csi/csi-vol-91510028-3e45-11ec-9461-0a580a82014a/.meta owner 0:0 mode 0100640) by caller 0:0 mask 1 new 0:0 cap: MDSAuthCaps[allow *]
debug 2023-02-16T09:49:56.267+0000 7f0462329700 20 mds.0.bal hit_dir 0 pop is 1, frag * size 2 [pop IRD:[C 1.00e+00] IWR:[C 0.00e+00] RDR:[C 0.00e+00] FET:[C 0.00e+00] STR:[C 0.00e+00] *LOAD:1.0]
_______________________________________________
ceph-users mailing list -- ceph-users@xxxxxxx
To unsubscribe send an email to ceph-users-leave@xxxxxxx
