Proxmox cooles Transferfeature

Vor einiger Zeit gab es Probleme mit der Storage eines unserer Hostingsysteme. Die auf dem PCIE Port verbaute M.2 sprang offenbar unter Last vom PCIE-Bus, was zum Totalausfall der VMs führte, die darauf Ihre Daten gelagert hatten.

Proxmox cooles Transferfeature

Nachdem klar war, daß das ein Problem des Mainboards ist und damit nicht ohne weiteres lösbar war, wurde eine alternative Storage in den Server eingebaut, die als neues Heim für Daten der VMs dienen sollte. Jetzt mußten die Daten da aber auch hin und da kommt die Livemigration von Proxmox ins Spiel.

Damit ist es möglich die Festplatten der VM’s auf eine andere Storage zu verschieben, ohne das die VM gestoppt werden muß. Ich habe Euch da ein Logfile mitgebracht, damit Ihr Euch das mal „ansehen“ könnt:

create full clone of drive sata1[1] (local-lvm:vm-101-disk-2)
Formatting[2] ‚/disks//images/101/vm-101-disk-0.qcow2‘, fmt=qcow2 cluster_size=65536 extended_l2=off preallocation=metadata compression_type=zlib size=85899345920 lazy_refcounts=off refcount_bits=16
drive mirror is starting for drive-sata1
drive-sata1: transferred 0.0 B of 80.0 GiB (0.00%) in 0s
drive-sata1: transferred 457.0 MiB of 80.0 GiB (0.56%) in 1s
drive-sata1: transferred 932.0 MiB of 80.0 GiB (1.14%) in 2s
drive-sata1: transferred 1.4 GiB of 80.0 GiB (1.70%) in 3s
drive-sata1: transferred 1.8 GiB of 80.0 GiB (2.27%) in 4s
drive-sata1: transferred 2.3 GiB of 80.0 GiB (2.84%) in 5s
drive-sata1: transferred 2.7 GiB of 80.0 GiB (3.42%) in 6s
drive-sata1: transferred 3.2 GiB of 80.0 GiB (3.99%) in 7s
drive-sata1: transferred 3.7 GiB of 80.0 GiB (4.56%) in 8s
drive-sata1: transferred 4.1 GiB of 80.0 GiB (5.13%) in 9s
drive-sata1: transferred 4.6 GiB of 80.0 GiB (5.70%) in 10s
drive-sata1: transferred 5.0 GiB of 80.0 GiB (6.27%) in 11s
drive-sata1: transferred 5.5 GiB of 80.0 GiB (6.84%) in 12s
drive-sata1: transferred 5.9 GiB of 80.0 GiB (7.41%) in 13s
drive-sata1: transferred 6.4 GiB of 80.0 GiB (7.98%) in 14s
drive-sata1: transferred 6.8 GiB of 80.0 GiB (8.54%) in 15s
drive-sata1: transferred 7.3 GiB of 80.0 GiB (9.12%) in 16s
drive-sata1: transferred 7.8 GiB of 80.0 GiB (9.70%) in 17s
drive-sata1: transferred 8.2 GiB of 80.0 GiB (10.27%) in 18s
drive-sata1: transferred 8.7 GiB of 80.0 GiB (10.84%) in 19s
drive-sata1: transferred 9.1 GiB of 80.0 GiB (11.39%) in 20s
drive-sata1: transferred 9.6 GiB of 80.0 GiB (11.98%) in 21s
drive-sata1: transferred 10.0 GiB of 80.0 GiB (12.55%) in 22s

drive-sata1: transferred 78.6 GiB of 80.0 GiB (98.22%) in 2m 55s
drive-sata1: transferred 79.0 GiB of 80.0 GiB (98.77%) in 2m 56s
drive-sata1: transferred 79.5 GiB of 80.0 GiB (99.29%) in 2m 57s
drive-sata1: transferred 79.9 GiB of 80.0 GiB (99.82%) in 2m 58s
drive-sata1: transferred 80.0 GiB of 80.0 GiB (100.00%) in 2m 59s, ready
all ‚mirror‘ jobs are ready
drive-sata1: Completing block job_id…
drive-sata1: Completed successfully.
drive-sata1: mirror-job finished
TASK OK

