Project

General

Profile

Bug #18516

"osd marked itself down" will not recognised if host runs mon + osd on shutdown/reboot

Added by Udo Lembke 3 months ago. Updated 4 days ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
-
Target version:
-
Start date:
01/13/2017
Due date:
% Done:

0%

Source:
Tags:
Backport:
kraken, jewel
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Release:
Needs Doc:
No

Description

On a small Proxmox-VE Ceph-cluster (three Nodes, all with one Mon and two OSDs, running systemd) produce an reboot of one node the message:
"osd.X marked itself down", but due the mon lost during the same time "mon.X calling new monitor election" this event will not recognised.

So it's takes grace-time (20sec) + X to caclulate an new osd-map.

ceph version 10.2.5 (c461ee19ecbc0c5c330aca20f7392c9a00730367)

Disccused on ceph-users: https://www.mail-archive.com/ceph-users@lists.ceph.com/msg35074.html

"ceph -w" Output from an reboot:
2017-01-12 10:18:04.925420 mon.0 [INF] pgmap v4800795: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 292 kB/s wr, 54 op/s
2017-01-12 10:18:07.800276 mon.0 [INF] pgmap v4800796: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 143 kB/s wr, 28 op/s
2017-01-12 10:18:08.834630 mon.0 [INF] pgmap v4800797: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 103 kB/s wr, 11 op/s
2017-01-12 10:18:09.931547 mon.0 [INF] pgmap v4800798: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 581 kB/s wr, 34 op/s
2017-01-12 10:18:12.801667 mon.0 [INF] pgmap v4800799: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 239 kB/s wr, 15 op/s
2017-01-12 10:18:13.584930 mon.0 [INF] osd.5 marked itself down
2017-01-12 10:18:13.585169 mon.0 [INF] osd.4 marked itself down
2017-01-12 10:18:22.809473 mon.2 [INF] mon.2 calling new monitor election
2017-01-12 10:18:22.847548 mon.0 [INF] mon.0 calling new monitor election
2017-01-12 10:18:27.879341 mon.0 [INF] mon.0@0 won leader election with quorum 0,2
2017-01-12 10:18:27.889797 mon.0 [INF] HEALTH_WARN; 1 mons down, quorum 0,2 0,2
2017-01-12 10:18:27.952672 mon.0 [INF] monmap e3: 3 mons at {0=10.132.7.11:6789/0,1=10.132.7.12:6789/0,2=10.132.7.13:6789/0}
2017-01-12 10:18:27.953410 mon.0 [INF] pgmap v4800799: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 239 kB/s wr, 15 op/s
2017-01-12 10:18:27.953453 mon.0 [INF] fsmap e1:
2017-01-12 10:18:27.953787 mon.0 [INF] osdmap e2053: 6 osds: 6 up, 6 in
2017-01-12 10:18:29.013968 mon.0 [INF] pgmap v4800800: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 73018 B/s wr, 12 op/s
2017-01-12 10:18:30.086787 mon.0 [INF] pgmap v4800801: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 59 B/s rd, 135 kB/s wr, 15 op/s
2017-01-12 10:18:34.559509 mon.0 [INF] pgmap v4800802: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 184 B/s rd, 189 kB/s wr, 7 op/s
2017-01-12 10:18:35.623838 mon.0 [INF] pgmap v4800803: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail
2017-01-12 10:18:39.580770 mon.0 [INF] pgmap v4800804: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail
2017-01-12 10:18:39.681058 mon.0 [INF] osd.4 10.132.7.12:6800/4064 failed (2 reporters from different host after 21.222945 >= grace 20.388836)
2017-01-12 10:18:39.681221 mon.0 [INF] osd.5 10.132.7.12:6802/4163 failed (2 reporters from different host after 21.222970 >= grace 20.388836)
2017-01-12 10:18:40.612401 mon.0 [INF] pgmap v4800805: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail
2017-01-12 10:18:40.670801 mon.0 [INF] osdmap e2054: 6 osds: 4 up, 6 in
2017-01-12 10:18:40.689302 mon.0 [INF] pgmap v4800806: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail
2017-01-12 10:18:41.730006 mon.0 [INF] osdmap e2055: 6 osds: 4 up, 6 in
2017-01-12 10:18:41.752597 mon.0 [INF] pgmap v4800807: 392 pgs: 130 stale+active+clean, 262 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail
2017-01-12 10:18:44.554077 mon.0 [INF] pgmap v4800808: 392 pgs: 103 active+undersized+degraded, 94 stale+active+clean, 195 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 76165 B/s wr, 27 op/s; 39643/438192 objects degraded (9.047%)
2017-01-12 10:18:45.597227 mon.0 [INF] pgmap v4800809: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 918 kB/s wr, 121 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:18:49.923089 mon.0 [INF] pgmap v4800810: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 719 kB/s wr, 103 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:18:54.549657 mon.0 [INF] pgmap v4800811: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 79432 B/s wr, 24 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:18:55.640648 mon.0 [INF] pgmap v4800812: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 427 kB/s wr, 38 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:18:59.547464 mon.0 [INF] pgmap v4800813: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 477 kB/s wr, 41 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:00.610963 mon.0 [INF] pgmap v4800814: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 61476 B/s wr, 12 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:04.551016 mon.0 [INF] pgmap v4800815: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 58154 B/s wr, 10 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:05.610954 mon.0 [INF] pgmap v4800816: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 182 kB/s wr, 13 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:09.551906 mon.0 [INF] pgmap v4800817: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 190 kB/s wr, 16 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:10.616393 mon.0 [INF] pgmap v4800818: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 244 kB/s wr, 27 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:14.556186 mon.0 [INF] pgmap v4800819: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 259 kB/s wr, 34 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:15.617205 mon.0 [INF] pgmap v4800820: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 238 kB/s wr, 33 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:19.592445 mon.0 [INF] pgmap v4800821: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 233 kB/s wr, 30 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:20.652538 mon.0 [INF] pgmap v4800822: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 166 kB/s wr, 25 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:24.559924 mon.0 [INF] pgmap v4800823: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 162 kB/s wr, 23 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:25.624041 mon.0 [INF] pgmap v4800824: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 405 kB/s wr, 44 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:27.890003 mon.0 [INF] HEALTH_WARN; 392 pgs degraded; 198 pgs stuck unclean; 392 pgs undersized; recovery 146064/438192 objects degraded (33.333%); 2/6 in osds are down; 1 mons down, quorum 0,2 0,2
2017-01-12 10:19:29.812658 mon.0 [INF] pgmap v4800825: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 516 kB/s wr, 65 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:34.553433 mon.0 [INF] pgmap v4800826: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 92591 B/s wr, 18 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:35.609435 mon.0 [INF] pgmap v4800827: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 261 kB/s wr, 19 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:39.843273 mon.0 [INF] pgmap v4800828: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 421 kB/s wr, 43 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:44.562581 mon.0 [INF] pgmap v4800829: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 90541 B/s wr, 15 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:45.618846 mon.0 [INF] pgmap v4800830: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 325 kB/s wr, 23 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:49.558223 mon.0 [INF] pgmap v4800831: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 430 kB/s wr, 44 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:50.591204 mon.0 [INF] pgmap v4800832: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 188 kB/s wr, 33 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:54.573249 mon.0 [INF] pgmap v4800833: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 148 kB/s wr, 21 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:55.629650 mon.0 [INF] pgmap v4800834: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 340 kB/s wr, 38 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:19:59.561740 mon.0 [INF] pgmap v4800835: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 332 kB/s wr, 35 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:00.618456 mon.0 [INF] pgmap v4800836: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 101811 B/s wr, 30 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:04.565851 mon.0 [INF] pgmap v4800837: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 100535 B/s wr, 30 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:05.632799 mon.0 [INF] pgmap v4800838: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 356 kB/s wr, 41 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:10.221389 mon.0 [INF] pgmap v4800839: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 523 kB/s wr, 74 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:14.565618 mon.0 [INF] pgmap v4800840: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 149 kB/s wr, 30 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:15.628899 mon.0 [INF] pgmap v4800841: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 227 kB/s wr, 24 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:16.609681 mon.2 [INF] from='client.? 10.132.7.12:0/3008319411' entity='osd.4' cmd=[{"prefix": "osd crush create-or-move", "args": ["host=pve02", "root=default"], "id": 4, "weight": 1.8136}]: dispatch
2017-01-12 10:20:16.612338 mon.0 [INF] from='client.5864657 :/0' entity='osd.4' cmd=[{"prefix": "osd crush create-or-move", "args": ["host=pve02", "root=default"], "id": 4, "weight": 1.8136}]: dispatch
2017-01-12 10:20:18.935201 mon.1 [INF] mon.1 calling new monitor election
2017-01-12 10:20:19.082448 mon.1 [WRN] message from mon.0 was stamped 0.451166s in the future, clocks not synchronized
2017-01-12 10:20:19.402059 mon.2 [INF] mon.2 calling new monitor election
2017-01-12 10:20:19.403986 mon.0 [INF] mon.0 calling new monitor election
2017-01-12 10:20:19.448656 mon.0 [INF] mon.0@0 won leader election with quorum 0,1,2
2017-01-12 10:20:19.457470 mon.0 [INF] HEALTH_WARN; 392 pgs degraded; 205 pgs stuck unclean; 392 pgs undersized; recovery 146064/438192 objects degraded (33.333%); 2/6 in osds are down
2017-01-12 10:20:19.534054 mon.0 [INF] monmap e3: 3 mons at {0=10.132.7.11:6789/0,1=10.132.7.12:6789/0,2=10.132.7.13:6789/0}
2017-01-12 10:20:19.534130 mon.0 [INF] pgmap v4800841: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 227 kB/s wr, 24 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:19.534170 mon.0 [INF] fsmap e1:
2017-01-12 10:20:19.535868 mon.0 [INF] osdmap e2055: 6 osds: 4 up, 6 in
2017-01-12 10:20:19.546088 mon.0 [WRN] mon.1 10.132.7.12:6789/0 clock skew 0.375823s > max 0.05s
2017-01-12 10:20:19.648215 mon.0 [INF] pgmap v4800842: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 234 kB/s wr, 22 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:20.708814 mon.0 [INF] pgmap v4800843: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 157 kB/s wr, 19 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:24.122886 mon.1 [WRN] message from mon.0 was stamped 0.445149s in the future, clocks not synchronized
2017-01-12 10:20:24.568172 mon.0 [INF] pgmap v4800844: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 183 kB/s wr, 24 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:25.637879 mon.0 [INF] pgmap v4800845: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 269 kB/s wr, 26 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:29.563241 mon.0 [INF] pgmap v4800846: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 247 kB/s wr, 23 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:30.606504 mon.0 [INF] osd.4 10.132.7.12:6802/4011 boot
2017-01-12 10:20:30.606628 mon.0 [INF] osdmap e2056: 6 osds: 5 up, 6 in
2017-01-12 10:20:30.672491 mon.0 [INF] pgmap v4800848: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 695 kB/s wr, 92 op/s; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:31.657623 mon.0 [INF] osdmap e2057: 6 osds: 5 up, 6 in
2017-01-12 10:20:31.675071 mon.0 [INF] pgmap v4800849: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:32.719055 mon.0 [INF] osdmap e2058: 6 osds: 5 up, 6 in
2017-01-12 10:20:32.742106 mon.0 [INF] pgmap v4800850: 392 pgs: 392 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 146064/438192 objects degraded (33.333%)
2017-01-12 10:20:34.907805 mon.0 [INF] pgmap v4800851: 392 pgs: 78 active+clean, 31 active+degraded, 21 active+recovery_wait+degraded, 262 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 331 kB/s wr, 41 op/s; 100586/438192 objects degraded (22.955%); 44026 kB/s, 10 objects/s recovering
2017-01-12 10:20:34.908739 mon.0 [INF] osd.5 10.132.7.12:6800/3826 boot
2017-01-12 10:20:34.908851 mon.0 [INF] osdmap e2059: 6 osds: 6 up, 6 in
2017-01-12 10:20:34.959378 mon.0 [INF] pgmap v4800852: 392 pgs: 78 active+clean, 31 active+degraded, 21 active+recovery_wait+degraded, 262 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 479 kB/s wr, 59 op/s; 100586/438192 objects degraded (22.955%); 63669 kB/s, 15 objects/s recovering
2017-01-12 10:20:35.939205 mon.0 [INF] osdmap e2060: 6 osds: 6 up, 6 in
2017-01-12 10:20:35.968361 mon.0 [INF] pgmap v4800853: 392 pgs: 1 active+recovering+degraded, 122 active+clean, 31 active+degraded, 38 active+recovery_wait+degraded, 200 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 72469 B/s wr, 8 op/s; 78601/438192 objects degraded (17.938%); 11008 kB/s, 2 objects/s recovering
2017-01-12 10:20:36.970077 mon.0 [INF] osdmap e2061: 6 osds: 6 up, 6 in
2017-01-12 10:20:37.021737 mon.0 [INF] pgmap v4800854: 392 pgs: 1 active+recovering+degraded, 122 active+clean, 31 active+degraded, 38 active+recovery_wait+degraded, 200 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 39252 B/s wr, 4 op/s; 78601/438192 objects degraded (17.938%); 5962 kB/s, 1 objects/s recovering
2017-01-12 10:20:35.730228 osd.6 [INF] 0.a1 scrub starts
2017-01-12 10:20:39.570523 mon.0 [INF] pgmap v4800855: 392 pgs: 1 active+recovering+degraded, 141 active+clean, 35 active+degraded, 48 active+recovery_wait+degraded, 167 active+undersized+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 12521 B/s wr, 2 op/s; 64196/438192 objects degraded (14.650%); 11072 kB/s, 2 objects/s recovering
2017-01-12 10:20:40.620178 mon.0 [INF] pgmap v4800856: 392 pgs: 1 active+clean+scrubbing, 1 active+recovering+degraded, 239 active+clean, 73 active+degraded, 78 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 123 kB/s wr, 26 op/s; 214/438192 objects degraded (0.049%); 60249 kB/s, 16 objects/s recovering
2017-01-12 10:20:41.747694 mon.0 [INF] pgmap v4800857: 392 pgs: 1 active+clean+scrubbing, 241 active+clean, 73 active+degraded, 77 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 259 kB/s wr, 46 op/s; 212/438192 objects degraded (0.048%); 87523 kB/s, 23 objects/s recovering
2017-01-12 10:20:44.584452 mon.0 [INF] pgmap v4800858: 392 pgs: 1 active+recovering+degraded, 1 active+clean+scrubbing, 241 active+clean, 69 active+degraded, 80 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 61041 B/s wr, 12 op/s; 204/438192 objects degraded (0.047%); 19214 kB/s, 4 objects/s recovering
2017-01-12 10:20:45.672822 mon.0 [INF] pgmap v4800859: 392 pgs: 1 active+recovering+degraded, 1 active+clean+scrubbing, 249 active+clean, 52 active+degraded, 89 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 677 kB/s wr, 82 op/s; 168/438192 objects degraded (0.038%); 80124 kB/s, 19 objects/s recovering
2017-01-12 10:20:46.859502 mon.0 [INF] pgmap v4800860: 392 pgs: 1 active+recovering+degraded, 1 active+clean+scrubbing, 250 active+clean, 52 active+degraded, 88 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 1240 kB/s wr, 141 op/s; 165/438192 objects degraded (0.038%); 118 MB/s, 29 objects/s recovering
2017-01-12 10:20:49.596806 mon.0 [INF] pgmap v4800861: 392 pgs: 1 active+clean+scrubbing, 253 active+clean, 51 active+degraded, 87 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 32785 B/s wr, 5 op/s; 161/438192 objects degraded (0.037%); 10489 kB/s, 2 objects/s recovering
2017-01-12 10:20:50.672634 mon.0 [INF] pgmap v4800862: 392 pgs: 1 active+clean+scrubbing, 270 active+clean, 46 active+degraded, 75 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 121 kB/s wr, 29 op/s; 135/438192 objects degraded (0.031%); 48923 kB/s, 12 objects/s recovering
2017-01-12 10:20:51.947955 mon.0 [INF] pgmap v4800863: 392 pgs: 1 active+clean+scrubbing, 272 active+clean, 46 active+degraded, 73 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9444 GB / 11142 GB avail; 237 kB/s wr, 54 op/s; 131/438192 objects degraded (0.030%); 80339 kB/s, 20 objects/s recovering
2017-01-12 10:20:55.194261 mon.0 [INF] pgmap v4800864: 392 pgs: 294 active+clean, 36 active+degraded, 62 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 340 kB/s wr, 42 op/s; 104/438192 objects degraded (0.024%); 48356 kB/s, 12 objects/s recovering
2017-01-12 10:20:56.551711 mon.0 [INF] pgmap v4800865: 392 pgs: 298 active+clean, 36 active+degraded, 58 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 331 kB/s wr, 43 op/s; 97/438192 objects degraded (0.022%); 50288 kB/s, 12 objects/s recovering
2017-01-12 10:20:53.700884 osd.1 [INF] 1.20 scrub starts
2017-01-12 10:20:53.701810 osd.1 [INF] 1.20 scrub ok
2017-01-12 10:20:54.701355 osd.1 [INF] 1.a deep-scrub starts
2017-01-12 10:20:54.702263 osd.1 [INF] 1.a deep-scrub ok
2017-01-12 10:20:50.861970 osd.6 [INF] 0.a1 scrub ok
2017-01-12 10:20:54.731094 osd.6 [INF] 3.a scrub starts
2017-01-12 10:21:00.061544 mon.0 [INF] pgmap v4800866: 392 pgs: 330 active+clean, 23 active+degraded, 39 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 455 kB/s wr, 39 op/s; 70/438192 objects degraded (0.016%); 47114 kB/s, 11 objects/s recovering
2017-01-12 10:21:01.179937 mon.0 [INF] pgmap v4800867: 392 pgs: 335 active+clean, 23 active+degraded, 34 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 470 kB/s wr, 39 op/s; 63/438192 objects degraded (0.014%); 47786 kB/s, 11 objects/s recovering
2017-01-12 10:21:04.600828 mon.0 [INF] pgmap v4800868: 392 pgs: 339 active+clean, 21 active+degraded, 32 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 24132 B/s wr, 4 op/s; 55/438192 objects degraded (0.013%); 20112 kB/s, 5 objects/s recovering
2017-01-12 10:21:05.732450 mon.0 [INF] pgmap v4800869: 392 pgs: 356 active+clean, 12 active+degraded, 24 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 207 kB/s wr, 16 op/s; 36/438192 objects degraded (0.008%); 39749 kB/s, 10 objects/s recovering
2017-01-12 10:21:06.825602 mon.0 [INF] pgmap v4800870: 392 pgs: 360 active+clean, 12 active+degraded, 20 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 443 kB/s wr, 36 op/s; 32/438192 objects degraded (0.007%); 58931 kB/s, 15 objects/s recovering
2017-01-12 10:20:59.677135 osd.6 [INF] 3.a scrub ok
2017-01-12 10:21:09.571884 mon.0 [INF] pgmap v4800871: 392 pgs: 367 active+clean, 9 active+degraded, 16 active+recovery_wait+degraded; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 28473 B/s wr, 8 op/s; 24/438192 objects degraded (0.005%); 20450 kB/s, 5 objects/s recovering
2017-01-12 10:21:10.606646 mon.0 [INF] pgmap v4800872: 392 pgs: 1 active+recovering+degraded, 391 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 177 kB/s wr, 39 op/s; 1/438192 objects degraded (0.000%); 50865 kB/s, 12 objects/s recovering
2017-01-12 10:21:11.679229 mon.0 [INF] pgmap v4800873: 392 pgs: 1 active+recovering+degraded, 391 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 473 kB/s wr, 74 op/s; 1/438192 objects degraded (0.000%); 61584 kB/s, 15 objects/s recovering
2017-01-12 10:21:14.884672 mon.0 [INF] pgmap v4800874: 392 pgs: 1 active+clean+scrubbing, 391 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 372 kB/s wr, 50 op/s; 1917 kB/s, 0 objects/s recovering
2017-01-12 10:21:09.478347 osd.7 [INF] 0.48 scrub starts
2017-01-12 10:21:15.919198 mon.0 [INF] pgmap v4800875: 392 pgs: 1 active+clean+scrubbing, 391 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 313 kB/s wr, 50 op/s; 1930 kB/s, 0 objects/s recovering
2017-01-12 10:21:19.457552 mon.0 [INF] HEALTH_OK
2017-01-12 10:21:20.510441 mon.0 [INF] pgmap v4800876: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 195 kB/s wr, 30 op/s
2017-01-12 10:21:21.671113 mon.0 [INF] pgmap v4800877: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 214 kB/s wr, 28 op/s
2017-01-12 10:21:24.565939 mon.0 [INF] pgmap v4800878: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 63970 B/s wr, 6 op/s
2017-01-12 10:21:17.461345 osd.7 [INF] 0.48 scrub ok
2017-01-12 10:21:25.632419 mon.0 [INF] pgmap v4800879: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 245 kB/s wr, 24 op/s
2017-01-12 10:21:26.834816 mon.0 [INF] pgmap v4800880: 392 pgs: 392 active+clean; 567 GB data, 1697 GB used, 9445 GB / 11142 GB avail; 534 kB/s wr, 47 op/s
2017-01-12 10:21:20.735449 osd.6 [INF] 0.42 scrub starts
2017-01-12 10:21:24.243832 osd.6 [INF] 0.42 scrub ok


