[SOLVED] incremental backup after adding an empty disk very slow, why? (just curious)

[Fra]

I'm just curious.

We have a (linux) VM with 2 hard drives: the second (200G) is a backup disk where the app (gitlab) backup itself, so we normally do not include it in pbs backup (which is pretty fast, btw, about 30min).

Today, due to a migration of that VM, we removed all backups from the second backup disks (so the disk is just empty), then we started a pbs backup, this time including that empty disk.

The backup has been running for hours, and it is just at 3%: we can wait, no problems, but we are just wondering why adding that empty HD added so much delay?


(we actually did backup that backup-disk, in pbs, once (20 days ago): can it be that pbs is just wasting time checking differences?)

 

[Fra]

This is the log so far... still waiting:

INFO: starting new backup job: vzdump 801 --mode snapshot --remove 0 --node vm3 --storage my-pbs
INFO: Starting Backup of VM 801 (qemu)
INFO: Backup started at 2021-07-31 08:13:19
INFO: status = stopped
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: gitlab
INFO: include disk 'scsi0' 'local-lvm:vm-801-disk-0' 80G
INFO: include disk 'scsi1' 'local-lvm:vm-801-disk-1' 200G
INFO: creating Proxmox Backup Server archive 'vm/801/2021-07-31T06:13:19Z'
INFO: starting kvm to execute backup task
INFO: started backup task '0358d5c5-87b3-4914-8b02-d4f59466720a'
INFO: scsi0: dirty-bitmap status: created new
INFO: scsi1: dirty-bitmap status: created new
INFO:   0% (104.0 MiB of 280.0 GiB) in 3s, read: 34.7 MiB/s, write: 25.3 MiB/s
INFO:   1% (2.8 GiB of 280.0 GiB) in 18m 20s, read: 2.5 MiB/s, write: 2.5 MiB/s
INFO:   2% (5.6 GiB of 280.0 GiB) in 37m 37s, read: 2.5 MiB/s, write: 2.5 MiB/s
INFO:   3% (8.4 GiB of 280.0 GiB) in 56m 11s, read: 2.6 MiB/s, write: 2.5 MiB/s
INFO:   4% (11.2 GiB of 280.0 GiB) in 1h 15m 29s, read: 2.5 MiB/s, write: 2.4 MiB/s
INFO:   5% (14.0 GiB of 280.0 GiB) in 1h 34m 33s, read: 2.5 MiB/s, write: 2.5 MiB/s
INFO:   6% (16.8 GiB of 280.0 GiB) in 1h 53m 2s, read: 2.6 MiB/s, write: 2.5 MiB/s

As you can see I guess it will take about 24hr to complete (!).

note: the write: 2.5 MiB/s is normal for our setup since we are sending the backup to a pbs using and ordinary "home" internet connection, but the backup should not send any data....

While this is the backup done 3 hours earlier (without the empty second HD): 9 minutes (!)