[1]  SATA1 ist schlicht und ergreifen die Nummerierung von Proxmox für die erste (und einzige) „SATA“-Platte an der VM. SATA meint hier nur den simulierten Anschluss, nicht das echte Speichermedium. Die Tragödie mit Fedora und SCSI hatte ich schon einmal thematisiert.
[2] Der Vorgang erzeugt auf der (nicht als LVM realisierten) neuen Storage erstmal eine Imagedatei passender Größe.

Wie man sehen kann, wurden da 80GB in 3 Minuten verschoben, was einer Datenrate von 455 MB/s entspricht. Das war schon mal viel schneller als wir das bei der Storage erwartet hatten. Diese soll eigentlich nur als Überbrückung dienen, um die defekte NVME aus dem RAID zu bekommen, ohne das es zum Datenverlust kommt.

Durch die Livemigration bleiben die VMs am laufen und die Benutzer merken idealerweise nichts von dem Transfer. Natürlich haben wir den nicht zur Primetime gemacht, daher war in der VM tatsächlich nichts von dem Transfer zu merken. An der Stelle, ein großes Lob für das Proxmox Team.Man muß die VM dafür nicht mal rebooten.

Das Feature soll auch bei externen Storages funktionieren, so daß eine nachträgliche Anschaffung einer „echten ;)“ Storage-Unit den Transfer von VMs  dort hin ermöglicht und die ehemals lokalen Server zu reinen Webslaves werden.

Also traut Euch ruhig das mal auszuprobieren, wenn Ihr neue Storages in Euren Proxmox einbaut.

 

Proxmox: Fedora 40 zerstört Filesystem wegen uraltem SCSI Bug

Es läuft nicht gut für neue Fedora Versionen. Erst diese Gnome 47 Bugs auf dem Tablet bei Fedora 41, dann die Sache mit dem Wayland & Cinnamon und jetzt hat es uns bei Fedora 40 fast einen Server gekostet 🙁

Proxmox: Fedora 40 zerstört Filesystem wegen uraltem SCSI Bug

Jetzt muß ich ein bisschen ausholen:

Anfang des Jahres haben wir einen neuen Server mit Proxmox als Virtualisierungsgrundlage installiert. Wenn man der Hilfe zur Einrichtung von VMs und der besten Auswahl des Festplattentreiber glaubt, dann ist SCSI die beste Wahl: Beste Performance, abgehangenes System, seit 1995 im Einsatz, simuliert jede Menge Platten gleichzeitig usw.

Also wurden, ohne groß darüber nachzudenken, die VMs im Standardmodus mit SCSI angelegt. Dann zogen die Daten auf den Server und er lief genauso gut, wie wir das von der Hardware erwartet hatten. Bis letzten Mittwoch  22 Uhr 🙁

Gut das so etwas um 22 Uhr gemacht wird!

Um 22 Uhr am Mittwoch wurde das System von Fedora 39 auf Fedora 40 aktualisiert, da Fedora 39 EOL hatte. Da man das nicht simulieren kann, wie ein System reagiert, legt man davor einen Snapshot an. Dann kann man nach dem Update mit geringen Verlusten zurück zu einem funktionierenden System, wenn man denn merkt, daß es nicht geht 🙁

Eine halbe Stunde nach dem Update fiel mir auf, daß ich vergessen hatte das Datenbankupgradescipt laufen zu lassen, was per se nicht weiter schlimm war, da man das jederzeit nachholen kann. Das Mysql Upgradescript behebt bekannte Fehler der Vorgängerversionen an den Datenbeständen und optimiert das alles. Jetzt hatten wir da 8 GB in 400 Datenbanken drin, so daß Mysql ein bisschen was zu tun hatte und dann passierte es: Das System blieb stehen!

