mds crash

mds_crash.txt

2016-08-09 18:51:50.716892 7f6890859180  0 set uid:gid to 64045:64045 (ceph:ceph)
2016-08-09 18:51:50.716931 7f6890859180  0 ceph version 10.2.1 (3a66dd4f30852819c1bdaa8ec23c795d4ad77269), process ceph-mds, pid 5966
2016-08-09 18:51:50.719011 7f6890859180  0 pidfile_write: ignore empty --pid-file
2016-08-09 18:51:50.914725 7f6889fd4700  1 mds.dal2mds2 handle_mds_map standby
2016-08-09 18:51:50.920982 7f6889fd4700  1 mds.0.1066 handle_mds_map i am now mds.0.1066
2016-08-09 18:51:50.920989 7f6889fd4700  1 mds.0.1066 handle_mds_map state change up:boot --> up:replay
2016-08-09 18:51:50.921002 7f6889fd4700  1 mds.0.1066 replay_start
2016-08-09 18:51:50.921007 7f6889fd4700  1 mds.0.1066  recovery set is
2016-08-09 18:51:50.921025 7f6889fd4700  1 mds.0.1066  waiting for osdmap 36590 (which blacklists prior instance)
2016-08-09 18:51:50.945892 7f6884cc7700  0 mds.0.cache creating system inode with ino:100
2016-08-09 18:51:50.946357 7f6884cc7700  0 mds.0.cache creating system inode with ino:1
2016-08-09 18:51:51.814796 7f6882ab3700  1 mds.0.1066 replay_done
2016-08-09 18:51:51.814818 7f6882ab3700  1 mds.0.1066 making mds journal writeable
2016-08-09 18:51:51.929687 7f6880494700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.123:0/1727908193 pipe(0x55a56aee6000 sd=42 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9000).accept peer addr is really 10.10.32.123:0/1727908193 (socket is 10.10.32.123:44412/0)
2016-08-09 18:51:51.929774 7f6880292700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.63:0/3780358878 pipe(0x55a56af1e000 sd=44 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9180).accept peer addr is really 10.10.32.63:0/3780358878 (socket is 10.10.32.63:41914/0)
2016-08-09 18:51:51.929777 7f6880393700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.49:0/1982015623 pipe(0x55a56af1f400 sd=43 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9300).accept peer addr is really 10.10.32.49:0/1982015623 (socket is 10.10.32.49:47863/0)
2016-08-09 18:51:51.929779 7f6880191700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.73:0/465903441 pipe(0x55a56af20800 sd=45 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9780).accept peer addr is really 10.10.32.73:0/465903441 (socket is 10.10.32.73:49935/0)
2016-08-09 18:51:51.929887 7f6880090700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.81:0/78289858 pipe(0x55a56bd80800 sd=46 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9600).accept peer addr is really 10.10.32.81:0/78289858 (socket is 10.10.32.81:33512/0)
2016-08-09 18:51:51.929917 7f687ff8f700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.68:0/3004109229 pipe(0x55a56bd7f400 sd=47 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a567ce9480).accept peer addr is really 10.10.32.68:0/3004109229 (socket is 10.10.32.68:41600/0)
2016-08-09 18:51:51.930375 7f687fc8c700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.77:0/363843554 pipe(0x55a56bd7e000 sd=48 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1c600).accept peer addr is really 10.10.32.77:0/363843554 (socket is 10.10.32.77:35489/0)
2016-08-09 18:51:51.930618 7f687fa8a700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.100:0/3082077960 pipe(0x55a5697ae800 sd=49 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1c480).accept peer addr is really 10.10.32.100:0/3082077960 (socket is 10.10.32.100:36085/0)
2016-08-09 18:51:51.930929 7f687f585700  0 -- 10.10.34.17:6801/5966 >> 10.10.34.16:0/2821184615 pipe(0x55a5697ac000 sd=51 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1c180).accept peer addr is really 10.10.34.16:0/2821184615 (socket is 10.10.34.16:51758/0)
2016-08-09 18:51:51.931017 7f687f484700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.140:0/3061890293 pipe(0x55a569b0a800 sd=52 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1d080).accept peer addr is really 10.10.32.140:0/3061890293 (socket is 10.10.32.140:47491/0)
2016-08-09 18:51:51.931140 7f687f282700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.35:0/2298050027 pipe(0x55a569b08000 sd=54 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1cd80).accept peer addr is really 10.10.32.35:0/2298050027 (socket is 10.10.32.35:59036/0)
2016-08-09 18:51:51.931212 7f687f181700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.141:0/300658029 pipe(0x55a569cf6800 sd=55 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1cc00).accept peer addr is really 10.10.32.141:0/300658029 (socket is 10.10.32.141:48408/0)
2016-08-09 18:51:51.931290 7f687ef7f700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.38:0/84797813 pipe(0x55a569cf5400 sd=56 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1ca80).accept peer addr is really 10.10.32.38:0/84797813 (socket is 10.10.32.38:60776/0)
2016-08-09 18:51:51.931322 7f687ee7e700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.78:0/2877140952 pipe(0x55a569cf4000 sd=57 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1de00).accept peer addr is really 10.10.32.78:0/2877140952 (socket is 10.10.32.78:55323/0)
2016-08-09 18:51:51.931333 7f687ed7d700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.15:0/257852104 pipe(0x55a56d65e800 sd=58 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1dc80).accept peer addr is really 10.10.32.15:0/257852104 (socket is 10.10.32.15:56696/0)
2016-08-09 18:51:51.931463 7f687ec7c700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.136:0/2992104801 pipe(0x55a56d65d400 sd=59 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1db00).accept peer addr is really 10.10.32.136:0/2992104801 (socket is 10.10.32.136:48950/0)
2016-08-09 18:51:51.931496 7f687ea7a700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.26:0/2997311861 pipe(0x55a56d65c000 sd=60 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1d980).accept peer addr is really 10.10.32.26:0/2997311861 (socket is 10.10.32.26:53425/0)
2016-08-09 18:51:51.931602 7f6889fd4700  1 mds.0.1066 handle_mds_map i am now mds.0.1066
2016-08-09 18:51:51.931609 7f6889fd4700  1 mds.0.1066 handle_mds_map state change up:replay --> up:reconnect
2016-08-09 18:51:51.931623 7f6889fd4700  1 mds.0.1066 reconnect_start
2016-08-09 18:51:51.931618 7f687e777700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.72:0/2010850783 pipe(0x55a569ad6800 sd=61 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1d800).accept peer addr is really 10.10.32.72:0/2010850783 (socket is 10.10.32.72:37157/0)
2016-08-09 18:51:51.931654 7f6889fd4700  1 mds.0.1066 reopen_log
2016-08-09 18:51:51.931682 7f6889fd4700  1 mds.0.server reconnect_clients -- 39 sessions
2016-08-09 18:51:51.931681 7f687e676700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.52:0/3242965456 pipe(0x55a569ad5400 sd=62 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1d680).accept peer addr is really 10.10.32.52:0/3242965456 (socket is 10.10.32.52:45305/0)
2016-08-09 18:51:51.931824 7f687e575700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.71:0/195556283 pipe(0x55a569ad4000 sd=63 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1f180).accept peer addr is really 10.10.32.71:0/195556283 (socket is 10.10.32.71:44739/0)
2016-08-09 18:51:51.931993 7f687e474700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.66:0/2894322147 pipe(0x55a56aefc800 sd=64 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1f000).accept peer addr is really 10.10.32.66:0/2894322147 (socket is 10.10.32.66:57124/0)
2016-08-09 18:51:51.932068 7f687e272700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.39:0/1091178261 pipe(0x55a56aefb400 sd=65 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1ee80).accept peer addr is really 10.10.32.39:0/1091178261 (socket is 10.10.32.39:54020/0)
2016-08-09 18:51:51.932163 7f687e171700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.76:0/1848375389 pipe(0x55a56aefa000 sd=66 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1ed00).accept peer addr is really 10.10.32.76:0/1848375389 (socket is 10.10.32.76:49531/0)
2016-08-09 18:51:51.932296 7f687e070700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.50:0/1148295859 pipe(0x55a5696c6800 sd=67 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1eb80).accept peer addr is really 10.10.32.50:0/1148295859 (socket is 10.10.32.50:53778/0)
2016-08-09 18:51:51.932389 7f687de6e700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.110:0/2283411619 pipe(0x55a5696c5400 sd=68 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1ea00).accept peer addr is really 10.10.32.110:0/2283411619 (socket is 10.10.32.110:46182/0)
2016-08-09 18:51:51.932473 7f687dc6c700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.117:0/568737751 pipe(0x55a5696c4000 sd=69 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1e880).accept peer addr is really 10.10.32.117:0/568737751 (socket is 10.10.32.117:58938/0)
2016-08-09 18:51:51.932571 7f687d868700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.25:0/823337668 pipe(0x55a569c71400 sd=71 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700d80).accept peer addr is really 10.10.32.25:0/823337668 (socket is 10.10.32.25:35152/0)
2016-08-09 18:51:51.932614 7f687da6a700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.45:0/1186735261 pipe(0x55a569c72800 sd=70 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569b1fd80).accept peer addr is really 10.10.32.45:0/1186735261 (socket is 10.10.32.45:36660/0)
2016-08-09 18:51:51.932786 7f687d666700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.64:0/2959683292 pipe(0x55a569c70000 sd=72 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700c00).accept peer addr is really 10.10.32.64:0/2959683292 (socket is 10.10.32.64:34478/0)
2016-08-09 18:51:51.933317 7f687d060700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.24:0/2769324456 pipe(0x55a5687bd400 sd=74 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700900).accept peer addr is really 10.10.32.24:0/2769324456 (socket is 10.10.32.24:37215/0)
2016-08-09 18:51:51.934605 7f687c555700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.43:0/1981053053 pipe(0x55a5687bc000 sd=75 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700780).accept peer addr is really 10.10.32.43:0/1981053053 (socket is 10.10.32.43:53392/0)
2016-08-09 18:51:51.934837 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170474151 10.10.32.73:0/465903441 after 0.003115
2016-08-09 18:51:51.934956 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170485746 10.10.32.81:0/78289858 after 0.003242
2016-08-09 18:51:51.935006 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170473371 10.10.32.68:0/3004109229 after 0.003304
2016-08-09 18:51:51.935057 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170477450 10.10.32.100:0/3082077960 after 0.003354
2016-08-09 18:51:51.935182 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.163158850 10.10.34.14:0/1012600691 after 0.003483
2016-08-09 18:51:51.935232 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.165314329 10.10.34.16:0/2821184615 after 0.003529
2016-08-09 18:51:51.935271 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170485558 10.10.32.140:0/3061890293 after 0.003572
2016-08-09 18:51:51.935326 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.162199232 10.10.34.13:0/3536127066 after 0.003629
2016-08-09 18:51:51.935365 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170486320 10.10.32.141:0/300658029 after 0.003666
2016-08-09 18:51:51.935407 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170483278 10.10.32.38:0/84797813 after 0.003710
2016-08-09 18:51:51.936202 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170497648 10.10.32.78:0/2877140952 after 0.004500
2016-08-09 18:51:51.936250 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170567867 10.10.32.136:0/2992104801 after 0.004551
2016-08-09 18:51:51.936292 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170530517 10.10.32.26:0/2997311861 after 0.004594
2016-08-09 18:51:51.936401 7f687c050700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.31:0/1698906833 pipe(0x55a5691f4800 sd=76 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700600).accept peer addr is really 10.10.32.31:0/1698906833 (socket is 10.10.32.31:35592/0)
2016-08-09 18:51:51.937187 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170497792 10.10.32.72:0/2010850783 after 0.005483
2016-08-09 18:51:51.937250 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170497645 10.10.32.52:0/3242965456 after 0.005552
2016-08-09 18:51:51.937296 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170497789 10.10.32.71:0/195556283 after 0.005601
2016-08-09 18:51:51.937338 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170568068 10.10.32.66:0/2894322147 after 0.005639
2016-08-09 18:51:51.937382 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170497651 10.10.32.39:0/1091178261 after 0.005687
2016-08-09 18:51:51.937463 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170568071 10.10.32.50:0/1148295859 after 0.005764
2016-08-09 18:51:51.937511 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170486317 10.10.32.117:0/568737751 after 0.005812
2016-08-09 18:51:51.937569 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170549927 10.10.32.64:0/2959683292 after 0.005869
2016-08-09 18:51:51.938366 7f687be4e700  0 -- 10.10.34.17:6801/5966 >> 10.10.34.19:0/3080043042 pipe(0x55a5691f3400 sd=77 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700480).accept peer addr is really 10.10.34.19:0/3080043042 (socket is 10.10.34.19:34191/0)
2016-08-09 18:51:51.940833 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.155993061 10.10.34.18:0/579481450 after 0.009128
2016-08-09 18:51:51.941826 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170475427 10.10.32.24:0/2769324456 after 0.010127
2016-08-09 18:51:51.943485 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170560943 10.10.32.43:0/1981053053 after 0.011787
2016-08-09 18:51:51.945649 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.166251240 10.10.32.31:0/1698906833 after 0.013948
2016-08-09 18:51:51.951914 7f687bc4c700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.113:0/4079558860 pipe(0x55a5691f2000 sd=78 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700300).accept peer addr is really 10.10.32.113:0/4079558860 (socket is 10.10.32.113:56601/0)
2016-08-09 18:51:51.953015 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.154923745 10.10.34.19:0/3080043042 after 0.021316
2016-08-09 18:51:51.953113 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.166540911 10.10.32.123:0/1727908193 after 0.021414
2016-08-09 18:51:51.953181 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170473377 10.10.32.49:0/1982015623 after 0.021483
2016-08-09 18:51:51.953226 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170485563 10.10.32.63:0/3780358878 after 0.021529
2016-08-09 18:51:51.962070 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170317006 10.10.32.113:0/4079558860 after 0.030361
2016-08-09 18:51:51.984705 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170473299 10.10.32.77:0/363843554 after 0.053001
2016-08-09 18:51:51.985726 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170533775 10.10.32.35:0/2298050027 after 0.054029
2016-08-09 18:51:51.985920 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170561126 10.10.32.15:0/257852104 after 0.054223
2016-08-09 18:51:51.986149 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170567972 10.10.32.110:0/2283411619 after 0.054450
2016-08-09 18:51:51.986328 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170486236 10.10.32.45:0/1186735261 after 0.054629
2016-08-09 18:51:51.987158 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170491963 10.10.32.25:0/823337668 after 0.055459
2016-08-09 18:51:51.988287 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.170567756 10.10.32.76:0/1848375389 after 0.056587
2016-08-09 18:51:52.000854 7f687ba4a700  0 -- 10.10.34.17:6801/5966 >> 10.10.32.124:0/785713111 pipe(0x55a56a29a800 sd=79 :6801 s=0 pgs=0 cs=0 l=0 c=0x55a569700180).accept peer addr is really 10.10.32.124:0/785713111 (socket is 10.10.32.124:57512/0)
2016-08-09 18:51:52.048710 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.169324584 10.10.32.124:0/785713111 after 0.116994
2016-08-09 18:51:52.120746 7f6889fd4700  0 log_channel(cluster) log [DBG] : reconnect by client.163182710 10.10.34.11:0/1814358457 after 0.189039
2016-08-09 18:51:52.153956 7f6889fd4700  1 mds.0.1066 reconnect_done
2016-08-09 18:51:52.940559 7f6889fd4700  1 mds.0.1066 handle_mds_map i am now mds.0.1066
2016-08-09 18:51:52.940566 7f6889fd4700  1 mds.0.1066 handle_mds_map state change up:reconnect --> up:rejoin
2016-08-09 18:51:52.940577 7f6889fd4700  1 mds.0.1066 rejoin_start
2016-08-09 18:51:56.499956 7f6889fd4700  1 mds.0.1066 rejoin_joint_start
2016-08-09 18:52:18.095935 7f6885ecb700  1 mds.0.1066 rejoin_done
2016-08-09 18:52:18.166960 7f6889fd4700  1 mds.0.1066 handle_mds_map i am now mds.0.1066
2016-08-09 18:52:18.166992 7f6889fd4700  1 mds.0.1066 handle_mds_map state change up:rejoin --> up:clientreplay
2016-08-09 18:52:18.167006 7f6889fd4700  1 mds.0.1066 recovery_done -- successful recovery!
2016-08-09 18:52:18.169727 7f6889fd4700  1 mds.0.1066 clientreplay_start
2016-08-09 18:52:18.320703 7f68856ca700  1 mds.0.1066 clientreplay_done
2016-08-09 18:52:19.170997 7f6889fd4700  1 mds.0.1066 handle_mds_map i am now mds.0.1066
2016-08-09 18:52:19.171003 7f6889fd4700  1 mds.0.1066 handle_mds_map state change up:clientreplay --> up:active
2016-08-09 18:52:19.171013 7f6889fd4700  1 mds.0.1066 active_start
2016-08-09 18:52:19.362172 7f6889fd4700  1 mds.0.1066 cluster recovered.
2016-08-09 18:52:19.365945 7f6889fd4700 -1 mds/Locker.cc: In function 'bool Locker::check_inode_max_size(CInode*, bool, bool, uint64_t, bool, uint64_t, utime_t)' thread 7f6889fd4700 time 2016-08-09 18:52:19.363935
mds/Locker.cc: 2190: FAILED assert(in->is_file())