Bug #21687: mgr: mark_down of osd without metadata is broken - mgr - Ceph

Actions

Copy link

Bug #21687

closed

mgr: mark_down of osd without metadata is broken

Added by Sage Weil over 6 years ago. Updated about 6 years ago.

Status:

Resolved

Priority:

Urgent

Assignee:

Chang Liu

Category:

Target version:

% Done:

Source:

Tags:

Backport:

luminous

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

2017-10-05 16:47:46.720413 7fd687b4f700 10 mgr.server ms_verify_authorizer registering osd.1 session 0x55a1d08d0ca0 con 0x55a1d09346c0
2017-10-05 16:47:46.720423 7fd687b4f700 10 In get_auth_session_handler for protocol 2
2017-10-05 16:47:46.720492 7fd687b4f700  1 -- 172.21.15.113:6800/260182 >> 172.21.15.159:6800/2561 pipe(0x55a1cf82c000 sd=20 :6800 s=2 pgs=1589 cs=1 l=1 c=0x55a1d09346c0).setting up a delay queue on Pipe 0x55a1cf82c000
2017-10-05 16:47:46.722833 7fd687b4f700 10 _calc_signature seq 1 front_crc_ = 1637758479 middle_crc = 0 data_crc = 0 sig = 3732551276752750330
2017-10-05 16:47:46.722925 7fd68d30f700  1 -- 172.21.15.113:6800/260182 <== osd.1 172.21.15.159:6800/2561 1 ==== mgropen(osd.1) v2 ==== 10+0+0 (1637758479 0 0) 0x55a1d08ccec0 con 0x55a1d09346c0
2017-10-05 16:47:46.722954 7fd68d30f700  4 mgr.server handle_open from 0x55a1d09346c0  osd,1
2017-10-05 16:47:46.722958 7fd68d30f700  1 -- 172.21.15.113:6800/260182 --> 172.21.15.159:6800/2561 -- mgrconfigure() v1 -- ?+0 0x55a1ce8b2400 con 0x55a1d09346c0
2017-10-05 16:47:46.723023 7fd68794d700 10 _calc_signature seq 1 front_crc_ = 2791807819 middle_crc = 0 data_crc = 0 sig = 5971460742716778938
2017-10-05 16:47:46.723039 7fd68794d700 20 Putting signature in client message(seq # 1): sig = 5971460742716778938
2017-10-05 16:47:46.724939 7fd687b4f700 10 _calc_signature seq 2 front_crc_ = 4184223999 middle_crc = 0 data_crc = 0 sig = 14943916633820690389
2017-10-05 16:47:46.725008 7fd687b4f700 10 _calc_signature seq 3 front_crc_ = 296065787 middle_crc = 0 data_crc = 0 sig = 4128270110835625172
2017-10-05 16:47:46.725052 7fd68d30f700  1 -- 172.21.15.113:6800/260182 <== osd.1 172.21.15.159:6800/2561 2 ==== mgrreport(osd.1 +446-0 packed 5398) v4 ==== 39454+0+0 (4184223999 0 0) 0x55a1cf799500 con 0x55a1d09346c0
2017-10-05 16:47:46.725083 7fd68d30f700  4 mgr.server handle_report from 0x55a1d09346c0 osd,1
2017-10-05 16:47:46.725087 7fd68d30f700  1 mgr.server handle_report rejecting report from osd,1, since we do not have its metadata now.
2017-10-05 16:47:46.725090 7fd68d30f700  1 -- 172.21.15.113:6800/260182 mark_down 0x55a1d09346c0 -- 0x55a1cf82c000
2017-10-05 16:47:46.725126 7fd68d30f700  0 ms_deliver_dispatch: unhandled message 0x55a1cf799500 mgrreport(osd.1 +446-0 packed 5398) v4 from osd.1 172.21.15.159:6800/2561
2017-10-05 16:47:46.725423 7fd68d30f700  1 -- 172.21.15.113:6800/260182 <== osd.1 172.21.15.159:6800/2561 3 ==== pg_stats(2 pgs tid 0 v 0) v1 ==== 1312+0+0 (296065787 0 0) 0x55a1cf798300 con 0x55a1d09346c0
2017-10-05 16:47:46.806561 7fd687b4f700  1 -- 172.21.15.113:6800/260182 >> - pipe(0x55a1cf82e800 sd=20 :6800 s=0 pgs=0 cs=0 l=0 c=0x55a1d0934ea0).accept sd=20 -

happens every 1-2 seconds, for each message we get from the osd.

/a/sage-2017-10-05_16:11:00-rados-wip-sage-testing-2017-10-05-0846-distro-basic-smithi/1706300

An ugly side-effect of this mark_down call is that we aren't removing the con from osd_cons. This fixes that:

diff --git a/src/mgr/DaemonServer.cc b/src/mgr/DaemonServer.cc
index bdb3cc96a7..d9d811998a 100644
--- a/src/mgr/DaemonServer.cc
+++ b/src/mgr/DaemonServer.cc
@@ -426,6 +426,7 @@ bool DaemonServer::handle_report(MMgrReport *m)
       return false;
     }
     m->get_connection()->mark_down();
+    osd_cons[m->get_source().num].erase(session->con);
     session->put();

     return false;