Load von 600, 100% iowait auf allen Kernen, keine Programmneustarts mehr und keine ersichtliche Ursache, was das ausgelöst hat auf einer 7 GB/s NVME.. und dann… puff.. löste sich der Stillstand von alleine nach einigen Minuten auf. Da dachte ich noch, daß Upgradescript wäre Schuld, was es im Prinzip auch war, aber es war nicht die Ursache, sondern nur der Auslöser. Die wahre Ursache zeigte sich erst, nachdem sich das mehrfach wiederholt hatte, ohne das das Script lief.

Der Kernel loggte es zum Glück

hier ein kleiner Auszug was passierte:

[ +4,915102] sd 2:0:0:0: ABORT operation timed-out.
[ +0,009657] scsi target2:0:0: TARGET RESET operation started
[Nov15 00:20] scsi target2:0:0: TARGET RESET operation timed-out.
[ +0,000006] scsi target2:0:1: TARGET RESET operation started
[Nov15 00:21] scsi target2:0:1: TARGET RESET operation timed-out.
[ +9,830340] sd 2:0:0:0: [sda] tag#389 ABORT operation started
[ +0,002342] sym0: SCSI BUS reset detected.
[ +0,007025] sym0: SCSI BUS has been reset.
[ +0,000016] sd 2:0:0:0: ABORT operation complete.
[ +3,193349] sd 2:0:1:0: Power-on or device reset occurred
[ +0,000056] sd 2:0:0:0: [sda] tag#389 BUS RESET operation started
[ +0,002306] sym0: SCSI BUS reset detected.
[ +0,007090] sym0: SCSI BUS has been reset.
[ +0,000010] sd 2:0:0:0: BUS RESET operation complete.
[ +10,058980] sd 2:0:0:0: Power-on or device reset occurred
[ +0,016222] sd 2:0:1:0: [sdb] tag#393 timing out command, waited 180s
[ +0,000005] sd 2:0:1:0: [sdb] tag#393 FAILED Result: hostbyte=DID_REQUEUE driverbyte=DRIVER_OK cmd_age=279s
[ +0,000002] sd 2:0:1:0: [sdb] tag#393 CDB: Write(10) 2a 00 00 00 a6 40 00 02 00 00
[ +0,000001] I/O error, dev sdb, sector 42560 op 0x1WRITE) flags 0x8800 phys_seg 64 prio class 2
[ +0,000003] I/O error, dev sdb, sector 42560 op 0x1WRITE) flags 0x8800 phys_seg 64 prio class 2
[ +0,000002] sd 2:0:1:0: [sdb] tag#394 timing out command, waited 180s
[ +0,000002] sd 2:0:1:0: [sdb] tag#394 FAILED Result: hostbyte=DID_REQUEUE driverbyte=DRIVER_OK cmd_age=279s
[ +0,000001] sd 2:0:1:0: [sdb] tag#394 CDB: Write(10) 2a 00 00 00 a3 40 00 03 00 00
[ +0,000000] I/O error, dev sdb, sector 41792 op 0x1WRITE) flags 0xc800 phys_seg 96 prio class 2
[ +0,000001] I/O error, dev sdb, sector 41792 op 0x1WRITE) flags 0xc800 phys_seg 96 prio class 2
[ +0,000002] sd 2:0:1:0: [sdb] tag#395 timing out command, waited 180s
[ +0,000001] sd 2:0:1:0: [sdb] tag#395 FAILED Result: hostbyte=DID_REQUEUE driverbyte=DRIVER_OK cmd_age=279s
[ +0,000001] sd 2:0:1:0: [sdb] tag#395 CDB: Write(10) 2a 00 00 00 a0 40 00 03 00 00
[ +0,000000] I/O error, dev sdb, sector 41024 op 0x1WRITE) flags 0xc800 phys_seg 96 prio class 2
[ +0,000001] I/O error, dev sdb, sector 41024 op 0x1WRITE) flags 0xc800 phys_seg 96 prio class 2
[ +0,000013] sd 2:0:1:0: [sdb] tag#396 timing out command, waited 180s
[ +0,000002] sd 2:0:1:0: [sdb] tag#396 FAILED Result: hostbyte=DID_REQUEUE driverbyte=DRIVER_OK cmd_age=279s
[ +0,000000] sd 2:0:1:0: [sdb] tag#396 CDB: Write(10) 2a 00 00 00 9e 40 00 02 00 00
[ +0,000001] I/O error, dev sdb, sector 40512 op 0x1WRITE) flags 0x8800 phys_seg 64 prio class 2
[ +0,000000] I/O error, dev sdb, sector 40512 op 0x1WRITE) flags 0x8800 phys_seg 64 prio class 2

