Hard reset after/during pve backup job

B

bogo22

Renowned Member
Nov 4, 2016
54
6
73
Hello,

today my pve rebooted forcefully after/during a pre backup job. I am not sure if this was the real trigger but I found some log entries which are pve related and maybe we can discuss them to fix them:

Time History:
02:00 backup of some qm
03:00 backup of some lxc
05:45 backup of my biggest qm (separat backup job)
Hard reboot directly after starting the last backup job

I am using only zfs (boot and data pools)
Backup job on local pve to local data-pool (not to bps)

Summary of the log cutout/interesting entries (details second post)
  • pvestatd[]: VM <id> qmp command failed - VM <id> not running
  • pvestatd[]: unable to get PID for CT <id> (not running?)
  • One Call Trace
  • Maybe as a result of that:
    pve-ha-crm[4766]: loop take too long (31 seconds)
    pve-ha-lrm[4799]: loop take too long (31 seconds)
    pve-firewall[4727]: firewall update time (24.969 seconds)
  • pvestatd[4729]: Use of uninitialized value in subtraction (-) at /usr/share/perl5/PVE/LXC.pm line 252.
  • kernel: traps: gdm-session-wor[907138] trap int3 ip:7f893720ed97 sp:7ffca3eb5f90 error:0 in libglib-2.0.so.0.6800.4[7f89371ce000+8d000]
  • status update error: can't lock file '/var/lock/pvefw.lck' - got timeout

Thanks for any help/understandy what's going on.

pveversion -v
proxmox-ve: 8.1.0 (running kernel: 6.5.11-7-pve)
pve-manager: 8.1.4 (running version: 8.1.4/ec5affc9e41f1d79)
proxmox-kernel-helper: 8.1.0
pve-kernel-5.15: 7.4-6
proxmox-kernel-6.5: 6.5.11-7
proxmox-kernel-6.5.11-7-pve-signed: 6.5.11-7
proxmox-kernel-6.2.16-20-pve: 6.2.16-20
proxmox-kernel-6.2: 6.2.16-20
proxmox-kernel-6.2.16-15-pve: 6.2.16-15
proxmox-kernel-6.2.16-14-pve: 6.2.16-14
pve-kernel-5.15.116-1-pve: 5.15.116-1
ceph-fuse: 16.2.11+ds-2
corosync: 3.1.7-pve3
criu: 3.17.1-2
glusterfs-client: 10.3-5
ifupdown2: 3.2.0-1+pmx8
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-4
libknet1: 1.28-pve1
libproxmox-acme-perl: 1.5.0
libproxmox-backup-qemu0: 1.4.1
libproxmox-rs-perl: 0.3.3
libpve-access-control: 8.0.7
libpve-apiclient-perl: 3.3.1
libpve-common-perl: 8.1.0
libpve-guest-common-perl: 5.0.6
libpve-http-server-perl: 5.0.5
libpve-network-perl: 0.9.5
libpve-rs-perl: 0.8.8
libpve-storage-perl: 8.0.5
libspice-server1: 0.15.1-1
lvm2: 2.03.16-2
lxc-pve: 5.0.2-4
lxcfs: 5.0.3-pve4
novnc-pve: 1.4.0-3
proxmox-backup-client: 3.1.2-1
proxmox-backup-file-restore: 3.1.2-1
proxmox-kernel-helper: 8.1.0
proxmox-mail-forward: 0.2.3
proxmox-mini-journalreader: 1.4.0
proxmox-offline-mirror-helper: 0.6.4
proxmox-widget-toolkit: 4.1.3
pve-cluster: 8.0.5
pve-container: 5.0.8
pve-docs: 8.1.3
pve-edk2-firmware: 4.2023.08-3
pve-firewall: 5.0.3
pve-firmware: 3.9-1
pve-ha-manager: 4.0.3
pve-i18n: 3.2.0
pve-qemu-kvm: 8.1.2-6
pve-xtermjs: 5.3.0-3
pve-zsync: 2.3.0
qemu-server: 8.0.10
smartmontools: 7.3-pve1
spiceterm: 3.3.0
swtpm: 0.8.0+pve1
vncterm: 1.8.0
zfsutils-linux: 2.2.2-pve1
Click to expand...
 
