qmp command 'guest-fsfreeze-thaw' failed - got timeout

[dmembibre]

Hi,

Yesterday we had many failed tasks with this error:

INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 251101 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 251101 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 251101 failed - VM 251101 qmp command 'backup' failed - got timeout

When this happens the vms respond to ping but we cannot access it via ssh and the services that run within them do not work. Sometimes they come back alone and sometimes you have to stop and start.

Any ideas with this problem?

Thank you
BR

 

[mailinglists]

No1 can help you when you do not provide enough detail.
Are these Linux VMs with /tmp as tmpfs?

 

[dmembibre]

Hi,

more details:


vm backup that has been running for a week without problem

INFO: Starting Backup of VM 801049 (qemu)
INFO: Backup started at 2020-10-13 13:52:26
INFO: status = running
INFO: VM Name: xxxxxxxxxxx
INFO: include disk 'virtio0' 'zfs_nvme:vm-801049-disk-0' 22732M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801049/2020-10-13T11:52:26Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 801049 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 801049 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 801049 failed - VM 801049 qmp command 'backup' failed - got timeout
INFO: Failed at 2020-10-13 13:53:37

The vms respond to ping but we cannot access it via ssh, after a few minutes we can access and the log says:

Oct 13 11:52:26 xxxxxx qemu-ga: info: guest-ping called
Oct 13 11:52:27 xxxxxx qemu-ga: info: guest-fsfreeze called
Oct 13 11:56:17 xxxxxx kernel: [1201633.025425] INFO: task systemd-journal:3180 blocked for more than 120 seconds.
Oct 13 11:56:17 xxxxxx kernel: [1201633.028632]       Not tainted 4.15.0-22-generic #24-Ubuntu
Oct 13 11:56:17 xxxxxx kernel: [1201633.029874] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 13 11:56:17 xxxxxx kernel: [1201633.031549] systemd-journal D    0  3180      1 0x00000100
Oct 13 11:56:17 xxxxxx kernel: [1201633.031559] Call Trace:
Oct 13 11:56:17 xxxxxx kernel: [1201633.031596]  __schedule+0x297/0x8b0
Oct 13 11:56:17 xxxxxx kernel: [1201633.031599]  schedule+0x2c/0x80
Oct 13 11:56:17 xxxxxx kernel: [1201633.031601]  rwsem_down_read_failed+0xee/0x150
Oct 13 11:56:17 xxxxxx kernel: [1201633.031604]  call_rwsem_down_read_failed+0x18/0x30
Oct 13 11:56:17 xxxxxx kernel: [1201633.031608]  ? call_rwsem_down_read_failed+0x18/0x30
Oct 13 11:56:17 xxxxxx kernel: [1201633.031612]  __percpu_down_read+0x58/0x80
Oct 13 11:56:17 xxxxxx kernel: [1201633.031616]  __sb_start_write+0x65/0x70
Oct 13 11:56:17 xxxxxx kernel: [1201633.031619]  do_sys_ftruncate.constprop.16+0xda/0x180
Oct 13 11:56:17 xxxxxx kernel: [1201633.031622]  SyS_ftruncate+0xe/0x10
Oct 13 11:56:17 xxxxxx kernel: [1201633.031625]  do_syscall_64+0x73/0x130
Oct 13 11:56:17 xxxxxx kernel: [1201633.031630]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
Oct 13 11:56:17 xxxxxx kernel: [1201633.031637] RIP: 0033:0x7f018d486d97
Oct 13 11:56:17 xxxxxx kernel: [1201633.031638] RSP: 002b:00007fffedfa0f98 EFLAGS: 00000202 ORIG_RAX: 000000000000004d
Oct 13 11:56:17 xxxxxx kernel: [1201633.031640] RAX: ffffffffffffffda RBX: 0000557932b181e0 RCX: 00007f018d486d97
Oct 13 11:56:17 xxxxxx kernel: [1201633.031641] RDX: 0000557932c86240 RSI: 0000000003800000 RDI: 000000000000000a
Oct 13 11:56:17 xxxxxx kernel: [1201633.031642] RBP: 00007fffedfa0fd0 R08: 000055793228308c R09: 0000557932b1825c
Oct 13 11:56:17 xxxxxx kernel: [1201633.031643] R10: 0000557932b181e0 R11: 0000000000000202 R12: 00007fffedfa0fc8
Oct 13 11:56:17 xxxxxx kernel: [1201633.031644] R13: 0000000000000003 R14: 0005b18c0c83e519 R15: 0000557931882920
Oct 13 11:58:18 xxxxxx kernel: [1201753.855771] INFO: task systemd:1 blocked for more than 120 seconds.
Oct 13 11:58:18 xxxxxx kernel: [1201753.858758]       Not tainted 4.15.0-22-generic #24-Ubuntu
Oct 13 11:58:18 xxxxxx kernel: [1201753.859844] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 13 11:58:18 xxxxxx kernel: [1201753.861302] systemd         D    0     1      0 0x00000000

