Ceph

I was running some test where ceph is underlying filsystem and slave nodes have corresponding directories under mount point.
last request was to create a file in-use.lock. It seems we got "create" request but then FS hangs. I saw that "cmds" was not running.
At times I am able to restart mds but often it stays laggy/crashed. I plan to run it under gdb, but any insight would be helpful.

From MDS.log:

11.07.12_16:04:19.731781 42886940 mds0.server handle_client_request client_request(client4133:9 mkdir #10000000028/pids)
11.07.12_16:04:19.734331 42886940 mds0.server handle_client_request client_request(client4131:9 mkdir #10000000023/pids)
11.07.12_16:04:19.736888 42886940 mds0.server handle_client_request client_request(client4132:9 mkdir #10000000026/pids)
11.07.12_16:04:19.739470 42886940 mds0.server handle_client_request client_request(client4129:9 mkdir #10000000024/pids)
11.07.12_16:04:19.759061 42886940 mds0.server handle_client_request client_request(client4135:8 lookup #10000000029/pids)
11.07.12_16:04:19.759916 42886940 mds0.server handle_client_request client_request(client4135:9 mkdir #10000000029/pids)
11.07.12_16:07:03.647537 42886940 mds0.server handle_client_request client_request(client4137:195 lookup #10000000037/current)
11.07.12_16:07:03.648499 42886940 mds0.server handle_client_request client_request(client4137:196 mkdir #10000000037/current)
11.07.12_16:07:03.654085 42886940 mds0.server handle_client_request client_request(client4137:197 lookup #10000000037/in_use.lock)
11.07.12_16:07:03.654800 42886940 mds0.server handle_client_request client_request(client4137:198 create #10000000037/in_use.lock)
11.07.12_16:07:03.667991 42886940 mds0.server handle_client_request client_request(client4137:199 ??? #10000000042)
1: (Server::handle_client_request(MClientRequest*)+0x453) [0x500e63]

...
...

[root@bz1 out]# tail 100 mds.0.log
11.07.12_16:07:03.656078 42886940 mds0.cache project to [2,head] n(v0 rc11.07.12_16:07:03.655877 1=0+1)
11.07.12_16:07:03.656086 42886940 mds0.cache result [2,head] n(v0 rc11.07.12_16:07:03.655877 2=1+1) [dir 10000000037 /dfs-name/cn1/ [2,head] auth pv=5 v=1 cv=0/0 ap=2+4+4 state=1610612738|complete f() n() hs=0+2,ss=0+0 | child dirty authpin 0x7f0abc0c5558]
11.07.12_16:07:03.656099 42886940 mds0.locker local_wrlock_grab on (iversion lock w=1 last_client=4137) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv22 ap=2 f() n(v0 1=0+1) (iauth sync r=1) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4137=pAsLsXsFsx/@5},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.656118 42886940 mds0.cache.ino(10000000037) project_inode 0x7f0ab403b010
11.07.12_16:07:03.656124 42886940 mds0.cache.dir(1000000002b) pre_dirty 24
11.07.12_16:07:03.656131 42886940 mds0.cache.den(1000000002b cn1) pre_dirty [dentry #1/dfs-name/cn1 [2,head] auth (dn sync) (dversion lock) pv=24 v=2 inode=0x7f0abc09c0d0 | inodepin dirty 0x7f0abc0b98e0]
11.07.12_16:07:03.656141 42886940 mds0.cache.ino(10000000037) pre_dirty 24 (current v 2)
11.07.12_16:07:03.656147 42886940 mds0.cache predirty_journal_parents take_diff f(v0 m11.07.12_16:07:03.655877 2=1+1)
11.07.12_16:07:03.656155 42886940 mds0.cache predirty_journal_parents - f(v0 m11.07.12_16:07:03.649830 1=0+1)
11.07.12_16:07:03.656163 42886940 mds0.cache predirty_journal_parents gives f(v0 m11.07.12_16:07:03.655877 2=1+1) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync r=1) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@5},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.656181 42886940 mds0.cache project_rstat_frag_to_inode [2,head]
11.07.12_16:07:03.656187 42886940 mds0.cache frag rstat n(v0 rc11.07.12_16:07:03.655877 2=1+1)
11.07.12_16:07:03.656195 42886940 mds0.cache frag accounted_rstat n(v0 rc11.07.12_16:07:03.649830 1=0+1)
11.07.12_16:07:03.656203 42886940 mds0.cache delta n(v0 rc11.07.12_16:07:03.655877 1=1+0)
11.07.12_16:07:03.656211 42886940 mds0.cache projecting to [2,head] n(v0 rc11.07.12_16:07:03.649830 2=0+2)
11.07.12_16:07:03.656219 42886940 mds0.cache result [2,head] n(v0 rc11.07.12_16:07:03.655877 3=1+2)
11.07.12_16:07:03.656228 42886940 mds0.cache.dir(1000000002b) auth_pin by 0x7f0ab401f4d0 on [dir 1000000002b /dfs-name/ [2,head] auth pv=24 v=21 cv=0/0 ap=2+2+3 state=1610612738|complete f(v0 m11.07.12_16:00:07.806759 10=0+10) n(v0 rc11.07.12_16:00:07.806759 10=0+10) hs=10+0,ss=0+0 dirty=10 | child dirty authpin 0x7f0abc0c0db8] count now 2 + 3
11.07.12_16:07:03.656255 42886940 mds0.cache.dir(1000000002b) project_fnode 0x7f0ab4009850
11.07.12_16:07:03.656261 42886940 mds0.cache.dir(1000000002b) pre_dirty 25
11.07.12_16:07:03.656268 42886940 mds0.cache frag head is [2,head]
11.07.12_16:07:03.656274 42886940 mds0.cache inode update is [2,head]
11.07.12_16:07:03.656280 42886940 mds0.cache floor of 2 from parent dn [dentry #1/dfs-name/cn1 [2,head] auth (dn sync) (dversion lock) pv=24 v=2 inode=0x7f0abc09c0d0 | inodepin dirty 0x7f0abc0b98e0]
11.07.12_16:07:03.656290 42886940 mds0.cache project_rstat_inode_to_frag [2,head]
11.07.12_16:07:03.656296 42886940 mds0.cache inode rstat n(v0 rc11.07.12_16:07:03.655877 3=1+2)
11.07.12_16:07:03.656304 42886940 mds0.cache inode accounted_rstat n(v0 rc11.07.12_16:07:03.649830 2=0+2)
11.07.12_16:07:03.656312 42886940 mds0.cache delta n(v0 rc11.07.12_16:07:03.655877 1=1+0)
11.07.12_16:07:03.656320 42886940 mds0.cache projecting to head [2,head] n(v0 rc11.07.12_16:07:03.649830 11=0+11)
11.07.12_16:07:03.656328 42886940 mds0.cache project to [2,head] n(v0 rc11.07.12_16:07:03.649830 11=0+11)
11.07.12_16:07:03.656337 42886940 mds0.cache result [2,head] n(v0 rc11.07.12_16:07:03.655877 12=1+11) [dir 1000000002b /dfs-name/ [2,head] auth pv=25 v=21 cv=0/0 ap=2+2+3 state=1610612738|complete f(v0 m11.07.12_16:00:07.806759 10=0+10) n(v0 rc11.07.12_16:00:07.806759 10=0+10) hs=10+0,ss=0+0 dirty=10 | child dirty authpin 0x7f0abc0c0db8]
11.07.12_16:07:03.656353 42886940 mds0.cache predirty_journal_parents last prop 0.006047 < 1, stopping
11.07.12_16:07:03.656362 42886940 mds0.cache predirty_journal_parents stop. marking nestlock on [inode 1000000002b [...2,head] /dfs-name/ auth v174 pv224 ap=2 f(v0 m11.07.12_16:00:07.806759 10=0+10) n(v0 rc11.07.12_16:00:07.806759 11=0+11) (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=1) (ifile sync) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4137=pAsLsXsFs/-@24},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc097510]
11.07.12_16:07:03.656384 42886940 mds0.locker mark_updated_scatterlock (inest mix w=1 dirty) - added at 11.07.12_16:07:03.656383
11.07.12_16:07:03.656394 42886940 mds0.cache journal_cow_dentry follows head on [dentry #1/dfs-name/cn1 [2,head] auth (dn sync) (dversion lock) pv=24 v=2 inode=0x7f0abc09c0d0 | inodepin dirty 0x7f0abc0b98e0]
11.07.12_16:07:03.656404 42886940 mds0.cache journal_cow_dentry follows 1 < first on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync r=1) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@5},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.656428 42886940 mds0.locker issue_new_caps for mode 3 on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) cr={4137=0-4194304} 0x7f0abc0a9dc0]
11.07.12_16:07:03.656443 42886940 mds0.cache.ino(10000000042) add_client_cap first cap, joining realm snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f0abc003a60)
11.07.12_16:07:03.656451 42886940 mds0.locker eval 2496 [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0} | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656467 42886940 mds0.locker eval set loner to client4137
11.07.12_16:07:03.656475 42886940 mds0.locker file_eval wanted=sxcrwb loner_wanted=sxcrwb other_wanted= filelock=(ifile sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656492 42886940 mds0.locker file_eval stable, bump to loner (ifile sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656520 42886940 mds0.locker file_excl (ifile sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile sync) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656536 42886940 mds0.locker simple_eval (iauth sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656553 42886940 mds0.locker simple_eval stable, going to excl (iauth sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656569 42886940 mds0.locker simple_excl on (iauth sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth sync) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656585 42886940 mds0.locker simple_eval (ilink sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656602 42886940 mds0.locker simple_eval (ixattr sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656621 42886940 mds0.locker simple_eval stable, going to excl (ixattr sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656637 42886940 mds0.locker simple_excl on (ixattr sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr sync) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656653 42886940 mds0.locker scatter_eval (inest sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr excl) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656669 42886940 mds0.locker file_mixed (inest sync) on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr excl) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656690 42886940 mds0.locker issue_caps loner client4137 allowed=pAsxLsXsxFsxcrwbl, xlocker allowed=pAsxLsXsxFsxcrwbl, others allowed=pLs on [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr excl) (iversion lock) cr={4137=0-4194304} caps={4137=-/pAsxXsxFsxcrwb@0},l=4137 | caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656710 42886940 mds0.locker client4137 pending - allowed pAsxLsXsxFsxcrwbl wanted pAsxXsxFsxcrwb
11.07.12_16:07:03.656728 42886940 mds0.locker suppressed and !revoke, skipping client4137
11.07.12_16:07:03.656734 42886940 mds0.locker eval done
11.07.12_16:07:03.656741 42886940 mds0.server journal_and_reply tracei 0x7f0abc0a9dc0 tracedn 0x7f0abc103450
11.07.12_16:07:03.656749 42886940 mds0.locker set_xlocks_done on (dn xlock x=1 by 0x7f0ab401f4d0) [dentry #1/dfs-name/cn1/in_use.lock [2,head] auth NULL (dn xlock x=1 by 0x7f0ab401f4d0) (dversion lock w=1 last_client=4137) pv=4 v=3 inode=0 | request lock authpin 0x7f0abc103450]
11.07.12_16:07:03.656762 42886940 mds0.server early_reply 0 (Success) client_request(client4137:198 create #10000000037/in_use.lock)
11.07.12_16:07:03.656771 42886940 mds0.server set_trace_dist snapid head
11.07.12_16:07:03.656777 42886940 mds0.server set_trace_dist snaprealm snaprealm(1 seq 1 lc 0 cr 0 cps 1 snaps={} 0x7f0abc003a60) len=48
11.07.12_16:07:03.656785 42886940 mds0.cache.ino(10000000037) pfile 1 pauth 0 plink 0 pxattr 0 plocal 1 ctime 11.07.12_16:07:03.655877 valid=1
11.07.12_16:07:03.656796 42886940 mds0.cache.ino(10000000037) encode_inodestat issueing pAsLsXsFsx seq 6
11.07.12_16:07:03.656804 42886940 mds0.cache.ino(10000000037) encode_inodestat caps pAsLsXsFsx seq 6 mseq 0
11.07.12_16:07:03.656813 42886940 mds0.server set_trace_dist added diri [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync r=1) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@6},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.656830 42886940 mds0.server set_trace_dist added dir [dir 10000000037 /dfs-name/cn1/ [2,head] auth pv=5 v=1 cv=0/0 ap=2+4+4 state=1610612738|complete f() n() hs=0+2,ss=0+0 | child dirty authpin 0x7f0abc0c5558]
11.07.12_16:07:03.656840 42886940 mds0.locker issue_client_lease no/null lease on [dentry #1/dfs-name/cn1/in_use.lock [2,head] auth NULL (dn xlockdone x=1) (dversion lock w=1 last_client=4137) pv=4 v=3 inode=0 | request lock authpin 0x7f0abc103450]
11.07.12_16:07:03.656851 42886940 mds0.server set_trace_dist added dn head [dentry #1/dfs-name/cn1/in_use.lock [2,head] auth NULL (dn xlockdone x=1) (dversion lock w=1 last_client=4137) pv=4 v=3 inode=0 | request lock authpin 0x7f0abc103450]
11.07.12_16:07:03.656862 42886940 mds0.cache.ino(10000000042) pfile 1 pauth 0 plink 0 pxattr 0 plocal 0 ctime 11.07.12_16:07:03.655877 valid=1
11.07.12_16:07:03.656875 42886940 mds0.cache.ino(10000000042) encode_inodestat issueing pAsxLsXsxFsxcrwb seq 1
11.07.12_16:07:03.656884 42886940 mds0.cache.ino(10000000042) encode_inodestat caps pAsxLsXsxFsxcrwb seq 1 mseq 0
11.07.12_16:07:03.656891 42886940 mds0.cache.ino(10000000042) including xattrs version 0
11.07.12_16:07:03.656898 42886940 mds0.server set_trace_dist added in [inode 10000000042 [2,head] {#10000000042 /dfs-name/cn1/in_use.lock} auth v4 s=0 nl=1 n(v0 1=1+0) (iauth excl) (ilink sync) (ifile excl) (ixattr excl) (iversion lock) cr={4137=0-4194304} caps={4137=pAsxLsXsxFsxcrwb/pAsxXsxFsxcrwb@1},l=4137 | request caps 0x7f0abc0a9dc0]
11.07.12_16:07:03.656916 42886940 -- 192.168.1.101:6800/3862 --> 192.168.1.141:0/3024721268 -- client_reply(?:198 = 0 Success unsafe) v1 -- ?+0 0x7f0ab40094d0
11.07.12_16:07:03.656933 42886940 mds0.server lat 0.002155
11.07.12_16:07:03.656952 42886940 mds0.log submit_entry 4399870~1379 : EUpdate openc [metablob 1000000002b, 2 dirs prealloc_ino=[10000002382~1] used_prealloc_ino=10000000042 v100]
11.07.12_16:07:03.656964 42886940 mds0.locker rdlock_finish on (isnap sync) on [inode 1 [...2,head] / auth v36 pv37 ap=2 snaprealm=0x7f0abc003a60 f(v0 m11.07.12_15:59:45.408430 14=0+14) n(v8 rc11.07.12_16:04:19.761104 68=0+68)/n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile sync) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4128=pAsLsXsFs/-@5,4129=pAsLsXsFs/-@5,4130=pAsLsXsFs/-@5,4131=pAsLsXsFs/-@5,4132=pAsLsXsFs/-@5,4133=pAsLsXsFs/-@5,4134=pAsLsXsFs/-@5,4135=pAsLsXsFs/-@5,4136=pLsXs/-@8,4137=pAsLsXsFs/-@52} | lock pastsnapparent dirfrag caps dirty authpin 0x7f0abc007050]
11.07.12_16:07:03.657012 42886940 mds0.locker simple_eval (isnap sync) on [inode 1 [...2,head] / auth v36 pv37 ap=2 snaprealm=0x7f0abc003a60 f(v0 m11.07.12_15:59:45.408430 14=0+14) n(v8 rc11.07.12_16:04:19.761104 68=0+68)/n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1) (ifile sync) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4128=pAsLsXsFs/-@5,4129=pAsLsXsFs/-@5,4130=pAsLsXsFs/-@5,4131=pAsLsXsFs/-@5,4132=pAsLsXsFs/-@5,4133=pAsLsXsFs/-@5,4134=pAsLsXsFs/-@5,4135=pAsLsXsFs/-@5,4136=pLsXs/-@8,4137=pAsLsXsFs/-@52} | lock pastsnapparent dirfrag caps dirty authpin 0x7f0abc007050]
11.07.12_16:07:03.657048 42886940 mds0.locker rdlock_finish on (isnap sync) on [inode 1000000002b [...2,head] /dfs-name/ auth v174 pv224 ap=2 f(v0 m11.07.12_16:00:07.806759 10=0+10) n(v0 rc11.07.12_16:00:07.806759 11=0+11) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4137=pAsLsXsFs/-@24},l=4137 | dirtyscattered lock dirfrag caps dirty authpin 0x7f0abc097510]
11.07.12_16:07:03.657068 42886940 mds0.locker simple_eval (isnap sync) on [inode 1000000002b [...2,head] /dfs-name/ auth v174 pv224 ap=2 f(v0 m11.07.12_16:00:07.806759 10=0+10) n(v0 rc11.07.12_16:00:07.806759 11=0+11) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=1 dirty) (ifile sync) (ixattr sync) (iversion lock w=1 last_client=4137) caps={4137=pAsLsXsFs/-@24},l=4137 | dirtyscattered lock dirfrag caps dirty authpin 0x7f0abc097510]
11.07.12_16:07:03.657088 42886940 mds0.locker rdlock_finish on (iauth sync) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@6},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.657104 42886940 mds0.locker simple_eval (iauth sync) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync r=1) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@6},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.657121 42886940 mds0.locker rdlock_finish on (isnap sync) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@6},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.657137 42886940 mds0.locker simple_eval (isnap sync) on [inode 10000000037 [...2,head] /dfs-name/cn1/ auth v2 pv24 ap=2 f() n(v0 1=0+1) (iauth sync) (ilink sync) (idft sync) (isnap sync) (inest mix w=2) (ifile excl w=2) (ixattr sync) (iversion lock w=2 last_client=4137) caps={4137=pAsLsXsFsx/-@6},l=4137 | lock dirfrag caps dirty authpin 0x7f0abc09c0d0]
11.07.12_16:07:03.667976 42886940 -- 192.168.1.101:6800/3862 <== client4137 192.168.1.141:0/3024721268 337 ==== client_request(client4137:199 ? #10000000042) ==== 114+0+0 (6360005 0 0) 0xa4c960
11.07.12_16:07:03.667991 42886940 mds0.server handle_client_request client_request(client4137:199 ? #10000000042)
11.07.12_16:07:03.667999 42886940 mds0.server get_session have 0xa40850 client4137 192.168.1.141:0/3024721268 state open
11.07.12_16:07:03.668007 42886940 mds0.server oldest_client_tid=196
11.07.12_16:07:03.668017 42886940 mds0.cache request_start request(client4137:199 cr=0xa4c960)
11.07.12_16:07:03.668024 42886940 mds0.server dispatch_client_request client_request(client4137:199 ? #10000000042)
11.07.12_16:07:03.668031 42886940 mds0.server unknown client op 4361
mds/Server.cc: In function 'void Server::dispatch_client_request(MDRequest*)':
mds/Server.cc:1175: FAILED assert(0)
1: (Server::handle_client_request(MClientRequest*)+0x453) [0x500e63]
2: (MDS::_dispatch(Message*)+0x3aff) [0x4b623f]
3: (MDS::ms_dispatch(Message*)+0x76) [0x4b6e86]
4: (SimpleMessenger::dispatch_entry()+0x439) [0x488869]
5: (SimpleMessenger::DispatchThread::entry()+0x52) [0x484072]
6: (Thread::_entry_func(void*)+0x7) [0x49d7f7]
7: /lib64/libpthread.so.0 [0x7f0ac386d73d]
8: (clone()+0x6d) [0x7f0ac2aff4bd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.