Discrepancy in numbers?

[EvertM]

INFO: Starting Backup of VM 333 (qemu)
INFO: Backup started at 2024-08-07 08:10:00
INFO: status = running
INFO: VM Name: some.vm
INFO: include disk 'scsi0' 'pool3:vm-333-disk-0' 500G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: skip unused drive 'local-zfs:vm-333-disk-0' (not included into backup)
INFO: snapshots found (not included into backup)
INFO: creating Proxmox Backup Server archive 'vm/333/2024-08-07T06:10:00Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'bcf1606f-bdd3-4d15-a402-f510e3258124'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO:   0% (1.2 GiB of 500.0 GiB) in 3s, read: 421.3 MiB/s, write: 9.3 MiB/s
INFO:   1% (5.0 GiB of 500.0 GiB) in 1m 16s, read: 53.2 MiB/s, write: 3.0 MiB/s
INFO:   2% (10.2 GiB of 500.0 GiB) in 2m 25s, read: 77.3 MiB/s, write: 1.4 MiB/s
INFO:   3% (15.6 GiB of 500.0 GiB) in 2m 48s, read: 237.9 MiB/s, write: 1.2 MiB/s
INFO:   4% (20.6 GiB of 500.0 GiB) in 2m 56s, read: 639.5 MiB/s, write: 1.0 MiB/s
INFO:   5% (25.5 GiB of 500.0 GiB) in 3m, read: 1.2 GiB/s, write: 2.0 MiB/s
INFO:   6% (31.5 GiB of 500.0 GiB) in 3m 4s, read: 1.5 GiB/s, write: 0 B/s
INFO:   7% (35.5 GiB of 500.0 GiB) in 3m 8s, read: 1.0 GiB/s, write: 0 B/s
INFO:   8% (41.2 GiB of 500.0 GiB) in 3m 11s, read: 1.9 GiB/s, write: 0 B/s
INFO:   9% (46.2 GiB of 500.0 GiB) in 3m 14s, read: 1.7 GiB/s, write: 0 B/s
INFO:  10% (51.5 GiB of 500.0 GiB) in 3m 17s, read: 1.8 GiB/s, write: 0 B/s
INFO:  11% (55.5 GiB of 500.0 GiB) in 3m 20s, read: 1.3 GiB/s, write: 0 B/s
INFO:  12% (60.8 GiB of 500.0 GiB) in 3m 25s, read: 1.1 GiB/s, write: 0 B/s
INFO:  13% (65.1 GiB of 500.0 GiB) in 3m 36s, read: 396.7 MiB/s, write: 372.4 KiB/s
INFO:  14% (70.7 GiB of 500.0 GiB) in 3m 46s, read: 582.0 MiB/s, write: 0 B/s
INFO:  15% (75.2 GiB of 500.0 GiB) in 3m 53s, read: 656.6 MiB/s, write: 585.1 KiB/s
INFO:  16% (80.3 GiB of 500.0 GiB) in 4m 3s, read: 514.4 MiB/s, write: 409.6 KiB/s
INFO:  17% (85.0 GiB of 500.0 GiB) in 4m 17s, read: 347.7 MiB/s, write: 1.7 MiB/s
INFO:  18% (90.0 GiB of 500.0 GiB) in 5m 36s, read: 64.9 MiB/s, write: 2.4 MiB/s
INFO:  19% (95.0 GiB of 500.0 GiB) in 6m 42s, read: 77.5 MiB/s, write: 682.7 KiB/s
INFO:  20% (100.0 GiB of 500.0 GiB) in 8m 10s, read: 58.5 MiB/s, write: 930.9 KiB/s
INFO:  21% (105.0 GiB of 500.0 GiB) in 9m 36s, read: 59.2 MiB/s, write: 13.3 MiB/s
INFO:  22% (110.2 GiB of 500.0 GiB) in 10m 42s, read: 80.1 MiB/s, write: 310.3 KiB/s
INFO:  23% (115.2 GiB of 500.0 GiB) in 11m 18s, read: 143.9 MiB/s, write: 113.8 KiB/s
INFO:  24% (120.0 GiB of 500.0 GiB) in 11m 40s, read: 224.2 MiB/s, write: 0 B/s
INFO:  25% (127.3 GiB of 500.0 GiB) in 12m 6s, read: 287.5 MiB/s, write: 0 B/s
INFO:  26% (130.2 GiB of 500.0 GiB) in 12m 22s, read: 183.2 MiB/s, write: 1.5 MiB/s
INFO:  27% (135.1 GiB of 500.0 GiB) in 13m 39s, read: 65.3 MiB/s, write: 2.5 MiB/s
INFO:  28% (140.1 GiB of 500.0 GiB) in 14m 54s, read: 67.4 MiB/s, write: 1.1 MiB/s
INFO:  29% (145.0 GiB of 500.0 GiB) in 15m 54s, read: 84.5 MiB/s, write: 1.5 MiB/s
INFO:  30% (150.2 GiB of 500.0 GiB) in 16m 37s, read: 122.6 MiB/s, write: 1.3 MiB/s
INFO:  31% (155.1 GiB of 500.0 GiB) in 17m 20s, read: 118.5 MiB/s, write: 2.1 MiB/s
INFO:  32% (160.2 GiB of 500.0 GiB) in 17m 52s, read: 161.0 MiB/s, write: 1.1 MiB/s
INFO:  33% (165.0 GiB of 500.0 GiB) in 19m 19s, read: 57.1 MiB/s, write: 753.3 KiB/s
INFO:  34% (170.0 GiB of 500.0 GiB) in 23m 50s, read: 18.9 MiB/s, write: 272.1 KiB/s
INFO:  35% (175.2 GiB of 500.0 GiB) in 25m 25s, read: 55.2 MiB/s, write: 258.7 KiB/s
INFO:  36% (180.1 GiB of 500.0 GiB) in 25m 59s, read: 149.8 MiB/s, write: 361.4 KiB/s
INFO:  37% (185.1 GiB of 500.0 GiB) in 26m 37s, read: 135.3 MiB/s, write: 0 B/s
INFO:  38% (190.1 GiB of 500.0 GiB) in 27m 24s, read: 107.1 MiB/s, write: 0 B/s
INFO:  39% (195.2 GiB of 500.0 GiB) in 28m 8s, read: 120.6 MiB/s, write: 0 B/s
INFO:  40% (204.0 GiB of 500.0 GiB) in 28m 25s, read: 530.1 MiB/s, write: 0 B/s
INFO:  43% (217.5 GiB of 500.0 GiB) in 28m 28s, read: 4.5 GiB/s, write: 0 B/s
INFO:  45% (229.9 GiB of 500.0 GiB) in 28m 31s, read: 4.1 GiB/s, write: 0 B/s
INFO:  48% (242.8 GiB of 500.0 GiB) in 28m 34s, read: 4.3 GiB/s, write: 0 B/s
INFO:  51% (256.7 GiB of 500.0 GiB) in 28m 37s, read: 4.6 GiB/s, write: 0 B/s
INFO:  54% (270.6 GiB of 500.0 GiB) in 28m 40s, read: 4.6 GiB/s, write: 0 B/s
INFO:  56% (284.7 GiB of 500.0 GiB) in 28m 43s, read: 4.7 GiB/s, write: 0 B/s
INFO:  59% (299.0 GiB of 500.0 GiB) in 28m 46s, read: 4.7 GiB/s, write: 0 B/s
INFO:  62% (313.2 GiB of 500.0 GiB) in 28m 49s, read: 4.7 GiB/s, write: 0 B/s
INFO:  65% (326.6 GiB of 500.0 GiB) in 28m 52s, read: 4.5 GiB/s, write: 0 B/s
INFO:  68% (340.7 GiB of 500.0 GiB) in 28m 55s, read: 4.7 GiB/s, write: 0 B/s
INFO:  71% (355.1 GiB of 500.0 GiB) in 28m 58s, read: 4.8 GiB/s, write: 0 B/s
INFO:  73% (368.9 GiB of 500.0 GiB) in 29m 1s, read: 4.6 GiB/s, write: 0 B/s
INFO:  76% (381.9 GiB of 500.0 GiB) in 29m 4s, read: 4.4 GiB/s, write: 0 B/s
INFO:  78% (393.6 GiB of 500.0 GiB) in 29m 7s, read: 3.9 GiB/s, write: 0 B/s
INFO:  81% (406.2 GiB of 500.0 GiB) in 29m 10s, read: 4.2 GiB/s, write: 0 B/s
INFO:  83% (418.4 GiB of 500.0 GiB) in 29m 13s, read: 4.1 GiB/s, write: 0 B/s
INFO:  86% (430.5 GiB of 500.0 GiB) in 29m 16s, read: 4.0 GiB/s, write: 0 B/s
INFO:  88% (443.0 GiB of 500.0 GiB) in 29m 19s, read: 4.1 GiB/s, write: 0 B/s
INFO:  91% (455.4 GiB of 500.0 GiB) in 29m 22s, read: 4.1 GiB/s, write: 0 B/s
INFO:  93% (467.5 GiB of 500.0 GiB) in 29m 25s, read: 4.1 GiB/s, write: 0 B/s
INFO:  96% (480.6 GiB of 500.0 GiB) in 29m 28s, read: 4.4 GiB/s, write: 0 B/s
INFO:  98% (494.3 GiB of 500.0 GiB) in 29m 31s, read: 4.6 GiB/s, write: 0 B/s
INFO: 100% (500.0 GiB of 500.0 GiB) in 29m 34s, read: 1.9 GiB/s, write: 0 B/s
INFO: Waiting for server to finish backup validation...
INFO: backup is sparse: 369.04 GiB (73%) total zero data
INFO: backup was done incrementally, reused 497.41 GiB (99%)
INFO: transferred 500.00 GiB in 1776 seconds (288.3 MiB/s)
INFO: adding notes to backup
INFO: Finished Backup of VM 333 (00:29:38)
INFO: Backup finished at 2024-08-07 08:39:38

