unerwarteter Crash einer VM, wiederholt

T

thoralf

New Member
Nov 29, 2023
10
0
1
Ich habe in den letzten Tagen wiederholt (2 oder 3x in den letzten 2 Wochen) einen Crash einer VM erlebt, die bisher recht zuverlässig gelaufen ist.
Die VM läuft auf einem AMD Ryzen Node.

Fehlermeldung:

Code: 
Jul 09 06:50:47 evcc kernel: BUG: unable to handle page fault for address: ffffffffaf67d513
Jul 09 06:50:47 evcc kernel: #PF: supervisor write access in kernel mode
Jul 09 06:50:47 evcc kernel: #PF: error_code(0x0003) - permissions violation
Jul 09 06:50:47 evcc kernel: PGD d015067 P4D d015067 PUD d016063 PMD b6001e1
Jul 09 06:50:47 evcc kernel: Oops: 0003 [#2] PREEMPT SMP PTI
Jul 09 06:50:47 evcc kernel: CPU: 0 PID: 620 Comm: evcc Tainted: G      D            6.1.0-37-amd64 #1  Debian 6.1.140-1
Jul 09 06:50:47 evcc kernel: Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 4.2025.02-3 04/03/2025
Jul 09 06:50:47 evcc kernel: RIP: 0010:kvm_kick_cpu+0x23/0x30
Jul 09 06:50:47 evcc kernel: Code: 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 63 ff 53 48 c7 c0 f8 99 01 00 31 db 48 8b 14 fd 60 8b a1 b0 0f b7 0c 02 b8 05 00 00 00 <0f> 01 c1 5b e9 04 48 d8 00 0f 1f 40 00 0f 1f>
Jul 09 06:50:47 evcc kernel: RSP: 0018:ffffa77d8227baf8 EFLAGS: 00010046
Jul 09 06:50:47 evcc kernel: RAX: 0000000000000005 RBX: 0000000000000000 RCX: 0000000000000001
Jul 09 06:50:47 evcc kernel: RDX: ffff8bf71e300000 RSI: 00000000000000ff RDI: 0000000000000001
Jul 09 06:50:47 evcc kernel: RBP: 0000000000031a80 R08: ffff8bf71febfec0 R09: 000000000000015d
Jul 09 06:50:47 evcc kernel: R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000000
Jul 09 06:50:47 evcc kernel: R13: 0000000000000283 R14: ffff8bf6c7a124f4 R15: 0000000000000001
Jul 09 06:50:47 evcc kernel: FS:  000000c000e40098(0000) GS:ffff8bf71e200000(0000) knlGS:0000000000000000
Jul 09 06:50:47 evcc kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 09 06:50:47 evcc kernel: CR2: ffffffffaf67d513 CR3: 00000000032bc000 CR4: 00000000000006f0
Jul 09 06:50:47 evcc kernel: Call Trace:
Jul 09 06:50:47 evcc kernel:  <TASK>
Jul 09 06:50:47 evcc kernel:  __pv_queued_spin_unlock_slowpath+0x98/0xd0
Jul 09 06:50:47 evcc kernel:  __raw_callee_save___pv_queued_spin_unlock_slowpath+0x11/0x24
Jul 09 06:50:47 evcc kernel:  .slowpath+0x9/0x16
Jul 09 06:50:47 evcc kernel:  _raw_spin_unlock_irqrestore+0xa/0x40
Jul 09 06:50:47 evcc kernel:  try_to_wake_up+0xd9/0x540
Jul 09 06:50:47 evcc kernel:  wake_up_q+0x4a/0x90
Jul 09 06:50:47 evcc kernel:  futex_wake+0x151/0x180
Jul 09 06:50:47 evcc kernel:  do_futex+0xda/0x1b0
Jul 09 06:50:47 evcc kernel:  __x64_sys_futex+0x8e/0x1d0
Jul 09 06:50:47 evcc kernel:  do_syscall_64+0x55/0xb0
Jul 09 06:50:47 evcc kernel:  ? ksys_write+0xd4/0xf0
Jul 09 06:50:47 evcc kernel:  ? exit_to_user_mode_prepare+0x40/0x1e0
Jul 09 06:50:47 evcc kernel:  ? syscall_exit_to_user_mode+0x1e/0x40
Jul 09 06:50:47 evcc kernel:  ? do_syscall_64+0x61/0xb0
Jul 09 06:50:47 evcc kernel:  ? _raw_spin_unlock+0xa/0x30
Jul 09 06:50:47 evcc kernel:  ? finish_task_switch.isra.0+0x90/0x2d0
Jul 09 06:50:47 evcc kernel:  ? __schedule+0x355/0x9e0
Jul 09 06:50:47 evcc kernel:  ? switch_fpu_return+0x4c/0xd0
Jul 09 06:50:47 evcc kernel:  ? exit_to_user_mode_prepare+0x14b/0x1e0
Jul 09 06:50:47 evcc kernel:  ? syscall_exit_to_user_mode+0x1e/0x40
Jul 09 06:50:47 evcc kernel:  ? do_syscall_64+0x61/0xb0
Jul 09 06:50:47 evcc kernel:  ? swake_up_one+0x36/0x60
Jul 09 06:50:47 evcc kernel:  ? _raw_spin_unlock_irqrestore+0xa/0x40
Jul 09 06:50:47 evcc kernel:  ? rcu_core+0x1f2/0x4d0
Jul 09 06:50:47 evcc kernel:  ? handle_softirqs+0xd7/0x280
Jul 09 06:50:47 evcc kernel:  ? __irq_exit_rcu+0x3b/0xe0
Jul 09 06:50:47 evcc kernel:  ? exit_to_user_mode_prepare+0x40/0x1e0
Jul 09 06:50:47 evcc kernel:  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
Jul 09 06:50:47 evcc kernel: RIP: 0033:0x484143
Jul 09 06:50:47 evcc kernel: Code: 24 20 c3 cc cc cc cc 48 8b 7c 24 08 8b 74 24 10 8b 54 24 14 4c 8b 54 24 18 4c 8b 44 24 20 44 8b 4c 24 28 b8 ca 00 00 00 0f 05 <89> 44 24 30 c3 cc cc cc cc cc cc cc cc cc cc>
Jul 09 06:50:47 evcc kernel: RSP: 002b:000000c0000b9e38 EFLAGS: 00000202 ORIG_RAX: 00000000000000ca
Jul 09 06:50:47 evcc kernel: RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 0000000000484143
Jul 09 06:50:47 evcc kernel: RDX: 0000000000000001 RSI: 0000000000000081 RDI: 000000c001382148
Jul 09 06:50:47 evcc kernel: RBP: 000000c0000b9e88 R08: 0000000000000000 R09: 0000000000000000
Jul 09 06:50:47 evcc kernel: R10: 0000000000000000 R11: 0000000000000202 R12: 000000c0000b9ea0
Jul 09 06:50:47 evcc kernel: R13: 000000c001c00ae0 R14: 000000c001156540 R15: 0000000000000000
Jul 09 06:50:47 evcc kernel:  </TASK>
Jul 09 06:50:47 evcc kernel: Modules linked in: binfmt_misc nls_ascii nls_cp437 bochs drm_vram_helper vfat cfg80211 drm_ttm_helper ttm drm_kms_helper virtio_console virtio_balloon fat rfkill button evdev joy>
Jul 09 06:50:47 evcc kernel: CR2: ffffffffaf67d513
Jul 09 06:50:47 evcc kernel: ---[ end trace 0000000000000000 ]---
Jul 09 06:50:47 evcc kernel: RIP: 0010:kvm_kick_cpu+0x23/0x30
Jul 09 06:50:47 evcc kernel: Code: 1f 84 00 00 00 00 00 0f 1f 44 00 00 48 63 ff 53 48 c7 c0 f8 99 01 00 31 db 48 8b 14 fd 60 8b a1 b0 0f b7 0c 02 b8 05 00 00 00 <0f> 01 c1 5b e9 04 48 d8 00 0f 1f 40 00 0f 1f>
Jul 09 06:50:47 evcc kernel: RSP: 0018:ffffa77d800a3da0 EFLAGS: 00010046
Jul 09 06:50:47 evcc kernel: RAX: 0000000000000005 RBX: 0000000000000000 RCX: 0000000000000001
Jul 09 06:50:47 evcc kernel: RDX: ffff8bf71e300000 RSI: 00000000000000ff RDI: 0000000000000001
Jul 09 06:50:47 evcc kernel: RBP: ffff8bf71e338500 R08: ffff8bf71febfec0 R09: 00000000000001c9
Jul 09 06:50:47 evcc kernel: R10: 0000000000000000 R11: 0000000000000000 R12: ffff8bf6c19d7a00
Jul 09 06:50:47 evcc kernel: R13: 0000000000000001 R14: 0000000000000001 R15: ffff8bf71e331480
Jul 09 06:50:47 evcc kernel: FS:  000000c000e40098(0000) GS:ffff8bf71e200000(0000) knlGS:0000000000000000
Jul 09 06:50:47 evcc kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jul 09 06:50:47 evcc kernel: CR2: ffffffffaf67d513 CR3: 00000000032bc000 CR4: 00000000000006f0
Jul 09 06:50:47 evcc kernel: note: evcc[620] exited with irqs disabled
Jul 09 06:50:47 evcc kernel: note: evcc[620] exited with preempt_count 2
Jul 09 06:50:47 evcc kernel: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
Jul 09 06:50:47 evcc kernel: rcu:         1-...!: (0 ticks this GP) idle=0324/1/0x4000000000000002 softirq=839512/839512 fqs=0
Jul 09 06:50:47 evcc kernel:         (detected by 0, t=5253 jiffies, g=1204569, q=56 ncpus=2)
Jul 09 06:50:47 evcc kernel: Sending NMI from CPU 0 to CPUs 1:
Jul 09 06:50:47 evcc kernel: NMI backtrace for cpu 1 skipped: idling at native_halt+0xa/0x10
Jul 09 06:50:47 evcc kernel: rcu: rcu_preempt kthread timer wakeup didn't happen for 5253 jiffies! g1204569 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
Jul 09 06:50:47 evcc kernel: rcu:         Possible timer handling issue on cpu=1 timer-softirq=874118

Bisher lief die VM auf einem anderen Node (Intel N95).
Mir ist nicht klar, warum die VM crashed.
 
Last edited:
Hallo thoralf! Kannst du uns bitte ebenfalls folgende Informationen geben:
  1. Informationen über die Hardware.
  2. Output von pveversion -v
  3. VM-Konfiguration (output von qm config <VMID>)
  4. Welches Betriebssystem läuft in der VM?
  5. Journal vom Host rund um die Zeit des Absturzes: journalctl --since "2025-07-09 06:00" --until "2025-07-09 07:00"
 
1. ACEMAGIC AM06Pro Mini-PC AMD Ryzen 7

2.
Code: 
proxmox-ve: 8.4.0 (running kernel: 6.8.12-11-pve)
pve-manager: 8.4.1 (running version: 8.4.1/2a5fa54a8503f96d)
proxmox-kernel-helper: 8.1.1
proxmox-kernel-6.8.12-11-pve-signed: 6.8.12-11
proxmox-kernel-6.8: 6.8.12-11
proxmox-kernel-6.8.12-9-pve-signed: 6.8.12-9
amd64-microcode: 3.20250311.1~deb12u1
ceph-fuse: 17.2.8-pve2
corosync: 3.1.9-pve1
criu: 3.17.1-2+deb12u1
frr-pythontools: 10.2.2-1+pve1
glusterfs-client: 10.3-5
ifupdown2: 3.2.0-1+pmx11
ksm-control-daemon: 1.5-1
libjs-extjs: 7.0.0-5
libknet1: 1.30-pve2
libproxmox-acme-perl: 1.6.0
libproxmox-backup-qemu0: 1.5.1
libproxmox-rs-perl: 0.3.5
libpve-access-control: 8.2.2
libpve-apiclient-perl: 3.3.2
libpve-cluster-api-perl: 8.1.1
libpve-cluster-perl: 8.1.1
libpve-common-perl: 8.3.1
libpve-guest-common-perl: 5.2.2
libpve-http-server-perl: 5.2.2
libpve-network-perl: 0.11.2
libpve-rs-perl: 0.9.4
libpve-storage-perl: 8.3.6
libspice-server1: 0.15.1-1
lvm2: 2.03.16-2
lxc-pve: 6.0.0-1
lxcfs: 6.0.0-pve2
novnc-pve: 1.6.0-2
proxmox-backup-client: 3.4.2-1
proxmox-backup-file-restore: 3.4.2-1
proxmox-firewall: 0.7.1
proxmox-kernel-helper: 8.1.1
proxmox-mail-forward: 0.3.3
proxmox-mini-journalreader: 1.5
proxmox-offline-mirror-helper: 0.6.7
proxmox-widget-toolkit: 4.3.11
pve-cluster: 8.1.1
pve-container: 5.2.7
pve-docs: 8.4.0
pve-edk2-firmware: 4.2025.02-3
pve-esxi-import-tools: 0.7.4
pve-firewall: 5.1.2
pve-firmware: 3.15-4
pve-ha-manager: 4.0.7
pve-i18n: 3.4.5
pve-qemu-kvm: 9.2.0-6
pve-xtermjs: 5.5.0-2
qemu-server: 8.3.14
smartmontools: 7.3-pve1
spiceterm: 3.3.0
swtpm: 0.8.0+pve1
vncterm: 1.8.0
zfsutils-linux: 2.2.7-pve2

3.
Code: 
agent: 1
balloon: 512
bios: ovmf
boot: order=scsi0
cores: 2
cpuunits: 100
description: <div align='center'><a href='https%3A//Helper-Scripts.com'><img src='https%3A//raw.githubusercontent.com/tteck/Proxmox/main/misc/images/logo-81x112.png'/></a>%0A%0A  # Debian 12 VM%0A%0A  <a href='https%3A//ko-fi.com/D1D7EP4GF'><img src='https%3A//img.shields.io/badge/&#x2615;-Buy me a coffee-blue' /></a>%0A  </div>
efidisk0: external:vm-126-disk-1,efitype=4m,size=528K
localtime: 1
memory: 1536
meta: creation-qemu=8.1.5,ctime=1716713288
name: evcc
net0: virtio=02:06:B1:05:D9:3A,bridge=vmbr0
numa: 0
onboot: 1
ostype: l26
scsi0: external:vm-126-disk-0,cache=writeback,discard=on,size=25G
scsihw: virtio-scsi-pci
serial0: socket
smbios1: uuid=1a313609-3b76-400c-996a-4384c6d6a688
sockets: 1
startup: order=1000
tablet: 0
tags: proxmox-helper-scripts
vmgenid: 9594c9c1-f411-47f0-a4cf-099288a8daf1

4. Debian 12.11

5. Der output ist oben schon im initialen Beitrag. Alles weitere sind nur applikationsspezifische (evcc) Meldungen (>5900 Zeilen), die damit nicht in Zusammenhang stehen.
 
ThoSo said:
Hast du schon mal an ein Update von Proxmox gedacht?
Prüf doch bitte mal in der GUI mal was alles an Updates ansteht.
Click to expand...
Ich installiere Updates in der Regel zeitnah.
Derzeit stehen nur Updates für grub in der Liste - und die dürften wohl kaum etwas damit zu tun haben.
 
Danke für die Infos!

thoralf said:
5. Der output ist oben schon im initialen Beitrag. Alles weitere sind nur applikationsspezifische (evcc) Meldungen (>5900 Zeilen), die damit nicht in Zusammenhang stehen.
Click to expand...
Ich habe den Output vom Host gemeint, für den Fall, dass er irgendwas Relevantes anzeigt - rund um den Crash herum, oder kurz davor.

Folgendes finde ich auch interessant:
Code: 
Jul 09 06:50:47 evcc kernel: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
Jul 09 06:50:47 evcc kernel: rcu:         1-...!: (0 ticks this GP) idle=0324/1/0x4000000000000002 softirq=839512/839512 fqs=0
Jul 09 06:50:47 evcc kernel:         (detected by 0, t=5253 jiffies, g=1204569, q=56 ncpus=2)
Jul 09 06:50:47 evcc kernel: Sending NMI from CPU 0 to CPUs 1:
Jul 09 06:50:47 evcc kernel: NMI backtrace for cpu 1 skipped: idling at native_halt+0xa/0x10
Jul 09 06:50:47 evcc kernel: rcu: rcu_preempt kthread timer wakeup didn't happen for 5253 jiffies! g1204569 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
Jul 09 06:50:47 evcc kernel: rcu:         Possible timer handling issue on cpu=1 timer-softirq=874118

Der output von dmesg am Host wäre ebenfalls interessant. Falls es ein Timer-Problem ist, könnten dort mehr Informationen stehen.

Ein paar Ideen:
  1. BIOS updaten.
  2. Am Host testweise den opt-in kernel 6.14 verwenden.
  3. RAM mit memtest86+ testen und warten, bis die Tests ein paar Mal erfolgreich sind (z.B. über die Nacht).
Ich bin gespannt, ob das Problem mit problematischem TSC oder deaktiviertem HPET zu tun hat. Eventuell könnte das BIOS Update auch damit helfen, falls irgendwelche Bugs in die Richtung gefixt wurden. Aber Schritt für Schritt ;)
 