Wie man sehen kann, sprang die simulierte Festplatte vom simulierten Bus runter. Wer bitte baut so eine Scheiße in ein Virtualisierungssystem ein?????? Stellt sich raus, niemand. Die Ursache liegt im Gastkernel, denn im RingBuffer vom Kernel von Proxmox war gar nichts zu sehen. Es handelte sich also um eine interne Angelegenheit der VM.

Aber wie beheben wir das?

Überlegung: „Der SCSI Treiber ist ein Sub-System vom Kernel, da wird wohl der aktuelle Kernel buggy sein.“

Also rebootet das System mit dem Kernel der vorher wunderbar lief. Das Systeme bootete und lief… denkste! Das ganze ging dermaßen in die Hose, daß der Kernel gecrasht ist!

Am Anfang lief es gut, aber das hat es mit dem Fedora 40 Kernel auch, bis es dann nicht mehr lief.

[ +26,879827] watchdog: BUG: soft lockup – CPU#1 stuck for 118s! [kworker/1:3:120797]
[ +0,000015] Modules linked in: xt_owner ipt_REJECT nf_reject_ipv4 xt_connlimit nf_conncount nf_conntrack nf_defrag_ipv6 nf_defrag_ip
v4 ip6table_filter ip6_tables xt_multiport iptable_filter ip_tables cfg80211 rfkill sunrpc intel_rapl_msr intel_rapl_common intel_unco
re_frequency_common nfit libnvdimm kvm_intel kvm irqbypass i2c_piix4 rapl virtio_balloon joydev fuse loop nfnetlink crct10dif_pclmul c
rc32_pclmul crc32c_intel polyval_clmulni bochs polyval_generic ghash_clmulni_intel sha512_ssse3 drm_vram_helper sha256_ssse3 drm_ttm_h
elper virtio_net ttm sym53c8xx sha1_ssse3 net_failover scsi_transport_spi failover serio_raw ata_generic pata_acpi qemu_fw_cfg
[ +0,000024] CPU: 1 PID: 120797 Comm: kworker/1:3 Tainted: G L 6.8.11-200.fc39.x86_64 #1
[ +0,000002] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
[ +0,000001] Workqueue: events netstamp_clear
[ +0,000006] RIP: 0010:smp_call_function_many_cond+0x12e/0x560
[ +0,000004] Code: 73 35 48 63 e8 49 8b 1f 48 81 fd 00 20 00 00 0f 83 f6 03 00 00 48 03 1c ed a0 4c c0 bb 8b 53 08 48 89 de 83 e2 01
74 0a f3 90 <8b> 4e 08 83 e1 01 75 f6 83 c0 01 eb b1 48 83 c4 40 5b 5d 41 5c 41
[ +0,000001] RSP: 0018:ff36e8b984593d60 EFLAGS: 00000202
[ +0,000001] RAX: 0000000000000000 RBX: ff26fb3f2483ce00 RCX: 0000000000000001
[ +0,000001] RDX: 0000000000000001 RSI: ff26fb3f2483ce00 RDI: ff26fb3940156b98
[ +0,000000] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000006
[ +0,000001] R10: 0000000000000002 R11: 0000000000000000 R12: ff26fb3f248b5ac0
[ +0,000000] R13: 0000000000000001 R14: 0000000000000001 R15: ff26fb3f248b5ac0
[ +0,000001] FS: 0000000000000000(0000) GS:ff26fb3f24880000(0000) knlGS:0000000000000000
[ +0,000001] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ +0,000001] CR2: 000014bce6b69d60 CR3: 000000010d428003 CR4: 0000000000771ef0
[ +0,000002] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ +0,000001] DR3: 0000000000000000 DR6: 00000000fffe07f0 DR7: 0000000000000400
[ +0,000000] PKRU: 55555554
[ +0,000001] Call Trace:
[ +0,000002] <IRQ>
[ +0,000002] ? watchdog_timer_fn+0x1e6/0x270
[ +0,000003] ? __pfx_watchdog_timer_fn+0x10/0x10
[ +0,000002] ? __hrtimer_run_queues+0x113/0x280
[ +0,000001] ? ktime_get_update_offsets_now+0x49/0x110
[ +0,000004] ? hrtimer_interrupt+0xf8/0x230
[ +0,000001] ? __sysvec_apic_timer_interrupt+0x4d/0x140
[ +0,000003] ? sysvec_apic_timer_interrupt+0x6d/0x90
[ +0,000002] </IRQ>
[ +0,000001] <TASK>
[ +0,000000] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ +0,000004] ? smp_call_function_many_cond+0x12e/0x560
[ +0,000001] ? __pfx_do_sync_core+0x10/0x10
[ +0,000003] on_each_cpu_cond_mask+0x24/0x40
[ +0,000001] text_poke_bp_batch+0xbe/0x300
[ +0,000001] ? arch_jump_label_transform_queue+0x57/0x80
[ +0,000003] text_poke_finish+0x1f/0x30
[ +0,000002] arch_jump_label_transform_apply+0x1a/0x30
[ +0,000002] static_key_enable_cpuslocked+0x63/0x90
[ +0,000003] static_key_enable+0x1a/0x20
[ +0,000001] process_one_work+0x173/0x340
[ +0,000004] worker_thread+0x27b/0x3a0
[ +0,000002] ? __pfx_worker_thread+0x10/0x10
[ +0,000001] kthread+0xe5/0x120
[ +0,000002] ? __pfx_kthread+0x10/0x10
[ +0,000001] ret_from_fork+0x31/0x50
[ +0,000002] ? __pfx_kthread+0x10/0x10

