Ceph cluster boot problem

ktkt

New Member
Jul 2, 2021
1
0
1
33
Greetings Proxmox community,

Since many of you are familiar with Ceph, I hope someone can help me with this issue.
We have a 3 node Ceph cluster (ceph-node1, ceph-node2 and ceph-node3) as the main storage for our Proxmox VMs. We had a power outage a few days ago, and after that ceph-node1 and ceph-node3 booted into emergency mode (its cause is probably unrelated to my question), ceph-node2 booted normally. I restarted ceph-node3 and then it booted properly, ceph-node2 and ceph-node3 could ping each other on both of their networks. The OSDs and ceph-mgr daemons were running (systemctl status showed no problems with the services), but according to the logs, ceph couldn't find any active nor standy ceph-mgr, and all of the OSDs from ceph-node2 and one OSD from ceph-node3 were in "down" state, and the cluster was unavailable. There were no answer to "ceph -s" command. If I understand correctly, ceph-mgr should have been in active state even if there is only 1 node available since it doesn't require quorum, and the cluster should have started with 2 nodes in degraded mode. Initially there was a clock skew between ceph-node2 and ceph-node3 due to a wrong DNS setting, but when it was cleared, it had no impact on either the aforementioned ceph-mgr issue nor the OSDs in "down" state. When I restarted ceph-node1 and it booted properly, its ceph-mgr became the active one, the other two came up as standbys, suddenly all of the OSDs came up and the cluster started.

After multiple days of searching, I found only these lines in the logs which could possibly indicate the issue, as this message didn't show up when started ceph-node1 and the cluster became available. (Note : rebooted ceph-node2 at 17:48 and restarted all of the daemons on ceph-node3 at 18:01. 192.168.99.1 is ceph-node1, 192.168.99.2 is ceph-node2, 192.168.99.3 is ceph-node3)

