The VMs start in Emergency mode.

W

WhiteTiger

Member
May 16, 2020
86
2
13
Italy
On Proxmox I have several Linux VMs, mainly Debian 11.
Very often the VMs start in Emergency mode and I don't understand the reason.
Sometimes the problem is starting a VM; other times asking for its reboot from Proxmox; other times asking for its reboot from the command line or from its GUI.

The VMs are installed by the ISO or clones of these.
They are installed in an LVM Group with three volumes each of 7x300GB HDDs. There is a log mirroring and cache, both on NVME.
The memory is 64GB and is still underused at the moment.

The problem is serious.
Today I go to the console, log in with root and ask for a reboot from command line.
When fully operational, the VMs should then start with Proxmox and manual intervention is unthinkable.
 
Last edited:
Did you look at the logs of the VMs? They should point out why the VMs isn't able to start like they should.
 
please don;t double post
 
After weeks that the problem does not arise, today I find myself with the VM (Debian 11 Server) going into Emergency Mode.
In the log I struggle to understand what could have gone wrong.
I entered the log for two VMs.
The 231100001 is the one that went as a block.
The 231100002 is a clone of his and started without problems, but with some error reports similar to those of 231100001.

If needed, I saved on my PC the log of the whole day, related to: Boot, Kernel Update, Reboot, the startup of these two VMs.