Ihr könnt Euch sicher denken, daß derartige IO Fehler nicht gut für das Filesystem und den Datenbestand sind, wenn man auch noch hart reseten muß, um die VM wieder zu starten.  Datenverlust vorprogrammiert.

Nächster Versuch

Überlegung: „Das ist SCSI, aber Proxmox kann auch SATA.“

Also biss ich um 2:30 Uhr in den sauren Apfel und wir hatten Glück, das noch genug Platz auf der Storage war, wir reden hier nämlich von TBweise Platz:

  1. VM gestoppt
  2. neue Festplatten exakt gleicher Größe angelegt, aber als SATA Gerät.
  3. VM mit Fedora 38 LiveDisk gestartet
  4. Alte Platten 1:1 auf die neuen Platten kopiert:
    dd if=/dev/sdalt of=/dev/sdneu bs=128M status=progress
  5. VM umkonfiguriert, so daß SATA zuerst bootet
  6. VM gestartet
  7. gebannt auf den RingBuffer vom Kerne gestarrt

Da die Maschine beim nächtlichen Backup abgestürzt war, muß das eh nachgeholt werden und wenn dieser Stresstest durchgehen würde, dann wäre das Problem bestimmt gelöst. Also startete das Backup durch und siehe da, nicht ein aufmucken, keine Einträge im Kernel. Geschafft!

Gegen 5 war ich dann endlich im Bett, weil wir natürlich im jugendlichen Leichtsinn mehr als einen Server auf dem Proxmox aktualisiert hatten und die brauchten die gleiche Prozedur 🙁