I run the backup again and...

INFO: Starting Backup of VM 801049 (qemu)
INFO: Backup started at 2020-10-13 14:10:29
INFO: status = running
INFO: VM Name: xxxxxxx
INFO: include disk 'virtio0' 'zfs_nvme:vm-801049-disk-0' 22732M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801049/2020-10-13T12:10:29Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '1baa4b83-1ab9-4834-b07b-93cc6b70c9a7'
INFO: resuming VM again
INFO:   2% (516.0 MiB of 22.2 GiB) in  3s, read: 172.0 MiB/s, write: 29.3 MiB/s
INFO:   4% (1.0 GiB of 22.2 GiB) in  6s, read: 172.0 MiB/s, write: 6.7 MiB/s
INFO:   6% (1.4 GiB of 22.2 GiB) in  9s, read: 146.7 MiB/s, write: 21.3 MiB/s
INFO:   7% (1.6 GiB of 22.2 GiB) in 14s, read: 38.4 MiB/s, write: 819.2 KiB/s
INFO:   9% (2.1 GiB of 22.2 GiB) in 17s, read: 161.3 MiB/s, write: 1.3 MiB/s
INFO:  11% (2.6 GiB of 22.2 GiB) in 20s, read: 165.3 MiB/s, write: 17.3 MiB/s
INFO:  13% (3.0 GiB of 22.2 GiB) in 23s, read: 157.3 MiB/s, write: 22.7 MiB/s
INFO:  15% (3.5 GiB of 22.2 GiB) in 26s, read: 145.3 MiB/s, write: 36.0 MiB/s
INFO:  17% (3.8 GiB of 22.2 GiB) in 29s, read: 122.7 MiB/s, write: 54.7 MiB/s
INFO:  18% (4.2 GiB of 22.2 GiB) in 32s, read: 124.0 MiB/s, write: 64.0 MiB/s
INFO:  20% (4.5 GiB of 22.2 GiB) in 35s, read: 98.7 MiB/s, write: 26.7 MiB/s
INFO:  22% (4.9 GiB of 22.2 GiB) in 38s, read: 144.0 MiB/s, write: 5.3 MiB/s
INFO:  24% (5.4 GiB of 22.2 GiB) in 41s, read: 157.3 MiB/s, write: 0 B/s
INFO:  26% (5.9 GiB of 22.2 GiB) in 44s, read: 173.3 MiB/s, write: 0 B/s
INFO:  28% (6.4 GiB of 22.2 GiB) in 47s, read: 169.3 MiB/s, write: 1.3 MiB/s
INFO:  30% (6.9 GiB of 22.2 GiB) in 50s, read: 165.3 MiB/s, write: 0 B/s
INFO:  33% (7.3 GiB of 22.2 GiB) in 53s, read: 164.0 MiB/s, write: 0 B/s
INFO:  35% (7.8 GiB of 22.2 GiB) in 56s, read: 172.0 MiB/s, write: 0 B/s
INFO:  37% (8.4 GiB of 22.2 GiB) in 59s, read: 178.7 MiB/s, write: 0 B/s
INFO:  40% (8.9 GiB of 22.2 GiB) in  1m  2s, read: 181.3 MiB/s, write: 0 B/s
INFO:  42% (9.4 GiB of 22.2 GiB) in  1m  5s, read: 170.7 MiB/s, write: 0 B/s
INFO:  44% (9.9 GiB of 22.2 GiB) in  1m  8s, read: 181.3 MiB/s, write: 1.3 MiB/s
INFO:  47% (10.4 GiB of 22.2 GiB) in  1m 11s, read: 180.0 MiB/s, write: 1.3 MiB/s
INFO:  49% (11.0 GiB of 22.2 GiB) in  1m 14s, read: 185.3 MiB/s, write: 0 B/s
INFO:  51% (11.5 GiB of 22.2 GiB) in  1m 17s, read: 177.3 MiB/s, write: 0 B/s
INFO:  54% (12.0 GiB of 22.2 GiB) in  1m 20s, read: 174.7 MiB/s, write: 0 B/s
INFO:  56% (12.5 GiB of 22.2 GiB) in  1m 23s, read: 162.7 MiB/s, write: 1.3 MiB/s
INFO:  57% (12.9 GiB of 22.2 GiB) in  1m 26s, read: 126.7 MiB/s, write: 0 B/s
INFO:  60% (13.4 GiB of 22.2 GiB) in  1m 29s, read: 186.7 MiB/s, write: 2.7 MiB/s
INFO:  61% (13.6 GiB of 22.2 GiB) in  1m 32s, read: 53.3 MiB/s, write: 0 B/s
INFO:  64% (14.2 GiB of 22.2 GiB) in  1m 35s, read: 225.3 MiB/s, write: 0 B/s
INFO:  67% (14.9 GiB of 22.2 GiB) in  1m 38s, read: 228.0 MiB/s, write: 0 B/s
INFO:  70% (15.6 GiB of 22.2 GiB) in  1m 41s, read: 222.7 MiB/s, write: 0 B/s
INFO:  73% (16.2 GiB of 22.2 GiB) in  1m 44s, read: 229.3 MiB/s, write: 0 B/s
INFO:  76% (16.9 GiB of 22.2 GiB) in  1m 47s, read: 221.3 MiB/s, write: 0 B/s
INFO:  78% (17.5 GiB of 22.2 GiB) in  1m 50s, read: 221.3 MiB/s, write: 0 B/s
INFO:  81% (18.1 GiB of 22.2 GiB) in  1m 53s, read: 209.3 MiB/s, write: 0 B/s
INFO:  84% (18.8 GiB of 22.2 GiB) in  1m 56s, read: 221.3 MiB/s, write: 0 B/s
INFO:  87% (19.4 GiB of 22.2 GiB) in  1m 59s, read: 222.7 MiB/s, write: 0 B/s
INFO:  90% (20.1 GiB of 22.2 GiB) in  2m  2s, read: 210.7 MiB/s, write: 0 B/s
INFO:  93% (20.7 GiB of 22.2 GiB) in  2m  5s, read: 206.7 MiB/s, write: 0 B/s
INFO:  95% (21.3 GiB of 22.2 GiB) in  2m  8s, read: 216.0 MiB/s, write: 0 B/s
INFO:  98% (21.9 GiB of 22.2 GiB) in  2m 11s, read: 220.0 MiB/s, write: 0 B/s
INFO: 100% (22.2 GiB of 22.2 GiB) in  2m 13s, read: 134.0 MiB/s, write: 0 B/s
INFO: backup was done incrementally, reused 21.34 GiB (96%)
INFO: transferred 22.20 GiB in 133 seconds (170.9 MiB/s)
INFO: Finished Backup of VM 801049 (00:02:14)
INFO: Backup finished at 2020-10-13 14:12:43
INFO: Backup job finished successfully
TASK OK

