Absturz ganzes Proxmox-Cluster mit 12 Nodes / Segfault cfs_loop

[fstrankowski]

Hallo,

wir haben am Wochenende einen massiven Absturz eines unserer Proxmox-Cluster erlebt. Von jetzt auf gleich ist ein ganzes Cluster abgestürzt, zeitgleich. Hier der Auszug aus der messages:

Feb 24 07:25:59 PX20-WW-SN06 kernel: [1448261.497103] cfs_loop[12091]: segfault at 7fbb0bd266ac ip 000055f7c1f366b0 sp 00007fbaa238f3b8 error 4 in pmxcfs[55f7c1f19000+2b000]

Feb 24 07:25:59 PX20-WW-N09 kernel: [1447565.088508] cfs_loop[11236]: segfault at 7fdcbbd0c65c ip 00005558baf636b0 sp 00007fdc52b853b8 error 4 in pmxcfs[5558baf46000+2b000]

Feb 24 07:25:59 PX20-WW-N07 kernel: [1446331.532136] cfs_loop[11216]: segfault at 7fd343d2522c ip 000056445e9fc6b0 sp 00007fd2da15e3b8 error 4 in pmxcfs[56445e9df000+2b000]

Das zieht sich durch unser gesamtes Cluster. Alles war offline. Jede Node hat das Netzwerk getrennt. Ich habe hier einen ähnlichen Thread gefunden, hier wurde jedoch gesagt, dass dieser Fehler nicht gedebuggt werden konnte.

 

[sb-jw]

Hast du ein paar mehr Infos? Wie ist das Cluster aufgebaut? Welche Netzwerk Hardware wird verwendet? Welche Hardware für die Nodes wird verwendet? Was gibt die Auswertung der Metriken her? Welche Version läuft drauf?

 

[fstrankowski]

SIcher. Wir betreiben 3 Cluster, jeweils über 3 Rechenzentren verteilt. Ein Cluster (über 3 RZ) ist komplett ausgefallen aufgrund des o.g. Fehlers. Alle zu exakt dem gleichen Zeitpunkt (Sekunden genau). Monitoring hat bis zuletzt funktioniert. Ist dann einfach ausgestiegen, da das ganze Cluster auf einen Schlag gerebootet wurde. Daher sieht man dort nichts besonderes.

Spoiler: Hardware

CPU:

2x Intel(R) Xeon(R) Silver 4114 CPU @ 2.20GHz
oder
2x Intel(R) Xeon(R) CPU E5-2620 v3 @ 2.40GHz

RAM: 256G

STORAGE: SSD only Ceph cluster
NIC: jeweils 2x 10G vLAG (LACP)

Spoiler: PROXMOX

PROXMOX: pve-manager/5.3-8/2929af8e (running kernel: 4.15.18-10-pve)
CEPH: ceph version 12.2.10 (fc2b1783e3727b66315cc667af9d663d30fe7ed4) luminous (stable)

Spoiler: DPKG -L

https://nopaste.chaoz-irc.net/view/564221c5

Spoiler: /VAR/LOG/MESSAGES

Die letzten Zeilen vor dem Reboot:

