Project

General

Profile

Bug #172 » mds1_crash_log.txt

Wido den Hollander, 06/03/2010 05:11 AM

 
root@mds1:~# tail -n 100 /var/log/ceph/mds0
10.06.03_12:58:14.413121 7f72666fa710 mds0.locker _issue_client_lease mask 1 dur 30000ms
10.06.03_12:58:14.413130 7f72666fa710 mds0.server including inode [inode 1000002a413 [9,head] /static/linux-2.6.34/REPORTING-BUGS auth v3858 s=3371 nl=1 rb=3371 rf=1 rd=0 (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFscr/-@1} | nref=2 0x7f72494d4bd0]
10.06.03_12:58:14.413154 7f72666fa710 mds0.cache.ino(1000002a413) pfile 0 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:38:43.239258 valid=1
10.06.03_12:58:14.413169 7f72666fa710 mds0.cache.ino(1000002a413) encode_inodestat issueing pAsLsXsFscr seq 2
10.06.03_12:58:14.413182 7f72666fa710 mds0.cache.ino(1000002a413) encode_inodestat caps pAsLsXsFscr seq 2 mseq 0
10.06.03_12:58:14.413192 7f72666fa710 mds0.server including dn [dentry #1/static/linux-2.6.34/arch [9,head] auth (dn sync) (dversion lock) v=2978 inode=0x7f72494d3f90 state=new | nref=2 0x7f72576ddeb0]
10.06.03_12:58:14.413207 7f72666fa710 mds0.locker _issue_client_lease mask 1 dur 30000ms
10.06.03_12:58:14.413216 7f72666fa710 mds0.server including inode [inode 1000002a414 [...9,head] /static/linux-2.6.34/arch/ auth v2978 f(v0 m10.06.03_12:46:15.328824 25=2+23) ds=25=2+23 rb=83630665 rf=13052 rd=926 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@51},l=5100 | nref=3 0x7f72494d3f90]
10.06.03_12:58:14.413243 7f72666fa710 mds0.cache.ino(1000002a414) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:46:23.671211 valid=1
10.06.03_12:58:14.413259 7f72666fa710 mds0.cache.ino(1000002a414) encode_inodestat issueing pAsLsXsFs seq 52
10.06.03_12:58:14.413271 7f72666fa710 mds0.cache.ino(1000002a414) encode_inodestat caps pAsLsXsFs seq 52 mseq 0
10.06.03_12:58:14.413282 7f72666fa710 mds0.server including dn [dentry #1/static/linux-2.6.34/block [9,head] auth (dn sync) (dversion lock) v=2744 inode=0x7f724aee8fd0 state=new | nref=2 0x7f7257c60850]
10.06.03_12:58:14.413297 7f72666fa710 mds0.locker _issue_client_lease mask 1 dur 30000ms
10.06.03_12:58:14.413306 7f72666fa710 mds0.server including inode [inode 1000002daae [...9,head] /static/linux-2.6.34/block/ auth v2744 f(v0 m10.06.03_12:46:23.911518 28=28+0) ds=28=28+0 rb=449640 rf=28 rd=1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@34},l=5100 | nref=3 0x7f724aee8fd0]
10.06.03_12:58:14.413333 7f72666fa710 mds0.cache.ino(1000002daae) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:46:23.917157 valid=1
10.06.03_12:58:14.413349 7f72666fa710 mds0.cache.ino(1000002daae) encode_inodestat issueing pAsLsXsFs seq 35
10.06.03_12:58:14.413361 7f72666fa710 mds0.cache.ino(1000002daae) encode_inodestat caps pAsLsXsFs seq 35 mseq 0
10.06.03_12:58:14.413372 7f72666fa710 mds0.server including dn [dentry #1/static/linux-2.6.34/crypto [9,head] auth (dn sync) (dversion lock) v=2916 inode=0x7f724aef4170 | nref=2 0x7f7257c63770]
10.06.03_12:58:14.413387 7f72666fa710 mds0.locker _issue_client_lease mask 1 dur 30000ms
10.06.03_12:58:14.413396 7f72666fa710 mds0.server including inode [inode 1000002dacb [...9,head] /static/linux-2.6.34/crypto/ auth v2916 f(v0 m10.06.03_12:46:29.972943 81=80+1) ds=81=80+1 rb=1494716 rf=89 rd=2 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@87},l=5100 | nref=4 0x7f724aef4170]
10.06.03_12:58:14.413430 7f72666fa710 mds0.cache.ino(1000002dacb) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:46:29.981033 valid=1
10.06.03_12:58:14.413447 7f72666fa710 mds0.cache.ino(1000002dacb) encode_inodestat issueing pAsLsXsFs seq 88
10.06.03_12:58:14.413459 7f72666fa710 mds0.cache.ino(1000002dacb) encode_inodestat caps pAsLsXsFs seq 88 mseq 0
10.06.03_12:58:14.413470 7f72666fa710 mds0.server including dn [dentry #1/static/linux-2.6.34/drivers [9,head] auth (dn sync) (dversion lock) v=4424 inode=0x7f724af16ed0 | nref=2 0x7f7257c6cb50]
10.06.03_12:58:14.413485 7f72666fa710 mds0.locker _issue_client_lease mask 1 dur 30000ms
10.06.03_12:58:14.413494 7f72666fa710 mds0.server including inode [inode 1000002db26 [...a,head] /static/linux-2.6.34/drivers/ auth v4424 f(v0 m10.06.03_12:55:40.318934 89=2+87) ds=89=2+87 rb=189011024 rf=10318 rd=512 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@133},l=5100 | nref=4 0x7f724af16ed0]
10.06.03_12:58:14.413520 7f72666fa710 mds0.cache.ino(1000002db26) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:55:40.454298 valid=1
10.06.03_12:58:14.413536 7f72666fa710 mds0.cache.ino(1000002db26) encode_inodestat issueing pAsLsXsFs seq 134
10.06.03_12:58:14.413548 7f72666fa710 mds0.cache.ino(1000002db26) encode_inodestat caps pAsLsXsFs seq 134 mseq 0
10.06.03_12:58:14.413559 7f72666fa710 mds0.cache.dir(10000029d94) pre_dirty 5100
10.06.03_12:58:14.413571 7f72666fa710 mds0.server reply to client_request(client5100:129643 readdir #10000029d94) readdir num=9 bytes=2272 end=1 complete=1
10.06.03_12:58:14.413594 7f72666fa710 mds0.server reply_request 0 (Success) client_request(client5100:129643 readdir #10000029d94)
10.06.03_12:58:14.413605 7f72666fa710 mds0.server apply_allocated_inos 0 / [] / 0
10.06.03_12:58:14.413617 7f72666fa710 mds0.server lat 0.257472
10.06.03_12:58:14.413644 7f72666fa710 mds0.cache request_finish request(client5100:129643 cr=0x7f725f1de720)
10.06.03_12:58:14.413655 7f72666fa710 mds0.cache request_cleanup request(client5100:129643 cr=0x7f725f1de720)
10.06.03_12:58:14.413666 7f72666fa710 mds0.locker rdlock_finish on (idft sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync r=1) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=9 0x7f724977b150]
10.06.03_12:58:14.413693 7f72666fa710 mds0.locker scatter_eval (idft sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync r=1) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=9 0x7f724977b150]
10.06.03_12:58:14.413720 7f72666fa710 mds0.locker rdlock_finish on (ifile sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=8 0x7f724977b150]
10.06.03_12:58:14.413746 7f72666fa710 mds0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=8 0x7f724977b150]
10.06.03_12:58:14.413773 7f72666fa710 mds0.locker file_eval stable, bump to loner (ifile sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=8 0x7f724977b150]
10.06.03_12:58:14.413807 7f72666fa710 mds0.locker file_excl (ifile sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=8 0x7f724977b150]
10.06.03_12:58:14.413845 7f72666fa710 mds0.locker issue_caps loner client5100 allowed=pAsLsXsFsxcrwbl, xlocker allowed=pAsLsXsFsxcrwbl, others allowed=pAsLsXs on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=8 0x7f724977b150]
10.06.03_12:58:14.413877 7f72666fa710 mds0.locker client5100 pending pAsLsXsFs allowed pAsLsXsFsxcrwbl wanted p
10.06.03_12:58:14.413888 7f72666fa710 mds0.locker rdlock_finish on (isnap sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=7 0x7f724977b150]
10.06.03_12:58:14.413914 7f72666fa710 mds0.locker simple_eval (isnap sync) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=2 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=7 0x7f724977b150]
10.06.03_12:58:14.413940 7f72666fa710 mds0.locker rdlock_finish on (isnap sync) on [inode 100000217aa [...a,head] /static/ auth v24616 ap=2 snaprealm=0x7f724e6866a0 f(v0 m10.06.03_12:55:48.242087 1=0+1) ds=1=0+1 rb=274956347 rf=23502 rd=1446 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@18},l=5100 | nref=2153 0x7f72510f02b0]
10.06.03_12:58:14.413965 7f72666fa710 mds0.locker simple_eval (isnap sync) on [inode 100000217aa [...a,head] /static/ auth v24616 ap=2 snaprealm=0x7f724e6866a0 f(v0 m10.06.03_12:55:48.242087 1=0+1) ds=1=0+1 rb=274956347 rf=23502 rd=1446 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@18},l=5100 | nref=2153 0x7f72510f02b0]
10.06.03_12:58:14.413991 7f72666fa710 mds0.locker rdlock_finish on (isnap sync) on [inode 1 [...a,head] / auth v12028 ap=2 snaprealm=0x7f725c600340 f(v8 m10.06.03_11:58:57.212765 3=0+3) ds=3=0+3 rb=278866916/0 rf=23978/0 rd=1494/1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXs/-@3} | nref=5 0x7f725c5f3f20]
10.06.03_12:58:14.414015 7f72666fa710 mds0.locker simple_eval (isnap sync) on [inode 1 [...a,head] / auth v12028 ap=2 snaprealm=0x7f725c600340 f(v8 m10.06.03_11:58:57.212765 3=0+3) ds=3=0+3 rb=278866916/0 rf=23978/0 rd=1494/1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXs/-@3} | nref=5 0x7f725c5f3f20]
10.06.03_12:58:14.414040 7f72666fa710 mds0.cache.ino(10000029d94) auth_unpin by 0x3034000 on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/p@30},l=5100 | nref=7 0x7f724977b150] now 1+1
10.06.03_12:58:14.414065 7f72666fa710 mds0.cache.dir(100000217aa) adjust_nested_auth_pins -1/-1 on [dir 100000217aa /static/ [a,head] auth v=7631 cv=1631/1631 ap=1+2+3 state=1610612738|complete f(v0 m10.06.03_12:55:48.242087 1=0+1) s=1=0+1 rb=274832904/274956347 rf=23492/23502 rd=1442/1445 hs=1+2,ss=3+0 dirty=4 | nref=3 0x7f725d4446c8] count now 1 + 3
10.06.03_12:58:14.414093 7f72666fa710 mds0.cache.ino(100000217aa) auth_unpin by 0x3034000 on [inode 100000217aa [...a,head] /static/ auth v24616 ap=1 snaprealm=0x7f724e6866a0 f(v0 m10.06.03_12:55:48.242087 1=0+1) ds=1=0+1 rb=274956347 rf=23502 rd=1446 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@18},l=5100 | nref=2153 0x7f72510f02b0] now 1+1
10.06.03_12:58:14.414119 7f72666fa710 mds0.cache.dir(1) adjust_nested_auth_pins -1/-1 on [dir 1 / [a,head] auth v=24617 cv=17495/17495 dir_auth=0 ap=0+2+3 state=1610612738|complete f(v8 m10.06.03_11:58:57.212765 3=0+3) s=3=0+3 rb=274956347/278866916 rf=23502/23978 rd=1448/1494 hs=3+1,ss=2+0 dirty=1 | nref=3 0xd5e010] count now 0 + 3
10.06.03_12:58:14.414139 7f72666fa710 mds0.cache.ino(1) auth_unpin by 0x3034000 on [inode 1 [...a,head] / auth v12028 ap=1 snaprealm=0x7f725c600340 f(v8 m10.06.03_11:58:57.212765 3=0+3) ds=3=0+3 rb=278866916/0 rf=23978/0 rd=1494/1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXs/-@3} | nref=5 0x7f725c5f3f20] now 1+0
10.06.03_12:58:14.414169 7f72666fa710 mds0.server set_trace_dist snapid head
10.06.03_12:58:14.414180 7f72666fa710 mds0.server set_trace_dist snaprealm snaprealm(100000217aa seq 9 lc 8 snaps={} 0x7f724e6866a0) len=96
10.06.03_12:58:14.414191 7f72666fa710 mds0.cache.ino(10000029d94) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 10.06.03_12:58:14.074295 valid=1
10.06.03_12:58:14.414207 7f72666fa710 mds0.cache.ino(10000029d94) encode_inodestat issueing pAsLsXsFsx seq 31
10.06.03_12:58:14.414219 7f72666fa710 mds0.cache.ino(10000029d94) encode_inodestat caps pAsLsXsFsx seq 31 mseq 0
10.06.03_12:58:14.414233 7f72666fa710 mds0.server set_trace_dist added in [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=6 0x7f724977b150]
10.06.03_12:58:14.414283 7f72666fa710 mds0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile excl) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=6 0x7f724977b150]
10.06.03_12:58:14.414311 7f72666fa710 mds0.locker is excl
10.06.03_12:58:14.414329 7f72666fa710 mds0.locker issue_caps loner client5100 allowed=pAsLsXsFsxcrwbl, xlocker allowed=pAsLsXsFsxcrwbl, others allowed=pAsLsXs on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=6 0x7f724977b150]
10.06.03_12:58:14.414361 7f72666fa710 mds0.locker client5100 pending pAsLsXsFsx allowed pAsLsXsFsxcrwbl wanted p
10.06.03_12:58:14.414371 7f72666fa710 mds0.locker wrlock_finish on (inest mix w=1 dirty) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=6 0x7f724977b150]
10.06.03_12:58:14.414398 7f72666fa710 mds0.locker scatter_eval (inest mix dirty) on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 ap=1 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=5 0x7f724977b150]
10.06.03_12:58:14.414431 7f72666fa710 mds0.locker local_wrlock_finish on (iversion lock w=1 last_client=5100) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile lock w=1) (ixattr sync) (iversion lock w=1 last_client=5100) | nref=7 0x7f7251c47810]
10.06.03_12:58:14.414458 7f72666fa710 mds0.locker wrlock_finish on (ifile lock w=1) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile lock w=1) (ixattr sync) (iversion lock) | nref=6 0x7f7251c47810]
10.06.03_12:58:14.414482 7f72666fa710 mds0.locker file_eval wanted= loner_wanted= other_wanted= filelock=(ifile lock) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile lock) (ixattr sync) (iversion lock) | nref=5 0x7f7251c47810]
10.06.03_12:58:14.414505 7f72666fa710 mds0.locker file_eval stable, bump to sync (ifile lock) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile lock) (ixattr sync) (iversion lock) | nref=5 0x7f7251c47810]
10.06.03_12:58:14.414528 7f72666fa710 mds0.locker simple_sync on (ifile lock) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile lock) (ixattr sync) (iversion lock) | nref=5 0x7f7251c47810]
10.06.03_12:58:14.414551 7f72666fa710 mds0.locker wrlock_finish on (inest mix w=1) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile sync) (ixattr sync) (iversion lock) | nref=5 0x7f7251c47810]
10.06.03_12:58:14.414574 7f72666fa710 mds0.locker scatter_eval (inest mix) on [inode 600 [...a,head] ~mds0/stray/ auth v351866 ap=1 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix) (ifile sync) (ixattr sync) (iversion lock) | nref=4 0x7f7251c47810]
10.06.03_12:58:14.414597 7f72666fa710 mds0.locker local_wrlock_finish on (dversion lock w=1 last_client=5100) on [dentry #1/static/linux-2.6.34/Documentation [a,head] auth NULL (dn sync) (dversion lock w=1 last_client=5100) v=5098 inode=0 state=new | nref=4 0x7f72573d5ad0]
10.06.03_12:58:14.414615 7f72666fa710 mds0.cache.dir(100) auth_unpin by 0x1f3bfa0 on [dir 100 ~mds0/ [a,head] auth v=351867 cv=278945/278945 dir_auth=0 ap=0+1+2 na=2170 state=1610612738|complete f(v0 m0.000000 2=1+1) s=2=1+1 rb=2324881541/2324605580 rf=163029/162987 rd=10042/10032 hs=2+0,ss=0+0 dirty=1 | nref=3 0xd5e5d8] count now 0 + 2
10.06.03_12:58:14.414635 7f72666fa710 mds0.cache.den(1 static) auth_unpin by 0x1f3bfa0 on [dentry #1/static [2,head] auth (dn sync) (dversion lock) v=24616 inode=0x7f72510f02b0 | nref=2 0xd69930] now 0+2
10.06.03_12:58:14.414650 7f72666fa710 mds0.cache.dir(1) adjust_nested_auth_pins -1/-1 on [dir 1 / [a,head] auth v=24617 cv=17495/17495 dir_auth=0 ap=0+1+2 state=1610612738|complete f(v8 m10.06.03_11:58:57.212765 3=0+3) s=3=0+3 rb=274956347/278866916 rf=23502/23978 rd=1448/1494 hs=3+1,ss=2+0 dirty=1 | nref=3 0xd5e010] count now 0 + 2
10.06.03_12:58:14.414677 7f72666fa710 mds0.cache.dir(600) auth_unpin by 0x1f3bfa0 on [dir 600 ~mds0/stray/ [a,head] auth v=545270 cv=540423/540423 ap=0+1+1 na=2170 state=1610612736 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) s=173069=163028+10041 rb=2324881541/2324881541 rf=163028/163028 rd=10041/10041 hs=4195+0,ss=0+0 dirty=168 | nref=2 0x1056440] count now 0 + 1
10.06.03_12:58:14.414700 7f72666fa710 mds0.cache.dir(10000029d94) auth_unpin by 0x1f3bfa0 on [dir 10000029d94 /static/linux-2.6.34/ [a,head] auth pv=5100 v=5099 cv=0/0 ap=0+1+1 state=1610612738|complete f(v0 m10.06.03_12:58:14.074295 9=5+4) s=9=5+4 rb=274832904/274832904|274832904/274832904 rf=23492/23492|23492/23492 rd=1441/1441|1441/1441 hs=9+2,ss=1+4294967295 dirty=11 | nref=2 0x7f7248946a00] count now 0 + 1
10.06.03_12:58:14.414722 7f72666fa710 mds0.cache.ino(10000029d99) auth_unpin by 0x1f3bfa0 on [inode 10000029d99 [...a,head] ~mds0/stray/10000029d99/ auth v545269 snaprealm=0x162fdd0 f(v0 m10.06.03_12:58:14.042412 0=0+0) ds=0=0+0 rb=0 rf=0 rd=1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=p/p@380},l=5100 | nref=4 0x7f7249777a30] now 0+0
10.06.03_12:58:14.414747 7f72666fa710 mds0.cache.dir(600) adjust_nested_auth_pins -1/-1 on [dir 600 ~mds0/stray/ [a,head] auth v=545270 cv=540423/540423 na=2170 state=1610612736 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) s=173069=163028+10041 rb=2324881541/2324881541 rf=163028/163028 rd=10041/10041 hs=4195+0,ss=0+0 dirty=168 | nref=2 0x1056440] count now 0 + 0
10.06.03_12:58:14.414768 7f72666fa710 mds0.cache.dir(100) adjust_nested_auth_pins -1/0 on [dir 100 ~mds0/ [a,head] auth v=351867 cv=278945/278945 dir_auth=0 ap=0+1+1 na=2170 state=1610612738|complete f(v0 m0.000000 2=1+1) s=2=1+1 rb=2324881541/2324605580 rf=163029/162987 rd=10042/10032 hs=2+0,ss=0+0 dirty=1 | nref=3 0xd5e5d8] count now 0 + 1
10.06.03_12:58:14.414787 7f72666fa710 mds0.cache.ino(10000029d94) auth_unpin by 0x1f3bfa0 on [inode 10000029d94 [...a,head] /static/linux-2.6.34/ auth v7630 f(v0 m10.06.03_12:58:14.074295 9=5+4) ds=9=5+4 rb=274832904 rf=23492 rd=1442 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile excl) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFsx/p@31},l=5100 | nref=4 0x7f724977b150] now 0+1
10.06.03_12:58:14.414813 7f72666fa710 mds0.cache.dir(100000217aa) adjust_nested_auth_pins -1/-1 on [dir 100000217aa /static/ [a,head] auth v=7631 cv=1631/1631 ap=1+1+2 state=1610612738|complete f(v0 m10.06.03_12:55:48.242087 1=0+1) s=1=0+1 rb=274832904/274956347 rf=23492/23502 rd=1442/1445 hs=1+2,ss=3+0 dirty=4 | nref=3 0x7f725d4446c8] count now 1 + 2
10.06.03_12:58:14.414833 7f72666fa710 mds0.cache.ino(100000217aa) auth_unpin by 0x1f3bfa0 on [inode 100000217aa [...a,head] /static/ auth v24616 snaprealm=0x7f724e6866a0 f(v0 m10.06.03_12:55:48.242087 1=0+1) ds=1=0+1 rb=274956347 rf=23502 rd=1446 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXsFs/-@18},l=5100 | nref=2152 0x7f72510f02b0] now 0+1
10.06.03_12:58:14.414858 7f72666fa710 mds0.cache.dir(1) adjust_nested_auth_pins -1/-1 on [dir 1 / [a,head] auth v=24617 cv=17495/17495 dir_auth=0 ap=0+0+1 state=1610612738|complete f(v8 m10.06.03_11:58:57.212765 3=0+3) s=3=0+3 rb=274956347/278866916 rf=23502/23978 rd=1448/1494 hs=3+1,ss=2+0 dirty=1 | nref=3 0xd5e010] count now 0 + 1
10.06.03_12:58:14.414878 7f72666fa710 mds0.cache.ino(600) auth_unpin by 0x1f3bfa0 on [inode 600 [...a,head] ~mds0/stray/ auth v351866 na=2170 f(v5 m10.06.03_12:58:14.074295 173069=163028+10041) ds=173069=163028+10041 rb=2324881541 rf=163028 rd=10041 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix) (ifile sync) (ixattr sync) (iversion lock) | nref=3 0x7f7251c47810] now 0+0
10.06.03_12:58:14.414900 7f72666fa710 mds0.cache.dir(100) adjust_nested_auth_pins -1/-1 on [dir 100 ~mds0/ [a,head] auth v=351867 cv=278945/278945 dir_auth=0 na=2170 state=1610612738|complete f(v0 m0.000000 2=1+1) s=2=1+1 rb=2324881541/2324605580 rf=163029/162987 rd=10042/10032 hs=2+0,ss=0+0 dirty=1 | nref=3 0xd5e5d8] count now 0 + 0
10.06.03_12:58:14.414926 7f72666fa710 mds0.cache.den(100000217aa linux-2.6.34) auth_unpin by 0x1f3bfa0 on [dentry #1/static/linux-2.6.34 [9,head] auth (dn sync) (dversion lock) v=7630 inode=0x7f724977b150 | nref=2 0x7f725730bab0] now 0+1
10.06.03_12:58:14.414942 7f72666fa710 mds0.cache.dir(100000217aa) adjust_nested_auth_pins -1/-1 on [dir 100000217aa /static/ [a,head] auth v=7631 cv=1631/1631 ap=1+0+1 state=1610612738|complete f(v0 m10.06.03_12:55:48.242087 1=0+1) s=1=0+1 rb=274832904/274956347 rf=23492/23502 rd=1442/1445 hs=1+2,ss=3+0 dirty=4 | nref=3 0x7f725d4446c8] count now 1 + 1
10.06.03_12:58:14.414962 7f72666fa710 mds0.cache.den(10000029d94 Documentation) auth_unpin by 0x1f3bfa0 on [dentry #1/static/linux-2.6.34/Documentation [a,head] auth NULL (dn sync) (dversion lock) v=5098 inode=0 state=new | nref=2 0x7f72573d5ad0] now 0+0
10.06.03_12:58:14.414978 7f72666fa710 mds0.cache.dir(10000029d94) adjust_nested_auth_pins -1/-1 on [dir 10000029d94 /static/linux-2.6.34/ [a,head] auth pv=5100 v=5099 cv=0/0 state=1610612738|complete f(v0 m10.06.03_12:58:14.074295 9=5+4) s=9=5+4 rb=274832904/274832904|274832904/274832904 rf=23492/23492|23492/23492 rd=1441/1441|1441/1441 hs=9+2,ss=1+4294967295 dirty=11 | nref=2 0x7f7248946a00] count now 0 + 0
10.06.03_12:58:14.414999 7f72666fa710 mds0.cache.dir(100000217aa) adjust_nested_auth_pins -1/0 on [dir 100000217aa /static/ [a,head] auth v=7631 cv=1631/1631 ap=1+0+0 state=1610612738|complete f(v0 m10.06.03_12:55:48.242087 1=0+1) s=1=0+1 rb=274832904/274956347 rf=23492/23502 rd=1442/1445 hs=1+2,ss=3+0 dirty=4 | nref=3 0x7f725d4446c8] count now 1 + 0
10.06.03_12:58:14.415018 7f72666fa710 mds0.cache.ino(1) auth_unpin by 0x1f3bfa0 on [inode 1 [...a,head] / auth v12028 snaprealm=0x7f725c600340 f(v8 m10.06.03_11:58:57.212765 3=0+3) ds=3=0+3 rb=278866916/0 rf=23978/0 rd=1494/1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=pAsLsXs/-@3} | nref=4 0x7f725c5f3f20] now 0+0
10.06.03_12:58:14.415044 7f72666fa710 mds0.cache.dir(100000217aa) auth_unpin by 0x1f3bfa0 on [dir 100000217aa /static/ [a,head] auth v=7631 cv=1631/1631 state=1610612738|complete f(v0 m10.06.03_12:55:48.242087 1=0+1) s=1=0+1 rb=274832904/274956347 rf=23492/23502 rd=1442/1445 hs=1+2,ss=3+0 dirty=4 | nref=2 0x7f725d4446c8] count now 0 + 0
10.06.03_12:58:14.415063 7f72666fa710 mds0.cache.dir(1) adjust_nested_auth_pins -1/0 on [dir 1 / [a,head] auth v=24617 cv=17495/17495 dir_auth=0 state=1610612738|complete f(v8 m10.06.03_11:58:57.212765 3=0+3) s=3=0+3 rb=274956347/278866916 rf=23502/23978 rd=1448/1494 hs=3+1,ss=2+0 dirty=1 | nref=3 0xd5e010] count now 0 + 0
10.06.03_12:58:14.415084 7f72666fa710 mds0.locker kick_cap_releases released at current seq 380, reissuing
10.06.03_12:58:14.415101 7f72666fa710 mds0.locker issue_caps loner client5100 allowed=pAsLsXsFscr, xlocker allowed=pAsLsXsFscr, others allowed=pAsLsXsFscr on [inode 10000029d99 [...a,head] ~mds0/stray/10000029d99/ auth v545269 snaprealm=0x162fdd0 f(v0 m10.06.03_12:58:14.042412 0=0+0) ds=0=0+0 rb=0 rf=0 rd=1 (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix dirty) (ifile sync) (ixattr sync) (iversion lock) caps={5100=p/p@380},l=5100 | nref=4 0x7f7249777a30]
10.06.03_12:58:14.415129 7f72666fa710 mds0.locker client5100 pending p allowed pAsLsXsFscr wanted p
root@mds1:~#

(10-10/11)