1. Die Firmware für den Prozessor habe ich aktualisiert (Reboot noch ausstehend) Das hatte auf anderen Hosts interessanterweise zu harten Fehlern mit der GLIBC geführt). BIOS-Update muss ich mal schauen, ob ich da was finde.

2. Den Kernel schaue ich mir mal an. Ich muss erstmal einen Stall anderer Services migrieren, die da auch laufen. Allerdings alles CT.

3. Das Log vom Host ist auch über Tausend Zeilen lang.
Direkt zum Zeitpunkt (der Gast läuft auf UTC, Host auf CET, daher 2 Stunden verschoben):

Code: 
Jul 09 08:50:42 pve4 systemd[1]: Stopping user@0.service - User Manager for UID 0...
Jul 09 08:50:42 pve4 systemd[3703034]: Activating special unit exit.target...
Jul 09 08:50:42 pve4 systemd[3703034]: Stopped target default.target - Main User Target.
Jul 09 08:50:42 pve4 systemd[3703034]: Stopped target basic.target - Basic System.
Jul 09 08:50:42 pve4 systemd[3703034]: Stopped target paths.target - Paths.
Jul 09 08:50:42 pve4 systemd[3703034]: Stopped target sockets.target - Sockets.
Jul 09 08:50:42 pve4 systemd[3703034]: Stopped target timers.target - Timers.
Jul 09 08:50:42 pve4 systemd[3703034]: Closed dirmngr.socket - GnuPG network certificate management daemon.
Jul 09 08:50:42 pve4 systemd[3703034]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
Jul 09 08:50:42 pve4 systemd[3703034]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
Jul 09 08:50:42 pve4 systemd[3703034]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
Jul 09 08:50:42 pve4 systemd[3703034]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
Jul 09 08:50:42 pve4 systemd[3703034]: Removed slice app.slice - User Application Slice.
Jul 09 08:50:42 pve4 systemd[3703034]: Reached target shutdown.target - Shutdown.
Jul 09 08:50:42 pve4 systemd[3703034]: Finished systemd-exit.service - Exit the Session.
Jul 09 08:50:42 pve4 systemd[3703034]: Reached target exit.target - Exit the Session.
Jul 09 08:50:42 pve4 systemd[1]: user@0.service: Deactivated successfully.
Jul 09 08:50:42 pve4 systemd[1]: Stopped user@0.service - User Manager for UID 0.
Jul 09 08:50:42 pve4 systemd[1]: Stopping user-runtime-dir@0.service - User Runtime Directory /run/user/0...
Jul 09 08:50:42 pve4 systemd[1]: run-user-0.mount: Deactivated successfully.
Jul 09 08:50:42 pve4 systemd[1]: user-runtime-dir@0.service: Deactivated successfully.
Jul 09 08:50:42 pve4 systemd[1]: Stopped user-runtime-dir@0.service - User Runtime Directory /run/user/0.
Jul 09 08:50:42 pve4 systemd[1]: Removed slice user-0.slice - User Slice of UID 0.
Jul 09 08:50:42 pve4 systemd[1]: user-0.slice: Consumed 13.328s CPU time.
 
You must log in or register to reply here.
Top Bottom