Almost all of our vms are ubuntu 18.04 and backups are done well for many days until one day they give this error, if you re-launch it does it well

Versions of pve and PBS:

pve-qemu-kvm: 5.1.0-3
qemu-server: 6.2-15
pbs: 0.9.0-2

 

[dmembibre]

Hi,

More details:

All backups of the task with errors

INFO: Starting Backup of VM 3019 (qemu)
INFO: Backup started at 2020-10-14 08:30:02
INFO: status = running
INFO: VM Name: xxx
INFO: include disk 'virtio0' 'zfs_nvme:vm-3019-disk-0' 32G
INFO: include disk 'virtio1' 'zfs_nvme:vm-3019-disk-1' 300G
INFO: include disk 'virtio2' 'zfs_nvme:vm-3019-disk-2' 300G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/3019/2020-10-14T06:30:02Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 3019 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 3019 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 3019 failed - VM 3019 qmp command 'backup' failed - got timeout
INFO: Failed at 2020-10-14 08:31:13
INFO: Starting Backup of VM 801056 (qemu)
INFO: Backup started at 2020-10-14 08:31:13
INFO: status = running
INFO: VM Name: xxxxx
INFO: include disk 'virtio0' 'zfs_ssd:vm-801056-disk-0' 32G
INFO: include disk 'virtio1' 'zfs_nvme:vm-801056-disk-0' 128G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801056/2020-10-14T06:31:13Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 801056 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 801056 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 801056 failed - VM 801056 qmp command 'backup' failed - got timeout
INFO: Failed at 2020-10-14 08:32:23
INFO: Starting Backup of VM 801057 (qemu)
INFO: Backup started at 2020-10-14 08:32:23
INFO: status = running
INFO: VM Name: xxxx
INFO: include disk 'virtio0' 'zfs_ssd:vm-801057-disk-0' 8G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801057/2020-10-14T06:32:23Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 801057 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 801057 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 801057 failed - VM 801057 qmp command 'backup' failed - got timeout
INFO: Failed at 2020-10-14 08:33:33
INFO: Backup job finished with errors