It's the following 3 lines which make me wonder:

INFO: backup is sparse: 369.04 GiB (73%) total zero data
INFO: backup was done incrementally, reused 497.41 GiB (99%)
INFO: transferred 500.00 GiB in 1776 seconds (288.3 MiB/s)

If the backup was both sparse and incremental, was there indeed still 500GB transferred? Or was there 500GB processed?

 

[Lukas Wagner]

It's the following 3 lines which make me wonder:

INFO: backup is sparse: 369.04 GiB (73%) total zero data
INFO: backup was done incrementally, reused 497.41 GiB (99%)
INFO: transferred 500.00 GiB in 1776 seconds (288.3 MiB/s)

If the backup was both sparse and incremental, was there indeed still 500GB transferred? Or was there 500GB processed?

Compression and deduplication are performed client-side. So no, only ~2.5GB were transmitted (without accounting for compression, which brings this number down even further).

Notice the ratio between read rate and write rate, e.g.:

INFO:   4% (20.6 GiB of 500.0 GiB) in 2m 56s, read: 639.5 MiB/s, write: 1.0 MiB/s

The write rate indicates the data being actually sent to the backup server.

 

[EvertM]

That's what I thought, yeah...
So perhaps 'INFO: processed 500.00 GiB in 1776 seconds (288.3 MiB/s)' would be a more accurate wording?

 

[gfngfn256]

was there indeed still 500GB transferred? Or was there 500GB processed?

I assume since you are using PBS you understand "transferred" as referring to backup data going across to the PBS. AFAIK this is not the case, all Proxmox backups, including those local, will show "transferred" data which refers to data of the VM being "transferred" to the backup archive.

If you take a look at the incremental write speeds verses the final "average" transfer speed you will see the actual difference of what was "transferred".

Notice the ratio between read rate and write rate, e.g.:

INFO: 4% (20.6 GiB of 500.0 GiB) in 2m 56s, read: 639.5 MiB/s, write: 1.0 MiB/s

The write rate indicates the data being actually sent to the backup server.

AFAIK that ratio may not be an indication of Data actually written verses data backed up, since the write speed will depend on where that data is actually being written & in the OP's case that is to a PBS (and over a NW?), verses the read speed which looks at the VM's disk/s being backed up, wherever they may be.