ceph-mon log from ceph-node3:
Code:
2021-06-29 17:48:46.710682 7f69b9d83700  0 -- 192.168.99.3:6789/0 >> 192.168.99.2:6789/0 conn(0x55c56feaf000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept peer reset, then tried to connect to us, replacing
Code:
2021-06-29 18:01:02.697113 7f3495cbd700  0 -- 192.168.99.3:6789/0 >> 192.168.99.2:6789/0 conn(0x555a9eb65000 :6789 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept peer reset, then tried to connect to us, replacing

I'm also attaching a segment from the ceph.log below; I can attach other logs too, just didn't want the post to be too long.

Any input on this is appreciated!

ceph.log from ceph-node2
Code:
2021-06-29 17:08:42.238623 mon.ceph-node2 mon.1 192.168.99.2:6789/0 1 : cluster [INF] mon.ceph-node2 calling monitor election
2021-06-29 17:08:47.252072 mon.ceph-node2 mon.1 192.168.99.2:6789/0 2 : cluster [INF] mon.ceph-node2 is new leader, mons ceph-node2,ceph-node3 in quorum (ranks 1,2)
2021-06-29 17:08:47.258215 mon.ceph-node2 mon.1 192.168.99.2:6789/0 3 : cluster [DBG] monmap e3: 3 mons at {ceph-node1=192.168.99.1:6789/0,ceph-node2=192.168.99.2:6789/0,ceph-node3=192.168.99.3:6789/0}
2021-06-29 17:08:47.258317 mon.ceph-node2 mon.1 192.168.99.2:6789/0 4 : cluster [DBG] fsmap
2021-06-29 17:08:47.258424 mon.ceph-node2 mon.1 192.168.99.2:6789/0 5 : cluster [DBG] osdmap e3782: 9 total, 9 up, 9 in
2021-06-29 17:08:47.258538 mon.ceph-node2 mon.1 192.168.99.2:6789/0 6 : cluster [DBG] mgrmap e268: ceph-node1(active), standbys: ceph-node3, ceph-node2
2021-06-29 17:08:47.258843 mon.ceph-node2 mon.1 192.168.99.2:6789/0 7 : cluster [WRN] Health check failed: 1/3 mons down, quorum ceph-node2,ceph-node3 (MON_DOWN)
2021-06-29 17:08:47.261904 mon.ceph-node2 mon.1 192.168.99.2:6789/0 8 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.186s > max 0.05s
2021-06-29 17:08:47.262203 mon.ceph-node2 mon.1 192.168.99.2:6789/0 9 : cluster [WRN] message from mon.2 was stamped 11.195340s in the future, clocks not synchronized
2021-06-29 17:08:47.263930 mon.ceph-node2 mon.1 192.168.99.2:6789/0 10 : cluster [WRN] overall HEALTH_WARN 1/3 mons down, quorum ceph-node2,ceph-node3
2021-06-29 17:08:50.842319 mon.ceph-node2 mon.1 192.168.99.2:6789/0 11 : cluster [WRN] Health check failed: clock skew detected on mon.ceph-node3 (MON_CLOCK_SKEW)
2021-06-29 17:08:53.897678 mon.ceph-node2 mon.1 192.168.99.2:6789/0 12 : cluster [WRN] message from mon.2 was stamped 11.199392s in the future, clocks not synchronized
2021-06-29 17:09:17.263184 mon.ceph-node2 mon.1 192.168.99.2:6789/0 13 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.1987s > max 0.05s
2021-06-29 17:09:20.318637 mon.ceph-node2 mon.1 192.168.99.2:6789/0 14 : cluster [WRN] message from mon.2 was stamped 11.199755s in the future, clocks not synchronized
2021-06-29 17:09:20.844879 mon.ceph-node2 mon.1 192.168.99.2:6789/0 15 : cluster [INF] Manager daemon ceph-node1 is unresponsive.  No standby daemons available.
2021-06-29 17:09:20.845031 mon.ceph-node2 mon.1 192.168.99.2:6789/0 16 : cluster [WRN] Health check failed: no active mgr (MGR_DOWN)
2021-06-29 17:09:20.850029 mon.ceph-node2 mon.1 192.168.99.2:6789/0 17 : cluster [DBG] mgrmap e269: no daemons active
2021-06-29 17:10:17.264398 mon.ceph-node2 mon.1 192.168.99.2:6789/0 20 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.1996s > max 0.05s
2021-06-29 17:11:27.829507 mon.ceph-node2 mon.1 192.168.99.2:6789/0 24 : cluster [WRN] message from mon.2 was stamped 11.201432s in the future, clocks not synchronized
2021-06-29 17:11:47.265702 mon.ceph-node2 mon.1 192.168.99.2:6789/0 25 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2007s > max 0.05s
2021-06-29 17:13:47.267079 mon.ceph-node2 mon.1 192.168.99.2:6789/0 32 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2022s > max 0.05s
2021-06-29 17:16:17.268446 mon.ceph-node2 mon.1 192.168.99.2:6789/0 35 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2043s > max 0.05s
2021-06-29 17:19:17.269758 mon.ceph-node2 mon.1 192.168.99.2:6789/0 40 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2068s > max 0.05s
2021-06-29 17:21:55.338312 mon.ceph-node2 mon.1 192.168.99.2:6789/0 44 : cluster [WRN] message from mon.2 was stamped 11.209843s in the future, clocks not synchronized
2021-06-29 17:22:47.270910 mon.ceph-node2 mon.1 192.168.99.2:6789/0 46 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2098s > max 0.05s
2021-06-29 17:26:47.272204 mon.ceph-node2 mon.1 192.168.99.2:6789/0 53 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2129s > max 0.05s
2021-06-29 17:31:17.273541 mon.ceph-node2 mon.1 192.168.99.2:6789/0 64 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 11.2165s > max 0.05s
2021-06-29 17:08:53.446973 mon.ceph-node3 mon.2 192.168.99.3:6789/0 1 : cluster [INF] mon.ceph-node3 calling monitor election
2021-06-29 17:35:36.506303 mon.ceph-node3 mon.2 192.168.99.3:6789/0 2 : cluster [WRN] message from mon.1 was stamped 0.162074s in the future, clocks not synchronized
2021-06-29 17:35:42.558266 mon.ceph-node3 mon.2 192.168.99.3:6789/0 3 : cluster [WRN] message from mon.1 was stamped 0.167346s in the future, clocks not synchronized
2021-06-29 17:36:07.818812 mon.ceph-node3 mon.2 192.168.99.3:6789/0 5 : cluster [WRN] message from mon.1 was stamped 0.168631s in the future, clocks not synchronized
2021-06-29 17:36:17.274935 mon.ceph-node2 mon.1 192.168.99.2:6789/0 71 : cluster [WRN] mon.2 192.168.99.3:6789/0 clock skew 0.1685s > max 0.05s
2021-06-29 17:38:13.290896 mon.ceph-node3 mon.2 192.168.99.3:6789/0 11 : cluster [WRN] message from mon.1 was stamped 0.170820s in the future, clocks not synchronized
2021-06-29 17:38:51.686573 mon.ceph-node2 mon.1 192.168.99.2:6789/0 74 : cluster [INF] osd.0 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686657 mon.ceph-node2 mon.1 192.168.99.2:6789/0 75 : cluster [INF] osd.1 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686700 mon.ceph-node2 mon.1 192.168.99.2:6789/0 76 : cluster [INF] osd.2 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686746 mon.ceph-node2 mon.1 192.168.99.2:6789/0 77 : cluster [INF] osd.3 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686789 mon.ceph-node2 mon.1 192.168.99.2:6789/0 78 : cluster [INF] osd.4 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686830 mon.ceph-node2 mon.1 192.168.99.2:6789/0 79 : cluster [INF] osd.5 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.686871 mon.ceph-node2 mon.1 192.168.99.2:6789/0 80 : cluster [INF] osd.6 marked down after no beacon for 900.759079 seconds
2021-06-29 17:38:51.692439 mon.ceph-node2 mon.1 192.168.99.2:6789/0 81 : cluster [WRN] Health check failed: 7 osds down (OSD_DOWN)
2021-06-29 17:38:51.692535 mon.ceph-node2 mon.1 192.168.99.2:6789/0 82 : cluster [WRN] Health check failed: 2 hosts (6 osds) down (OSD_HOST_DOWN)
2021-06-29 17:38:51.700691 mon.ceph-node2 mon.1 192.168.99.2:6789/0 83 : cluster [DBG] osdmap e3783: 9 total, 2 up, 9 in
2021-06-29 17:41:21.709107 mon.ceph-node2 mon.1 192.168.99.2:6789/0 88 : cluster [INF] Health check cleared: MON_CLOCK_SKEW (was: clock skew detected on mon.ceph-node3)
2021-06-29 17:48:46.710151 mon.ceph-node2 mon.1 192.168.99.2:6789/0 1 : cluster [INF] mon.ceph-node2 calling monitor election
2021-06-29 17:48:51.723029 mon.ceph-node2 mon.1 192.168.99.2:6789/0 2 : cluster [INF] mon.ceph-node2 is new leader, mons ceph-node2,ceph-node3 in quorum (ranks 1,2)
2021-06-29 17:48:51.726550 mon.ceph-node2 mon.1 192.168.99.2:6789/0 3 : cluster [DBG] monmap e3: 3 mons at {ceph-node1=192.168.99.1:6789/0,ceph-node2=192.168.99.2:6789/0,ceph-node3=192.168.99.3:6789/0}
2021-06-29 17:48:51.726606 mon.ceph-node2 mon.1 192.168.99.2:6789/0 4 : cluster [DBG] fsmap
2021-06-29 17:48:51.726684 mon.ceph-node2 mon.1 192.168.99.2:6789/0 5 : cluster [DBG] osdmap e3783: 9 total, 2 up, 9 in
2021-06-29 17:48:51.726782 mon.ceph-node2 mon.1 192.168.99.2:6789/0 6 : cluster [DBG] mgrmap e269: no daemons active
2021-06-29 17:48:51.726942 mon.ceph-node2 mon.1 192.168.99.2:6789/0 7 : cluster [WRN] overall HEALTH_WARN 7 osds down; 2 hosts (6 osds) down; no active mgr; 1/3 mons down, quorum ceph-node2,ceph-node3
2021-06-29 17:49:09.513535 mon.ceph-node3 mon.2 192.168.99.3:6789/0 1 : cluster [INF] mon.ceph-node3 calling monitor election
2021-06-29 17:49:09.527029 mon.ceph-node2 mon.1 192.168.99.2:6789/0 9 : cluster [INF] mon.ceph-node2 calling monitor election
2021-06-29 17:49:14.540594 mon.ceph-node2 mon.1 192.168.99.2:6789/0 10 : cluster [INF] mon.ceph-node2 is new leader, mons ceph-node2,ceph-node3 in quorum (ranks 1,2)
2021-06-29 17:49:14.544403 mon.ceph-node2 mon.1 192.168.99.2:6789/0 11 : cluster [DBG] monmap e3: 3 mons at {ceph-node1=192.168.99.1:6789/0,ceph-node2=192.168.99.2:6789/0,ceph-node3=192.168.99.3:6789/0}
2021-06-29 17:49:14.544510 mon.ceph-node2 mon.1 192.168.99.2:6789/0 12 : cluster [DBG] fsmap
2021-06-29 17:49:14.544635 mon.ceph-node2 mon.1 192.168.99.2:6789/0 13 : cluster [DBG] osdmap e3783: 9 total, 2 up, 9 in
2021-06-29 17:49:14.544771 mon.ceph-node2 mon.1 192.168.99.2:6789/0 14 : cluster [DBG] mgrmap e269: no daemons active
2021-06-29 17:49:14.545029 mon.ceph-node2 mon.1 192.168.99.2:6789/0 15 : cluster [WRN] overall HEALTH_WARN 7 osds down; 2 hosts (6 osds) down; no active mgr; 1/3 mons down, quorum ceph-node2,ceph-node3
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!