TASK ERROR: job errors

 

[mailinglists]

Looks like your VMs are freezing on:
ERROR: VM 3019 qmp command 'guest-fsfreeze-thaw' failed - got timeout

Sadly you did not answer my question about tmp or. i did not see it (have no time for detailed reading).

Can you show me "df -h" from inside a Linux machine, that freezes on backup?

As a proof of concept for my idea, you can disable QEMU Agent on VM configuration and let backups run. It will not call fsfreeze and your instances will not crash, however when using such backup, it will have to fsck filesystem (replay journal) when booting.

 

[dmembibre]

Hi,

 ⚡ root@cloud  ~  df -h
S.ficheros                                    Tamaño Usados  Disp Uso% Montado en
/dev/vda1                                        31G    11G   19G  37% /
udev                                             10M      0   10M   0% /dev
tmpfs                                           200M    25M  176M  13% /run
tmpfs                                           500M      0  500M   0% /dev/shm
tmpfs                                           5,0M      0  5,0M   0% /run/lock
tmpfs                                           500M      0  500M   0% /sys/fs/cgroup
/dev/mapper/xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx  197G   146G   42G  78% /var/www/owncloud_data/xxxx
/dev/mapper/xxxxxxxxxxxxxxxxxxxxxxxxxxx         294G   182G   98G  66% /var/www/owncloud_data/xxxx

if I disable the agent the backup is done without problem , but now I just relaunched it with QEMU Agent enable and it was done without problem.

