[SOLVED] very poor backup Performance

[DrillSgtErnst]

Hi,
I have installed a fresh Proxmox.
ZFS-Raid10 Enterprise NVMe Drives

I backupped once to a external USB3, now on second try it is exhaustingly slow

Detailed backup logs:


vzdump 103 101 102 --compress zstd --mailnotification always --mailto --storage usb-sda --quiet 1 --mode snapshot


101: 2021-01-17 22:30:03 INFO: Starting Backup of VM 101 (qemu)
101: 2021-01-17 22:30:03 INFO: status = running
101: 2021-01-17 22:30:03 INFO: VM Name:
101: 2021-01-17 22:30:03 INFO: include disk 'virtio0' 'local-zfs:vm-101-disk-0' 120G
101: 2021-01-17 22:30:03 INFO: include disk 'virtio1' 'local-zfs:vm-101-disk-1' 332G
101: 2021-01-17 22:30:03 INFO: backup mode: snapshot
101: 2021-01-17 22:30:03 INFO: ionice priority: 7
101: 2021-01-17 22:30:03 INFO: creating vzdump archive '/media/sda/dump/vzdump-qemu-101-2021_01_17-22_30_02.vma.zst'
101: 2021-01-17 22:30:03 INFO: issuing guest-agent 'fs-freeze' command
101: 2021-01-17 22:30:08 INFO: issuing guest-agent 'fs-thaw' command
101: 2021-01-17 22:30:12 INFO: started backup task '4eb45992-f69c-4aec-95da-4ad4b694ed49'
101: 2021-01-17 22:30:12 INFO: resuming VM again
101: 2021-01-17 22:30:15 INFO: 0% (54.4 MiB of 452.0 GiB) in 3s, read: 18.1 MiB/s, write: 6.3 MiB/s
101: 2021-01-17 23:26:36 INFO: 1% (4.5 GiB of 452.0 GiB) in 56m 24s, read: 1.4 MiB/s, write: 1.4 MiB/s
101: 2021-01-18 00:26:45 INFO: 2% (9.0 GiB of 452.0 GiB) in 1h 56m 33s, read: 1.3 MiB/s, write: 1.3 MiB/s
101: 2021-01-18 01:23:30 INFO: 3% (13.6 GiB of 452.0 GiB) in 2h 53m 18s, read: 1.4 MiB/s, write: 1.3 MiB/s
101: 2021-01-18 02:24:57 INFO: 4% (18.1 GiB of 452.0 GiB) in 3h 54m 45s, read: 1.3 MiB/s, write: 1.2 MiB/s
101: 2021-01-18 03:23:09 INFO: 5% (22.6 GiB of 452.0 GiB) in 4h 52m 57s, read: 1.3 MiB/s, write: 1.3 MiB/s
101: 2021-01-18 04:21:36 INFO: 6% (27.1 GiB of 452.0 GiB) in 5h 51m 24s, read: 1.3 MiB/s, write: 1.3 MiB/s
101: 2021-01-18 05:19:52 INFO: 7% (31.6 GiB of 452.0 GiB) in 6h 49m 40s, read: 1.3 MiB/s, write: 1.3 MiB/s
101: 2021-01-18 06:16:39 INFO: 8% (36.2 GiB of 452.0 GiB) in 7h 46m 27s, read: 1.4 MiB/s, write: 1.4 MiB/s
101: 2021-01-18 07:13:34 INFO: 9% (40.7 GiB of 452.0 GiB) in 8h 43m 22s, read: 1.4 MiB/s, write: 1.4 MiB/s
101: 2021-01-18 07:51:03 INFO: 10% (45.2 GiB of 452.0 GiB) in 9h 20m 51s, read: 2.1 MiB/s, write: 2.1 MiB/s
101: 2021-01-18 07:57:54 INFO: 11% (49.7 GiB of 452.0 GiB) in 9h 27m 42s, read: 11.2 MiB/s, write: 11.1 MiB/s
101: 2021-01-18 07:58:45 INFO: 11% (49.9 GiB of 452.0 GiB) in 9h 28m 33s, read: 2.6 MiB/s, write: 2.6 MiB/s
101: 2021-01-18 07:58:45 ERROR: vma_queue_write: write error - Broken pipe
101: 2021-01-18 07:58:45 INFO: aborting backup job
101: 2021-01-18 07:58:45 ERROR: Backup of VM 101 failed - vma_queue_write: write error - Broken pipe

102: no log available

103: no log available

8AM the external drive was disconnected

What can cause such slow backups?

NOTE: It is USB 2.0, but 30MB/Sek should be possible though

NOTE2: There has been an USB->Serial Adapter plugged in on the same bus for communications with an UPS.
I disconnected it and will run the Backup again later and keep you updated.

Will insert an USB 3.0 later on and report if this does anything more in addition

 

[DrillSgtErnst]

INFO: starting new backup job: vzdump 103 101 102 --quiet 1 --mailto --mode snapshot --compress zstd --mailnotification always --storage usb-sda
INFO: Starting Backup of VM 101 (qemu)
INFO: Backup started at 2021-01-18 22:30:03
INFO: status = running
INFO: VM Name: dc..local
INFO: include disk 'virtio0' 'local-zfs:vm-101-disk-0' 120G
INFO: include disk 'virtio1' 'local-zfs:vm-101-disk-1' 332G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/media/sda/dump/vzdump-qemu-101-2021_01_18-22_30_02.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '22861924-e69b-49bb-b7df-9ec64eef7370'
INFO: resuming VM again
INFO: 0% (54.4 MiB of 452.0 GiB) in 3s, read: 18.1 MiB/s, write: 6.3 MiB/s
INFO: 1% (4.5 GiB of 452.0 GiB) in 51m 58s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 2% (9.0 GiB of 452.0 GiB) in 1h 46m 31s, read: 1.4 MiB/s, write: 1.4 MiB/s
INFO: 3% (13.6 GiB of 452.0 GiB) in 2h 38m 22s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 4% (18.1 GiB of 452.0 GiB) in 3h 33m 40s, read: 1.4 MiB/s, write: 1.4 MiB/s
INFO: 5% (22.6 GiB of 452.0 GiB) in 4h 25m 28s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 6% (27.1 GiB of 452.0 GiB) in 5h 19m 58s, read: 1.4 MiB/s, write: 1.4 MiB/s
INFO: 7% (31.6 GiB of 452.0 GiB) in 6h 12m 41s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 8% (36.2 GiB of 452.0 GiB) in 7h 4m 7s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 9% (40.7 GiB of 452.0 GiB) in 7h 55m 53s, read: 1.5 MiB/s, write: 1.5 MiB/s
INFO: 10% (45.2 GiB of 452.0 GiB) in 8h 29m 23s, read: 2.3 MiB/s, write: 2.3 MiB/s
INFO: 11% (49.7 GiB of 452.0 GiB) in 8h 35m 35s, read: 12.4 MiB/s, write: 12.3 MiB/s
INFO: 12% (54.2 GiB of 452.0 GiB) in 9h 19m 12s, read: 1.8 MiB/s, write: 1.8 MiB/s
INFO: 13% (58.8 GiB of 452.0 GiB) in 10h 2m 45s, read: 1.8 MiB/s, write: 1.8 MiB/s
ERROR: interrupted by signal
INFO: aborting backup job
ERROR: Backup of VM 101 failed - interrupted by signal
INFO: Failed at 2021-01-19 08:36:32
ERROR: Backup job failed - interrupted by signal

TASK ERROR: interrupted by signal
EDIT: The Task Error occurred on my End of Task

Again very very very poor Speed.
Any reply would be appreciated

 

[Alwin Antreich]

In general USB controller in those external disks aren't the best. It might very well be the external drive that fails under the load. How does it perform if you simply write with dd from urandom into a file on that USB disk?

 

[bobmc]

Can you give details of the external drive? is it possibly an SMR drive? Also what format is the external drive in?

 

[DrillSgtErnst]

In general USB controller in those external disks aren't the best. It might very well be the external drive that fails under the load. How does it perform if you simply write with dd from urandom into a file on that USB disk?

Well yes, it is an HDD indeed, BUT I wrote a full backup on the Weekend in less than 4 Hours. Same Server, Same Drive, same USB.
Unfortunately I am still backupping since 24 hours, so I get an backup at least before I can test the HDDs themselves.

Can you give details of the external drive? is it possibly an SMR drive? Also what format is the external drive in?

The Drives are https://shop.westerndigital.com/de-...g-technology-g-drive-ev-raw-usb-3-0#0G06021-1

 

[fabian]

with VMA backups, a first and subsequent backups are no different at all.. so it must be the disk acting up? do you still have the logs from the first time for comparison?

 

[bobmc]

Highly likely that this is an SMR drive



source: https://www.truenas.com/community/resources/list-of-known-smr-drives.141/

 

[DrillSgtErnst]

with VMA backups, a first and subsequent backups are no different at all.. so it must be the disk acting up? do you still have the logs from the first time for comparison?

Actually, no I do not.
at athe end it does speed up though

INFO: starting new backup job: vzdump 103 101 102 --mailnotification always --storage usb-sda --node pve --all 0 --quiet 1 - --compress zstd --mode snapshot
INFO: Starting Backup of VM 101 (qemu)
INFO: Backup started at 2021-01-19 09:20:18
INFO: status = running
INFO: VM Name: dc.local
INFO: include disk 'virtio0' 'local-zfs:vm-101-disk-0' 120G
INFO: include disk 'virtio1' 'local-zfs:vm-101-disk-1' 332G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/media/sda/dump/vzdump-qemu-101-2021_01_19-09_20_18.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
ERROR: VM 101 qmp command 'guest-fsfreeze-thaw' failed - got timeout
INFO: started backup task '3fdee144-a888-4be2-8ee0-d338696b8c1d'
INFO: resuming VM again
INFO: 0% (61.6 MiB of 452.0 GiB) in 3s, read: 20.5 MiB/s, write: 8.7 MiB/s
INFO: 1% (4.5 GiB of 452.0 GiB) in 1h 0m 23s, read: 1.3 MiB/s, write: 1.3 MiB/s
INFO: 2% (9.0 GiB of 452.0 GiB) in 2h 3m 52s, read: 1.2 MiB/s, write: 1.2 MiB/s
...
INFO: 97% (438.8 GiB of 452.0 GiB) in 1d 10h 2m, read: 425.6 MiB/s, write: 0 B/s
INFO: 98% (443.3 GiB of 452.0 GiB) in 1d 10h 3m, read: 410.6 MiB/s, write: 0 B/s
INFO: 99% (447.8 GiB of 452.0 GiB) in 1d 10h 3m, read: 466.7 MiB/s, write: 0 B/s
INFO: 100% (452.0 GiB of 452.0 GiB) in 1d 10h 3m, read: 475.9 MiB/s, write: 455.0 B/s
INFO: backup is sparse: 264.17 GiB (58%) total zero data
INFO: transferred 452.00 GiB in 122602 seconds (3.8 MiB/s)
INFO: archive file size: 122.01GB
INFO: Finished Backup of VM 101 (34:03:37)
INFO: Backup finished at 2021-01-20 19:23:55
INFO: Starting Backup of VM 102 (qemu)
INFO: Backup started at 2021-01-20 19:23:56
INFO: status = running
INFO: VM Name: sql.local
INFO: include disk 'virtio0' 'local-zfs:vm-102-disk-0' 490G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/media/sda/dump/vzdump-qemu-102-2021_01_20-19_23_56.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '59eeb1be-09ec-4186-86ee-029ce7b711b6'
INFO: resuming VM again
INFO: 0% (32.6 MiB of 490.0 GiB) in 3s, read: 10.9 MiB/s, write: 7.8 MiB/s
INFO: 1% (4.9 GiB of 490.0 GiB) in 28m 22s, read: 2.9 MiB/s, write: 2.5 MiB/s
INFO: 2% (9.8 GiB of 490.0 GiB) in 1h 8m 0s, read: 2.1 MiB/s, write: 2.1 MiB/s
INFO: 3% (14.7 GiB of 490.0 GiB) in 1h 43m 52s, read: 2.3 MiB/s, write: 2.3 MiB/s
...
INFO: 16% (78.4 GiB of 490.0 GiB) in 13h 38m 25s, read: 16.9 MiB/s, write: 16.9 MiB/s
INFO: 17% (83.3 GiB of 490.0 GiB) in 13h 43m 2s, read: 18.1 MiB/s, write: 18.1 MiB/s
INFO: 18% (88.2 GiB of 490.0 GiB) in 13h 47m 55s, read: 17.1 MiB/s, write: 17.1 MiB/s
INFO: 19% (93.1 GiB of 490.0 GiB) in 13h 52m 41s, read: 17.6 MiB/s, write: 17.6 MiB/s
INFO: 20% (98.0 GiB of 490.0 GiB) in 13h 57m 20s, read: 18.0 MiB/s, write: 18.0 MiB/s
INFO: 21% (102.9 GiB of 490.0 GiB) in 14h 2m 49s, read: 15.3 MiB/s, write: 15.3 MiB/s
INFO: 22% (107.8 GiB of 490.0 GiB) in 14h 8m 27s, read: 14.8 MiB/s, write: 14.8 MiB/s
INFO: 23% (112.7 GiB of 490.0 GiB) in 14h 14m 20s, read: 14.2 MiB/s, write: 14.2 MiB/s
INFO: 24% (117.6 GiB of 490.0 GiB) in 14h 21m 47s, read: 11.2 MiB/s, write: 11.2 MiB/s
INFO: 25% (122.5 GiB of 490.0 GiB) in 14h 28m 1s, read: 13.4 MiB/s, write: 13.4 MiB/s
INFO: 26% (127.4 GiB of 490.0 GiB) in 14h 32m 50s, read: 17.4 MiB/s, write: 17.4 MiB/s
INFO: 27% (132.3 GiB of 490.0 GiB) in 14h 39m 5s, read: 13.4 MiB/s, write: 13.3 MiB/s
INFO: 28% (137.2 GiB of 490.0 GiB) in 14h 52m 23s, read: 6.3 MiB/s, write: 6.3 MiB/s
INFO: 29% (142.1 GiB of 490.0 GiB) in 15h 11m 30s, read: 4.4 MiB/s, write: 4.4 MiB/s
INFO: 30% (147.0 GiB of 490.0 GiB) in 15h 31m 0s, read: 4.3 MiB/s, write: 4.3 MiB/s
...
INFO: 94% (461.0 GiB of 490.0 GiB) in 2d 20h 34m, read: 436.2 MiB/s, write: 0 B/s
INFO: 95% (465.7 GiB of 490.0 GiB) in 2d 20h 34m, read: 435.6 MiB/s, write: 0 B/s
INFO: 96% (470.6 GiB of 490.0 GiB) in 2d 20h 34m, read: 418.4 MiB/s, write: 0 B/s
INFO: 97% (475.6 GiB of 490.0 GiB) in 2d 20h 34m, read: 423.2 MiB/s, write: 0 B/s
INFO: 98% (480.5 GiB of 490.0 GiB) in 2d 20h 34m, read: 422.1 MiB/s, write: 0 B/s
INFO: 99% (485.5 GiB of 490.0 GiB) in 2d 20h 35m, read: 423.0 MiB/s, write: 0 B/s
INFO: 100% (490.0 GiB of 490.0 GiB) in 2d 20h 35m, read: 422.6 MiB/s, write: 372.0 B/s
INFO: backup is sparse: 47.12 GiB (9%) total zero data
INFO: transferred 490.00 GiB in 246921 seconds (2.0 MiB/s)
INFO: archive file size: 258.31GB
INFO: Finished Backup of VM 102 (68:35:31)
INFO: Backup finished at 2021-01-23 15:59:27
INFO: Starting Backup of VM 103 (qemu)
INFO: Backup started at 2021-01-23 15:59:27
INFO: status = running
INFO: VM Name: homeoffice0.local
INFO: include disk 'virtio0' 'local-zfs:vm-103-disk-0' 250G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/media/sda/dump/vzdump-qemu-103-2021_01_23-15_59_27.vma.zst'
INFO: started backup task 'ecea16b7-6e25-4a0c-b0b2-692aca3b0448'
INFO: resuming VM again
INFO: 0% (32.6 MiB of 250.0 GiB) in 3s, read: 10.9 MiB/s, write: 4.9 MiB/s
INFO: 1% (2.5 GiB of 250.0 GiB) in 20m 13s, read: 2.1 MiB/s, write: 2.0 MiB/s
INFO: 2% (5.0 GiB of 250.0 GiB) in 34m 38s, read: 3.0 MiB/s, write: 2.9 MiB/s
INFO: 3% (7.5 GiB of 250.0 GiB) in 51m 53s, read: 2.5 MiB/s, write: 2.4 MiB/s
INFO: 4% (10.0 GiB of 250.0 GiB) in 1h 12m 19s, read: 2.1 MiB/s, write: 2.0 MiB/s
INFO: 5% (12.5 GiB of 250.0 GiB) in 1h 17m 35s, read: 8.1 MiB/s, write: 2.2 MiB/s
INFO: 6% (15.4 GiB of 250.0 GiB) in 1h 19m 27s, read: 26.3 MiB/s, write: 2.3 MiB/s
INFO: 7% (17.5 GiB of 250.0 GiB) in 1h 32m 38s, read: 2.8 MiB/s, write: 2.0 MiB/s
...
INFO: 99% (247.7 GiB of 250.0 GiB) in 4h 23m 7s, read: 408.2 MiB/s, write: 0 B/s
INFO: 100% (250.0 GiB of 250.0 GiB) in 4h 28m 51s, read: 6.9 MiB/s, write: 1.2 MiB/s
INFO: backup is sparse: 220.43 GiB (88%) total zero data
INFO: transferred 250.00 GiB in 16131 seconds (15.9 MiB/s)
INFO: archive file size: 16.75GB
INFO: Finished Backup of VM 103 (04:28:58)
INFO: Backup finished at 2021-01-23 20:28:25
INFO: Backup job finished successfully
TASK OK


But I guess the "Speed" is just empty space.
The SQL does speed up to 20MB/Sec though.


Maybe I confused you with my choice of words.
The Backups are not on the same drive. I had one backup written onto usb-sda, then changed the drive and again wrote to usb-sda.

I now have a brand new USB 3.0 Controller Card with 4 independent USB Controllers, so no other device can interfere wirh the speed and I am going to Test the speed without the Dockingstation.

I'll keep you updated


EDIT:
I found the old Log
INFO: starting new backup job: vzdump 101 102 103 --quiet 1 --mailnotification always --compress zstd --mode snapshot --node pve --storage backup --all 0
INFO: Starting Backup of VM 101 (qemu)
INFO: Backup started at 2021-01-17 00:03:45
INFO: status = running
INFO: VM Name: dc.local
INFO: include disk 'virtio0' 'local-zfs:vm-101-disk-0' 120G
INFO: include disk 'virtio1' 'local-zfs:vm-101-disk-1' 332G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/backup/dump/vzdump-qemu-101-2021_01_17-00_03_45.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'e6bd17b2-71e0-4b91-878a-ada3a646a65f'
INFO: resuming VM again
INFO: 0% (855.5 MiB of 452.0 GiB) in 3s, read: 285.2 MiB/s, write: 273.3 MiB/s
INFO: 1% (4.6 GiB of 452.0 GiB) in 39s, read: 107.5 MiB/s, write: 107.5 MiB/s
INFO: 2% (9.1 GiB of 452.0 GiB) in 1m 22s, read: 105.7 MiB/s, write: 105.0 MiB/s
INFO: 3% (13.7 GiB of 452.0 GiB) in 2m 4s, read: 112.8 MiB/s, write: 110.4 MiB/s
INFO: 4% (18.2 GiB of 452.0 GiB) in 2m 43s, read: 117.7 MiB/s, write: 116.4 MiB/s
INFO: 5% (22.7 GiB of 452.0 GiB) in 3m 35s, read: 88.6 MiB/s, write: 88.4 MiB/s
INFO: 6% (27.2 GiB of 452.0 GiB) in 4m 55s, read: 57.5 MiB/s, write: 57.5 MiB/s
INFO: 7% (31.6 GiB of 452.0 GiB) in 6m 55s, read: 38.3 MiB/s, write: 38.3 MiB/s
INFO: 8% (36.2 GiB of 452.0 GiB) in 8m 33s, read: 47.6 MiB/s, write: 47.6 MiB/s
...
INFO: 98% (443.3 GiB of 452.0 GiB) in 55m 1s, read: 414.5 MiB/s, write: 0 B/s
INFO: 99% (447.8 GiB of 452.0 GiB) in 55m 10s, read: 508.7 MiB/s, write: 0 B/s
INFO: 100% (452.0 GiB of 452.0 GiB) in 55m 20s, read: 431.5 MiB/s, write: 409.0 B/s
INFO: backup is sparse: 264.48 GiB (58%) total zero data
INFO: transferred 452.00 GiB in 3320 seconds (139.4 MiB/s)
INFO: archive file size: 121.67GB
INFO: Finished Backup of VM 101 (00:55:28)
INFO: Backup finished at 2021-01-17 00:59:13

INFO: Starting Backup of VM 102 (qemu)
INFO: 0% (950.2 MiB of 490.0 GiB) in 3s, read: 316.8 MiB/s, write: 135.6 MiB/s
INFO: 1% (5.0 GiB of 490.0 GiB) in 43s, read: 103.8 MiB/s, write: 102.8 MiB/s
INFO: 2% (9.8 GiB of 490.0 GiB) in 1m 30s, read: 105.7 MiB/s, write: 104.7 MiB/s
INFO: 3% (14.7 GiB of 490.0 GiB) in 2m 57s, read: 57.5 MiB/s, write: 55.7 MiB/s
INFO: 4% (19.6 GiB of 490.0 GiB) in 4m 11s, read: 68.0 MiB/s, write: 67.5 MiB/s
INFO: 5% (24.5 GiB of 490.0 GiB) in 5m 47s, read: 52.2 MiB/s, write: 50.8 MiB/s
INFO: 6% (29.4 GiB of 490.0 GiB) in 8m 7s, read: 35.9 MiB/s, write: 35.9 MiB/s
INFO: 7% (34.3 GiB of 490.0 GiB) in 10m 21s, read: 37.5 MiB/s, write: 37.5 MiB/s
INFO: 8% (39.2 GiB of 490.0 GiB) in 12m 10s, read: 45.8 MiB/s, write: 45.3 MiB/s
INFO: 9% (44.1 GiB of 490.0 GiB) in 14m 10s, read: 41.9 MiB/s, write: 41.8 MiB/s
INFO: 10% (49.0 GiB of 490.0 GiB) in 16m 23s, read: 37.6 MiB/s, write: 37.5 MiB/s
INFO: 11% (53.9 GiB of 490.0 GiB) in 18m 30s, read: 39.6 MiB/s, write: 39.5 MiB/s
INFO: 12% (58.8 GiB of 490.0 GiB) in 20m 7s, read: 51.8 MiB/s, write: 51.5 MiB/s
INFO: 13% (63.7 GiB of 490.0 GiB) in 21m 41s, read: 53.4 MiB/s, write: 52.9 MiB/s
...
INFO: 99% (485.1 GiB of 490.0 GiB) in 2h 10m 26s, read: 380.4 MiB/s, write: 0 B/s
INFO: 100% (490.0 GiB of 490.0 GiB) in 2h 10m 38s, read: 416.9 MiB/s, write: 341.0 B/s
INFO: backup is sparse: 50.59 GiB (10%) total zero data
INFO: transferred 490.00 GiB in 7838 seconds (64.0 MiB/s)
INFO: archive file size: 256.15GB
INFO: Finished Backup of VM 102 (02:10:45)

INFO: Starting Backup of VM 103 (qemu)
INFO: 0% (395.1 MiB of 250.0 GiB) in 3s, read: 131.7 MiB/s, write: 117.0 MiB/s
INFO: 1% (2.6 GiB of 250.0 GiB) in 22s, read: 119.1 MiB/s, write: 102.4 MiB/s
INFO: 2% (5.0 GiB of 250.0 GiB) in 46s, read: 103.9 MiB/s, write: 103.5 MiB/s
INFO: 3% (7.5 GiB of 250.0 GiB) in 1m 10s, read: 105.9 MiB/s, write: 104.4 MiB/s
INFO: 4% (10.1 GiB of 250.0 GiB) in 1m 34s, read: 111.6 MiB/s, write: 107.4 MiB/s
INFO: 5% (12.6 GiB of 250.0 GiB) in 1m 41s, read: 354.6 MiB/s, write: 44.5 MiB/s
INFO: 6% (15.2 GiB of 250.0 GiB) in 1m 47s, read: 454.9 MiB/s, write: 28.9 MiB/s
INFO: 7% (17.5 GiB of 250.0 GiB) in 2m 2s, read: 157.1 MiB/s, write: 105.6 MiB/s
...
INFO: 11% (27.6 GiB of 250.0 GiB) in 3m 5s, read: 548.4 MiB/s, write: 0 B/s
INFO: 12% (30.4 GiB of 250.0 GiB) in 3m 10s, read: 570.3 MiB/s, write: 0 B/s
INFO: 13% (32.9 GiB of 250.0 GiB) in 3m 15s, read: 515.1 MiB/s, write: 0 B/s

hence the different mountpoint only because I mounted it manually at that time.

 

[DrillSgtErnst]

Highly likely that this is an SMR drive


View attachment 22870
source: https://www.truenas.com/community/resources/list-of-known-smr-drives.141/

They are not SMR

WD20NPVZ-82WFZT0​

actually I haven't seen it before, but they are consumer grade.

This is really uncool, they were pretty expensive and I bought them from G-Technology, whose products are for professionals and creatives.

I am really disappointed right now, but no SMR

 

[fabian]

unless I misread something, those are laptop drives inside the enclosure? the WD20NPVZ 2TB is a 5200RPM drive with 8MB of cache according to the datasheet, so I'd not expect much from it..

the speedup in your logs at the end is definitely because of zero blocks, not because the disk got faster there

 

[DrillSgtErnst]

You're not wrong. But definately I should expect more than 2MB/Sec, as I had on my first Backup Process on the 17.01.2021.

Before that I used these drives for I think ten years to backup the old SBS 2008.

I am still not convinced it is the drive.

You can see a speed up in the middle of 102 where we reach ~30MB/Sek. This would be sufficient.

I will give you feedback after installing the new USB Controller shortly

 

[fabian]

that speedup when backing up 103 is very likely a shorter streak of all-zero data (the burst is on the read-side only)

 

[guletz]

They are not SMR

Hi,

Maybe could be a usb interface that can be faulty in many ways(or several spin down/up, many blocks that can not be read/write/re-write from the first try, or others problems). The best that you can do is to test your usb HDD with smartd(if it is supported) AND with badblocks(r/w mode). After this test/tests you can have a good reason to think that your device it is OK. In any other cases(without any other tests) I will have a big problem to think that your hdd-usb is OK.

And also I would try to write a backup(local file) to /dev/null to see if the reading from the source is OK(as speed/time). If it is what is expected, then the problem is for sure on the destination side.

Another problem could be the block size of your HDD-usb(I guess is 512) and the FS that you have on it(NTFS? maybe is a too fragment FS, or low free space ???)

Good luck / Bafta !

 

[DrillSgtErnst]

Sooo I'm back.
performance keeps low.
I installed a brand new USB 3 Card with 4 independent USB Controllers
I started an backup without compression for testing and I am getting about 30MB/Sec performance. Either ZST or GZIP or LZO are dragging down the performance to the known low performance.

Also I started an quick Test with hdparam.
It looks like the Disk is not at fault. (I took a photo from the screen directly in the Serverroom after attaching the disk.
The CPU should have enough Power (Xeon E5 2680) and I still have 25GB RAM available.
The Server should be able to backup faster.

 

[fabian]

can you watch with something like atop during the backup and see which resources are bottle necking? there must be something strange going on..

 

[DrillSgtErnst]

top - 13:06:38 up 23:51, 3 users, load average: 4.08, 2.79, 2.24
Tasks: 678 total, 1 running, 676 sleeping, 0 stopped, 1 zombie
%Cpu(s): 7.4 us, 0.9 sy, 0.0 ni, 88.6 id, 3.0 wa, 0.0 hi, 0.1 si, 0.0 st
MiB Mem : 128897.4 total, 656.9 free, 96477.4 used, 31763.1 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 31313.8 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3333 root 20 0 20.2g 16.1g 3992 S 221.6 12.8 642:36.09 kvm
16227 root 20 0 67.4g 64.0g 3808 S 24.6 50.9 762:26.40 kvm
16555 root 20 0 12.9g 8.1g 3944 S 4.3 6.4 71:06.33 kvm
17085 root 20 0 138296 50604 1576 D 2.7 0.0 0:03.05 zstd
3064 root 20 0 303216 87688 8164 S 2.0 0.1 6:50.18 pvestatd
593 root 0 -20 0 0 0 S 0.7 0.0 15:26.03 zvol
772 root 1 -19 0 0 0 S 0.7 0.0 1:06.60 z_wr_iss
776 root 1 -19 0 0 0 S 0.7 0.0 1:06.64 z_wr_iss
779 root 1 -19 0 0 0 S 0.7 0.0 1:06.61 z_wr_iss
781 root 1 -19 0 0 0 S 0.7 0.0 1:06.56 z_wr_iss
782 root 1 -19 0 0 0 S 0.7 0.0 1:06.64 z_wr_iss
788 root 1 -19 0 0 0 S 0.7 0.0 1:06.71 z_wr_iss
793 root 0 -20 0 0 0 S 0.7 0.0 0:53.08 z_wr_int
922 www-data 20 0 363608 131308 10076 S 0.7 0.1 0:03.25 pveproxy worker
19205 root 20 0 361672 127888 8472 S 0.7 0.1 0:00.66 pvedaemon worke


I also added a screenshot, since it is better aligned


EDIT:
I mounted the drive now manually.
The performance is NUTS.
above 100MB/Sec. The Problem seems to be the usb-automount feature


EDIT 2:
I found something about that in the PVE USB Automount Tutorial Article
https://forum.proxmox.com/threads/usb-automount.39296/page-2#post-360502
testing this right now, keep you updated!

 

[guletz]

I mounted the drive now manually.
The performance is NUTS.

.... so if you would have the willing to try what I have write

And also I would try to write a backup(local file) to /dev/null to see if the reading from the source is OK(as speed/time). If it is what is expected, then the problem is for sure on the destination side.

Anyway, good to know that you are on the good path!

Good luck / Bafta !

 

[DrillSgtErnst]

.... so if you would have the willing to try what I have write



Anyway, good to know that you are on the good path!

Good luck / Bafta !

Yeah I'm sorry. I could only start the test yesterday, because the servers were still locked in backup process.

I now ran all tests with a separate Win 10 machine and it's looking good so far.
tbh. I did not understand some points of your post prior, but as far as I understood I should test whether the HDD is okay and my tests with hdparam said the hdd is okay. And I installed a completely new usb card, so I could determine it is no pin problem.

The source meanwhile is a NVME Enterprise SSD Raid ZFS10, I could not think of these as faulty.

But yeah. with the mounting on my own path mount /dev/sda /mnt/backup and good backup performance on that mount I could determine, that neither source, nor target are faulty and it must be something with the USB automount feature. And yeah. It was known as I linked in my article above.

I ran a full backup now.30 Minutes for 50%, instead of 30 hours for 20%

 

[fabian]

great that you found the cause

 

[guletz]

I did not understand some points of your post prior, but as far as I understood I should test whether the HDD is okay and my tests with hdparam said the hdd is okay. And I installed a completely new usb card, so I could determine it is no pin problem.

Hi,

I will try again with some more details. When you have a problem on a system with 2 different sorage systems(A and B, A=zfs in your case, B= usb drive) and you discover a problem(low speed or whatever) you must start to investigate the source(A) and destination(B).
You start from the A storage, and test if the redings from A are OK, so copy a large file(biggest then your RAM/cache, 2xRAM?) like this:

cp big_file_from_A /dev/null

With this command you can see if reading from A is OK or not. Think that any opp with /dev/null is super-fast!
If the problem is not on A side, then the problem will be on B side. The B storage can be tested(biggest then your RAM/cache) like this:

head -c 10 G </dev/urandom > big_file_on_B

Now I hope it is clear what I write(especially regarding /dev/null )!


Good luck /Bafta !