Last edited:
Relevant cutouts of log: journalctl -f -n900 -b -1

Feb 01 02:00:05 PVE-1 pvescheduler[842243]: INFO: starting new backup job: vzdump 700 400 1600 --prune-backups 'keep-last=1' --mailnotification always --mode stop --node PVE-1 --compress zstd --quiet 1 --storage vm_backup --mailto root
Feb 01 02:00:05 PVE-1 pvescheduler[842243]: INFO: Starting Backup of VM 400 (qemu)
Feb 01 02:00:06 PVE-1 systemd[1]: Started 400.scope.
Feb 01 02:00:06 PVE-1 kernel: tap400i0: entered promiscuous mode
Feb 01 02:00:06 PVE-1 kernel: vmbr1: port 13(tap400i0) entered blocking state
Feb 01 02:00:06 PVE-1 kernel: vmbr1: port 13(tap400i0) entered disabled state
Feb 01 02:00:06 PVE-1 kernel: tap400i0: entered allmulticast mode
Feb 01 02:00:06 PVE-1 kernel: vmbr1: port 13(tap400i0) entered blocking state
Feb 01 02:00:06 PVE-1 kernel: vmbr1: port 13(tap400i0) entered forwarding state
Feb 01 02:01:38 PVE-1 kernel: zd32: p1 p2 p3 p4 p5
Feb 01 02:01:38 PVE-1 kernel: tap400i0: left allmulticast mode
Feb 01 02:01:38 PVE-1 kernel: vmbr1: port 13(tap400i0) entered disabled state
Feb 01 02:01:38 PVE-1 qmeventd[3728]: read: Connection reset by peer
Feb 01 02:01:38 PVE-1 pvestatd[4729]: VM 400 qmp command failed - VM 400 not running
Feb 01 02:01:38 PVE-1 systemd[1]: 400.scope: Deactivated successfully.
Feb 01 02:01:38 PVE-1 systemd[1]: 400.scope: Consumed 2min 59.264s CPU time.
Feb 01 02:01:39 PVE-1 pvescheduler[842243]: INFO: Finished Backup of VM 400 (00:01:34)
Feb 01 02:01:39 PVE-1 pvescheduler[842243]: INFO: Starting Backup of VM 700 (qemu)
...
Feb 01 02:03:15 PVE-1 pvescheduler[842243]: INFO: Starting Backup of VM 1600 (qemu)
Feb 01 02:03:15 PVE-1 systemd[1]: Started 1600.scope.
Feb 01 02:03:16 PVE-1 qmeventd[846013]: Starting cleanup for 700
Feb 01 02:03:16 PVE-1 qmeventd[846013]: Finished cleanup for 700
Feb 01 02:03:16 PVE-1 kernel: tap1600i0: entered promiscuous mode
Feb 01 02:03:16 PVE-1 kernel: vmbr1: port 13(tap1600i0) entered blocking state
Feb 01 02:03:16 PVE-1 kernel: vmbr1: port 13(tap1600i0) entered disabled state
Feb 01 02:03:16 PVE-1 kernel: tap1600i0: entered allmulticast mode
Feb 01 02:03:16 PVE-1 kernel: vmbr1: port 13(tap1600i0) entered blocking state
Feb 01 02:03:16 PVE-1 kernel: vmbr1: port 13(tap1600i0) entered forwarding state
Feb 01 02:04:17 PVE-1 kernel: zd48: p1
Feb 01 02:04:17 PVE-1 kernel: tap1600i0: left allmulticast mode
Feb 01 02:04:17 PVE-1 kernel: vmbr1: port 13(tap1600i0) entered disabled state
Feb 01 02:04:17 PVE-1 qmeventd[3728]: read: Connection reset by peer
Feb 01 02:04:17 PVE-1 pvestatd[4729]: VM 1600 qmp command failed - VM 1600 not running
Feb 01 02:04:17 PVE-1 systemd[1]: 1600.scope: Deactivated successfully.
Feb 01 02:04:17 PVE-1 systemd[1]: 1600.scope: Consumed 1min 11.512s CPU time.
Feb 01 02:04:18 PVE-1 qmeventd[847221]: Starting cleanup for 1600
Feb 01 02:04:18 PVE-1 qmeventd[847221]: Finished cleanup for 1600
Feb 01 02:04:18 PVE-1 pvescheduler[842243]: INFO: Finished Backup of VM 1600 (00:01:03)
Feb 01 02:04:18 PVE-1 pvescheduler[842243]: INFO: Backup job finished successfully
....
Feb 01 03:00:07 PVE-1 pvescheduler[888815]: <root@pam> starting task UPID:PVE-1:000D8FF0:0265E5FB:65BAFB27:vzdump::root@pam:
Feb 01 03:00:07 PVE-1 pvescheduler[888816]: INFO: starting new backup job: vzdump 200 250 600 2250 1100 1000 1500 1505 2700 2300 1700 2400 2100 2000 2200 2500 2600 --mailto root --storage vm_backup --quiet 1 --compress zstd --node PVE-1 --mode stop --mailnotification always --notes-template '{{node}}_{{vmid}}_{{guestname}}' --prune-backups 'keep-last=1'
Feb 01 03:00:07 PVE-1 pvescheduler[888816]: INFO: Starting Backup of VM 200 (lxc)
Feb 01 03:00:07 PVE-1 kernel: vmbr1: port 3(veth200i0) entered disabled state
Feb 01 03:00:07 PVE-1 kernel: veth200i0 (unregistering): left allmulticast mode
Feb 01 03:00:07 PVE-1 kernel: veth200i0 (unregistering): left promiscuous mode
Feb 01 03:00:07 PVE-1 kernel: vmbr1: port 3(veth200i0) entered disabled state
Feb 01 03:00:07 PVE-1 audit[888888]: AVC apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-200_</var/lib/lxc>" pid=888888 comm="apparmor_parser"
Feb 01 03:00:07 PVE-1 kernel: audit: type=1400 audit(1706752807.726:422): apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-200_</var/lib/lxc>" pid=888888 comm="apparmor_parser"
Feb 01 03:00:07 PVE-1 pvestatd[4729]: unable to get PID for CT 200 (not running?)
Feb 01 03:00:08 PVE-1 pvestatd[4729]: unable to get PID for CT 200 (not running?)
Feb 01 03:00:08 PVE-1 systemd[1]: pve-container@200.service: Deactivated successfully.
Feb 01 03:00:24 PVE-1 systemd[1]: Started pve-container@200.service - PVE LXC Container: 200.
Feb 01 03:00:25 PVE-1 audit[889282]: AVC apparmor="STATUS" operation="profile_load" profile="/usr/bin/lxc-start" name="lxc-200_</var/lib/lxc>" pid=889282 comm="apparmor_parser"
Feb 01 03:00:25 PVE-1 kernel: audit: type=1400 audit(1706752825.649:423): apparmor="STATUS" operation="profile_load" profile="/usr/bin/lxc-start" name="lxc-200_</var/lib/lxc>" pid=889282 comm="apparmor_parser"
Feb 01 03:00:26 PVE-1 kernel: vmbr1: port 3(veth200i0) entered blocking state
Feb 01 03:00:26 PVE-1 kernel: vmbr1: port 3(veth200i0) entered disabled state
Feb 01 03:00:26 PVE-1 kernel: veth200i0: entered allmulticast mode
Feb 01 03:00:26 PVE-1 kernel: veth200i0: entered promiscuous mode
Feb 01 03:00:26 PVE-1 kernel: eth0: renamed from veth2JowO7
Feb 01 03:00:26 PVE-1 pvescheduler[888816]: INFO: Finished Backup of VM 200 (00:00:19)
...
Feb 01 03:00:27 PVE-1 pvestatd[4729]: unable to get PID for CT 250 (not running?)
Feb 01 03:00:27 PVE-1 pvestatd[4729]: modified cpu set for lxc/1500: 1,3-11
Feb 01 03:00:28 PVE-1 pvestatd[4729]: unable to get PID for CT 250 (not running?)
Feb 01 03:00:28 PVE-1 systemd[1]: pve-container@250.service: Deactivated successfully.
Feb 01 03:00:49 PVE-1 systemd[1]: Started pve-container@250.service - PVE LXC Container: 250.
...
Feb 01 03:01:33 PVE-1 pvescheduler[888816]: INFO: Starting Backup of VM 1000 (lxc)
Feb 01 03:01:34 PVE-1 kernel: vmbr1: port 5(veth1000i0) entered disabled state
Feb 01 03:01:34 PVE-1 kernel: veth1000i0 (unregistering): left allmulticast mode
Feb 01 03:01:34 PVE-1 kernel: veth1000i0 (unregistering): left promiscuous mode
Feb 01 03:01:34 PVE-1 kernel: vmbr1: port 5(veth1000i0) entered disabled state
Feb 01 03:01:35 PVE-1 systemd[1]: pve-container@1000.service: Deactivated successfully.
Feb 01 03:01:37 PVE-1 pvestatd[4729]: modified cpu set for lxc/1500: 1-2,4-11
Feb 01 03:01:37 PVE-1 pvestatd[4729]: modified cpu set for lxc/200: 3-4,8-9
Feb 01 03:01:37 PVE-1 pvestatd[4729]: modified cpu set for lxc/2300: 0,5,8,11
Feb 01 03:10:01 PVE-1 kernel: INFO: task cron:892104 blocked for more than 120 seconds.
Feb 01 03:10:01 PVE-1 kernel: Tainted: P O 6.5.11-7-pve #1
Feb 01 03:10:01 PVE-1 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Feb 01 03:10:01 PVE-1 kernel: task:cron state:D stack:0 pid:892104 ppid:889442 flags:0x00000000
Feb 01 03:10:01 PVE-1 kernel: Call Trace:
Feb 01 03:10:01 PVE-1 kernel: <TASK>
Feb 01 03:10:01 PVE-1 kernel: __schedule+0x3fd/0x1450
Feb 01 03:10:01 PVE-1 kernel: ? shmem_swapin+0x6d/0x100
Feb 01 03:10:01 PVE-1 kernel: schedule+0x63/0x110
Feb 01 03:10:01 PVE-1 kernel: io_schedule+0x46/0x80
Feb 01 03:10:01 PVE-1 kernel: folio_wait_bit_common+0x136/0x330
Feb 01 03:10:01 PVE-1 kernel: ? __pfx_wake_page_function+0x10/0x10
Feb 01 03:10:01 PVE-1 kernel: __folio_lock+0x17/0x30
Feb 01 03:10:01 PVE-1 kernel: shmem_swapin_folio+0x270/0x7b0
Feb 01 03:10:01 PVE-1 kernel: ? profile_path_perm+0xd5/0xe0
Feb 01 03:10:01 PVE-1 kernel: ? filemap_get_entry+0xea/0x160
Feb 01 03:10:01 PVE-1 kernel: shmem_get_folio_gfp+0x195/0x7f0
Feb 01 03:10:01 PVE-1 kernel: shmem_file_read_iter+0x191/0x3e0
Feb 01 03:10:01 PVE-1 kernel: ? fsnotify_perm.part.0+0x83/0x200
Feb 01 03:10:01 PVE-1 kernel: vfs_read+0x20d/0x360
Feb 01 03:10:01 PVE-1 kernel: __x64_sys_pread64+0xa6/0xd0
Feb 01 03:10:01 PVE-1 kernel: do_syscall_64+0x5b/0x90
Feb 01 03:10:01 PVE-1 kernel: ? do_syscall_64+0x67/0x90
Feb 01 03:10:01 PVE-1 kernel: ? syscall_exit_to_user_mode+0x37/0x60
Feb 01 03:10:01 PVE-1 kernel: ? do_syscall_64+0x67/0x90
Feb 01 03:10:01 PVE-1 kernel: ? syscall_exit_to_user_mode+0x37/0x60
Feb 01 03:10:01 PVE-1 kernel: ? do_syscall_64+0x67/0x90
Feb 01 03:10:01 PVE-1 kernel: ? syscall_exit_to_user_mode+0x37/0x60
Feb 01 03:10:01 PVE-1 kernel: ? do_syscall_64+0x67/0x90
Feb 01 03:10:01 PVE-1 kernel: ? irqentry_exit+0x43/0x50
Feb 01 03:10:01 PVE-1 kernel: ? exc_page_fault+0x94/0x1b0
Feb 01 03:10:01 PVE-1 kernel: entry_SYSCALL_64_after_hwframe+0x6e/0xd8
Feb 01 03:10:01 PVE-1 kernel: RIP: 0033:0x7fb3e49d979e
Feb 01 03:10:01 PVE-1 kernel: RSP: 002b:00007ffdbfada8e8 EFLAGS: 00000206 ORIG_RAX: 0000000000000011
Feb 01 03:10:01 PVE-1 kernel: RAX: ffffffffffffffda RBX: 00007ffdbfadab10 RCX: 00007fb3e49d979e
Feb 01 03:10:01 PVE-1 kernel: RDX: 0000000000000180 RSI: 00007ffdbfada920 RDI: 0000000000000007
Feb 01 03:10:01 PVE-1 kernel: RBP: 00007ffdbfada920 R08: 0000000000000000 R09: 0000000000000000
Feb 01 03:10:01 PVE-1 kernel: R10: 0000000000000000 R11: 0000000000000206 R12: 0000000000000000
Feb 01 03:10:01 PVE-1 kernel: R13: 00007ffdbfadab48 R14: 0000000000000000 R15: 0000555b6408c6e0
Feb 01 03:10:01 PVE-1 kernel: </TASK>
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Watchdog timeout (limit 3min)!
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Killing process 847 (systemd-udevd) with signal SIGABRT.
Feb 01 03:10:01 PVE-1 CRON[892225]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Feb 01 03:10:01 PVE-1 CRON[892251]: (root) CMD (test -e /run/systemd/system || SERVICE_MODE=1 /sbin/e2scrub_all -A -r)
Feb 01 03:10:01 PVE-1 CRON[892225]: pam_unix(cron:session): session closed for user root
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Main process exited, code=killed, status=6/ABRT
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Failed with result 'watchdog'.
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Consumed 7.616s CPU time.
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Scheduled restart job, restart counter is at 1.
Feb 01 03:10:01 PVE-1 systemd[1]: Stopped systemd-udevd.service - Rule-based Manager for Device Events and Files.
Feb 01 03:10:01 PVE-1 systemd[1]: systemd-udevd.service: Consumed 7.616s CPU time.
Feb 01 03:10:02 PVE-1 pve-ha-crm[4766]: loop take too long (38 seconds)
Feb 01 03:10:02 PVE-1 pve-ha-lrm[4799]: loop take too long (38 seconds)
...
Feb 01 03:13:38 PVE-1 pvescheduler[888816]: INFO: Finished Backup of VM 1100 (00:00:26)
Feb 01 03:13:38 PVE-1 pvescheduler[888816]: INFO: Starting Backup of VM 1500 (lxc)
Feb 01 03:13:46 PVE-1 kernel: vmbr1: port 6(veth1500i0) entered disabled state
Feb 01 03:13:46 PVE-1 kernel: veth1500i0 (unregistering): left allmulticast mode
Feb 01 03:13:46 PVE-1 kernel: veth1500i0 (unregistering): left promiscuous mode
Feb 01 03:13:46 PVE-1 kernel: vmbr1: port 6(veth1500i0) entered disabled state
Feb 01 03:13:46 PVE-1 audit[895852]: AVC apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-1500_</var/lib/lxc>" pid=895852 comm="apparmor_parser"
Feb 01 03:13:46 PVE-1 kernel: audit: type=1400 audit(1706753626.676:479): apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-1500_</var/lib/lxc>" pid=895852 comm="apparmor_parser"
Feb 01 03:13:47 PVE-1 systemd[1]: pve-container@1500.service: Deactivated successfully.
Feb 01 03:13:53 PVE-1 pvestatd[4729]: modified cpu set for lxc/1000: 1-2,5-7,9-11
Feb 01 03:14:28 PVE-1 pve-ha-crm[4766]: loop take too long (31 seconds)
Feb 01 03:14:28 PVE-1 pve-ha-lrm[4799]: loop take too long (31 seconds)
Feb 01 03:14:28 PVE-1 pve-firewall[4727]: firewall update time (24.969 seconds)
...
Feb 01 03:24:19 PVE-1 pvescheduler[888816]: INFO: Starting Backup of VM 2600 (lxc)
Feb 01 03:24:19 PVE-1 kernel: vmbr1: port 12(veth2600i0) entered disabled state
Feb 01 03:24:19 PVE-1 kernel: veth2600i0 (unregistering): left allmulticast mode
Feb 01 03:24:19 PVE-1 kernel: veth2600i0 (unregistering): left promiscuous mode
Feb 01 03:24:19 PVE-1 kernel: vmbr1: port 12(veth2600i0) entered disabled state
Feb 01 03:24:19 PVE-1 pvestatd[4729]: Use of uninitialized value in subtraction (-) at /usr/share/perl5/PVE/LXC.pm line 252.
Feb 01 03:24:19 PVE-1 audit[906592]: AVC apparmor="STATUS" operation="profile_remove" profile="/usr/bin/lxc-start" name="lxc-2600_</var/lib/lxc>" pid=906592 comm="apparmor_parser"
Feb 01 03:24:19 PVE-1 pvestatd[4729]: lxc console cleanup error: failed to read from command socket: Connection reset by peer
Feb 01 03:24:21 PVE-1 systemd[1]: pve-container@2600.service: Deactivated successfully.
Feb 01 03:24:29 PVE-1 kernel: show_signal: 9 callbacks suppressed
Feb 01 03:24:29 PVE-1 kernel: traps: gdm-session-wor[907138] trap int3 ip:7f893720ed97 sp:7ffca3eb5f90 error:0 in libglib-2.0.so.0.6800.4[7f89371ce000+8d000]
Feb 01 03:25:09 PVE-1 systemd[1]: Started pve-container@2600.service - PVE LXC Container: 2600.
Feb 01 03:25:10 PVE-1 audit[907921]: AVC apparmor="STATUS" operation="profile_load" profile="/usr/bin/lxc-start" name="lxc-2600_</var/lib/lxc>" pid=907921 comm="apparmor_parser"
Feb 01 03:25:10 PVE-1 kernel: audit: type=1400 audit(1706754310.134:569): apparmor="STATUS" operation="profile_load" profile="/usr/bin/lxc-start" name="lxc-2600_</var/lib/lxc>" pid=907921 comm="apparmor_parser"
Feb 01 03:25:10 PVE-1 kernel: vmbr1: port 12(veth2600i0) entered blocking state
Feb 01 03:25:10 PVE-1 kernel: vmbr1: port 12(veth2600i0) entered disabled state
Feb 01 03:25:10 PVE-1 kernel: veth2600i0: entered allmulticast mode
Feb 01 03:25:10 PVE-1 kernel: veth2600i0: entered promiscuous mode
Feb 01 03:25:10 PVE-1 kernel: eth0: renamed from vethFk6fJk
Feb 01 03:25:10 PVE-1 pvescheduler[888816]: INFO: Finished Backup of VM 2600 (00:00:51)
Feb 01 03:25:10 PVE-1 pvescheduler[888816]: INFO: Starting Backup of VM 2700 (lxc)
..
Feb 01 04:05:33 PVE-1 pve-firewall[4727]: firewall update time (34.809 seconds)
Feb 01 04:05:38 PVE-1 pve-ha-crm[4766]: loop take too long (39 seconds)
Feb 01 04:05:38 PVE-1 pve-ha-lrm[4799]: loop take too long (44 seconds)
Feb 01 04:07:20 PVE-1 pvestatd[4729]: status update time (141.574 seconds)
Feb 01 04:07:20 PVE-1 pve-firewall[4727]: firewall update time (106.662 seconds)
Feb 01 04:07:25 PVE-1 pve-ha-lrm[4799]: loop take too long (102 seconds)
...
Feb 01 05:39:40 PVE-1 pve-firewall[4727]: firewall update time (10.045 seconds)
Feb 01 05:39:41 PVE-1 pvestatd[4729]: status update time (10.188 seconds)
Feb 01 05:44:53 PVE-1 pve-firewall[4727]: status update error: can't lock file '/var/lock/pvefw.lck' - got timeout
Feb 01 05:44:53 PVE-1 pve-firewall[4727]: firewall update time (13.191 seconds)
Feb 01 05:44:54 PVE-1 pvestatd[4729]: status update time (12.301 seconds)
Feb 01 05:45:20 PVE-1 pvescheduler[1021648]: <root@pam> starting task UPID:PVE-1:000F96D1:02750655:65BB21E0:vzdump:1270:root@pam:
Feb 01 05:45:20 PVE-1 pvescheduler[1021649]: INFO: starting new backup job: vzdump 1270 --mailto root --storage backup_pool_pbs1_pve1 --quiet 1 --node PVE-1 --mode stop --notes-template '{{node}}_{{vmid}}_{{guestname}}' --mailnotification always --prune-backups 'keep-all=1'
Feb 01 05:45:20 PVE-1 pvescheduler[1021649]: INFO: Starting Backup of VM 1270 (lxc)
LAST ENTRY before hard reset
Click to expand...
 
