Stuck when backup

RobertusIT

Member
Jul 13, 2021
62
0
11
38
Hi,

Issue for me, when i make backup, random issue.

Code:
INFO: starting new backup job: vzdump 100 102 104 107 109 110 111 112 114 116 115 103 105 106 108 --compress zstd --prune-backups 'keep-last=1,keep-monthly=1' --mailnotification always --quiet 1 --storage USB1TB --notes-template '{{node}} - {{guestname}} - {{cluster}} - {{vmid}}' --mode snapshot
INFO: Starting Backup of VM 100 (qemu)
INFO: Backup started at 2023-09-17 03:00:05
INFO: status = running
INFO: VM Name: BACKUP-VM-GDRIVE
INFO: include disk 'scsi0' 'local-lvm:vm-100-disk-0' 5G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/USB1TB/dump/vzdump-qemu-100-2023_09_17-03_00_05.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '5b6343dd-12e5-44f8-8b8c-f324a388bbc7'
INFO: resuming VM again
INFO:  19% (982.4 MiB of 5.0 GiB) in 3s, read: 327.5 MiB/s, write: 256.2 MiB/s
INFO:  36% (1.8 GiB of 5.0 GiB) in 6s, read: 294.8 MiB/s, write: 260.9 MiB/s
INFO:  53% (2.7 GiB of 5.0 GiB) in 9s, read: 294.8 MiB/s, write: 258.0 MiB/s
INFO:  70% (3.5 GiB of 5.0 GiB) in 12s, read: 293.6 MiB/s, write: 230.1 MiB/s
INFO:  87% (4.4 GiB of 5.0 GiB) in 15s, read: 276.7 MiB/s, write: 220.6 MiB/s
INFO: 100% (5.0 GiB of 5.0 GiB) in 18s, read: 219.2 MiB/s, write: 192.1 MiB/s
INFO: backup is sparse: 866.70 MiB (16%) total zero data
INFO: transferred 5.00 GiB in 18 seconds (284.4 MiB/s)
INFO: archive file size: 1.88GB
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=1, keep-monthly=1
INFO: removing backup 'USB1TB:backup/vzdump-qemu-100-2023_09_16-03_00_01.vma.zst'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 100 (00:00:20)
INFO: Backup finished at 2023-09-17 03:00:25
INFO: Starting Backup of VM 102 (qemu)
INFO: Backup started at 2023-09-17 03:00:25
INFO: status = running
INFO: VM Name: BITWARDEN
INFO: include disk 'scsi0' 'local-lvm:vm-102-disk-0' 20G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/USB1TB/dump/vzdump-qemu-102-2023_09_17-03_00_25.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'ba33a4f5-8a90-4802-89eb-a578d7da565b'
INFO: resuming VM again
INFO:   3% (750.0 MiB of 20.0 GiB) in 3s, read: 250.0 MiB/s, write: 203.8 MiB/s
INFO:  16% (3.4 GiB of 20.0 GiB) in 6s, read: 896.7 MiB/s, write: 139.4 MiB/s
INFO:  31% (6.3 GiB of 20.0 GiB) in 9s, read: 995.7 MiB/s, write: 90.8 MiB/s
INFO:  42% (8.5 GiB of 20.0 GiB) in 12s, read: 754.0 MiB/s, write: 172.7 MiB/s
INFO:  45% (9.0 GiB of 20.0 GiB) in 15s, read: 182.5 MiB/s, write: 114.2 MiB/s
INFO:  46% (9.2 GiB of 20.0 GiB) in 18s, read: 61.6 MiB/s, write: 53.3 MiB/s
INFO:  47% (9.5 GiB of 20.0 GiB) in 22s, read: 87.0 MiB/s, write: 68.2 MiB/s
INFO:  48% (9.8 GiB of 20.0 GiB) in 25s, read: 83.4 MiB/s, write: 66.9 MiB/s
INFO:  50% (10.0 GiB of 20.0 GiB) in 28s, read: 77.3 MiB/s, write: 73.6 MiB/s
INFO:  52% (10.4 GiB of 20.0 GiB) in 31s, read: 148.6 MiB/s, write: 95.1 MiB/s
INFO:  53% (10.8 GiB of 20.0 GiB) in 34s, read: 105.1 MiB/s, write: 90.1 MiB/s
INFO:  56% (11.2 GiB of 20.0 GiB) in 37s, read: 155.9 MiB/s, write: 88.3 MiB/s
INFO:  57% (11.5 GiB of 20.0 GiB) in 40s, read: 93.0 MiB/s, write: 73.0 MiB/s
INFO:  71% (14.3 GiB of 20.0 GiB) in 43s, read: 952.2 MiB/s, write: 118.1 MiB/s
INFO:  86% (17.2 GiB of 20.0 GiB) in 46s, read: 1002.8 MiB/s, write: 85.5 MiB/s
INFO:  88% (17.7 GiB of 20.0 GiB) in 49s, read: 157.2 MiB/s, write: 78.9 MiB/s
INFO:  91% (18.3 GiB of 20.0 GiB) in 52s, read: 204.2 MiB/s, write: 136.3 MiB/s
INFO:  94% (18.9 GiB of 20.0 GiB) in 55s, read: 211.5 MiB/s, write: 90.9 MiB/s
INFO:  95% (19.2 GiB of 20.0 GiB) in 58s, read: 101.5 MiB/s, write: 78.9 MiB/s
INFO:  97% (19.4 GiB of 20.0 GiB) in 1m 1s, read: 84.6 MiB/s, write: 66.1 MiB/s
INFO:  98% (19.7 GiB of 20.0 GiB) in 1m 4s, read: 81.0 MiB/s, write: 73.7 MiB/s
INFO:  99% (19.9 GiB of 20.0 GiB) in 1m 7s, read: 82.2 MiB/s, write: 54.1 MiB/s
INFO: 100% (20.0 GiB of 20.0 GiB) in 1m 8s, read: 89.4 MiB/s, write: 77.2 MiB/s
INFO: backup is sparse: 13.67 GiB (68%) total zero data
INFO: transferred 20.00 GiB in 68 seconds (301.2 MiB/s)
INFO: archive file size: 2.52GB
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=1, keep-monthly=1
INFO: removing backup 'USB1TB:backup/vzdump-qemu-102-2023_09_16-03_00_22.vma.zst'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 102 (00:01:11)
INFO: Backup finished at 2023-09-17 03:01:36
INFO: Starting Backup of VM 103 (qemu)
INFO: Backup started at 2023-09-17 03:01:36
INFO: status = running
INFO: VM Name: WG-PA-MI
INFO: include disk 'scsi0' 'SSD1TB:103/vm-103-disk-0.qcow2' 6G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/USB1TB/dump/vzdump-qemu-103-2023_09_17-03_01_36.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '806050b2-1a4b-4f83-a332-4c4d50d56a0e'
INFO: resuming VM again
INFO:   7% (485.8 MiB of 6.0 GiB) in 3s, read: 161.9 MiB/s, write: 154.0 MiB/s
INFO:  13% (812.0 MiB of 6.0 GiB) in 6s, read: 108.8 MiB/s, write: 106.8 MiB/s
INFO:  15% (982.4 MiB of 6.0 GiB) in 9s, read: 56.8 MiB/s, write: 48.5 MiB/s
INFO:  24% (1.5 GiB of 6.0 GiB) in 12s, read: 170.4 MiB/s, write: 124.4 MiB/s
INFO:  33% (2.0 GiB of 6.0 GiB) in 15s, read: 180.0 MiB/s, write: 144.8 MiB/s
INFO:  42% (2.5 GiB of 6.0 GiB) in 18s, read: 187.3 MiB/s, write: 148.9 MiB/s
INFO:  46% (2.8 GiB of 6.0 GiB) in 21s, read: 81.0 MiB/s, write: 77.6 MiB/s
INFO:  50% (3.0 GiB of 6.0 GiB) in 24s, read: 79.8 MiB/s, write: 75.1 MiB/s
INFO:  53% (3.2 GiB of 6.0 GiB) in 27s, read: 73.7 MiB/s, write: 72.2 MiB/s
INFO:  57% (3.5 GiB of 6.0 GiB) in 30s, read: 81.0 MiB/s, write: 78.6 MiB/s
INFO:  61% (3.7 GiB of 6.0 GiB) in 33s, read: 85.8 MiB/s, write: 78.7 MiB/s
INFO:  65% (3.9 GiB of 6.0 GiB) in 36s, read: 81.0 MiB/s, write: 63.6 MiB/s
INFO:  69% (4.1 GiB of 6.0 GiB) in 39s, read: 67.7 MiB/s, write: 53.8 MiB/s
INFO:  73% (4.4 GiB of 6.0 GiB) in 42s, read: 89.4 MiB/s, write: 83.3 MiB/s
INFO:  75% (4.5 GiB of 6.0 GiB) in 45s, read: 32.6 MiB/s, write: 32.4 MiB/s
INFO:  77% (4.6 GiB of 6.0 GiB) in 48s, read: 48.3 MiB/s, write: 48.2 MiB/s
INFO:  80% (4.8 GiB of 6.0 GiB) in 51s, read: 61.6 MiB/s, write: 60.6 MiB/s
INFO:  84% (5.1 GiB of 6.0 GiB) in 54s, read: 84.6 MiB/s, write: 79.0 MiB/s
INFO:  91% (5.5 GiB of 6.0 GiB) in 57s, read: 151.0 MiB/s, write: 94.4 MiB/s
INFO:  98% (5.9 GiB of 6.0 GiB) in 1m, read: 130.5 MiB/s, write: 94.9 MiB/s
INFO: 100% (6.0 GiB of 6.0 GiB) in 1m 1s, read: 104.8 MiB/s, write: 103.5 MiB/s
INFO: backup is sparse: 881.12 MiB (14%) total zero data
INFO: transferred 6.00 GiB in 61 seconds (100.7 MiB/s)
INFO: archive file size: 2.14GB
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=1, keep-monthly=1
INFO: removing backup 'USB1TB:backup/vzdump-qemu-103-2023_09_16-03_01_09.vma.zst'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 103 (00:01:03)
INFO: Backup finished at 2023-09-17 03:02:39
INFO: Starting Backup of VM 104 (qemu)
INFO: Backup started at 2023-09-17 03:02:39
INFO: status = running
INFO: VM Name: ORGANIZER
INFO: include disk 'scsi0' 'local-lvm:vm-104-disk-0' 5G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/USB1TB/dump/vzdump-qemu-104-2023_09_17-03_02_39.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '4c206ece-d918-4971-9329-3cbdcbca3953'
INFO: resuming VM again
INFO:  11% (605.4 MiB of 5.0 GiB) in 3s, read: 201.8 MiB/s, write: 140.7 MiB/s
INFO:  18% (971.5 MiB of 5.0 GiB) in 6s, read: 122.0 MiB/s, write: 99.4 MiB/s
INFO:  22% (1.1 GiB of 5.0 GiB) in 9s, read: 62.8 MiB/s, write: 56.1 MiB/s
INFO:  26% (1.3 GiB of 5.0 GiB) in 12s, read: 70.1 MiB/s, write: 56.8 MiB/s
INFO:  34% (1.7 GiB of 5.0 GiB) in 15s, read: 124.5 MiB/s, write: 106.2 MiB/s
INFO:  41% (2.1 GiB of 5.0 GiB) in 18s, read: 135.3 MiB/s, write: 113.9 MiB/s
INFO:  48% (2.4 GiB of 5.0 GiB) in 21s, read: 116.0 MiB/s, write: 106.7 MiB/s
INFO:  53% (2.7 GiB of 5.0 GiB) in 24s, read: 82.2 MiB/s, write: 72.1 MiB/s
INFO:  61% (3.1 GiB of 5.0 GiB) in 27s, read: 137.8 MiB/s, write: 121.3 MiB/s
INFO: 100% (5.0 GiB of 5.0 GiB) in 30s, read: 654.2 MiB/s, write: 52.1 MiB/s
INFO: backup is sparse: 2.29 GiB (45%) total zero data
INFO: transferred 5.00 GiB in 30 seconds (170.7 MiB/s)
INFO: archive file size: 1014MB
INFO: adding notes to backup
INFO: prune older backups with retention: keep-last=1, keep-monthly=1
INFO: removing backup 'USB1TB:backup/vzdump-qemu-104-2023_09_16-03_02_11.vma.zst'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 104 (00:00:31)
INFO: Backup finished at 2023-09-17 03:03:10
INFO: Starting Backup of VM 105 (lxc)
INFO: Backup started at 2023-09-17 03:03:10
INFO: status = running
INFO: CT Name: FRIGATE
INFO: including mount point rootfs ('/') in backup
INFO: mode failure - some volumes do not support snapshots
INFO: trying 'suspend' mode instead
INFO: backup mode: suspend
INFO: ionice priority: 7
INFO: CT Name: FRIGATE
INFO: including mount point rootfs ('/') in backup
INFO: starting first sync /proc/2416380/root/ to /mnt/USB1TB/dump/vzdump-lxc-105-2023_09_17-03_03_10.tmp
INFO: first sync finished - transferred 3.79G bytes in 121s
INFO: suspending guest

1694944302222.png

Last lines about dmesg
Code:
[483607.993150] EXT4-fs (dm-7): write access unavailable, skipping orphan cleanup
[483607.993158] EXT4-fs (dm-7): mounted filesystem without journal. Opts: noload. Quota mode: none.
[486071.189655] EXT4-fs (dm-12): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[555676.132838] nfs: server 192.168.178.111 not responding, still trying
[555756.707137] nfs: server 192.168.178.111 OK
[569992.195363] vmbr0: port 11(tap107i0) entered disabled state
[570043.366334] EXT4-fs (dm-7): write access unavailable, skipping orphan cleanup
[570043.366346] EXT4-fs (dm-7): mounted filesystem without journal. Opts: noload. Quota mode: none.
[572548.397563] EXT4-fs (dm-12): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[598221.454629] INFO: task kcompactd0:91 blocked for more than 120 seconds.
[598221.454639]       Tainted: P           O      5.15.111-1-pve #1
[598221.454642] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[598221.454645] task:kcompactd0      state:D stack:    0 pid:   91 ppid:     2 flags:0x00004000
[598221.454649] Call Trace:
[598221.454650]  <TASK>
[598221.454653]  __schedule+0x34e/0x1740
[598221.454658]  ? __mod_lruvec_state+0x37/0x50
[598221.454662]  ? __mod_lruvec_page_state+0x6b/0xb0
[598221.454663]  ? page_vma_mapped_walk+0x595/0xa30
[598221.454666]  schedule+0x69/0x110
[598221.454667]  io_schedule+0x46/0x80
[598221.454668]  wait_on_page_bit_common+0x114/0x3e0
[598221.454671]  ? filemap_invalidate_unlock_two+0x50/0x50
[598221.454672]  __lock_page+0x4c/0x60

[598221.454696]  ? set_kthread_struct+0x50/0x50
[598221.454698]  ret_from_fork+0x22/0x30
[598221.454701]  </TASK>
[598237.806101] nfs: server 192.168.178.111 not responding, still trying
[598342.282719] INFO: task kcompactd0:91 blocked for more than 241 seconds.
[598342.282727]       Tainted: P           O      5.15.111-1-pve #1
[598342.282729] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[598342.282730] task:kcompactd0      state:D stack:    0 pid:   91 ppid:     2 flags:0x00004000
[598342.282734] Call Trace:
[598342.282735]  <TASK>

[598342.282764]  ? migrate_vma_check_page+0xc0/0xc0
[598342.282765]  compact_zone+0x634/0xe80
[598342.282767]  ? __schedule+0x356/0x1740
[598342.282767]  ? lock_timer_base+0x3b/0xd0
[598342.282770]  proactive_compact_node+0x82/0xd0
[598342.282772]  kcompactd+0x21e/0x4c0
[598342.282773]  ? wait_woken+0x70/0x70
[598342.282775]  ? kcompactd_do_work+0x210/0x210
[598342.282776]  kthread+0x12a/0x150
[598342.282779]  ? set_kthread_struct+0x50/0x50
[598342.282780]  ret_from_fork+0x22/0x30
[598342.282783]  </TASK>
[598393.767457] nfs: server 192.168.178.111 OK
[656149.407662] device tap106i0 entered promiscuous mode
[656174.748015] fwbr106i0: port 1(fwln106i0) entered disabled state
[656174.785069] device fwpr106p0 left promiscuous mode
[656174.785072] vmbr0: port 11(fwpr106p0) entered disabled state
[656177.373751] device tap107i0 entered promiscuous mode
[656177.382979] vmbr0: port 11(tap107i0) entered blocking state
[656177.382982] vmbr0: port 11(tap107i0) entered disabled state
[656177.383061] vmbr0: port 11(tap107i0) entered blocking state
[656177.383062] vmbr0: port 11(tap107i0) entered forwarding state
[656381.141658] vmbr0: port 11(tap107i0) entered disabled state
[656428.332443] EXT4-fs (dm-7): write access unavailable, skipping orphan cleanup
[656428.332450] EXT4-fs (dm-7): mounted filesystem without journal. Opts: noload. Quota mode: none.
[658950.009156] EXT4-fs (dm-12): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[742614.990245] device tap106i0 entered promiscuous mode
[742615.019658] vmbr0: port 11(fwpr106p0) entered blocking state
[742615.019662] vmbr0: port 11(fwpr106p0) entered disabled state
[742615.019729] device fwpr106p0 entered promiscuous mode
[742615.019754] vmbr0: port 11(fwpr106p0) entered blocking state
[742615.019755] vmbr0: port 11(fwpr106p0) entered forwarding state
[742642.661666] vmbr0: port 11(tap107i0) entered blocking state
[742642.661667] vmbr0: port 11(tap107i0) entered forwarding state
[742845.372022] vmbr0: port 11(tap107i0) entered disabled state
[742893.696622] EXT4-fs (dm-7): write access unavailable, skipping orphan cleanup
[742893.696629] EXT4-fs (dm-7): mounted filesystem without journal. Opts: noload. Quota mode: none.
[745424.819007] EXT4-fs (dm-12): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[780821.622368] ata1.00: exception Emask 0x0 SAct 0x400000 SErr 0xc0000 action 0x6 frozen
[780821.622389] ata1: SError: { CommWake 10B8B }
[780821.622399] ata1.00: failed command: WRITE FPDMA QUEUED
[780821.622403] ata1.00: cmd 61/d0:b0:48:75:94/02:00:01:00:00/40 tag 22 ncq dma 368640 out
                         res 40/00:01:06:4f:c2/00:00:00:00:00/00 Emask 0x4 (timeout)