INFO: starting new backup job: vzdump 801 --storage my-pbs --node vm3 --remove 0 --mode snapshot
INFO: Starting Backup of VM 801 (qemu)
INFO: Backup started at 2021-07-31 05:25:06
INFO: status = stopped
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: gitlab
INFO: include disk 'scsi0' 'local-lvm:vm-801-disk-0' 80G
INFO: exclude disk 'scsi1' 'local-lvm:vm-801-disk-1' (backup=no)
INFO: creating Proxmox Backup Server archive 'vm/801/2021-07-31T03:25:06Z'
INFO: starting kvm to execute backup task
INFO: started backup task '23c30b9d-a7f0-441c-9638-c33befec60aa'
INFO: scsi0: dirty-bitmap status: created new
INFO:   0% (600.0 MiB of 80.0 GiB) in 3s, read: 200.0 MiB/s, write: 1.3 MiB/s
INFO:   1% (1.3 GiB of 80.0 GiB) in 6s, read: 236.0 MiB/s, write: 9.3 MiB/s
INFO:   2% (1.7 GiB of 80.0 GiB) in 9s, read: 154.7 MiB/s, write: 0 B/s
INFO:   3% (2.5 GiB of 80.0 GiB) in 14s, read: 151.2 MiB/s, write: 819.2 KiB/s
INFO:   4% (3.2 GiB of 80.0 GiB) in 19s, read: 155.2 MiB/s, write: 20.0 MiB/s
INFO:   5% (4.0 GiB of 80.0 GiB) in 29s, read: 80.0 MiB/s, write: 1.2 MiB/s
INFO:   6% (4.8 GiB of 80.0 GiB) in 35s, read: 137.3 MiB/s, write: 0 B/s
INFO:   8% (6.9 GiB of 80.0 GiB) in 40s, read: 424.8 MiB/s, write: 3.2 MiB/s
INFO:  10% (8.2 GiB of 80.0 GiB) in 43s, read: 449.3 MiB/s, write: 9.3 MiB/s
INFO:  11% (8.9 GiB of 80.0 GiB) in 48s, read: 152.0 MiB/s, write: 0 B/s
INFO:  12% (9.7 GiB of 80.0 GiB) in 53s, read: 156.0 MiB/s, write: 1.6 MiB/s
INFO:  13% (10.5 GiB of 80.0 GiB) in 58s, read: 156.0 MiB/s, write: 0 B/s
INFO:  14% (11.3 GiB of 80.0 GiB) in 1m 3s, read: 165.6 MiB/s, write: 6.4 MiB/s
INFO:  15% (12.1 GiB of 80.0 GiB) in 1m 10s, read: 122.3 MiB/s, write: 0 B/s
INFO:  16% (12.8 GiB of 80.0 GiB) in 1m 15s, read: 150.4 MiB/s, write: 0 B/s
INFO:  17% (13.7 GiB of 80.0 GiB) in 1m 20s, read: 168.0 MiB/s, write: 2.4 MiB/s
INFO:  18% (14.4 GiB of 80.0 GiB) in 1m 25s, read: 157.6 MiB/s, write: 0 B/s
INFO:  19% (15.3 GiB of 80.0 GiB) in 1m 30s, read: 170.4 MiB/s, write: 0 B/s
INFO:  20% (16.1 GiB of 80.0 GiB) in 1m 35s, read: 162.4 MiB/s, write: 0 B/s
INFO:  21% (16.8 GiB of 80.0 GiB) in 1m 40s, read: 152.0 MiB/s, write: 0 B/s
INFO:  22% (17.7 GiB of 80.0 GiB) in 1m 46s, read: 156.7 MiB/s, write: 1.3 MiB/s
INFO:  23% (18.5 GiB of 80.0 GiB) in 1m 52s, read: 135.3 MiB/s, write: 0 B/s
INFO:  24% (19.3 GiB of 80.0 GiB) in 1m 57s, read: 154.4 MiB/s, write: 819.2 KiB/s
INFO:  25% (20.0 GiB of 80.0 GiB) in 2m 2s, read: 154.4 MiB/s, write: 0 B/s
INFO:  26% (20.9 GiB of 80.0 GiB) in 2m 9s, read: 130.3 MiB/s, write: 0 B/s
INFO:  27% (21.7 GiB of 80.0 GiB) in 2m 14s, read: 155.2 MiB/s, write: 819.2 KiB/s
INFO:  28% (22.4 GiB of 80.0 GiB) in 2m 19s, read: 156.0 MiB/s, write: 0 B/s
INFO:  29% (23.3 GiB of 80.0 GiB) in 2m 24s, read: 172.0 MiB/s, write: 0 B/s
INFO:  30% (24.0 GiB of 80.0 GiB) in 2m 29s, read: 151.2 MiB/s, write: 0 B/s
INFO:  31% (24.9 GiB of 80.0 GiB) in 2m 35s, read: 151.3 MiB/s, write: 682.7 KiB/s
INFO:  32% (25.6 GiB of 80.0 GiB) in 2m 40s, read: 152.8 MiB/s, write: 8.8 MiB/s
INFO:  33% (26.5 GiB of 80.0 GiB) in 2m 46s, read: 152.0 MiB/s, write: 1.3 MiB/s
INFO:  34% (27.3 GiB of 80.0 GiB) in 2m 51s, read: 162.4 MiB/s, write: 819.2 KiB/s
INFO:  35% (28.1 GiB of 80.0 GiB) in 2m 56s, read: 153.6 MiB/s, write: 819.2 KiB/s
INFO:  36% (28.9 GiB of 80.0 GiB) in 3m 2s, read: 141.3 MiB/s, write: 0 B/s
INFO:  37% (29.7 GiB of 80.0 GiB) in 3m 7s, read: 160.0 MiB/s, write: 2.4 MiB/s
INFO:  38% (30.5 GiB of 80.0 GiB) in 3m 12s, read: 165.6 MiB/s, write: 0 B/s
INFO:  39% (31.4 GiB of 80.0 GiB) in 3m 17s, read: 176.8 MiB/s, write: 4.0 MiB/s
INFO:  40% (32.1 GiB of 80.0 GiB) in 3m 22s, read: 156.8 MiB/s, write: 0 B/s
INFO:  41% (32.9 GiB of 80.0 GiB) in 3m 27s, read: 154.4 MiB/s, write: 0 B/s
INFO:  42% (33.7 GiB of 80.0 GiB) in 3m 32s, read: 172.0 MiB/s, write: 819.2 KiB/s
INFO:  43% (34.4 GiB of 80.0 GiB) in 3m 37s, read: 147.2 MiB/s, write: 2.4 MiB/s
INFO:  44% (35.3 GiB of 80.0 GiB) in 3m 42s, read: 170.4 MiB/s, write: 4.0 MiB/s
INFO:  45% (36.1 GiB of 80.0 GiB) in 3m 50s, read: 111.5 MiB/s, write: 0 B/s
INFO:  46% (36.9 GiB of 80.0 GiB) in 3m 55s, read: 159.2 MiB/s, write: 0 B/s
INFO:  47% (37.6 GiB of 80.0 GiB) in 3m 59s, read: 175.0 MiB/s, write: 0 B/s
INFO:  48% (38.5 GiB of 80.0 GiB) in 4m 5s, read: 153.3 MiB/s, write: 0 B/s
INFO:  49% (39.3 GiB of 80.0 GiB) in 4m 10s, read: 160.0 MiB/s, write: 1.6 MiB/s
INFO:  50% (40.1 GiB of 80.0 GiB) in 4m 15s, read: 161.6 MiB/s, write: 0 B/s
INFO:  51% (40.8 GiB of 80.0 GiB) in 4m 20s, read: 153.6 MiB/s, write: 0 B/s
INFO:  52% (41.6 GiB of 80.0 GiB) in 4m 25s, read: 161.6 MiB/s, write: 0 B/s
INFO:  53% (42.5 GiB of 80.0 GiB) in 4m 31s, read: 150.7 MiB/s, write: 0 B/s
INFO:  54% (43.3 GiB of 80.0 GiB) in 4m 36s, read: 172.8 MiB/s, write: 0 B/s
INFO:  55% (44.1 GiB of 80.0 GiB) in 4m 41s, read: 151.2 MiB/s, write: 0 B/s
INFO:  56% (44.8 GiB of 80.0 GiB) in 4m 46s, read: 150.4 MiB/s, write: 0 B/s
INFO:  57% (45.7 GiB of 80.0 GiB) in 4m 51s, read: 172.8 MiB/s, write: 819.2 KiB/s
INFO:  58% (46.4 GiB of 80.0 GiB) in 4m 56s, read: 154.4 MiB/s, write: 0 B/s
INFO:  59% (47.2 GiB of 80.0 GiB) in 5m 1s, read: 163.2 MiB/s, write: 5.6 MiB/s
INFO:  60% (48.0 GiB of 80.0 GiB) in 5m 7s, read: 141.3 MiB/s, write: 5.3 MiB/s
INFO:  61% (48.9 GiB of 80.0 GiB) in 5m 13s, read: 150.7 MiB/s, write: 0 B/s
INFO:  62% (49.7 GiB of 80.0 GiB) in 5m 18s, read: 152.0 MiB/s, write: 5.6 MiB/s
INFO:  63% (50.5 GiB of 80.0 GiB) in 5m 27s, read: 98.7 MiB/s, write: 0 B/s
INFO:  64% (51.3 GiB of 80.0 GiB) in 5m 32s, read: 160.0 MiB/s, write: 819.2 KiB/s
INFO:  65% (52.1 GiB of 80.0 GiB) in 5m 37s, read: 156.8 MiB/s, write: 0 B/s
INFO:  66% (52.8 GiB of 80.0 GiB) in 5m 43s, read: 124.7 MiB/s, write: 2.0 MiB/s
INFO:  67% (53.7 GiB of 80.0 GiB) in 5m 49s, read: 146.0 MiB/s, write: 4.0 MiB/s
INFO:  68% (54.5 GiB of 80.0 GiB) in 5m 55s, read: 144.7 MiB/s, write: 2.7 MiB/s
INFO:  69% (55.3 GiB of 80.0 GiB) in 6m 1s, read: 139.3 MiB/s, write: 1.3 MiB/s
INFO:  70% (56.0 GiB of 80.0 GiB) in 6m 6s, read: 139.2 MiB/s, write: 0 B/s
INFO:  71% (56.9 GiB of 80.0 GiB) in 6m 13s, read: 131.4 MiB/s, write: 1.7 MiB/s
INFO:  72% (57.6 GiB of 80.0 GiB) in 6m 18s, read: 153.6 MiB/s, write: 2.4 MiB/s
INFO:  73% (58.4 GiB of 80.0 GiB) in 6m 23s, read: 161.6 MiB/s, write: 0 B/s
INFO:  74% (59.2 GiB of 80.0 GiB) in 6m 28s, read: 159.2 MiB/s, write: 1.6 MiB/s
INFO:  75% (60.0 GiB of 80.0 GiB) in 6m 34s, read: 134.7 MiB/s, write: 682.7 KiB/s
INFO:  76% (60.9 GiB of 80.0 GiB) in 6m 42s, read: 108.5 MiB/s, write: 1.5 MiB/s
INFO:  77% (61.7 GiB of 80.0 GiB) in 6m 49s, read: 125.1 MiB/s, write: 585.1 KiB/s
INFO:  78% (62.5 GiB of 80.0 GiB) in 6m 56s, read: 110.3 MiB/s, write: 0 B/s
INFO:  79% (63.2 GiB of 80.0 GiB) in 7m 2s, read: 128.0 MiB/s, write: 1.3 MiB/s
INFO:  80% (64.1 GiB of 80.0 GiB) in 7m 10s, read: 113.0 MiB/s, write: 1.0 MiB/s
INFO:  81% (64.8 GiB of 80.0 GiB) in 7m 28s, read: 40.7 MiB/s, write: 6.9 MiB/s
INFO:  82% (65.6 GiB of 80.0 GiB) in 7m 55s, read: 30.5 MiB/s, write: 1.3 MiB/s
INFO:  83% (66.5 GiB of 80.0 GiB) in 8m 2s, read: 129.1 MiB/s, write: 0 B/s
INFO:  84% (67.3 GiB of 80.0 GiB) in 8m 7s, read: 156.8 MiB/s, write: 819.2 KiB/s
INFO:  85% (68.1 GiB of 80.0 GiB) in 8m 13s, read: 134.7 MiB/s, write: 682.7 KiB/s
INFO:  86% (68.9 GiB of 80.0 GiB) in 8m 19s, read: 145.3 MiB/s, write: 0 B/s
INFO:  87% (69.8 GiB of 80.0 GiB) in 8m 24s, read: 173.6 MiB/s, write: 0 B/s
INFO:  88% (70.5 GiB of 80.0 GiB) in 8m 29s, read: 157.6 MiB/s, write: 0 B/s
INFO:  89% (71.3 GiB of 80.0 GiB) in 8m 34s, read: 168.8 MiB/s, write: 0 B/s
INFO:  90% (72.1 GiB of 80.0 GiB) in 8m 39s, read: 153.6 MiB/s, write: 0 B/s
INFO:  91% (72.9 GiB of 80.0 GiB) in 8m 44s, read: 160.0 MiB/s, write: 0 B/s
INFO:  92% (73.7 GiB of 80.0 GiB) in 8m 49s, read: 169.6 MiB/s, write: 0 B/s
INFO:  93% (74.4 GiB of 80.0 GiB) in 8m 54s, read: 152.8 MiB/s, write: 0 B/s
INFO:  94% (75.7 GiB of 80.0 GiB) in 8m 58s, read: 320.0 MiB/s, write: 0 B/s
INFO: 100% (80.0 GiB of 80.0 GiB) in 9m 1s, read: 1.4 GiB/s, write: 0 B/s
INFO: backup is sparse: 10.82 GiB (13%) total zero data
INFO: backup was done incrementally, reused 79.23 GiB (99%)
INFO: transferred 80.00 GiB in 541 seconds (151.4 MiB/s)
INFO: stopping kvm after backup task
INFO: Finished Backup of VM 801 (00:09:06)
INFO: Backup finished at 2021-07-31 05:34:12
INFO: Backup job finished successfully
TASK OK
[ICODE]

 