INFO: Starting Backup of VM 3019 (qemu)
INFO: Backup started at 2020-10-14 12:24:54
INFO: status = running
INFO: VM Name: xxxxxx
INFO: include disk 'virtio0' 'zfs_nvme:vm-3019-disk-0' 32G
INFO: include disk 'virtio1' 'zfs_nvme:vm-3019-disk-1' 300G
INFO: include disk 'virtio2' 'zfs_nvme:vm-3019-disk-2' 300G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/3019/2020-10-14T10:24:54Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'f29bf6a4-c66d-4b23-b6eb-23a43f902dc6'
INFO: resuming VM again
INFO: using fast incremental mode (dirty-bitmap), 868.0 MiB dirty of 632.0 GiB total
INFO:  35% (308.0 MiB of 868.0 MiB) in  3s, read: 102.7 MiB/s, write: 0 B/s
INFO:  69% (604.0 MiB of 868.0 MiB) in  6s, read: 98.7 MiB/s, write: 98.7 MiB/s
INFO: 100% (868.0 MiB of 868.0 MiB) in  9s, read: 88.0 MiB/s, write: 88.0 MiB/s
INFO: backup was done incrementally, reused 631.16 GiB (99%)
INFO: transferred 868.00 MiB in 9 seconds (96.4 MiB/s)
INFO: Finished Backup of VM 3019 (00:00:11)
INFO: Backup finished at 2020-10-14 12:25:05
INFO: Backup job finished successfully
TASK OK

 

[villain666]

I think this problem related with
https://forum.proxmox.com/threads/frequent-cpu-stalls-in-kvm-guests-during-high-io-on-host.30702/
https://forum.proxmox.com/threads/3000-msec-ping-and-packet-drops-with-virtio-under-load.36687/

high IO on host slowdown VMs terrible (i have this problem on small host (on desktop pc with sata storage for backup data) when GC and backup or other disk intensive task running 8-/)

 

[mailinglists]

Please leave qemu agents disabled with VM options and let it run for a while, so we can confirm my assumption.
Report back, if you get any more issues or if it works. Then we can find a suitable long term solution.

 

[dmembibre]

I think that all problems are caused by qemu agent, for example:

INFO: Starting Backup of VM 801036 (qemu)
INFO: Backup started at 2020-10-15 08:32:55
INFO: status = running
INFO: VM Name: xxxxx
INFO: include disk 'virtio0' 'zfs_ssd:vm-801036-disk-0' 50380M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801036/2020-10-15T06:32:55Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 801036 qmp command 'guest-fsfreeze-thaw' failed - got timeout
ERROR: VM 801036 qmp command 'backup' failed - got timeout
ERROR: Backup of VM 801036 failed - VM 801036 qmp command 'backup' failed - got timeout
INFO: Failed at 2020-10-15 08:34:05
INFO: Backup job finished with errors

I run the task again and not detect qemu agent:

INFO: Starting Backup of VM 801036 (qemu)
INFO: Backup started at 2020-10-15 09:03:15
INFO: status = running
INFO: VM Name: xxxxxxxx
INFO: include disk 'virtio0' 'zfs_ssd:vm-801036-disk-0' 50380M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801036/2020-10-15T07:03:15Z'
INFO: skipping guest-agent 'fs-freeze', agent configured but not running?
INFO: started backup task '4c6bd0eb-0ac7-4223-ba1e-ef33cbab1e81'
INFO: resuming VM again
INFO:   1% (540.0 MiB of 49.2 GiB) in  3s, read: 180.0 MiB/s, write: 22.7 MiB/s
INFO:   2% (1.0 GiB of 49.2 GiB) in  6s, read: 173.3 MiB/s, write: 8.0 MiB/s
INFO:   3% (1.5 GiB of 49.2 GiB) in  9s, read: 172.0 MiB/s, write: 13.3 MiB/s
INFO:   4% (2.0 GiB of 49.2 GiB) in 12s, read: 168.0 MiB/s, write: 13.3 MiB/s
INFO:   5% (2.6 GiB of 49.2 GiB) in 15s, read: 184.0 MiB/s, write: 2.7 MiB/s
INFO:   6% (3.1 GiB of 49.2 GiB) in 18s, read: 168.0 MiB/s, write: 2.7 MiB/s
INFO:   7% (3.6 GiB of 49.2 GiB) in 21s, read: 168.0 MiB/s, write: 0 B/s
INFO:   8% (4.1 GiB of 49.2 GiB) in 24s, read: 172.0 MiB/s, write: 5.3 MiB/s
INFO:   9% (4.6 GiB of 49.2 GiB) in 27s, read: 174.7 MiB/s, write: 2.7 MiB/s
INFO:  10% (5.1 GiB of 49.2 GiB) in 30s, read: 164.0 MiB/s, write: 0 B/s
INFO:  11% (5.5 GiB of 49.2 GiB) in 33s, read: 157.3 MiB/s, write: 9.3 MiB/s
INFO:  12% (6.0 GiB of 49.2 GiB) in 36s, read: 154.7 MiB/s, write: 0 B/s
INFO:  13% (6.6 GiB of 49.2 GiB) in 39s, read: 209.3 MiB/s, write: 4.0 MiB/s
INFO:  14% (6.9 GiB of 49.2 GiB) in 42s, read: 125.3 MiB/s, write: 72.0 MiB/s
INFO:  15% (7.4 GiB of 49.2 GiB) in 45s, read: 168.0 MiB/s, write: 0 B/s
INFO:  16% (7.9 GiB of 49.2 GiB) in 48s, read: 164.0 MiB/s, write: 0 B/s
INFO:  17% (8.5 GiB of 49.2 GiB) in 51s, read: 200.0 MiB/s, write: 0 B/s
INFO:  18% (9.2 GiB of 49.2 GiB) in 54s, read: 232.0 MiB/s, write: 0 B/s
INFO:  20% (9.9 GiB of 49.2 GiB) in 57s, read: 233.3 MiB/s, write: 0 B/s
INFO:  21% (10.5 GiB of 49.2 GiB) in  1m  0s, read: 230.7 MiB/s, write: 0 B/s
INFO:  22% (11.2 GiB of 49.2 GiB) in  1m  3s, read: 234.7 MiB/s, write: 0 B/s
INFO:  24% (11.9 GiB of 49.2 GiB) in  1m  6s, read: 232.0 MiB/s, write: 0 B/s
INFO:  25% (12.6 GiB of 49.2 GiB) in  1m  9s, read: 233.3 MiB/s, write: 0 B/s
INFO:  26% (13.3 GiB of 49.2 GiB) in  1m 12s, read: 232.0 MiB/s, write: 0 B/s
INFO:  28% (14.0 GiB of 49.2 GiB) in  1m 15s, read: 233.3 MiB/s, write: 0 B/s
INFO:  29% (14.6 GiB of 49.2 GiB) in  1m 18s, read: 233.3 MiB/s, write: 0 B/s
INFO:  31% (15.3 GiB of 49.2 GiB) in  1m 21s, read: 234.7 MiB/s, write: 0 B/s
INFO:  32% (16.0 GiB of 49.2 GiB) in  1m 24s, read: 233.3 MiB/s, write: 0 B/s
INFO:  33% (16.7 GiB of 49.2 GiB) in  1m 27s, read: 232.0 MiB/s, write: 0 B/s
INFO:  35% (17.4 GiB of 49.2 GiB) in  1m 30s, read: 233.3 MiB/s, write: 0 B/s
INFO:  36% (18.1 GiB of 49.2 GiB) in  1m 33s, read: 234.7 MiB/s, write: 0 B/s
INFO:  38% (18.8 GiB of 49.2 GiB) in  1m 36s, read: 234.7 MiB/s, write: 0 B/s
INFO:  39% (19.4 GiB of 49.2 GiB) in  1m 39s, read: 233.3 MiB/s, write: 0 B/s
INFO:  40% (20.1 GiB of 49.2 GiB) in  1m 42s, read: 234.7 MiB/s, write: 0 B/s
INFO:  42% (20.8 GiB of 49.2 GiB) in  1m 45s, read: 232.0 MiB/s, write: 0 B/s
INFO:  43% (21.5 GiB of 49.2 GiB) in  1m 48s, read: 233.3 MiB/s, write: 0 B/s
INFO:  45% (22.2 GiB of 49.2 GiB) in  1m 51s, read: 237.3 MiB/s, write: 0 B/s
INFO:  46% (22.9 GiB of 49.2 GiB) in  1m 54s, read: 233.3 MiB/s, write: 0 B/s
INFO:  47% (23.5 GiB of 49.2 GiB) in  1m 57s, read: 232.0 MiB/s, write: 0 B/s
INFO:  49% (24.2 GiB of 49.2 GiB) in  2m  0s, read: 236.0 MiB/s, write: 0 B/s
INFO:  50% (24.9 GiB of 49.2 GiB) in  2m  3s, read: 234.7 MiB/s, write: 0 B/s
INFO:  52% (25.6 GiB of 49.2 GiB) in  2m  6s, read: 234.7 MiB/s, write: 0 B/s
INFO:  53% (26.3 GiB of 49.2 GiB) in  2m  9s, read: 236.0 MiB/s, write: 0 B/s
INFO:  54% (27.0 GiB of 49.2 GiB) in  2m 12s, read: 232.0 MiB/s, write: 0 B/s
INFO:  56% (27.6 GiB of 49.2 GiB) in  2m 15s, read: 228.0 MiB/s, write: 0 B/s
INFO:  57% (28.3 GiB of 49.2 GiB) in  2m 18s, read: 229.3 MiB/s, write: 0 B/s
INFO:  58% (29.0 GiB of 49.2 GiB) in  2m 21s, read: 234.7 MiB/s, write: 0 B/s
INFO:  60% (29.7 GiB of 49.2 GiB) in  2m 24s, read: 236.0 MiB/s, write: 0 B/s
INFO:  61% (30.4 GiB of 49.2 GiB) in  2m 27s, read: 233.3 MiB/s, write: 0 B/s
INFO:  63% (31.1 GiB of 49.2 GiB) in  2m 30s, read: 230.7 MiB/s, write: 0 B/s
INFO:  64% (31.8 GiB of 49.2 GiB) in  2m 33s, read: 237.3 MiB/s, write: 0 B/s
INFO:  65% (32.4 GiB of 49.2 GiB) in  2m 36s, read: 232.0 MiB/s, write: 0 B/s
INFO:  67% (33.1 GiB of 49.2 GiB) in  2m 39s, read: 230.7 MiB/s, write: 0 B/s
INFO:  68% (33.8 GiB of 49.2 GiB) in  2m 42s, read: 230.7 MiB/s, write: 0 B/s
INFO:  70% (34.5 GiB of 49.2 GiB) in  2m 45s, read: 233.3 MiB/s, write: 0 B/s
INFO:  71% (35.1 GiB of 49.2 GiB) in  2m 48s, read: 230.7 MiB/s, write: 0 B/s
INFO:  72% (35.8 GiB of 49.2 GiB) in  2m 51s, read: 234.7 MiB/s, write: 0 B/s
INFO:  74% (36.5 GiB of 49.2 GiB) in  2m 54s, read: 234.7 MiB/s, write: 0 B/s
INFO:  75% (37.2 GiB of 49.2 GiB) in  2m 57s, read: 229.3 MiB/s, write: 0 B/s
INFO:  76% (37.9 GiB of 49.2 GiB) in  3m  0s, read: 234.7 MiB/s, write: 0 B/s
INFO:  78% (38.6 GiB of 49.2 GiB) in  3m  3s, read: 237.3 MiB/s, write: 0 B/s
INFO:  79% (39.3 GiB of 49.2 GiB) in  3m  6s, read: 233.3 MiB/s, write: 0 B/s
INFO:  81% (39.9 GiB of 49.2 GiB) in  3m  9s, read: 236.0 MiB/s, write: 0 B/s
INFO:  82% (40.6 GiB of 49.2 GiB) in  3m 12s, read: 234.7 MiB/s, write: 0 B/s
INFO:  83% (41.1 GiB of 49.2 GiB) in  3m 15s, read: 157.3 MiB/s, write: 0 B/s
INFO:  84% (41.8 GiB of 49.2 GiB) in  3m 18s, read: 234.7 MiB/s, write: 0 B/s
INFO:  86% (42.5 GiB of 49.2 GiB) in  3m 21s, read: 233.3 MiB/s, write: 0 B/s
INFO:  87% (43.2 GiB of 49.2 GiB) in  3m 24s, read: 233.3 MiB/s, write: 0 B/s
INFO:  89% (43.8 GiB of 49.2 GiB) in  3m 27s, read: 232.0 MiB/s, write: 0 B/s
INFO:  90% (44.5 GiB of 49.2 GiB) in  3m 30s, read: 233.3 MiB/s, write: 0 B/s
INFO:  91% (45.2 GiB of 49.2 GiB) in  3m 33s, read: 234.7 MiB/s, write: 0 B/s
INFO:  93% (45.9 GiB of 49.2 GiB) in  3m 36s, read: 233.3 MiB/s, write: 0 B/s
INFO:  94% (46.6 GiB of 49.2 GiB) in  3m 39s, read: 232.0 MiB/s, write: 0 B/s
INFO:  96% (47.2 GiB of 49.2 GiB) in  3m 42s, read: 233.3 MiB/s, write: 0 B/s
INFO:  97% (47.9 GiB of 49.2 GiB) in  3m 45s, read: 234.7 MiB/s, write: 0 B/s
INFO:  98% (48.6 GiB of 49.2 GiB) in  3m 48s, read: 232.0 MiB/s, write: 0 B/s
INFO: 100% (49.2 GiB of 49.2 GiB) in  3m 51s, read: 198.7 MiB/s, write: 0 B/s
INFO: backup was done incrementally, reused 48.74 GiB (99%)
INFO: transferred 49.20 GiB in 231 seconds (218.1 MiB/s)
INFO: Finished Backup of VM 801036 (00:03:52)
INFO: Backup finished at 2020-10-15 09:07:07
INFO: Backup job finished successfully

