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:
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
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