[Fra]

we had to stop the backup (it takes too long): we will backup without the empty disk, then just add it from scratch in the new proxmox where we are migrating.

I just want to confirm that the second disk was, indeed, empty:

# df -h
Filesystem                         Size  Used Avail Use% Mounted on
...
/dev/sdb1                          196G   60M  187G   1% /home/backupuser
---

# cd /home/backupuser 
# ls -la
total 28 
drwxr-xr-x 4 root root  4096 Mar 23 11:48 ./ 
drwxr-xr-x 5 root root  4096 Dec  8  2019 ../ 
drwx------ 2 git  root  4096 Jul 31 06:54 gitlab/ 
drwx------ 2 root root 16384 Dec  8  2019 lost+found/ 

# du -sh gitlab/ 
4.0K    gitlab/ 
# tree  
. 
├── gitlab 
└── lost+found 
 
2 directories, 0 files

 

[birdy]

Expected behaviour. PBS doesn’t backup files but blocks. So it doesn’t see it‘s empty but it sees 200GB of changed (because you emptied them) blocks. If you would have let it finish and start the backup again it then would take less then 30 sec.

 

[Fra]

oh, I see.
Thanks!

Forgive me some more questions:
* the expected 24hrs are needed in this case to send 200GB of data?
* so, in general, if I have a VM already backed up in pbs, with a disk of 200GB of data, then I empty the disk (or even format, or even write zeros), the next backup (and that backup, only) will anyhow need to send 200GB of data?

 

[birdy]

the expected 24hrs are needed in this case to send 200GB of data?

Exactly.

so, in general, if I have a VM already backed up in pbs, with a disk of 200GB of data, then I empty the disk (or even format, or even write zeros), the next backup (and that backup, only) will anyhow need to send 200GB of data?

Yes, because all of your blocks have changed so they all need to be backuped again. On the other hand if only a small amount of blocks have changed (some files added/changed/deleted) only these blocks need to be backuped.

 

[dietmar]

Maybe you can make sure that the disk is really empty containing zeroes. Then the first backup will still read all data, but will not transfer any data over the network.