..but doesn't help the fact that we kill all osd connections. the result is that we can't send scrub messages from mgr -> osd. Almost all of the failures in this run were affected by this:

http://pulpito.ceph.com/sage-2017-10-05_16:11:00-rados-wip-sage-testing-2017-10-05-0846-distro-basic-smithi/

Related issues 2 (0 open — 2 closed)

Actions

Copy link

Updated by Sage Weil over 6 years ago

Project changed from RADOS to mgr

Actions

Copy link

Updated by John Spray over 6 years ago

Ah -- didn't think about how the OSD conns were used for commands when this change (https://github.com/ceph/ceph/pull/17138) was made.

I wonder how the OSD is ending up with no metadata on the mons? The expectation on the mgr side is that this is a transient condition, where an OSD might have send a MMgrOpen before we had loaded its metadata.

Although now that I look again at how we load metadata, we won't retry until the next update to the OSD map, so if nothing else is going on then we could be metadata-less for some time :-/

tldr: yeah, this is broken...

Actions

Copy link

Updated by Chang Liu over 6 years ago

John Spray wrote:

Ah -- didn't think about how the OSD conns were used for commands when this change (https://github.com/ceph/ceph/pull/17138) was made.

I wonder how the OSD is ending up with no metadata on the mons? The expectation on the mgr side is that this is a transient condition, where an OSD might have send a MMgrOpen before we had loaded its metadata.

Although now that I look again at how we load metadata, we won't retry until the next update to the OSD map, so if nothing else is going on then we could be metadata-less for some time :-/

tldr: yeah, this is broken...

hay, John, any suggestion to fix this problem?

Actions

Copy link

Updated by Chang Liu over 6 years ago

Maybe we could request OSD's metadata when We kill a OSD connection. how about creating a background thread and requesting those OSDs metadata periodically?

Actions

Copy link

Updated by Chang Liu over 6 years ago

Assignee set to Chang Liu

Actions

Copy link

Updated by Chang Liu over 6 years ago

Status changed from 12 to In Progress

Actions

Copy link

Updated by Chang Liu over 6 years ago

2017-10-05 18:11:49.261176 7f23e79dc700 10 mgr notify_all notify_all: notify_all osd_map
2017-10-05 18:11:49.261193 7f23e79dc700 10 monclient: _renew_subs
2017-10-05 18:11:49.261197 7f23e79dc700 10 monclient: _send_mon_message to mon.b at 172.21.15.156:6790/0
2017-10-05 18:11:49.261203 7f23e79dc700  1 -- 172.21.15.156:0/770085597 --> 172.21.15.156:6790/0 -- mon_subscribe({osdmap=29}) v2 -- ?+0 0x7f23f87dda80 con 0x7f23f8827f00
2017-10-05 18:11:49.261339 7f23e2fd1700 20 mgr Gil GIL acquired for thread state 0x7f23f8044790
2017-10-05 18:11:49.261542 7f23e2fd1700 20 mgr[restful] Unhandled notification type 'osd_map'
2017-10-05 18:11:49.261565 7f23e2fd1700 20 mgr ~Gil GIL released for thread state 0x7f23f8044790
2017-10-05 18:11:49.263045 7f23e79dc700  1 -- 172.21.15.156:0/770085597 <== mon.1 172.21.15.156:6790/0 41 ==== mon_command_ack([{"prefix": "osd metadata", "id": 0}]=0  v28) v1 ==== 69+0+1166 (4071984089 0 111155761) 0x7f23f87dbf80 con 0x7f23f8827f00
2017-10-05 18:11:49.263072 7f23e79dc700 10 monclient: handle_mon_command_ack 77 [{"prefix": "osd metadata", "id": 0}]
2017-10-05 18:11:49.263078 7f23e79dc700 10 monclient: _finish_command 77 = 0 
2017-10-05 18:11:49.263097 7f23e79dc700  1 -- 172.21.15.156:0/770085597 <== mon.1 172.21.15.156:6790/0 42 ==== mon_command_ack([{"prefix": "osd metadata", "id": 1}]=0  v28) v1 ==== 69+0+1166 (3776385966 0 2700020360) 0x7f23f87dd3c0 con 0x7f23f8827f00
2017-10-05 18:11:49.263111 7f23e79dc700 10 monclient: handle_mon_command_ack 78 [{"prefix": "osd metadata", "id": 1}]
2017-10-05 18:11:49.263114 7f23e79dc700 10 monclient: _finish_command 78 = 0 
2017-10-05 18:11:49.263714 7f23e79dc700  1 -- 172.21.15.156:0/770085597 <== mon.1 172.21.15.156:6790/0 43 ==== mon_command_ack([{"prefix": "osd metadata", "id": 2}]=0  v28) v1 ==== 69+0+1170 (3589323575 0 604917393) 0x7f23f87dcac0 con 0x7f23f8827f00
2017-10-05 18:11:49.263742 7f23e79dc700 10 monclient: handle_mon_command_ack 79 [{"prefix": "osd metadata", "id": 2}]
2017-10-05 18:11:49.263747 7f23e79dc700 10 monclient: _finish_command 79 = 0

Sage, John. Here is a problem, ceph-mgr receives OSDMap's notifications and fetches OSD's metadata successfully(? finish_command 79=0 above). Why ceph-mgr hasn't those metadata?

Actions

Copy link