I run the task again and detect qemu agent:

INFO: Starting Backup of VM 801036 (qemu)
INFO: Backup started at 2020-10-15 09:11:15
INFO: status = running
INFO: VM Name: xxxx
INFO: include disk 'virtio0' 'zfs_ssd:vm-801036-disk-0' 50380M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/801036/2020-10-15T07:11:15Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'fa8f65d9-eae6-4677-a9fb-a0b9dd5e1375'
INFO: resuming VM again
INFO: using fast incremental mode (dirty-bitmap), 468.0 MiB dirty of 49.2 GiB total
INFO:  82% (388.0 MiB of 468.0 MiB) in  3s, read: 129.3 MiB/s, write: 0 B/s
INFO: 100% (468.0 MiB of 468.0 MiB) in  4s, read: 80.0 MiB/s, write: 80.0 MiB/s
INFO: backup was done incrementally, reused 48.74 GiB (99%)
INFO: transferred 468.00 MiB in 4 seconds (117.0 MiB/s)
INFO: Finished Backup of VM 801036 (00:00:05)
INFO: Backup finished at 2020-10-15 09:11:20
INFO: Backup job finished successfully

I'm going to stop the agent in the vms (I can't remove the agent from the vms configuration because they are production machines and I would have to shut them down) and see what happens these days.

 

[mailinglists]

OK,
there is a bug in Qemu Guest Agent or in kernel, that makes VMs lock up (IO operations are halted but not reported back or not all filesystems are halted). I noticed the error goes away once one stops using tmpfs (just unmounts it). Hopefully someone fixes it.

You can edit the vm conf file directly and set agent to 0. Then reboot instance, when it is appropriate.