Same problem here, but while backup is running to PBS.
Same all-zfs storage.
What I watch is that the backups are running normal until the biggest VM (File Server) start to backup. 3 minutes later some unrelated, events started to occur (loosing access to the UPS via USB), then ZED related errors, and few seconds after this - reboot


Code: 
Mar 05 02:29:23 pve-node-2 zed[498952]: eid=1102 class=delay pool='zfs-data' vdev=ata-SAMSUNG_MZ7L31T9HBLT-00A07_S6ESNS0W311565-part1 size=114688 offset=451412381696 priority=0 err=0 flags=0x40080480 delay=35758ms
Mar 05 02:29:23 pve-node-2 zed[498957]: eid=1103 class=delay pool='zfs-data' vdev=ata-SAMSUNG_MZ7L31T9HBLT-00A07_S6ESNS0W311566-part1 size=16384 offset=451413291008 priority=0 err=0 flags=0x180080 delay=36212ms bookmark=61172:1:0:2228973
Mar 05 02:29:23 pve-node-2 zed[498959]: eid=1104 class=delay pool='zfs-data' vdev=ata-SAMSUNG_MZ7L31T9HBLT-00A07_S6ESNS0W311561-part1 size=16384 offset=1646379479040 priority=0 err=0 flags=0x180080 delay=36164ms bookmark=61172:1:0:2228994
Mar 05 02:29:23 pve-node-2 zed[498964]: eid=1105 class=delay pool='zfs-data' vdev=ata-SAMSUNG_MZ7L31T9HBLT-00A07_S6ESNS0W311562-part1 size=16384 offset=1646379495424 priority=0 err=0 flags=0x180080 delay=36164ms bookmark=61172:1:0:2228995
 
You must log in or register to reply here.
Top Bottom