Related issues

Copied to Backport #18906: jewel: "osd marked itself down" will not recognised if host runs mon + osd on shutdown/reboot Resolved
Copied to Backport #18907: kraken: "osd marked itself down" will not recognised if host runs mon + osd on shutdown/reboot Resolved

History

#1 Updated by Greg Farnum 3 months ago

We discussed this on the mailing list.

Sam wrote:
Oh, this is basically working as intended. What happened is that the mon died before the pending map was actually committed. The OSD has a timeout (5s) after which it stops trying to mark itself down and just dies (so that OSDs don't hang when killed). It took a bit longer than 5s for the remaining 2 mons to form a new quorum, so they never got the MOSDMarkMeDown message so we had to do it the slow way. I would prefer this behavior to changing the mon shutdown process or making the OSDs wait longer, so I think that's it. If you want to avoid disruption with colocated mons and osds, stop the osds first and then reboot.

I wrote:
We can probably make our systemd scripts do this automatically? Or at least, there's a Ceph super-task thingy and I bet we can order the shutdown so it waits to kill the monitor until all the OSDs processes have ended.

#2 Updated by Greg Farnum 3 months ago

  • Assignee set to Boris Ranto

Boris, Dan suggests you know the most about our systemd scripts. Is this a feasible change to make?

#3 Updated by Greg Farnum 3 months ago

Boris said, in the tracker-period-which-was-lost:

Hey Greg, this is feasible to do, in a way.
We can add either After= (preferred afaik) or Before= line in the unit scripts to define this behaviour. The line will define the behaviour on both the boot as well as shutdown (in reverse order, i.e. if there is 'After=B' line in 'A' then 'A' is started after 'B' and 'B' is stopped After 'A'). By default, the daemons are started/stopped simultaneously so we can see the described behaviour (mons are usually faster to go down).

However, we can only define this behaviour for a single machine that is running both mon and osd which we do not recommend to do anyway. We cannot (well, not with systemd) control this behaviour when we are doing a full cluster reboot.

#4 Updated by Greg Farnum 3 months ago

That sounds to me like exactly what we're after. This doesn't need to be coordinated across nodes; it's specifically about small clusters where all the nodes are doing double-duty. We don't need to solve cluster-wide shutdown happening in the wrong order (that would be the fault of the orchestration system or the admin), and it's less likely to cause trouble anyway.

#6 Updated by Nathan Cutler 2 months ago

  • Status changed from New to Resolved

#7 Updated by Greg Farnum 2 months ago

  • Status changed from Resolved to Pending Backport
  • Backport set to Kraken, jewel, hammer

Adding backport fields. This should go wherever we have systems in supported releases; I think I got the right ones.

#8 Updated by Nathan Cutler 2 months ago

  • Backport changed from Kraken, jewel, hammer to kraken, jewel, hammer

Greg IIRC systemd support wasn't production-ready when hammer was released, but it is backportable because there is a systemd/ directory and a ceph-osd.service file in it.

#10 Updated by Loic Dachary 2 months ago

  • Copied to Backport #18906: jewel: "osd marked itself down" will not recognised if host runs mon + osd on shutdown/reboot added

#11 Updated by Loic Dachary 2 months ago

  • Copied to Backport #18907: kraken: "osd marked itself down" will not recognised if host runs mon + osd on shutdown/reboot added

#12 Updated by Nathan Cutler 2 months ago

  • Backport changed from kraken, jewel, hammer to kraken, jewel

#13 Updated by Nathan Cutler 2 months ago

systemd fixes are not needed in hammer, since systemd support was still in its infancy when hammer was released.

#14 Updated by Nathan Cutler 4 days ago

  • Status changed from Pending Backport to Resolved

Also available in: Atom PDF