Code: 
Nov 28 08:24:49 ul-hq-hvm1 pvedaemon[6490]: start VM 231100001: UPID:ul-hq-hvm1:0000195A:00002A1B:61A32EC1:qmstart:231100001:root@pam:
Nov 28 08:24:49 ul-hq-hvm1 pvedaemon[6365]: <root@pam> starting task UPID:ul-hq-hvm1:0000195A:00002A1B:61A32EC1:qmstart:231100001:root@pam:
Nov 28 08:24:49 ul-hq-hvm1 systemd[1]: Created slice qemu.slice.
Nov 28 08:24:49 ul-hq-hvm1 systemd[1]: Started 231100001.scope.
Nov 28 08:24:49 ul-hq-hvm1 systemd-udevd[6503]: Using default interface naming scheme 'v247'.
Nov 28 08:24:49 ul-hq-hvm1 systemd-udevd[6503]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:24:51 ul-hq-hvm1 kernel: device tap231100001i0 entered promiscuous mode
Nov 28 08:24:51 ul-hq-hvm1 ovs-vsctl[6509]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port tap231100001i0
Nov 28 08:24:51 ul-hq-hvm1 ovs-vsctl[6509]: ovs|00002|db_ctl_base|ERR|no port named tap231100001i0
Nov 28 08:24:51 ul-hq-hvm1 ovs-vsctl[6510]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port fwln231100001i0
Nov 28 08:24:51 ul-hq-hvm1 ovs-vsctl[6510]: ovs|00002|db_ctl_base|ERR|no port named fwln231100001i0
Nov 28 08:24:51 ul-hq-hvm1 systemd-udevd[6503]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:24:51 ul-hq-hvm1 systemd-udevd[6507]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:24:51 ul-hq-hvm1 systemd-udevd[6503]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:24:51 ul-hq-hvm1 systemd-udevd[6507]: Using default interface naming scheme 'v247'.
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 1(fwln231100001i0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 1(fwln231100001i0) entered disabled state
Nov 28 08:24:51 ul-hq-hvm1 kernel: device fwln231100001i0 entered promiscuous mode
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 1(fwln231100001i0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 1(fwln231100001i0) entered forwarding state
Nov 28 08:24:51 ul-hq-hvm1 kernel: vmbr0130: port 2(fwpr231100001p0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: vmbr0130: port 2(fwpr231100001p0) entered disabled state
Nov 28 08:24:51 ul-hq-hvm1 kernel: device fwpr231100001p0 entered promiscuous mode
Nov 28 08:24:51 ul-hq-hvm1 kernel: vmbr0130: port 2(fwpr231100001p0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: vmbr0130: port 2(fwpr231100001p0) entered forwarding state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 2(tap231100001i0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 2(tap231100001i0) entered disabled state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 2(tap231100001i0) entered blocking state
Nov 28 08:24:51 ul-hq-hvm1 kernel: fwbr231100001i0: port 2(tap231100001i0) entered forwarding state
Nov 28 08:24:51 ul-hq-hvm1 pvedaemon[6365]: <root@pam> end task UPID:ul-hq-hvm1:0000195A:00002A1B:61A32EC1:qmstart:231100001:root@pam: OK
Nov 28 08:24:54 ul-hq-hvm1 pvedaemon[6366]: VM 231100001 qmp command failed - VM 231100001 qmp command 'guest-ping' failed - got timeout
Nov 28 08:25:15 ul-hq-hvm1 pvedaemon[7503]: starting vnc proxy UPID:ul-hq-hvm1:00001D4F:0000340A:61A32EDA:vncproxy:231100001:root@pam:
Nov 28 08:25:15 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:00001D4F:0000340A:61A32EDA:vncproxy:231100001:root@pam:
Nov 28 08:26:00 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:00001D4F:0000340A:61A32EDA:vncproxy:231100001:root@pam: OK
Nov 28 08:26:03 ul-hq-hvm1 pvedaemon[6366]: VM 231100001 qmp command failed - VM 231100001 qmp command 'guest-ping' failed - got timeout
Nov 28 08:26:07 ul-hq-hvm1 pvedaemon[7801]: starting vnc proxy UPID:ul-hq-hvm1:00001E79:0000489C:61A32F0F:vncproxy:231100001:root@pam:
Nov 28 08:26:07 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:00001E79:0000489C:61A32F0F:vncproxy:231100001:root@pam:
Nov 28 08:26:28 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:00001E79:0000489C:61A32F0F:vncproxy:231100001:root@pam: OK
Nov 28 08:26:29 ul-hq-hvm1 pvedaemon[7886]: starting vnc proxy UPID:ul-hq-hvm1:00001ECE:0000510D:61A32F25:vncproxy:231100002:root@pam:
Nov 28 08:26:29 ul-hq-hvm1 pvedaemon[6365]: <root@pam> starting task UPID:ul-hq-hvm1:00001ECE:0000510D:61A32F25:vncproxy:231100002:root@pam:
Nov 28 08:26:30 ul-hq-hvm1 qm[7888]: VM 231100002 qmp command failed - VM 231100002 not running
Nov 28 08:26:30 ul-hq-hvm1 pvedaemon[7886]: Failed to run vncproxy.
Nov 28 08:26:31 ul-hq-hvm1 pvedaemon[6365]: <root@pam> end task UPID:ul-hq-hvm1:00001ECE:0000510D:61A32F25:vncproxy:231100002:root@pam: Failed to run vncproxy.
Nov 28 08:26:33 ul-hq-hvm1 pvedaemon[7889]: start VM 231100002: UPID:ul-hq-hvm1:00001ED1:000052B1:61A32F29:qmstart:231100002:root@pam:
Nov 28 08:26:33 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:00001ED1:000052B1:61A32F29:qmstart:231100002:root@pam:
Nov 28 08:26:33 ul-hq-hvm1 systemd[1]: Started 231100002.scope.
Nov 28 08:26:33 ul-hq-hvm1 systemd-udevd[7902]: Using default interface naming scheme 'v247'.
Nov 28 08:26:33 ul-hq-hvm1 systemd-udevd[7902]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:26:34 ul-hq-hvm1 kernel: device tap231100002i0 entered promiscuous mode
Nov 28 08:26:34 ul-hq-hvm1 ovs-vsctl[7907]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port tap231100002i0
Nov 28 08:26:34 ul-hq-hvm1 ovs-vsctl[7907]: ovs|00002|db_ctl_base|ERR|no port named tap231100002i0
Nov 28 08:26:34 ul-hq-hvm1 ovs-vsctl[7908]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port fwln231100002i0
Nov 28 08:26:34 ul-hq-hvm1 ovs-vsctl[7908]: ovs|00002|db_ctl_base|ERR|no port named fwln231100002i0
Nov 28 08:26:34 ul-hq-hvm1 systemd-udevd[7905]: Using default interface naming scheme 'v247'.
Nov 28 08:26:34 ul-hq-hvm1 systemd-udevd[7905]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:26:35 ul-hq-hvm1 systemd-udevd[7905]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:26:35 ul-hq-hvm1 systemd-udevd[7902]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered disabled state
Nov 28 08:26:35 ul-hq-hvm1 kernel: device fwln231100002i0 entered promiscuous mode
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered forwarding state
Nov 28 08:26:35 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered disabled state
Nov 28 08:26:35 ul-hq-hvm1 kernel: device fwpr231100002p0 entered promiscuous mode
Nov 28 08:26:35 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered forwarding state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 2(tap231100002i0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 2(tap231100002i0) entered disabled state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 2(tap231100002i0) entered blocking state
Nov 28 08:26:35 ul-hq-hvm1 kernel: fwbr231100002i0: port 2(tap231100002i0) entered forwarding state
Nov 28 08:26:35 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:00001ED1:000052B1:61A32F29:qmstart:231100002:root@pam: OK
Nov 28 08:26:35 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:00001F01:00005395:61A32F2B:vncproxy:231100002:root@pam:
Nov 28 08:26:35 ul-hq-hvm1 pvedaemon[7937]: starting vnc proxy UPID:ul-hq-hvm1:00001F01:00005395:61A32F2B:vncproxy:231100002:root@pam:
Nov 28 08:26:42 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:00001F01:00005395:61A32F2B:vncproxy:231100002:root@pam: OK
Nov 28 08:26:42 ul-hq-hvm1 pvedaemon[6364]: <root@pam> starting task UPID:ul-hq-hvm1:00001F94:00005649:61A32F32:vncproxy:231100001:root@pam:
Nov 28 08:26:42 ul-hq-hvm1 pvedaemon[8084]: starting vnc proxy UPID:ul-hq-hvm1:00001F94:00005649:61A32F32:vncproxy:231100001:root@pam:
Nov 28 08:27:12 ul-hq-hvm1 pvedaemon[6364]: <root@pam> end task UPID:ul-hq-hvm1:00001F94:00005649:61A32F32:vncproxy:231100001:root@pam: OK
Nov 28 08:27:17 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:000033C4:00006402:61A32F55:vncproxy:231100001:root@pam:
Nov 28 08:27:17 ul-hq-hvm1 pvedaemon[13252]: starting vnc proxy UPID:ul-hq-hvm1:000033C4:00006402:61A32F55:vncproxy:231100001:root@pam:
Nov 28 08:30:23 ul-hq-hvm1 pveproxy[6375]: problem with client ::ffff:10.101.101.2; Connection reset by peer
Nov 28 08:30:23 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:000033C4:00006402:61A32F55:vncproxy:231100001:root@pam: OK
Nov 28 08:30:51 ul-hq-hvm1 pvedaemon[6364]: VM 231100001 qmp command failed - VM 231100001 qmp command 'guest-ping' failed - got timeout
Nov 28 08:32:23 ul-hq-hvm1 pvedaemon[35752]: starting vnc proxy UPID:ul-hq-hvm1:00008BA8:0000DB46:61A33087:vncproxy:231100002:root@pam:
Nov 28 08:32:23 ul-hq-hvm1 pvedaemon[6366]: <root@pam> starting task UPID:ul-hq-hvm1:00008BA8:0000DB46:61A33087:vncproxy:231100002:root@pam:
Nov 28 08:32:37 ul-hq-hvm1 QEMU[7898]: kvm: terminating on signal 15 from pid 5004 (/usr/sbin/qmeventd)
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd512: p1
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd1008: p1
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd704: p1
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:513...
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:1009...
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:705...
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Requested transaction contradicts existing jobs: Resource deadlock avoided
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Requested transaction contradicts existing jobs: Resource deadlock avoided
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Requested transaction contradicts existing jobs: Resource deadlock avoided
Nov 28 08:32:37 ul-hq-hvm1 lvm[37583]:   pvscan[37583] /dev/zd512p1 excluded by filters: device is rejected by filter config.
Nov 28 08:32:37 ul-hq-hvm1 lvm[37614]:   pvscan[37614] /dev/zd704p1 excluded by filters: device is rejected by filter config.
Nov 28 08:32:37 ul-hq-hvm1 lvm[37602]:   pvscan[37602] /dev/zd1008p1 excluded by filters: device is rejected by filter config.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: lvm2-pvscan@230:513.service: Succeeded.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopped LVM event activation on device 230:513.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: lvm2-pvscan@230:705.service: Succeeded.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopped LVM event activation on device 230:705.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: lvm2-pvscan@230:1009.service: Succeeded.
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopped LVM event activation on device 230:1009.
Nov 28 08:32:37 ul-hq-hvm1 kernel: fwbr231100002i0: port 2(tap231100002i0) entered disabled state
Nov 28 08:32:38 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered disabled state
Nov 28 08:32:38 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered disabled state
Nov 28 08:32:38 ul-hq-hvm1 kernel: device fwln231100002i0 left promiscuous mode
Nov 28 08:32:38 ul-hq-hvm1 kernel: fwbr231100002i0: port 1(fwln231100002i0) entered disabled state
Nov 28 08:32:38 ul-hq-hvm1 kernel: device fwpr231100002p0 left promiscuous mode
Nov 28 08:32:38 ul-hq-hvm1 kernel: vmbr0130: port 3(fwpr231100002p0) entered disabled state
Nov 28 08:32:38 ul-hq-hvm1 ovs-vsctl[37634]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port fwln231100002i0
Nov 28 08:32:38 ul-hq-hvm1 ovs-vsctl[37634]: ovs|00002|db_ctl_base|ERR|no port named fwln231100002i0
Nov 28 08:32:38 ul-hq-hvm1 ovs-vsctl[37636]: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port tap231100002i0
Nov 28 08:32:38 ul-hq-hvm1 ovs-vsctl[37636]: ovs|00002|db_ctl_base|ERR|no port named tap231100002i0
Nov 28 08:32:38 ul-hq-hvm1 systemd[1]: 231100002.scope: Succeeded.
Nov 28 08:32:38 ul-hq-hvm1 systemd[1]: 231100002.scope: Consumed 2min 52.567s CPU time.
Nov 28 08:32:38 ul-hq-hvm1 pvedaemon[6366]: <root@pam> end task UPID:ul-hq-hvm1:00008BA8:0000DB46:61A33087:vncproxy:231100002:root@pam: OK
Nov 28 08:32:39 ul-hq-hvm1 qmeventd[37638]: Starting cleanup for 231100002
Nov 28 08:32:39 ul-hq-hvm1 qmeventd[37638]: Finished cleanup for 231100002
Nov 28 08:32:44 ul-hq-hvm1 pvedaemon[37639]: starting vnc proxy UPID:ul-hq-hvm1:00009307:0000E3B0:61A3309C:vncproxy:231100002:root@pam:
Nov 28 08:32:44 ul-hq-hvm1 pvedaemon[6364]: <root@pam> starting task UPID:ul-hq-hvm1:00009307:0000E3B0:61A3309C:vncproxy:231100002:root@pam:
Nov 28 08:32:54 ul-hq-hvm1 pvedaemon[37639]: connection timed out
Nov 28 08:32:54 ul-hq-hvm1 pvedaemon[6364]: <root@pam> end task UPID:ul-hq-hvm1:00009307:0000E3B0:61A3309C:vncproxy:231100002:root@pam: connection timed out
 
Code: 
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd512: p1
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd1008: p1
Nov 28 08:32:37 ul-hq-hvm1 kernel:  zd704: p1
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:513...
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:1009...
Nov 28 08:32:37 ul-hq-hvm1 systemd[1]: Stopping LVM event activation on device 230:705...

this looks strange.. how is the storage configured on the host and in the VM? could you please post pveversion -v, the VM config, and storage.cfg?
 
You must log in or register to reply here.

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!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

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!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom