[SOLVED] PBS: backup write data failed: command error: protocol canceled

voarsh

Member
Nov 20, 2020
218
19
23
28
I just tried a 500 GB VM backup just fine, but running this one, for some reason, results in this. I've tried more than once.

Code:
INFO: starting new backup job: vzdump 142 --storage PBS --node HPProliantDL360PGen8 --mode snapshot --remove 0
INFO: Starting Backup of VM 142 (qemu)
INFO: Backup started at 2021-05-23 04:27:08
INFO: status = running
INFO: VM Name: virtualmin
INFO: include disk 'scsi0' 'HPBay8:vm-142-disk-0' 310G
INFO: backup mode: snapshot
INFO: ionice priority: 5
INFO: creating Proxmox Backup Server archive 'vm/142/2021-05-23T03:27:08Z'
INFO: started backup task 'f75937ee-c7e5-481e-bd28-805a4b1a1936'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO:   0% (300.0 MiB of 310.0 GiB) in 3s, read: 100.0 MiB/s, write: 61.3 MiB/s
INFO:   1% (3.1 GiB of 310.0 GiB) in 43s, read: 72.8 MiB/s, write: 67.0 MiB/s
INFO:   2% (6.3 GiB of 310.0 GiB) in 1m 19s, read: 89.7 MiB/s, write: 88.2 MiB/s
INFO:   3% (9.3 GiB of 310.0 GiB) in 2m 1s, read: 74.5 MiB/s, write: 73.9 MiB/s
INFO:   4% (12.4 GiB of 310.0 GiB) in 2m 51s, read: 63.6 MiB/s, write: 62.5 MiB/s
INFO:   4% (13.1 GiB of 310.0 GiB) in 3m 20s, read: 22.6 MiB/s, write: 22.6 MiB/s
ERROR: backup write data failed: command error: protocol canceled
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 142 failed - backup write data failed: command error: protocol canceled
INFO: Failed at 2021-05-23 04:30:29
INFO: Backup job finished with errors
TASK ERROR: job errors
 
Any hint in the backup task log on the backup server?
Nothing useful I think:
Code:
2021-05-23T03:27:08+00:00: starting new backup on datastore 'StoragePool': "vm/142/2021-05-23T03:27:08Z"
2021-05-23T03:27:08+00:00: GET /previous: 400 Bad Request: no valid previous backup
2021-05-23T03:27:08+00:00: created new fixed index 1 ("vm/142/2021-05-23T03:27:08Z/drive-scsi0.img.fidx")
2021-05-23T03:27:08+00:00: add blob "/storage/vm/142/2021-05-23T03:27:08Z/qemu-server.conf.blob" (365 bytes, comp: 365)
 
This issue continues to happen.
Strangely, on other stores:
I have one. E.G. PBS and several others.

PBS works 90% of the time, but other ones on separate disks don't.

E.G.
PBS:
Code:
INFO: starting new backup job: vzdump 148 --node pve --storage PBS --mode snapshot --remove 0
INFO: Starting Backup of VM 148 (qemu)
INFO: Backup started at 2021-05-23 13:42:24
INFO: status = running
INFO: VM Name: Virtualminmainmaintenance
INFO: include disk 'scsi0' 'local-lvm:vm-148-disk-0' 15G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/148/2021-05-23T12:42:24Z'
INFO: started backup task '3343ab57-55f1-4fcb-b19f-2a5efab2a6a8'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: created new
INFO:   1% (252.0 MiB of 15.0 GiB) in 3s, read: 84.0 MiB/s, write: 45.3 MiB/s
INFO:   2% (384.0 MiB of 15.0 GiB) in 6s, read: 44.0 MiB/s, write: 44.0 MiB/s
INFO:   3% (480.0 MiB of 15.0 GiB) in 9s, read: 32.0 MiB/s, write: 32.0 MiB/s
INFO:   4% (616.0 MiB of 15.0 GiB) in 12s, read: 45.3 MiB/s, write: 44.0 MiB/s
INFO:   7% (1.1 GiB of 15.0 GiB) in 15s, read: 177.3 MiB/s, write: 36.0 MiB/s
INFO:   8% (1.3 GiB of 15.0 GiB) in 18s, read: 46.7 MiB/s, write: 37.3 MiB/s
INFO:   9% (1.4 GiB of 15.0 GiB) in 21s, read: 38.7 MiB/s, write: 38.7 MiB/s
INFO:  10% (1.5 GiB of 15.0 GiB) in 24s, read: 44.0 MiB/s, write: 44.0 MiB/s
INFO:  11% (1.7 GiB of 15.0 GiB) in 28s, read: 39.0 MiB/s, write: 39.0 MiB/s
INFO:  12% (1.8 GiB of 15.0 GiB) in 32s, read: 38.0 MiB/s, write: 36.0 MiB/s
INFO:  13% (2.0 GiB of 15.0 GiB) in 37s, read: 36.8 MiB/s, write: 36.8 MiB/s
INFO:  14% (2.1 GiB of 15.0 GiB) in 41s, read: 37.0 MiB/s, write: 37.0 MiB/s
INFO:  15% (2.3 GiB of 15.0 GiB) in 44s, read: 44.0 MiB/s, write: 44.0 MiB/s
INFO:  16% (2.4 GiB of 15.0 GiB) in 48s, read: 43.0 MiB/s, write: 43.0 MiB/s
INFO:  17% (2.6 GiB of 15.0 GiB) in 51s, read: 52.0 MiB/s, write: 52.0 MiB/s
INFO:  18% (2.7 GiB of 15.0 GiB) in 55s, read: 34.0 MiB/s, write: 27.0 MiB/s
INFO:  19% (2.9 GiB of 15.0 GiB) in 1m 1s, read: 28.0 MiB/s, write: 28.0 MiB/s
INFO:  21% (3.2 GiB of 15.0 GiB) in 1m 4s, read: 112.0 MiB/s, write: 24.0 MiB/s
INFO:  22% (3.3 GiB of 15.0 GiB) in 1m 7s, read: 49.3 MiB/s, write: 38.7 MiB/s
INFO:  34% (5.2 GiB of 15.0 GiB) in 1m 10s, read: 625.3 MiB/s, write: 33.3 MiB/s
INFO:  35% (5.4 GiB of 15.0 GiB) in 1m 13s, read: 62.7 MiB/s, write: 40.0 MiB/s
INFO:  36% (5.4 GiB of 15.0 GiB) in 1m 16s, read: 29.3 MiB/s, write: 29.3 MiB/s
INFO:  37% (5.6 GiB of 15.0 GiB) in 1m 19s, read: 40.0 MiB/s, write: 40.0 MiB/s
INFO:  38% (5.7 GiB of 15.0 GiB) in 1m 24s, read: 36.0 MiB/s, write: 36.0 MiB/s
INFO:  39% (5.9 GiB of 15.0 GiB) in 1m 28s, read: 38.0 MiB/s, write: 38.0 MiB/s
INFO:  40% (6.0 GiB of 15.0 GiB) in 1m 31s, read: 41.3 MiB/s, write: 41.3 MiB/s
INFO:  41% (6.2 GiB of 15.0 GiB) in 1m 35s, read: 38.0 MiB/s, write: 38.0 MiB/s
INFO:  42% (6.3 GiB of 15.0 GiB) in 1m 39s, read: 38.0 MiB/s, write: 38.0 MiB/s
INFO:  43% (6.5 GiB of 15.0 GiB) in 1m 43s, read: 38.0 MiB/s, write: 38.0 MiB/s
INFO:  44% (6.6 GiB of 15.0 GiB) in 1m 48s, read: 38.4 MiB/s, write: 36.8 MiB/s
INFO:  45% (6.8 GiB of 15.0 GiB) in 1m 51s, read: 38.7 MiB/s, write: 32.0 MiB/s
INFO:  46% (6.9 GiB of 15.0 GiB) in 1m 55s, read: 42.0 MiB/s, write: 42.0 MiB/s
INFO:  47% (7.1 GiB of 15.0 GiB) in 1m 59s, read: 34.0 MiB/s, write: 33.0 MiB/s
INFO:  48% (7.2 GiB of 15.0 GiB) in 2m 3s, read: 50.0 MiB/s, write: 42.0 MiB/s
INFO:  49% (7.4 GiB of 15.0 GiB) in 2m 6s, read: 37.3 MiB/s, write: 37.3 MiB/s
INFO:  50% (7.5 GiB of 15.0 GiB) in 2m 10s, read: 42.0 MiB/s, write: 42.0 MiB/s
INFO:  51% (7.7 GiB of 15.0 GiB) in 2m 14s, read: 35.0 MiB/s, write: 35.0 MiB/s
INFO:  52% (7.8 GiB of 15.0 GiB) in 2m 19s, read: 36.8 MiB/s, write: 36.8 MiB/s
INFO:  53% (8.0 GiB of 15.0 GiB) in 2m 23s, read: 37.0 MiB/s, write: 37.0 MiB/s
INFO:  54% (8.1 GiB of 15.0 GiB) in 2m 27s, read: 36.0 MiB/s, write: 36.0 MiB/s
INFO:  55% (8.2 GiB of 15.0 GiB) in 2m 31s, read: 33.0 MiB/s, write: 33.0 MiB/s
INFO:  56% (8.4 GiB of 15.0 GiB) in 2m 38s, read: 26.3 MiB/s, write: 21.7 MiB/s
INFO:  57% (8.6 GiB of 15.0 GiB) in 2m 43s, read: 25.6 MiB/s, write: 20.8 MiB/s
INFO:  58% (8.7 GiB of 15.0 GiB) in 2m 48s, read: 34.4 MiB/s, write: 32.8 MiB/s
INFO:  59% (8.9 GiB of 15.0 GiB) in 2m 52s, read: 35.0 MiB/s, write: 28.0 MiB/s
INFO:  60% (9.0 GiB of 15.0 GiB) in 2m 57s, read: 29.6 MiB/s, write: 29.6 MiB/s
INFO:  61% (9.2 GiB of 15.0 GiB) in 3m, read: 64.0 MiB/s, write: 34.7 MiB/s
INFO:  62% (9.3 GiB of 15.0 GiB) in 3m 4s, read: 38.0 MiB/s, write: 38.0 MiB/s
INFO:  63% (9.5 GiB of 15.0 GiB) in 3m 8s, read: 37.0 MiB/s, write: 37.0 MiB/s
INFO:  64% (9.6 GiB of 15.0 GiB) in 3m 12s, read: 34.0 MiB/s, write: 34.0 MiB/s
INFO:  65% (9.8 GiB of 15.0 GiB) in 3m 17s, read: 33.6 MiB/s, write: 33.6 MiB/s
INFO:  66% (9.9 GiB of 15.0 GiB) in 3m 21s, read: 39.0 MiB/s, write: 36.0 MiB/s
INFO:  67% (10.1 GiB of 15.0 GiB) in 3m 24s, read: 42.7 MiB/s, write: 42.7 MiB/s
INFO:  68% (10.2 GiB of 15.0 GiB) in 3m 29s, read: 35.2 MiB/s, write: 34.4 MiB/s
INFO:  69% (10.4 GiB of 15.0 GiB) in 3m 33s, read: 40.0 MiB/s, write: 40.0 MiB/s
INFO:  70% (10.5 GiB of 15.0 GiB) in 3m 36s, read: 46.7 MiB/s, write: 44.0 MiB/s
INFO:  74% (11.2 GiB of 15.0 GiB) in 3m 39s, read: 228.0 MiB/s, write: 33.3 MiB/s
INFO:  75% (11.3 GiB of 15.0 GiB) in 3m 42s, read: 25.3 MiB/s, write: 25.3 MiB/s
INFO:  76% (11.4 GiB of 15.0 GiB) in 3m 48s, read: 26.7 MiB/s, write: 26.7 MiB/s
INFO:  86% (13.0 GiB of 15.0 GiB) in 3m 51s, read: 554.7 MiB/s, write: 28.0 MiB/s
INFO:  88% (13.2 GiB of 15.0 GiB) in 3m 54s, read: 57.3 MiB/s, write: 36.0 MiB/s
INFO:  89% (13.4 GiB of 15.0 GiB) in 4m, read: 25.3 MiB/s, write: 25.3 MiB/s
INFO:  90% (13.5 GiB of 15.0 GiB) in 4m 7s, read: 23.4 MiB/s, write: 23.4 MiB/s
INFO:  91% (13.7 GiB of 15.0 GiB) in 4m 13s, read: 25.3 MiB/s, write: 25.3 MiB/s
INFO:  92% (13.8 GiB of 15.0 GiB) in 4m 18s, read: 29.6 MiB/s, write: 29.6 MiB/s
INFO: 100% (15.0 GiB of 15.0 GiB) in 4m 20s, read: 606.0 MiB/s, write: 18.0 MiB/s
INFO: backup is sparse: 6.11 GiB (40%) total zero data
INFO: backup was done incrementally, reused 6.27 GiB (41%)
INFO: transferred 15.00 GiB in 260 seconds (59.1 MiB/s)
INFO: Finished Backup of VM 148 (00:04:21)
INFO: Backup finished at 2021-05-23 13:46:45
INFO: Backup job finished successfully
TASK OK

Other:

Code:
INFO: starting new backup job: vzdump 198 --remove 0 --mode snapshot --node HPProliantDL360PGen8 --storage PBS-HPStorageWorksD2600-16TBTwo
INFO: Starting Backup of VM 198 (qemu)
INFO: Backup started at 2021-05-26 11:21:56
INFO: status = running
INFO: VM Name: kubernetes-7
INFO: include disk 'scsi0' 'Seagate1TBDriveThree:198/vm-198-disk-0.qcow2' 67G
INFO: include disk 'scsi1' 'HPStorageWorksD2600-16TBTwo:198/vm-198-disk-0.qcow2' 500G
INFO: backup mode: snapshot
INFO: ionice priority: 5
INFO: snapshots found (not included into backup)
INFO: creating Proxmox Backup Server archive 'vm/198/2021-05-26T10:21:56Z'
INFO: started backup task 'e3a27f71-b62e-4bab-96e7-d45b575ca6e2'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO: scsi1: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO:   0% (168.0 MiB of 567.0 GiB) in 3s, read: 56.0 MiB/s, write: 25.3 MiB/s
INFO:   0% (620.0 MiB of 567.0 GiB) in 18s, read: 30.1 MiB/s, write: 22.4 MiB/s
ERROR: backup write data failed: command error: write_data upload error: pipelined request failed: broken pipe
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 198 failed - backup write data failed: command error: write_data upload error: pipelined request failed: broken pipe
INFO: Failed at 2021-05-26 11:22:18
INFO: Backup job finished with errors
TASK ERROR: job errors


Code:
INFO: starting new backup job: vzdump 142 --compress lzo --mailto reesevader@hotmail.co.uk --mailnotification always --storage PBS-Seagate1TBDrive8 --node HPProliantDL360PGen8 --quiet 1 --mode snapshot
INFO: Starting Backup of VM 142 (qemu)
INFO: Backup started at 2021-05-26 07:00:04
INFO: status = running
INFO: VM Name: virtualmin
INFO: include disk 'scsi0' 'HPBay8:vm-142-disk-0' 310G
INFO: backup mode: snapshot
INFO: ionice priority: 5
INFO: creating Proxmox Backup Server archive 'vm/142/2021-05-26T06:00:04Z'
INFO: started backup task '3d59ebd3-7af8-4b53-a8a9-d1a2fb0d2b83'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO:   0% (212.0 MiB of 310.0 GiB) in 3s, read: 70.7 MiB/s, write: 32.0 MiB/s
INFO:   0% (2.1 GiB of 310.0 GiB) in 50s, read: 41.9 MiB/s, write: 36.9 MiB/s
ERROR: backup write data failed: command error: connection reset
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 142 failed - backup write data failed: command error: connection reset
INFO: Failed at 2021-05-26 07:00:56
INFO: Backup job finished with errors

TASK ERROR: job errors



Basically, any PBS store that isn't the first one, has not completed, ever.

These are separate PBS disk datastores, they have enough space.
 
All,
i´d same issue backing up 1.3tb VM from PVE to PBS 2.0.4
Solved now.

on my system the error occured now and then, some times after 250gb of backup, sometimes after 900gb. It never finished the backup.
Error message: "backup write data failed: command error: protocol canceled"

i´ve read your articles here but in my case it did not help.
by mistake i found the problems root cause: duplicate IP on the LAN !

My scanner had same IP than the PBS. but only when the Scanner was become active while the backup job was running, then the error occured. - no message thou in the logs. - this activity was sometimes a scan i did but also DHCP renewal requests the scanner send on the network and then the backup job crashed...

i though it is worth to share. Sometimes things are that simple...


rgds
Stephan
 
Last edited:
  • Like
Reactions: voarsh

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!