Feb 24 06:25:03 PX20-WW-N09 liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="1394" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Feb 24 06:25:03 PX20-WW-N09 liblogging-stdlog:  [origin software="rsyslogd" swVersion="8.24.0" x-pid="1394" x-info="http://www.rsyslog.com"] rsyslogd was HUPed
Feb 24 07:25:59 PX20-WW-N09 kernel: [1447565.088508] cfs_loop[11236]: segfault at 7fdcbbd0c65c ip 00005558baf636b0 sp 00007fdc52b853b8 error 4 in pmxcfs[5558baf46000+2b000]
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000] Linux version 4.15.18-10-pve (build@pve) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1)) #1 SMP PVE 4.15.18-32 (Sat, 19 Jan 2019 10:09:37 +0100) ()
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-4.15.18-10-pve root=/dev/mapper/pve-root ro rootdelay=30 quiet
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000] KERNEL supported cpus:
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000]   Intel GenuineIntel
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000]   AMD AuthenticAMD
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000]   Centaur CentaurHauls
Feb 24 07:29:48 PX20-WW-N09 kernel: [    0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'

Spoiler: BROCADE LOGS (SWITCHING)

2019/02/24-07:27:07, [NSM-1025], 227467, SW/0 | Active | RBridge ID 27 has left Port-channel 209. Port-channel has only RBridge ID  28 and is no longer a vLAG.
2019/02/24-07:28:10, [NSM-1025], 227470, SW/0 | Active | RBridge ID 27 has left Port-channel 207. Port-channel has only RBridge ID  28 and is no longer a vLAG.
2019/02/24-07:28:11, [NSM-1025], 227472, SW/0 | Active | RBridge ID 27 has left Port-channel 208. Port-channel has only RBridge ID  28 and is no longer a vLAG.
2019/02/24-07:28:17, [NSM-1025], 227474, SW/0 | Active | RBridge ID 27 has left Port-channel 220. Port-channel has only RBridge ID  28 and is no longer a vLAG.

2019/02/24-07:28:14, [NSM-1025], 178993, SW/0 | Active | RBridge ID 40 has left Port-channel 201. Port-channel has only RBridge ID  39 and is no longer a vLAG.
2019/02/24-07:28:16, [NSM-1025], 178994, SW/0 | Active | RBridge ID 39 has left Port-channel 209. Port-channel has only RBridge ID  40 and is no longer a vLAG.
2019/02/24-07:28:18, [NSM-1025], 178996, SW/0 | Active | RBridge ID 39 has left Port-channel 207. Port-channel has only RBridge ID  40 and is no longer a vLAG.
2019/02/24-07:28:30, [NSM-1025], 179001, SW/0 | Active | RBridge ID 39 has left Port-channel 208. Port-channel has only RBridge ID  40 and is no longer a vLAG.

2019/02/24-07:28:06, [NSM-1025], 11735, SW/0 | Active | RBridge ID 51 has left Port-channel 209. Port-channel has only RBridge ID  52 and is no longer a vLAG.
2019/02/24-07:28:16, [NSM-1025], 11737, SW/0 | Active | RBridge ID 51 has left Port-channel 208. Port-channel has only RBridge ID  52 and is no longer a vLAG.
2019/02/24-07:28:23, [NSM-1025], 11742, SW/0 | Active | RBridge ID 51 has left Port-channel 220. Port-channel has only RBridge ID  52 and is no longer a vLAG.

 

[t.lamprecht]

FYI,

pveversion -v

gibt die relevante versions info an, dpkg -l geht aber natürlich auch

Ein Cluster (über 3 RZ)

Wie über 3 Rechenzentren? Wie schaut den die Netzwerkstruktur aus, ist corosync noch für multicast konfiguriert?

Wie lang liefen die nodes den (uptime, circa)? Benützt Ihr HA?

"error 4" ist ein "user mode read" wo die page nicht gefunden wurde, es schau ähnlich aus wie der verlinkte Thread, die stelle ist aber nicht dieselbe:

addr2line -e /usr/bin/pmxcfs -fCi $(printf "%x" $[0x000055f7c1f366b0 - 0x55f7c1f19000])
clog_entry_sort_fn
/home/builder/source/build/src/logger.c:315

deutet drauf hin das irgendwo ein unbekanntes/falsche clog_entry objekt reinkommt. Aufgrund der Seltenheit des Auftretens ist das sehr schwierig hier nachzuvollziehen, aber wir werden uns den logger code nochmals genauer anschauen.

 

[fstrankowski]

Antworten Inline:

Wie über 3 Rechenzentren? Wie schaut den die Netzwerkstruktur aus, ist corosync noch für multicast konfiguriert?

3 physisch voneinander getrennte Standorte. Abstand wie folgt: RZ1 <--- 600m ---> RZ2 <--- 3KM ---> RZ3.
Multicast ist korrekt.

Wie lang liefen die nodes den (uptime, circa)? Benützt Ihr HA?

Circa 1 Woche, wir benutzen HA auf allen Nodes. (Hat hier nichts gebracht, da das gesamte Cluster offline war. Glücklicherweise betreiben wir ein 2. Cluster mit den gleichen Diensten als FO)

deutet drauf hin das irgendwo ein unbekanntes/falsche clog_entry objekt reinkommt. Aufgrund der Seltenheit des Auftretens ist das sehr schwierig hier nachzuvollziehen, aber wir werden uns den logger code nochmals genauer anschauen.

Wie kann dieses Phänomen dazu führen, dass _alle_ Nodes restarten und nicht eine gefenced wird?

 

[fstrankowski]

Wir glauben den Ursprung gefunden zu haben, dies ist der einzige Server, der trotz Segfault nicht neugestartet worden ist:

Feb 24 07:25:58 PX20-WW-N07 pmxcfs[11213]: [status] notice: received log
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [dcdb] notice: members: 2/11238, 3/12062, 4/11417, 5/12088, 6/11411, 7/11247, 8/1122
6, 9/11253, 10/11213, 11/11195, 12/11233
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [dcdb] notice: starting data syncronisation
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [status] notice: members: 2/11238, 3/12062, 4/11417, 5/12088, 6/11411, 7/11247, 8/11
226, 9/11253, 10/11213, 11/11195, 12/11233
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [status] notice: starting data syncronisation
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [dcdb] notice: received sync request (epoch 2/11238/0000002A)
Feb 24 07:25:59 PX20-WW-N07 pmxcfs[11213]: [status] notice: received sync request (epoch 2/11238/0000002A)
Feb 24 07:25:59 PX20-WW-N07 kernel: [1446331.532136] cfs_loop[11216]: segfault at 7fd343d2522c ip 000056445e9fc6b0 sp 00007fd2d
a15e3b8 error 4 in pmxcfs[56445e9df000+2b000]

Es hat also definitiv mit dem Sync-Prozess des CFS zu tun. Jetzt ist die Frage, wie kommen wir an die Daten, welche dort ausschlaggebend für den Sync-Fail waren. Habe mal mit echo "1" > /etc/pve/.debug probiert hier Infos zu bekommen, aber das können wir ja nicht einen Monat laufen lassen, das ist ja so verbose [..]

 

[t.lamprecht]

Wir glauben den Ursprung gefunden zu haben, dies ist der einzige Server, der trotz Segfault nicht neugestartet worden ist:

Der segfault ist nicht der direkte Grund für den neustart würd ich mal behaupten. Es ist eher so, pmxcfs segfaulted -> cluster stack kaputt, d.h. dann falls HA services auf der node aktiv sind und so der Watchdog aufgezogen ist wird dieser nach 60 sekunden getriggert. Kann es sein das auf der "überlebenden" node einfach kein watchdog aktiv war, da sich (seit letzten restart vom pve-ha-lrm.service) kein HA service befand?

Es hat also definitiv mit dem Sync-Prozess des CFS zu tun.

Wieso definitiv, in es könnte auch der nächste log request gewesen sein (da segfault im logger.c), oder haben Sie da näheren verdacht? Denn auch wenn es in der selben Sekunde war kann auf einen modernen System in einer Sekunde schon extrem viel verschiedenes passieren.

Habe mal mit echo "1" > /etc/pve/.debug probiert hier Infos zu bekommen, aber das können wir ja nicht einen Monat laufen lassen, das ist ja so verbose [..]

würde denk ich auch nicht 100% was nützen, besser das pve-cluster-dbgsym Paket installieren und coredumps anmachen, so haben wir volle info und stacktraces falls es nochmals passieren sollte.