Hi It is Possible that I have extracted the wrong log message. I will look into that. What happened is that out of the blue all MDSs started failing. Only after many failed stating attempts with the OSDs blocking "old" messages I reset the journal. After the MDSs where running again we had several files the were empty or filled with 0x0, that were previously fine. I guess that was to be expected after resetting the journal but I had no idea how to get them running otherwise. Regards Chris Am Samstag, den 24.03.2018, 05:13 +0800 schrieb John Spray: > On Fri, Mar 23, 2018 at 7:45 PM, Perrin, Christopher (zimkop1) > <zimkop1@xxxxxxxxxxxx> wrote: > > Hi, > > > > Last week out MDSs started failing one after another, and could not be started anymore. After a lot of tinkering I found out that MDSs crashed after trying to rejoin the Cluster. The only Solution I found that, let them start again was resetting the journal vie cephfs-journal-tool. Now I have broken files all over the Cluster. > > Can you clarify: > - is the backtrace below is from before you used cephfs-journal-tool > or after? > - what do you mean by "broken file" > > The backtrace you're seeing is in some damage-handling code -- the > crash is a bug (http://tracker.ceph.com/issues/23452), but you'd only > be hitting it if your metadata was already inconsistent. One way it > could get inconsistent would be from use of cephfs-journal-tool > (wiping the journal but not the session table, resulting in session > state inconsistent with the rest of the metadata), but if the crash > was from before you did that then something else would be going on. > > It would also help if you could be more specific about the original > issue that drove you to using cephfs-journal-tool, if that was > something other than the backtrace you included. > > Cheers, > John > > > Before the crash the OSDs blocked tens of thousands of slow requests. > > > > Can I somehow restore the broken files (I still have a backup of the journal) and how can I make sure that this doesn't happen agian. I am still not sure why this even happened. > > > > This happened on ceph version 12.2.3. > > > > This is the log of one MDS: > > -224> 2018-03-22 15:52:47.310437 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 2 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 33+0+0 (3611581813 0 0) 0x555883df2780 con 0x555883eb5000 > > -223> 2018-03-22 15:52:47.310482 7fd5798fd700 10 monclient(hunting): my global_id is 745317 > > -222> 2018-03-22 15:52:47.310634 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- auth(proto 2 32 bytes epoch 0) v1 -- 0x555883df2f00 con 0 > > -221> 2018-03-22 15:52:47.311096 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 3 0x555883df2f00 auth_reply(proto 2 0 (0) Success) v1 > > -220> 2018-03-22 15:52:47.311178 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 3 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 222+0+0 (1789869469 0 0) 0x555883df2f00 con 0x555883eb5000 > > -219> 2018-03-22 15:52:47.311319 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- auth(proto 2 181 bytes epoch 0) v1 -- 0x555883df2780 con 0 > > -218> 2018-03-22 15:52:47.312122 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 4 0x555883df2780 auth_reply(proto 2 0 (0) Success) v1 > > -217> 2018-03-22 15:52:47.312208 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 4 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 799+0+0 (4156877078 0 0) 0x555883df2780 con 0x555883eb5000 > > -216> 2018-03-22 15:52:47.312393 7fd5798fd700 1 monclient: found mon.filer1 > > -215> 2018-03-22 15:52:47.312416 7fd5798fd700 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -214> 2018-03-22 15:52:47.312427 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mon_subscribe({monmap=0+}) v2 -- 0x555883c8ed80 con 0 > > -213> 2018-03-22 15:52:47.312461 7fd5798fd700 10 monclient: _check_auth_rotating renewing rotating keys (they expired before 2018-03-22 15:52:17.312460) > > -212> 2018-03-22 15:52:47.312477 7fd5798fd700 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -211> 2018-03-22 15:52:47.312482 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- auth(proto 2 2 bytes epoch 0) v1 -- 0x555883df2f00 con 0 > > -210> 2018-03-22 15:52:47.312552 7fd580637200 5 monclient: authenticate success, global_id 745317 > > -209> 2018-03-22 15:52:47.312570 7fd580637200 10 monclient: wait_auth_rotating waiting (until 2018-03-22 15:53:17.312568) > > -208> 2018-03-22 15:52:47.312776 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 5 0x555883c8f8c0 mon_map magic: 0 v1 > > -207> 2018-03-22 15:52:47.312841 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 5 ==== mon_map magic: 0 v1 ==== 433+0+0 (493202164 0 0) 0x555883c8f8c0 con 0x555883eb5000 > > -206> 2018-03-22 15:52:47.312868 7fd5798fd700 10 monclient: handle_monmap mon_map magic: 0 v1 > > -205> 2018-03-22 15:52:47.312892 7fd5798fd700 10 monclient: got monmap 7, mon.filer1 is now rank 0 > > -204> 2018-03-22 15:52:47.312901 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 6 0x555883df2f00 auth_reply(proto 2 0 (0) Success) v1 > > -203> 2018-03-22 15:52:47.312900 7fd5798fd700 10 monclient: dump: > > epoch 7 > > fsid a5473adc-cfb8-4672-883e-40f5f6541a36 > > last_changed 2017-12-08 10:38:51.267030 > > created 2017-01-20 17:05:29.092109 > > 0: x.x.1.17:6789/0 mon.filer1 > > 1: x.x.1.18:6789/0 mon.filer2 > > 2: x.x.1.21:6789/0 mon.master1 > > > > -202> 2018-03-22 15:52:47.312950 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 6 ==== auth_reply(proto 2 0 (0) Success) v1 ==== 194+0+0 (1424514407 0 0) 0x555883df2f00 con 0x555883eb5000 > > -201> 2018-03-22 15:52:47.313072 7fd5798fd700 10 monclient: _check_auth_rotating have uptodate secrets (they expire after 2018-03-22 15:52:17.313071) > > -200> 2018-03-22 15:52:47.313108 7fd580637200 10 monclient: wait_auth_rotating done > > -199> 2018-03-22 15:52:47.313172 7fd580637200 10 monclient: _renew_subs > > -198> 2018-03-22 15:52:47.313179 7fd580637200 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -197> 2018-03-22 15:52:47.313188 7fd580637200 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mon_subscribe({mdsmap=0+,mgrmap=0+}) v2 -- 0x555883c8efc0 con 0 > > -196> 2018-03-22 15:52:47.313209 7fd580637200 5 asok(0x555883c661e0) register_command status hook 0x555883c362f0 > > -195> 2018-03-22 15:52:47.313219 7fd580637200 5 asok(0x555883c661e0) register_command dump_ops_in_flight hook 0x555883c362f0 > > -194> 2018-03-22 15:52:47.313224 7fd580637200 5 asok(0x555883c661e0) register_command ops hook 0x555883c362f0 > > -193> 2018-03-22 15:52:47.313231 7fd580637200 5 asok(0x555883c661e0) register_command dump_blocked_ops hook 0x555883c362f0 > > -192> 2018-03-22 15:52:47.313234 7fd580637200 5 asok(0x555883c661e0) register_command dump_historic_ops hook 0x555883c362f0 > > -191> 2018-03-22 15:52:47.313238 7fd580637200 5 asok(0x555883c661e0) register_command dump_historic_ops_by_duration hook 0x555883c362f0 > > -190> 2018-03-22 15:52:47.313246 7fd580637200 5 asok(0x555883c661e0) register_command scrub_path hook 0x555883c362f0 > > -189> 2018-03-22 15:52:47.313250 7fd580637200 5 asok(0x555883c661e0) register_command tag path hook 0x555883c362f0 > > -188> 2018-03-22 15:52:47.313259 7fd580637200 5 asok(0x555883c661e0) register_command flush_path hook 0x555883c362f0 > > -187> 2018-03-22 15:52:47.313262 7fd580637200 5 asok(0x555883c661e0) register_command export dir hook 0x555883c362f0 > > -186> 2018-03-22 15:52:47.313268 7fd580637200 5 asok(0x555883c661e0) register_command dump cache hook 0x555883c362f0 > > -185> 2018-03-22 15:52:47.313275 7fd580637200 5 asok(0x555883c661e0) register_command cache status hook 0x555883c362f0 > > -184> 2018-03-22 15:52:47.313279 7fd580637200 5 asok(0x555883c661e0) register_command dump tree hook 0x555883c362f0 > > -183> 2018-03-22 15:52:47.313284 7fd580637200 5 asok(0x555883c661e0) register_command session evict hook 0x555883c362f0 > > -182> 2018-03-22 15:52:47.313291 7fd580637200 5 asok(0x555883c661e0) register_command osdmap barrier hook 0x555883c362f0 > > -181> 2018-03-22 15:52:47.313304 7fd580637200 5 asok(0x555883c661e0) register_command session ls hook 0x555883c362f0 > > -180> 2018-03-22 15:52:47.313315 7fd580637200 5 asok(0x555883c661e0) register_command flush journal hook 0x555883c362f0 > > -179> 2018-03-22 15:52:47.313323 7fd580637200 5 asok(0x555883c661e0) register_command force_readonly hook 0x555883c362f0 > > -178> 2018-03-22 15:52:47.313333 7fd580637200 5 asok(0x555883c661e0) register_command get subtrees hook 0x555883c362f0 > > -177> 2018-03-22 15:52:47.313346 7fd580637200 5 asok(0x555883c661e0) register_command dirfrag split hook 0x555883c362f0 > > -176> 2018-03-22 15:52:47.313361 7fd580637200 5 asok(0x555883c661e0) register_command dirfrag merge hook 0x555883c362f0 > > -175> 2018-03-22 15:52:47.313375 7fd580637200 5 asok(0x555883c661e0) register_command dirfrag ls hook 0x555883c362f0 > > -174> 2018-03-22 15:52:47.313528 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 7 0x555883df3180 mdsmap(e 5323) v1 > > -173> 2018-03-22 15:52:47.313589 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 8 0x555883c8a600 mgrmap(e 279) v1 > > -172> 2018-03-22 15:52:47.313582 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 7 ==== mdsmap(e 5323) v1 ==== 464+0+0 (1833395745 0 0) 0x555883df3180 con 0x555883eb5000 > > -171> 2018-03-22 15:52:47.313829 7fd580637200 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -170> 2018-03-22 15:52:47.313838 7fd580637200 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mdsbeacon(745317/filer1 up:boot seq 1 v0) v7 -- 0x555883f20380 con 0 > > -169> 2018-03-22 15:52:47.313888 7fd5798fd700 5 mds.filer1 handle_mds_map epoch 5323 from mon.0 > > -168> 2018-03-22 15:52:47.313954 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 8 ==== mgrmap(e 279) v1 ==== 476+0+0 (79426338 0 0) 0x555883c8a600 con 0x555883eb5000 > > -167> 2018-03-22 15:52:47.313982 7fd5798fd700 4 mgrc handle_mgr_map Got map version 279 > > -166> 2018-03-22 15:52:47.313988 7fd5798fd700 4 mgrc handle_mgr_map Active mgr is now x.x.1.17:6800/63308 > > -165> 2018-03-22 15:52:47.313993 7fd5798fd700 4 mgrc reconnect Starting new session with x.x.1.17:6800/63308 > > -164> 2018-03-22 15:52:47.314044 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6800/63308 -- mgropen(unknown.filer1) v2 -- 0x555883df2780 con 0 > > -163> 2018-03-22 15:52:47.314639 7fd57b89e700 2 -- x.x.1.17:6803/122963511 >> x.x.1.17:6800/63308 conn(0x555883f2e800 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0 > > -162> 2018-03-22 15:52:47.314984 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6800/63308 conn(0x555883f2e800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=251 cs=1 l=1). rx mgr.744273 seq 1 0x555883c66b40 mgrconfigure(period=5, threshold=5) v2 > > -161> 2018-03-22 15:52:47.315023 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mgr.744273 x.x.1.17:6800/63308 1 ==== mgrconfigure(period=5, threshold=5) v2 ==== 8+0+0 (3460719617 0 0) 0x555883c66b40 con 0x555883f2e800 > > -160> 2018-03-22 15:52:47.315044 7fd5798fd700 4 mgrc handle_mgr_configure stats_period=5 > > -159> 2018-03-22 15:52:47.315047 7fd5798fd700 4 mgrc handle_mgr_configure updated stats threshold: 5 > > -158> 2018-03-22 15:52:47.315057 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6800/63308 -- mgrreport(unknown.filer1 +0-0 packed 6) v5 -- 0x555883c8a600 con 0 > > -157> 2018-03-22 15:52:51.313978 7fd5768f7700 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -156> 2018-03-22 15:52:51.313995 7fd5768f7700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mdsbeacon(745317/filer1 up:boot seq 2 v5323) v7 -- 0x555883f20700 con 0 > > -155> 2018-03-22 15:52:51.967269 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 9 0x555883df3400 mdsmap(e 5324) v1 > > -154> 2018-03-22 15:52:51.967345 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 9 ==== mdsmap(e 5324) v1 ==== 588+0+0 (543550856 0 0) 0x555883df3400 con 0x555883eb5000 > > -153> 2018-03-22 15:52:51.967377 7fd5798fd700 5 mds.filer1 handle_mds_map epoch 5324 from mon.0 > > -152> 2018-03-22 15:52:51.967463 7fd5798fd700 1 mds.filer1 handle_mds_map standby > > -151> 2018-03-22 15:52:51.967741 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 10 0x555883f20700 mdsbeacon(745317/filer1 up:boot seq 2 v5324) v7 > > -150> 2018-03-22 15:52:51.967790 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 10 ==== mdsbeacon(745317/filer1 up:boot seq 2 v5324) v7 ==== 139+0+0 (3023608128 0 0) 0x555883f20700 con 0x555883eb5000 > > -149> 2018-03-22 15:52:52.068410 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 11 0x555883df3680 mdsmap(e 5325) v1 > > -148> 2018-03-22 15:52:52.068475 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 11 ==== mdsmap(e 5325) v1 ==== 625+0+0 (3633367692 0 0) 0x555883df3680 con 0x555883eb5000 > > -147> 2018-03-22 15:52:52.068506 7fd5798fd700 5 mds.filer1 handle_mds_map epoch 5325 from mon.0 > > -146> 2018-03-22 15:52:52.068813 7fd5798fd700 4 mds.0.purge_queue operator(): data pool 6 not found in OSDMap > > -145> 2018-03-22 15:52:52.069016 7fd5798fd700 5 asok(0x555883c661e0) register_command objecter_requests hook 0x555883c362e0 > > -144> 2018-03-22 15:52:52.069078 7fd5798fd700 10 monclient: _renew_subs > > -143> 2018-03-22 15:52:52.069090 7fd5798fd700 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -142> 2018-03-22 15:52:52.069118 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mon_subscribe({osdmap=0}) v2 -- 0x555883c8f680 con 0 > > -141> 2018-03-22 15:52:52.069199 7fd5798fd700 10 log_channel(cluster) update_config to_monitors: true to_syslog: false syslog_facility: daemon prio: info to_graylog: false graylog_host: 127.0.0.1 graylog_port: 12201) > > -140> 2018-03-22 15:52:52.069430 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6789/0 conn(0x555883eb5000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=793748 cs=1 l=1). rx mon.0 seq 12 0x555883df3900 osd_map(1396..1396 src has 752..1396) v3 > > -139> 2018-03-22 15:52:52.069523 7fd5798fd700 4 mds.0.purge_queue operator(): data pool 6 not found in OSDMap > > -138> 2018-03-22 15:52:52.069538 7fd5798fd700 4 mds.0.0 handle_osd_map epoch 0, 0 new blacklist entries > > -137> 2018-03-22 15:52:52.069774 7fd5798fd700 1 mds.0.5325 handle_mds_map i am now mds.0.5325 > > -136> 2018-03-22 15:52:52.069784 7fd5798fd700 1 mds.0.5325 handle_mds_map state change up:boot --> up:replay > > -135> 2018-03-22 15:52:52.069810 7fd5798fd700 1 mds.0.5325 replay_start > > -134> 2018-03-22 15:52:52.069821 7fd5798fd700 1 mds.0.5325 recovery set is > > -133> 2018-03-22 15:52:52.069845 7fd5798fd700 1 mds.0.5325 waiting for osdmap 1396 (which blacklists prior instance) > > -132> 2018-03-22 15:52:52.069855 7fd5798fd700 4 mds.0.purge_queue operator(): data pool 6 not found in OSDMap > > -131> 2018-03-22 15:52:52.069888 7fd5798fd700 1 -- x.x.1.17:6803/122963511 <== mon.0 x.x.1.17:6789/0 12 ==== osd_map(1396..1396 src has 752..1396) v3 ==== 3162+0+0 (2330026281 0 0) 0x555883df3900 con 0x555883eb5000 > > -130> 2018-03-22 15:52:52.070103 7fd5798fd700 4 mds.0.5325 handle_osd_map epoch 1396, 0 new blacklist entries > > -129> 2018-03-22 15:52:52.070119 7fd5798fd700 10 monclient: _renew_subs > > -128> 2018-03-22 15:52:52.070125 7fd5798fd700 10 monclient: _send_mon_message to mon.filer1 at x.x.1.17:6789/0 > > -127> 2018-03-22 15:52:52.070147 7fd5798fd700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6789/0 -- mon_subscribe({osdmap=1397}) v2 -- 0x555883c8efc0 con 0 > > -126> 2018-03-22 15:52:52.070243 7fd5738f1700 2 mds.0.5325 boot_start 0: opening inotable > > -125> 2018-03-22 15:52:52.070422 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:1 7.13 7:c91d4a1d:::mds0_inotable:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64000 con 0 > > -124> 2018-03-22 15:52:52.070473 7fd5738f1700 2 mds.0.5325 boot_start 0: opening sessionmap > > -123> 2018-03-22 15:52:52.070555 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:2 7.b 7:d0630e4c:::mds0_sessionmap:head [omap-get-header,omap-get-vals] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64340 con 0 > > -122> 2018-03-22 15:52:52.070585 7fd5738f1700 2 mds.0.5325 boot_start 0: opening mds log > > -121> 2018-03-22 15:52:52.070593 7fd5738f1700 5 mds.0.log open discovering log bounds > > -120> 2018-03-22 15:52:52.070718 7fd5738f1700 2 mds.0.5325 boot_start 0: opening purge queue (async) > > -119> 2018-03-22 15:52:52.070733 7fd5738f1700 4 mds.0.purge_queue open: opening > > -118> 2018-03-22 15:52:52.070736 7fd5738f1700 1 mds.0.journaler.pq(ro) recover start > > -117> 2018-03-22 15:52:52.070739 7fd5738f1700 1 mds.0.journaler.pq(ro) read_head > > -116> 2018-03-22 15:52:52.070744 7fd5730f0700 4 mds.0.journalpointer Reading journal pointer '400.00000000' > > -115> 2018-03-22 15:52:52.070759 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:3 7.55 7:aa448500:::500.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64680 con 0 > > -114> 2018-03-22 15:52:52.070799 7fd5730f0700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:4 7.f 7:f1f69726:::400.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f649c0 con 0 > > -113> 2018-03-22 15:52:52.070832 7fd5738f1700 2 mds.0.5325 boot_start 0: opening snap table > > -112> 2018-03-22 15:52:52.070876 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:5 7.2d 7:b50e409b:::mds_snaptable:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64d00 con 0 > > -111> 2018-03-22 15:52:52.071154 7fd57c8a0700 2 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0 > > -110> 2018-03-22 15:52:52.071287 7fd57c09f700 2 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0 > > -109> 2018-03-22 15:52:52.071525 7fd57b89e700 2 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_CONNECTING_WAIT_ACK_SEQ pgs=0 cs=0 l=1)._process_connection got newly_acked_seq 0 vs out_seq 0 > > -108> 2018-03-22 15:52:52.071941 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 1 0x555883f64d00 osd_op_reply(5 mds_snaptable [read 0~46] v0'0 uv1 ondisk = 0) v8 > > -107> 2018-03-22 15:52:52.071968 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 1 ==== osd_op_reply(5 mds_snaptable [read 0~46] v0'0 uv1 ondisk = 0) v8 ==== 157+0+46 (367977290 0 2603725198) 0x555883f64d00 con 0x555883f5d000 > > -106> 2018-03-22 15:52:52.071951 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 1 0x555883f64340 osd_op_reply(3 500.00000000 [read 0~90] v0'0 uv142815 ondisk = 0) v8 > > -105> 2018-03-22 15:52:52.072004 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 1 ==== osd_op_reply(3 500.00000000 [read 0~90] v0'0 uv142815 ondisk = 0) v8 ==== 156+0+90 (4167717821 0 1992813580) 0x555883f64340 con 0x555883f5a000 > > -104> 2018-03-22 15:52:52.072062 7fd5748f3700 1 mds.0.journaler.pq(ro) _finish_read_head loghead(trim 12582912, expire 13845209, write 13845209, stream_format 1). probing for end of log (from 13845209)... > > -103> 2018-03-22 15:52:52.072074 7fd5748f3700 1 mds.0.journaler.pq(ro) probing for end of the log > > -102> 2018-03-22 15:52:52.072123 7fd5748f3700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:6 7.34 7:2e992e0f:::500.00000003:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e1396) v8 -- 0x555883f64000 con 0 > > -101> 2018-03-22 15:52:52.072213 7fd5748f3700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:7 7.26 7:66eb7180:::500.00000004:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e1396) v8 -- 0x555883f64680 con 0 > > -100> 2018-03-22 15:52:52.072690 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 2 0x555883f64d00 osd_op_reply(6 500.00000003 [stat] v0'0 uv282976 ondisk = 0) v8 > > -99> 2018-03-22 15:52:52.072712 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 2 ==== osd_op_reply(6 500.00000003 [stat] v0'0 uv282976 ondisk = 0) v8 ==== 156+0+16 (3036645653 0 1497514102) 0x555883f64d00 con 0x555883f5d000 > > -98> 2018-03-22 15:52:52.285269 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 1 0x555883f64680 osd_op_reply(2 mds0_sessionmap [omap-get-header,omap-get-vals] v0'0 uv158730 ondisk = 0) v8 > > -97> 2018-03-22 15:52:52.285301 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 1 ==== osd_op_reply(2 mds0_sessionmap [omap-get-header,omap-get-vals] v0'0 uv158730 ondisk = 0) v8 ==== 201+0+16343 (2396657306 0 2795133511) 0x555883f64680 con 0x555883f5b800 > > -96> 2018-03-22 15:52:52.290264 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 2 0x555883f64680 osd_op_reply(7 500.00000004 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 > > -95> 2018-03-22 15:52:52.290300 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 2 ==== osd_op_reply(7 500.00000004 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (2305979436 0 0) 0x555883f64680 con 0x555883f5b800 > > -94> 2018-03-22 15:52:52.290376 7fd5748f3700 1 mds.0.journaler.pq(ro) _finish_probe_end write_pos = 13845209 (header had 13845209). recovered. > > -93> 2018-03-22 15:52:52.290397 7fd5748f3700 4 mds.0.purge_queue operator(): open complete > > -92> 2018-03-22 15:52:52.290402 7fd5748f3700 1 mds.0.journaler.pq(ro) set_writeable > > -91> 2018-03-22 15:52:52.290899 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 3 0x555883f64680 osd_op_reply(4 400.00000000 [read 0~22] v0'0 uv1 ondisk = 0) v8 > > -90> 2018-03-22 15:52:52.290928 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 3 ==== osd_op_reply(4 400.00000000 [read 0~22] v0'0 uv1 ondisk = 0) v8 ==== 156+0+22 (657553539 0 3825830296) 0x555883f64680 con 0x555883f5b800 > > -89> 2018-03-22 15:52:52.291057 7fd5730f0700 1 mds.0.journaler.mdlog(ro) recover start > > -88> 2018-03-22 15:52:52.291068 7fd5730f0700 1 mds.0.journaler.mdlog(ro) read_head > > -87> 2018-03-22 15:52:52.291098 7fd5730f0700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:8 7.14 7:292cf221:::200.00000000:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f65a00 con 0 > > -86> 2018-03-22 15:52:52.291138 7fd5730f0700 4 mds.0.log Waiting for journal 0x200 to recover... > > -85> 2018-03-22 15:52:52.291677 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 2 0x555883f65a00 osd_op_reply(8 200.00000000 [read 0~90] v0'0 uv261722 ondisk = 0) v8 > > -84> 2018-03-22 15:52:52.291707 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 2 ==== osd_op_reply(8 200.00000000 [read 0~90] v0'0 uv261722 ondisk = 0) v8 ==== 156+0+90 (4187966182 0 1006404943) 0x555883f65a00 con 0x555883f5a000 > > -83> 2018-03-22 15:52:52.291754 7fd5738f1700 1 mds.0.journaler.mdlog(ro) _finish_read_head loghead(trim 219550842880, expire 219552551048, write 219615507873, stream_format 1). probing for end of log (from 219615507873)... > > -82> 2018-03-22 15:52:52.291771 7fd5738f1700 1 mds.0.journaler.mdlog(ro) probing for end of the log > > -81> 2018-03-22 15:52:52.291847 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:9 7.18 7:19465a45:::200.0000cc88:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e1396) v8 -- 0x555883f65380 con 0 > > -80> 2018-03-22 15:52:52.291906 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:10 7.2 7:41bb3fc2:::200.0000cc89:head [stat] snapc 0=[] ondisk+read+rwordered+known_if_redirected+full_force e1396) v8 -- 0x555883f66080 con 0 > > -79> 2018-03-22 15:52:52.292473 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 4 0x555883f64680 osd_op_reply(9 200.0000cc88 [stat] v0'0 uv120158 ondisk = 0) v8 > > -78> 2018-03-22 15:52:52.292514 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 4 ==== osd_op_reply(9 200.0000cc88 [stat] v0'0 uv120158 ondisk = 0) v8 ==== 156+0+16 (2414739881 0 2839007350) 0x555883f64680 con 0x555883f5b800 > > -77> 2018-03-22 15:52:52.292570 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 5 0x555883f64680 osd_op_reply(10 200.0000cc89 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 > > -76> 2018-03-22 15:52:52.292592 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 5 ==== osd_op_reply(10 200.0000cc89 [stat] v0'0 uv0 ondisk = -2 ((2) No such file or directory)) v8 ==== 156+0+0 (1518717806 0 0) 0x555883f64680 con 0x555883f5b800 > > -75> 2018-03-22 15:52:52.292637 7fd5738f1700 1 mds.0.journaler.mdlog(ro) _finish_probe_end write_pos = 219615508275 (header had 219615507873). recovered. > > -74> 2018-03-22 15:52:52.292712 7fd5730f0700 4 mds.0.log Journal 0x200 recovered. > > -73> 2018-03-22 15:52:52.292727 7fd5730f0700 4 mds.0.log Recovered journal 0x200 in format 1 > > -72> 2018-03-22 15:52:52.315373 7fd5778f9700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6800/63308 -- mgrreport(unknown.filer1 +24-0 packed 214) v5 -- 0x555883c8be00 con 0 > > -71> 2018-03-22 15:52:52.478646 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 3 0x555883f65a00 osd_op_reply(1 mds0_inotable [read 0~34] v0'0 uv143709 ondisk = 0) v8 > > -70> 2018-03-22 15:52:52.478690 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 3 ==== osd_op_reply(1 mds0_inotable [read 0~34] v0'0 uv143709 ondisk = 0) v8 ==== 157+0+34 (3459761511 0 469722454) 0x555883f65a00 con 0x555883f5a000 > > -69> 2018-03-22 15:52:52.478757 7fd5738f1700 2 mds.0.5325 boot_start 1: loading/discovering base inodes > > -68> 2018-03-22 15:52:52.478789 7fd5738f1700 0 mds.0.cache creating system inode with ino:0x100 > > -67> 2018-03-22 15:52:52.478860 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:11 7.33 7:cd5a64a3:::100.00000000:head [getxattr inode] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f663c0 con 0 > > -66> 2018-03-22 15:52:52.478916 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:12 7.3f 7:fe07bba1:::100.00000000.inode:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f66700 con 0 > > -65> 2018-03-22 15:52:52.478966 7fd5738f1700 0 mds.0.cache creating system inode with ino:0x1 > > -64> 2018-03-22 15:52:52.479063 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:13 7.3f 7:ff5b34d6:::1.00000000:head [getxattr inode] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f66a40 con 0 > > -63> 2018-03-22 15:52:52.479123 7fd5738f1700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:14 7.14 7:287034c4:::1.00000000.inode:head [read 0~0] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f649c0 con 0 > > -62> 2018-03-22 15:52:52.479479 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 4 0x555883f649c0 osd_op_reply(11 100.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 > > -61> 2018-03-22 15:52:52.479506 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 3 0x555883f64000 osd_op_reply(12 100.00000000.inode [read 0~536] v0'0 uv304042 ondisk = 0) v8 > > -60> 2018-03-22 15:52:52.479533 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 3 ==== osd_op_reply(12 100.00000000.inode [read 0~536] v0'0 uv304042 ondisk = 0) v8 ==== 162+0+536 (4230129339 0 4167152603) 0x555883f64000 con 0x555883f5d000 > > -59> 2018-03-22 15:52:52.479524 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 4 ==== osd_op_reply(11 100.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 ==== 156+0+0 (802953997 0 0) 0x555883f649c0 con 0x555883f5a000 > > -58> 2018-03-22 15:52:52.479576 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 4 0x555883f64000 osd_op_reply(13 1.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 > > -57> 2018-03-22 15:52:52.479592 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 4 ==== osd_op_reply(13 1.00000000 [getxattr] v0'0 uv0 ondisk = -61 ((61) No data available)) v8 ==== 154+0+0 (2478131573 0 0) 0x555883f64000 con 0x555883f5d000 > > -56> 2018-03-22 15:52:52.479712 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 5 0x555883f649c0 osd_op_reply(14 1.00000000.inode [read 0~536] v0'0 uv261708 ondisk = 0) v8 > > -55> 2018-03-22 15:52:52.479731 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 5 ==== osd_op_reply(14 1.00000000.inode [read 0~536] v0'0 uv261708 ondisk = 0) v8 ==== 160+0+536 (3842073863 0 828467972) 0x555883f649c0 con 0x555883f5a000 > > -54> 2018-03-22 15:52:52.479769 7fd5738f1700 2 mds.0.5325 boot_start 2: replaying mds log > > -53> 2018-03-22 15:52:52.479783 7fd5738f1700 2 mds.0.5325 boot_start 2: waiting for purge queue recovered > > -52> 2018-03-22 15:52:52.479906 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:15 7.3a 7:5d17787c:::200.0000cc79:head [read 1708168~2486136 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f670c0 con 0 > > -51> 2018-03-22 15:52:52.480004 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:16 7.2f 7:f43cbe1a:::200.0000cc7a:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f67400 con 0 > > -50> 2018-03-22 15:52:52.480059 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:17 7.5 7:a1dc1a9d:::200.0000cc7b:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f67740 con 0 > > -49> 2018-03-22 15:52:52.480109 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:18 7.0 7:00cc040d:::200.0000cc7c:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f67a80 con 0 > > -48> 2018-03-22 15:52:52.480192 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:19 7.2d 7:b5788a65:::200.0000cc7d:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f66a40 con 0 > > -47> 2018-03-22 15:52:52.480242 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:20 7.43 7:c359db68:::200.0000cc7e:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f66700 con 0 > > -46> 2018-03-22 15:52:52.480306 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:21 7.36 7:6d91f983:::200.0000cc7f:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64d00 con 0 > > -45> 2018-03-22 15:52:52.480351 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:22 7.8 7:1168fae1:::200.0000cc80:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64000 con 0 > > -44> 2018-03-22 15:52:52.480395 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:23 7.30 7:0f8e423f:::200.0000cc81:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f66080 con 0 > > -43> 2018-03-22 15:52:52.480437 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:24 7.2a 7:553af0e4:::200.0000cc82:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f65380 con 0 > > -42> 2018-03-22 15:52:52.480493 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:25 7.f 7:f136b8d6:::200.0000cc83:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f64680 con 0 > > -41> 2018-03-22 15:52:52.509055 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 6 0x555883f64680 osd_op_reply(18 200.0000cc7c [read 0~4194304 [fadvise_dontneed]] v0'0 uv111922 ondisk = 0) v8 > > -40> 2018-03-22 15:52:52.509100 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 6 ==== osd_op_reply(18 200.0000cc7c [read 0~4194304 [fadvise_dontneed]] v0'0 uv111922 ondisk = 0) v8 ==== 156+0+4194304 (2889947030 0 2232087157) 0x555883f64680 con 0x555883f5b800 > > -39> 2018-03-22 15:52:52.511367 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 6 0x555883f649c0 osd_op_reply(22 200.0000cc80 [read 0~4194304 [fadvise_dontneed]] v0'0 uv122611 ondisk = 0) v8 > > -38> 2018-03-22 15:52:52.511416 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 6 ==== osd_op_reply(22 200.0000cc80 [read 0~4194304 [fadvise_dontneed]] v0'0 uv122611 ondisk = 0) v8 ==== 156+0+4194304 (360001783 0 3146556651) 0x555883f649c0 con 0x555883f5a000 > > -37> 2018-03-22 15:52:52.514358 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 7 0x555883f649c0 osd_op_reply(20 200.0000cc7e [read 0~4194304 [fadvise_dontneed]] v0'0 uv133445 ondisk = 0) v8 > > -36> 2018-03-22 15:52:52.514389 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 7 ==== osd_op_reply(20 200.0000cc7e [read 0~4194304 [fadvise_dontneed]] v0'0 uv133445 ondisk = 0) v8 ==== 156+0+4194304 (2090475696 0 2923532206) 0x555883f649c0 con 0x555883f5a000 > > -35> 2018-03-22 15:52:52.515913 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 7 0x555883f64680 osd_op_reply(15 200.0000cc79 [read 1708168~2486136 [fadvise_dontneed]] v0'0 uv267351 ondisk = 0) v8 > > -34> 2018-03-22 15:52:52.516279 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 7 ==== osd_op_reply(15 200.0000cc79 [read 1708168~2486136 [fadvise_dontneed]] v0'0 uv267351 ondisk = 0) v8 ==== 156+0+2486136 (2310531997 0 1366848730) 0x555883f64680 con 0x555883f5b800 > > -33> 2018-03-22 15:52:52.519771 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 8 0x555883f649c0 osd_op_reply(24 200.0000cc82 [read 0~4194304 [fadvise_dontneed]] v0'0 uv270305 ondisk = 0) v8 > > -32> 2018-03-22 15:52:52.519817 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 8 ==== osd_op_reply(24 200.0000cc82 [read 0~4194304 [fadvise_dontneed]] v0'0 uv270305 ondisk = 0) v8 ==== 156+0+4194304 (3850178096 0 828145897) 0x555883f649c0 con 0x555883f5a000 > > -31> 2018-03-22 15:52:52.523971 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 5 0x555883f66a40 osd_op_reply(17 200.0000cc7b [read 0~4194304 [fadvise_dontneed]] v0'0 uv128946 ondisk = 0) v8 > > -30> 2018-03-22 15:52:52.524006 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 5 ==== osd_op_reply(17 200.0000cc7b [read 0~4194304 [fadvise_dontneed]] v0'0 uv128946 ondisk = 0) v8 ==== 156+0+4194304 (2098079074 0 3003574979) 0x555883f66a40 con 0x555883f5d000 > > -29> 2018-03-22 15:52:52.526237 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 8 0x555883f64680 osd_op_reply(21 200.0000cc7f [read 0~4194304 [fadvise_dontneed]] v0'0 uv284169 ondisk = 0) v8 > > -28> 2018-03-22 15:52:52.526262 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 8 ==== osd_op_reply(21 200.0000cc7f [read 0~4194304 [fadvise_dontneed]] v0'0 uv284169 ondisk = 0) v8 ==== 156+0+4194304 (3827053419 0 3788447424) 0x555883f64680 con 0x555883f5b800 > > -27> 2018-03-22 15:52:52.533474 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 9 0x555883f64680 osd_op_reply(25 200.0000cc83 [read 0~4194304 [fadvise_dontneed]] v0'0 uv120894 ondisk = 0) v8 > > -26> 2018-03-22 15:52:52.533509 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 9 ==== osd_op_reply(25 200.0000cc83 [read 0~4194304 [fadvise_dontneed]] v0'0 uv120894 ondisk = 0) v8 ==== 156+0+4194304 (1476261173 0 3169243193) 0x555883f64680 con 0x555883f5b800 > > -25> 2018-03-22 15:52:52.533943 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 9 0x555883f649c0 osd_op_reply(23 200.0000cc81 [read 0~4194304 [fadvise_dontneed]] v0'0 uv232635 ondisk = 0) v8 > > -24> 2018-03-22 15:52:52.533982 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 9 ==== osd_op_reply(23 200.0000cc81 [read 0~4194304 [fadvise_dontneed]] v0'0 uv232635 ondisk = 0) v8 ==== 156+0+4194304 (3321494973 0 2672554052) 0x555883f649c0 con 0x555883f5a000 > > -23> 2018-03-22 15:52:52.534996 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 6 0x555883f66a40 osd_op_reply(16 200.0000cc7a [read 0~4194304 [fadvise_dontneed]] v0'0 uv254456 ondisk = 0) v8 > > -22> 2018-03-22 15:52:52.535027 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 6 ==== osd_op_reply(16 200.0000cc7a [read 0~4194304 [fadvise_dontneed]] v0'0 uv254456 ondisk = 0) v8 ==== 156+0+4194304 (2101888833 0 3301144556) 0x555883f66a40 con 0x555883f5d000 > > -21> 2018-03-22 15:52:52.535213 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:26 7.5 7:a0c3938f:::200.0000cc84:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555883f670c0 con 0 > > -20> 2018-03-22 15:52:52.541605 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 7 0x555883f670c0 osd_op_reply(19 200.0000cc7d [read 0~4194304 [fadvise_dontneed]] v0'0 uv255276 ondisk = 0) v8 > > -19> 2018-03-22 15:52:52.541629 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 7 ==== osd_op_reply(19 200.0000cc7d [read 0~4194304 [fadvise_dontneed]] v0'0 uv255276 ondisk = 0) v8 ==== 156+0+4194304 (561833161 0 2848452092) 0x555883f670c0 con 0x555883f5d000 > > -18> 2018-03-22 15:52:52.574486 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 8 0x555883f670c0 osd_op_reply(26 200.0000cc84 [read 0~4194304 [fadvise_dontneed]] v0'0 uv128948 ondisk = 0) v8 > > -17> 2018-03-22 15:52:52.574508 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 8 ==== osd_op_reply(26 200.0000cc84 [read 0~4194304 [fadvise_dontneed]] v0'0 uv128948 ondisk = 0) v8 ==== 156+0+4194304 (2539366010 0 517612525) 0x555883f670c0 con 0x555883f5d000 > > -16> 2018-03-22 15:52:52.644645 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.17:6801/61085 -- osd_op(unknown.0.5325:27 7.44 7:221f44ba:::200.0000cc85:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x55588859f740 con 0 > > -15> 2018-03-22 15:52:52.663434 7fd57c8a0700 5 -- x.x.1.17:6803/122963511 >> x.x.1.17:6801/61085 conn(0x555883f5a000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=117 cs=1 l=1). rx osd.0 seq 10 0x55588859f740 osd_op_reply(27 200.0000cc85 [read 0~4194304 [fadvise_dontneed]] v0'0 uv122793 ondisk = 0) v8 > > -14> 2018-03-22 15:52:52.663477 7fd57c8a0700 1 -- x.x.1.17:6803/122963511 <== osd.0 x.x.1.17:6801/61085 10 ==== osd_op_reply(27 200.0000cc85 [read 0~4194304 [fadvise_dontneed]] v0'0 uv122793 ondisk = 0) v8 ==== 156+0+4194304 (4175891152 0 992964831) 0x55588859f740 con 0x555883f5a000 > > -13> 2018-03-22 15:52:52.691398 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.19:6801/56955 -- osd_op(unknown.0.5325:28 7.19 7:999ffb8c:::200.0000cc86:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555887d6da80 con 0 > > -12> 2018-03-22 15:52:52.709210 7fd57b89e700 5 -- x.x.1.17:6803/122963511 >> x.x.1.19:6801/56955 conn(0x555883f5d000 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=111 cs=1 l=1). rx osd.2 seq 9 0x555887d6da80 osd_op_reply(28 200.0000cc86 [read 0~4194304 [fadvise_dontneed]] v0'0 uv133938 ondisk = 0) v8 > > -11> 2018-03-22 15:52:52.709280 7fd57b89e700 1 -- x.x.1.17:6803/122963511 <== osd.2 x.x.1.19:6801/56955 9 ==== osd_op_reply(28 200.0000cc86 [read 0~4194304 [fadvise_dontneed]] v0'0 uv133938 ondisk = 0) v8 ==== 156+0+4194304 (3792192724 0 3482327516) 0x555887d6da80 con 0x555883f5d000 > > -10> 2018-03-22 15:52:52.732088 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:29 7.58 7:1b7f2330:::200.0000cc87:head [read 0~4194304 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555886c63a00 con 0 > > -9> 2018-03-22 15:52:52.776011 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 10 0x555886c63a00 osd_op_reply(29 200.0000cc87 [read 0~4194304 [fadvise_dontneed]] v0'0 uv123301 ondisk = 0) v8 > > -8> 2018-03-22 15:52:52.776055 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 10 ==== osd_op_reply(29 200.0000cc87 [read 0~4194304 [fadvise_dontneed]] v0'0 uv123301 ondisk = 0) v8 ==== 156+0+4194304 (3322835623 0 1085409543) 0x555886c63a00 con 0x555883f5b800 > > -7> 2018-03-22 15:52:52.807570 7fd5720ee700 1 -- x.x.1.17:6803/122963511 --> x.x.1.18:6801/2025 -- osd_op(unknown.0.5325:30 7.18 7:19465a45:::200.0000cc88:head [read 0~1750835 [fadvise_dontneed]] snapc 0=[] ondisk+read+known_if_redirected+full_force e1396) v8 -- 0x555886ff2680 con 0 > > -6> 2018-03-22 15:52:52.865657 7fd57c09f700 5 -- x.x.1.17:6803/122963511 >> x.x.1.18:6801/2025 conn(0x555883f5b800 :-1 s=STATE_OPEN_MESSAGE_READ_FOOTER_AND_DISPATCH pgs=110 cs=1 l=1). rx osd.1 seq 11 0x555886ff2680 osd_op_reply(30 200.0000cc88 [read 0~1750835 [fadvise_dontneed]] v0'0 uv120158 ondisk = 0) v8 > > -5> 2018-03-22 15:52:52.865702 7fd57c09f700 1 -- x.x.1.17:6803/122963511 <== osd.1 x.x.1.18:6801/2025 11 ==== osd_op_reply(30 200.0000cc88 [read 0~1750835 [fadvise_dontneed]] v0'0 uv120158 ondisk = 0) v8 ==== 156+0+1750835 (3927299451 0 1933165720) 0x555886ff2680 con 0x555883f5b800 > > -4> 2018-03-22 15:52:53.231977 7fd5720ee700 -1 log_channel(cluster) log [ERR] : journal replay inotablev mismatch 1 -> 53668 > > -3> 2018-03-22 15:52:53.273998 7fd5720ee700 -1 log_channel(cluster) log [ERR] : Client session loaded with invalid preallocated inodes, evicting session r-laptop:nodes (705417) > > -2> 2018-03-22 15:52:53.274027 7fd5720ee700 -1 log_channel(cluster) log [ERR] : Client session loaded with invalid preallocated inodes, evicting session node01:nodes (724115) > > -1> 2018-03-22 15:52:53.274030 7fd5720ee700 -1 log_channel(cluster) log [ERR] : Client session loaded with invalid preallocated inodes, evicting session r-laptop:nodes (724169) > > 0> 2018-03-22 15:52:53.275454 7fd5720ee700 -1 /build/ceph-12.2.4/src/mds/MDLog.cc: In function 'void MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)' thread 7fd5720ee700 time 2018-03-22 15:52:53.274039 > > /build/ceph-12.2.4/src/mds/MDLog.cc: 275: FAILED assert(!mds->is_any_replay()) > > > > ceph version 12.2.4 (52085d5249a80c5f5121a76d6288429f35e4e77b) luminous (stable) > > 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x102) [0x555879e88942] > > 2: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x567) [0x555879ddd4e7] > > 3: (Server::journal_close_session(Session*, int, Context*)+0x963) [0x555879b8d603] > > 4: (Server::kill_session(Session*, Context*)+0x1fd) [0x555879b8e56d] > > 5: (MDSRank::validate_sessions()+0x2dc) [0x555879b4c2dc] > > 6: (MDSRank::boot_start(MDSRank::BootStep, int)+0xc08) [0x555879b4d228] > > 7: (MDSInternalContextBase::complete(int)+0x18b) [0x555879dc56db] > > 8: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::sub_finish(MDSInternalContextBase*, int)+0x127) [0x555879b66627] > > 9: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::C_GatherSub::complete(int)+0x21) [0x555879b668d1] > > 10: (MDLog::_replay_thread()+0x43c) [0x555879ddac8c] > > 11: (MDLog::ReplayThread::entry()+0xd) [0x555879b56fcd] > > 12: (()+0x76ba) [0x7fd57f3f06ba] > > 13: (clone()+0x6d) [0x7fd57e45c41d] > > NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. > > > > --- logging levels --- > > 0/ 5 none > > 0/ 1 lockdep > > 0/ 1 context > > 1/ 1 crush > > 1/ 5 mds > > 1/ 5 mds_balancer > > 1/ 5 mds_locker > > 1/ 5 mds_log > > 1/ 5 mds_log_expire > > 1/ 5 mds_migrator > > 0/ 1 buffer > > 0/ 1 timer > > 0/ 1 filer > > 0/ 1 striper > > 0/ 1 objecter > > 0/ 5 rados > > 0/ 5 rbd > > 0/ 5 rbd_mirror > > 0/ 5 rbd_replay > > 0/ 5 journaler > > 0/ 5 objectcacher > > 0/ 5 client > > 1/ 5 osd > > 0/ 5 optracker > > 0/ 5 objclass > > 1/ 3 filestore > > 1/ 3 journal > > 0/ 5 ms > > 1/ 5 mon > > 0/10 monc > > 1/ 5 paxos > > 0/ 5 tp > > 1/ 5 auth > > 1/ 5 crypto > > 1/ 1 finisher > > 1/ 1 reserver > > 1/ 5 heartbeatmap > > 1/ 5 perfcounter > > 1/ 5 rgw > > 1/10 civetweb > > 1/ 5 javaclient > > 1/ 5 asok > > 1/ 1 throttle > > 0/ 0 refs > > 1/ 5 xio > > 1/ 5 compressor > > 1/ 5 bluestore > > 1/ 5 bluefs > > 1/ 3 bdev > > 1/ 5 kstore > > 4/ 5 rocksdb > > 4/ 5 leveldb > > 4/ 5 memdb > > 1/ 5 kinetic > > 1/ 5 fuse > > 1/ 5 mgr > > 1/ 5 mgrc > > 1/ 5 dpdk > > 1/ 5 eventtrace > > -2/-2 (syslog threshold) > > -1/-1 (stderr threshold) > > max_recent 10000 > > max_new 1000 > > log_file /var/log/ceph/ceph-mds.filer1.log > > --- end dump of recent events --- > > 2018-03-22 15:52:53.278049 7fd5720ee700 -1 *** Caught signal (Aborted) ** > > in thread 7fd5720ee700 thread_name:md_log_replay > > > > ceph version 12.2.4 (52085d5249a80c5f5121a76d6288429f35e4e77b) luminous (stable) > > 1: (()+0x5ab254) [0x555879e42254] > > 2: (()+0x11390) [0x7fd57f3fa390] > > 3: (gsignal()+0x38) [0x7fd57e38a428] > > 4: (abort()+0x16a) [0x7fd57e38c02a] > > 5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x28e) [0x555879e88ace] > > 6: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x567) [0x555879ddd4e7] > > 7: (Server::journal_close_session(Session*, int, Context*)+0x963) [0x555879b8d603] > > 8: (Server::kill_session(Session*, Context*)+0x1fd) [0x555879b8e56d] > > 9: (MDSRank::validate_sessions()+0x2dc) [0x555879b4c2dc] > > 10: (MDSRank::boot_start(MDSRank::BootStep, int)+0xc08) [0x555879b4d228] > > 11: (MDSInternalContextBase::complete(int)+0x18b) [0x555879dc56db] > > 12: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::sub_finish(MDSInternalContextBase*, int)+0x127) [0x555879b66627] > > 13: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::C_GatherSub::complete(int)+0x21) [0x555879b668d1] > > 14: (MDLog::_replay_thread()+0x43c) [0x555879ddac8c] > > 15: (MDLog::ReplayThread::entry()+0xd) [0x555879b56fcd] > > 16: (()+0x76ba) [0x7fd57f3f06ba] > > 17: (clone()+0x6d) [0x7fd57e45c41d] > > NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. > > > > --- begin dump of recent events --- > > 0> 2018-03-22 15:52:53.278049 7fd5720ee700 -1 *** Caught signal (Aborted) ** > > in thread 7fd5720ee700 thread_name:md_log_replay > > > > ceph version 12.2.4 (52085d5249a80c5f5121a76d6288429f35e4e77b) luminous (stable) > > 1: (()+0x5ab254) [0x555879e42254] > > 2: (()+0x11390) [0x7fd57f3fa390] > > 3: (gsignal()+0x38) [0x7fd57e38a428] > > 4: (abort()+0x16a) [0x7fd57e38c02a] > > 5: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x28e) [0x555879e88ace] > > 6: (MDLog::_submit_entry(LogEvent*, MDSLogContextBase*)+0x567) [0x555879ddd4e7] > > 7: (Server::journal_close_session(Session*, int, Context*)+0x963) [0x555879b8d603] > > 8: (Server::kill_session(Session*, Context*)+0x1fd) [0x555879b8e56d] > > 9: (MDSRank::validate_sessions()+0x2dc) [0x555879b4c2dc] > > 10: (MDSRank::boot_start(MDSRank::BootStep, int)+0xc08) [0x555879b4d228] > > 11: (MDSInternalContextBase::complete(int)+0x18b) [0x555879dc56db] > > 12: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::sub_finish(MDSInternalContextBase*, int)+0x127) [0x555879b66627] > > 13: (C_GatherBase<MDSInternalContextBase, MDSInternalContextGather>::C_GatherSub::complete(int)+0x21) [0x555879b668d1] > > 14: (MDLog::_replay_thread()+0x43c) [0x555879ddac8c] > > 15: (MDLog::ReplayThread::entry()+0xd) [0x555879b56fcd] > > 16: (()+0x76ba) [0x7fd57f3f06ba] > > 17: (clone()+0x6d) [0x7fd57e45c41d] > > NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. > > > > --- logging levels --- > > 0/ 5 none > > 0/ 1 lockdep > > 0/ 1 context > > 1/ 1 crush > > 1/ 5 mds > > 1/ 5 mds_balancer > > 1/ 5 mds_locker > > 1/ 5 mds_log > > 1/ 5 mds_log_expire > > 1/ 5 mds_migrator > > 0/ 1 buffer > > 0/ 1 timer > > 0/ 1 filer > > 0/ 1 striper > > 0/ 1 objecter > > 0/ 5 rados > > 0/ 5 rbd > > 0/ 5 rbd_mirror > > 0/ 5 rbd_replay > > 0/ 5 journaler > > 0/ 5 objectcacher > > 0/ 5 client > > 1/ 5 osd > > 0/ 5 optracker > > 0/ 5 objclass > > 1/ 3 filestore > > 1/ 3 journal > > 0/ 5 ms > > 1/ 5 mon > > 0/10 monc > > 1/ 5 paxos > > 0/ 5 tp > > 1/ 5 auth > > 1/ 5 crypto > > 1/ 1 finisher > > 1/ 1 reserver > > 1/ 5 heartbeatmap > > 1/ 5 perfcounter > > 1/ 5 rgw > > 1/10 civetweb > > 1/ 5 javaclient > > 1/ 5 asok > > 1/ 1 throttle > > 0/ 0 refs > > 1/ 5 xio > > 1/ 5 compressor > > 1/ 5 bluestore > > 1/ 5 bluefs > > 1/ 3 bdev > > 1/ 5 kstore > > 4/ 5 rocksdb > > 4/ 5 leveldb > > 4/ 5 memdb > > 1/ 5 kinetic > > 1/ 5 fuse > > 1/ 5 mgr > > 1/ 5 mgrc > > 1/ 5 dpdk > > 1/ 5 eventtrace > > -2/-2 (syslog threshold) > > -1/-1 (stderr threshold) > > max_recent 10000 > > max_new 1000 > > log_file /var/log/ceph/ceph-mds.filer1.log > > --- end dump of recent events --- > > _______________________________________________ > > ceph-users mailing list > > ceph-users@xxxxxxxxxxxxxx > > http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com _______________________________________________ ceph-users mailing list ceph-users@xxxxxxxxxxxxxx http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
 |