[780821.622417] ata1.00: status: { DRDY }
[780821.622424] ata1: hard resetting link
[780822.102299] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[780822.117637] ata1.00: configured for UDMA/133
[780822.128642] ata1: EH complete
[799560.230416] br-998b4902fcbd: port 1(veth7127f4e) entered disabled state
[799560.230523] veth731be34: renamed from eth0
[799560.304897] br-998b4902fcbd: port 1(veth7127f4e) entered disabled state
[799560.305585] device veth7127f4e left promiscuous mode
[799560.305589] br-998b4902fcbd: port 1(veth7127f4e) entered disabled state
[799597.192490] br-998b4902fcbd: port 1(vethfcf5acc) entered blocking state
[799597.192495] br-998b4902fcbd: port 1(vethfcf5acc) entered disabled state
[799597.192543] device vethfcf5acc entered promiscuous mode
[799597.888958] eth0: renamed from vethe098903
[799597.915791] IPv6: ADDRCONF(NETDEV_CHANGE): vethfcf5acc: link becomes ready
[799597.915829] br-998b4902fcbd: port 1(vethfcf5acc) entered blocking state
[799597.915832] br-998b4902fcbd: port 1(vethfcf5acc) entered forwarding state
[799601.652938] usb 3-3: reset high-speed USB device number 10 using xhci_hcd
root@AEROFARA:~#
 
tonught same story, please can someone help us? need other logs?
make sure there is no network issue
Code:
[555676.132838] nfs: server 192.168.178.111 not responding, still trying
or bcs of high I/O load
try to backup with limit bandwidth
 
Last edited:

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!

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!