Die Geister von 2015 holen einen immer wieder ein

Ihr lest richtig: 2015. 2015 wurde ein Fehler im Linux Kernel SCSI Subsystem behoben, der genau diese Auswirkungen hatte. Und welche waren das? Das SCSI Subsystem hat auf die Steuersignale vom Controller nicht richtig reagiert und dann eine Art Deadlock erschaffen, wenn da zuviele IO Requests durchgingen, der erst nach 5-10 MInuten aufgelöst wurde, also genau das, was wir jetzt auch hatten: Lahmarsch IO => läuft / High Performance Kleinteil IO => Deadlock / 5-10Minuten bis Auflösung.

Das nennt man eine Übersättigung des Treibers mit IO-Requests, passiert, wenn z.b. zig tausende Request jeweils nur einen Block haben wollen, statt in weniger Requests einfach größere Blöcke zu transportieren. Darf natürlich trotzdem nicht passieren, sondern der Treiber muß die Prozesse blockieren, bis wieder genug Reserven frei sind, was beim SATA Driver offensichtlich der Fall ist, beim SCSI Treiber gabs wohl vermutlich irgendwann zwischen 2015 und heute eine REGRESSION, die den alten Bug wieder eingebaut hat. Das letzte mal, daß ich so einen Fehler gesehen habe, da hatte die Jahreszahl noch 2 Nullen drin 😉

Jetzt ist es aber viel zu leicht, nur dem Kernel die Schuld zu geben, denn wir hatten mit Fedora 39 den gleichen Kernel ( Version ) laufen, wie mit Fedora 40 und der zeigte das Problem ja auch erst zusammen mit dem Rest von Fedora 40 und nicht schon mit Fedora 39. Da muß also etwas in der Distro sein, daß das ausgelöst hat!

Reaktionen

Nicht so gut gelaufen. Wir haben Montag und ich habe bei Proxmox und beim Fedora im Kernelteam ( weil ist am Ende halt doch ein Kernelbug ) noch in der Nacht vom Mittwoch auf Donnerstag letzter Woche einen Bugreport bzw. einen Foreneintrag eröffnet.

Keine der beiden Parteien äußerte sich, wobei ich das bei Proxmox verstehen kann, ist ja nur das Forum und ohne Subscription gibt es keinen Support. Das auch niemand aus der Community geantwortet hat, das ist dann doch bedenklich, weil das Forum von Proxmox ist genau der Ort, wo das schon 2015 gefunden wurde!

Das das Kernelteam jetzt erstmal vor einem fetten Haufen Mist steht und nicht weiß, wo es da anfangen soll mit rumstochern, kann ich auch verstehen, zumal das Fedora Maintainerteam ja nicht die Kernelentwickler sind. Aber gar nicht zu reagieren auf so einen Fatalen Fehler, der ein Produktionssystem zu einem Datenverlust geleitet hat, das geht nun mal auch nicht.

Zum Glück habe ich einen von denen nächsten Donnerstag zu meiner privaten Verfügbarkeit, da werde ich ihn mal drauf ansprechen, wieso da nichts passiert 😀

Linux am Dienstag – Programm für den 6.2.2024

Das mit der IT-Newsflaute scheint ja vorbei zu sein, trotzdem peppen wir unser Programm mit ein bisschen Proxmox auf.

Linux am Dienstag: Programm für den 6.2.2024

u.a. im Programm am 6.2.2024, ab 19 Uhr:

Vortrag – Proxmox und das LVM Problem (Marius)
Sicherheit – AnyDesk gehackt
Sicherheit – HP gehackt
Sicherheit – Ivanti VPN gehackt.
Sicherheit – Dockerhostsysteme hackbar

und andere IT-Newsbeiträge aus aller Welt. Wie jede Woche per Videokonferenz auf https://meet.cloud-foo.de/Linux .

Hinweis: Die bisherigen Vorträge findet man unter https://linux-am-dienstag.de/archiv/ .