Backup very slow

pblou

Well-Known Member
Jan 9, 2017
32
0
46
35
Hello,

On many cluster (not in the same network) i use Proxmox 3.4 or Proxmox 4.5 and I have very slow backup.

I use NFS mount and the I/O performance test say +- 120 MB/s

Backup log:

INFO: starting new backup job: vzdump 133 134 --quiet 1 --mode snapshot --compress lzo --mailnotification failure --mailto xxxt@xxxxxx.xxx --storage Dataserv1
INFO: Starting Backup of VM 133 (qemu)
INFO: status = running
INFO: update VM 133: -lock backup
INFO: VM Name: divalto
INFO: include disk 'virtio0' 'local:133/vm-133-disk-1.raw'
INFO: include disk 'virtio1' 'local:133/vm-133-disk-2.raw'
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating archive '/mnt/pve/Dataserv1/dump/vzdump-qemu-133-2017_04_26-22_00_01.vma.lzo'
INFO: started backup task 'f5dc73a5-e481-45aa-90cd-6054870249a2'
INFO: status: 0% (183697408/158938955776), sparse 0% (3293184), duration 3, 61/60 MB/s
INFO: status: 1% (1693712384/158938955776), sparse 0% (30556160), duration 39, 41/41 MB/s
INFO: status: 2% (3250651136/158938955776), sparse 0% (57847808), duration 82, 36/35 MB/s
INFO: status: 3% (4833673216/158938955776), sparse 0% (69611520), duration 148, 23/23 MB/s
INFO: status: 4% (6431375360/158938955776), sparse 0% (80646144), duration 200, 30/30 MB/s
INFO: status: 5% (8029798400/158938955776), sparse 0% (86810624), duration 248, 33/33 MB/s
INFO: status: 6% (9636216832/158938955776), sparse 0% (97935360), duration 297, 32/32 MB/s
INFO: status: 7% (11182473216/158938955776), sparse 0% (104554496), duration 339, 36/36 MB/s
INFO: status: 8% (12817268736/158938955776), sparse 0% (108806144), duration 390, 32/31 MB/s
INFO: status: 9% (14332723200/158938955776), sparse 0% (111067136), duration 531, 10/10 MB/s
INFO: status: 10% (15900213248/158938955776), sparse 0% (113238016), duration 699, 9/9 MB/s
INFO: status: 11% (17489788928/158938955776), sparse 0% (114405376), duration 867, 9/9 MB/s
INFO: status: 12% (19080937472/158938955776), sparse 0% (170950656), duration 980, 14/13 MB/s

INFO: status: 100% (158938955776/158938955776), sparse 0% (341524480), duration 17283, 66/66 MB/s
INFO: transferred 158938 MB in 17283 seconds (9 MB/s)
INFO: archive file size: 55.04GB
INFO: delete old backup '/mnt/pve/Dataserv1/dump/vzdump-qemu-133-2017_04_19-22_00_01.vma.lzo'
INFO: Finished Backup of VM 133 (04:48:07)

This example is a Windows VM with 30Gb system and 120Gb datas (applications and data base). The disk of this VM are full at 85%.

In this example, server is: DELL 2x Intel® Xeon® E5 2660 v3 20C / 40T 2x @2,6 Ghz, 192 Go DDR4, 5x 6to SATA Raid 6 hardware

Kernel Version Linux 4.4.35-1-pve #1 PVE Manager Version pve-manager/4.4-5/c43015a

There is 3 actives VM (2 x Windows 2003 and 1 x Windows 2008)

In charge CPU Load no more than 3~5% !

I think that the problem is not Read Write Disk but compression performance...

Thk's for help or idea ;)

FF
 
Hi
The problem might be that you're not readling that fast from your local disks.
INFO: status: 10% (15900213248/158938955776), sparse 0% (113238016), duration 699, 9/9 MB/s

here in 9/9 means that in this intervall the backup process could only read 9MB/s from your local disks
maybe the local disks were busy at that time ?

I would advise to benchmakr them with the following command
fio --size=9G --bs=64k --rw=write --direct=1 --runtime=60 --name=64kwrite --group_reporting

and look at the bw output in MB/s
 
I have the following throughput when backing to a NFS server on a Gigabit Link
INFO: transferred 51539 MB in 346 seconds (148 MB/s)

but I am reading from SSDs, and the pve host is not that busy
 
Hello everyone,
I have a Xeon E5-2630 dual processor Supermicro server with 128Gb and LSI raid controller cache 2Gb SAS/SATA, number 5x SSD 480Gb in raid5. Installed Proxmox 5.1
When I do backup Vm in local storage or NFS storage(NAS Buffalo 10GBE), is very slow:

INFO: starting new backup job: vzdump 101 --node PVEserverPP --remove 0 --compress gzip --mode snapshot --storage test
INFO: Starting Backup of VM 101 (qemu)
INFO: status = stopped
INFO: update VM 101: -lock backup
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: Server-Nts
INFO: include disk 'virtio1' 'local-lvm:vm-101-disk-1' 569G
INFO: creating archive '/mnt/pve/test/dump/vzdump-qemu-101-2018_04_13-09_05_23.vma.gz'
INFO: starting kvm to execute backup task
INFO: started backup task '6d8c5e33-c17c-4e1a-83dd-1d01124c3b09'
INFO: status: 0% (163446784/610959097856), sparse 0% (82554880), duration 3, read/write 54/26 MB/s
INFO: status: 1% (6131154944/610959097856), sparse 0% (161861632), duration 278, read/write 21/21 MB/s
INFO: status: 2% (12228100096/610959097856), sparse 0% (1342218240), duration 495, read/write 28/22 MB/s
INFO: status: 3% (18328846336/610959097856), sparse 0% (1387536384), duration 704, read/write 29/28 MB/s
INFO: status: 4% (24444796928/610959097856), sparse 0% (2735403008), duration 873, read/write 36/28 MB/s
INFO: status: 5% (30579752960/610959097856), sparse 0% (2835169280), duration 1114, read/write 25/25 MB/s
INFO: status: 6% (36657692672/610959097856), sparse 0% (2935164928), duration 1363, read/write 24/24 MB/s
INFO: status: 7% (42777444352/610959097856), sparse 0% (3053625344), duration 1624, read/write 23/22 MB/s
INFO: status: 8% (48893394944/610959097856), sparse 0% (3204685824), duration 1885, read/write 23/22 MB/s
INFO: status: 9% (55001743360/610959097856), sparse 0% (3327344640), duration 2111, read/write 27/26 MB/s
INFO: status: 10% (61121495040/610959097856), sparse 0% (3442053120), duration 2331, read/write 27/27 MB/s
INFO: status: 11% (67218440192/610959097856), sparse 0% (3549347840), duration 2548, read/write 28/27 MB/s
INFO: status: 12% (73338191872/610959097856), sparse 0% (3627229184), duration 2738, read/write 32/31 MB/s
INFO: status: 13% (79435137024/610959097856), sparse 0% (5148119040), duration 2897, read/write 38/28 MB/s
INFO: status: 14% (85539684352/610959097856), sparse 0% (5200814080), duration 3105, read/write 29/29 MB/s
INFO: status: 15% (91644231680/610959097856), sparse 0% (5232668672), duration 3325, read/write 27/27 MB/s
INFO: status: 16% (97771585536/610959097856), sparse 0% (5310480384), duration 3557, read/write 26/26 MB/s
INFO: status: 17% (103887536128/610959097856), sparse 0% (5457092608), duration 3765, read/write 29/28 MB/s
INFO: status: 18% (110007287808/610959097856), sparse 1% (6806859776), duration 3943, read/write 34/26 MB/s
INFO: status: 19% (116085227520/610959097856), sparse 1% (6846205952), duration 4134, read/write 31/31 MB/s
INFO: status: 20% (122204979200/610959097856), sparse 1% (6929371136), duration 4375, read/write 25/25 MB/s
INFO: status: 21% (128317128704/610959097856), sparse 1% (6985777152), duration 4590, read/write 28/28 MB/s
INFO: status: 22% (134425477120/610959097856), sparse 1% (7067488256), duration 4810, read/write 27/27 MB/s
INFO: status: 23% (140549029888/610959097856), sparse 1% (7111532544), duration 5026, read/write 28/28 MB/s
INFO: status: 24% (146645975040/610959097856), sparse 1% (7224606720), duration 5229, read/write 30/29 MB/s
INFO: status: 25% (152758124544/610959097856), sparse 1% (7225090048), duration 5501, read/write 22/22 MB/s
INFO: status: 26% (158866472960/610959097856), sparse 1% (7225540608), duration 5786, read/write 21/21 MB/s
INFO: status: 27% (164963418112/610959097856), sparse 1% (7226109952), duration 6069, read/write 21/21 MB/s
INFO: status: 28% (171090771968/610959097856), sparse 1% (7226609664), duration 6356, read/write 21/21 MB/s
INFO: status: 29% (177180114944/610959097856), sparse 1% (7227203584), duration 6637, read/write 21/21 MB/s
INFO: status: 30% (183296065536/610959097856), sparse 1% (7227756544), duration 6924, read/write 21/21 MB/s
INFO: status: 31% (189413064704/610959097856), sparse 1% (7228317696), duration 7210, read/write 21/21 MB/s
INFO: status: 32% (195520364544/610959097856), sparse 1% (7228895232), duration 7491, read/write 21/21 MB/s
INFO: status: 33% (201624911872/610959097856), sparse 1% (7273086976), duration 7759, read/write 22/22 MB/s
INFO: status: 34% (207740862464/610959097856), sparse 1% (7346286592), duration 7986, read/write 26/26 MB/s
INFO: status: 35% (213864415232/610959097856), sparse 1% (7355056128), duration 8234, read/write 24/24 MB/s
INFO: status: 36% (219961360384/610959097856), sparse 1% (7357792256), duration 8497, read/write 23/23 MB/s
INFO: status: 37% (226069708800/610959097856), sparse 1% (7358509056), duration 8777, read/write 21/21 MB/s
INFO: status: 38% (232185659392/610959097856), sparse 1% (7359123456), duration 9059, read/write 21/21 MB/s
INFO: status: 39% (238290206720/610959097856), sparse 1% (7359619072), duration 9344, read/write 21/21 MB/s
INFO: status: 40% (244402356224/610959097856), sparse 1% (7360110592), duration 9630, read/write 21/21 MB/s
INFO: status: 41% (250503102464/610959097856), sparse 1% (7360688128), duration 9918, read/write 21/21 MB/s
INFO: status: 42% (256619053056/610959097856), sparse 1% (7361265664), duration 10199, read/write 21/21 MB/s
INFO: status: 43% (262727401472/610959097856), sparse 1% (7361822720), duration 10477, read/write 21/21 MB/s
INFO: status: 44% (268839550976/610959097856), sparse 1% (7362404352), duration 10764, read/write 21/21 MB/s
INFO: status: 45% (274947899392/610959097856), sparse 1% (7363084288), duration 11045, read/write 21/21 MB/s
INFO: status: 46% (281044844544/610959097856), sparse 1% (7366299648), duration 11312, read/write 22/22 MB/s
INFO: status: 47% (287164596224/610959097856), sparse 1% (7372247040), duration 11568, read/write 23/23 MB/s
INFO: status: 48% (293280546816/610959097856), sparse 1% (7373152256), duration 11845, read/write 22/22 MB/s
INFO: status: 49% (299381293056/610959097856), sparse 1% (7420162048), duration 12084, read/write 25/25 MB/s
INFO: status: 50% (305489641472/610959097856), sparse 1% (7420162048), duration 12231, read/write 41/41 MB/s
INFO: status: 51% (311616995328/610959097856), sparse 1% (7420227584), duration 12366, read/write 45/45 MB/s
INFO: status: 52% (317729144832/610959097856), sparse 1% (7420227584), duration 12511, read/write 42/42 MB/s
INFO: status: 53% (323833692160/610959097856), sparse 1% (7420227584), duration 12620, read/write 56/56 MB/s
INFO: status: 54% (329953443840/610959097856), sparse 1% (7420227584), duration 12721, read/write 60/60 MB/s
INFO: status: 55% (336069394432/610959097856), sparse 1% (7420227584), duration 12811, read/write 67/67 MB/s
INFO: status: 56% (342147334144/610959097856), sparse 1% (7430651904), duration 12905, read/write 64/64 MB/s
INFO: status: 57% (348270886912/610959097856), sparse 1% (8223494144), duration 13017, read/write 54/47 MB/s
INFO: status: 58% (354383036416/610959097856), sparse 1% (9053749248), duration 13128, read/write 55/47 MB/s
INFO: status: 59% (360468578304/610959097856), sparse 1% (9055510528), duration 13253, read/write 48/48 MB/s
INFO: status: 60% (366599733248/610959097856), sparse 1% (9055997952), duration 13378, read/write 49/49 MB/s
INFO: status: 61% (372685275136/610959097856), sparse 1% (9056030720), duration 13490, read/write 54/54 MB/s
INFO: status: 62% (378839236608/610959097856), sparse 1% (9056063488), duration 13673, read/write 33/33 MB/s
INFO: status: 63% (384909574144/610959097856), sparse 1% (9134587904), duration 13794, read/write 50/49 MB/s
INFO: status: 64% (391040729088/610959097856), sparse 1% (9135960064), duration 13917, read/write 49/49 MB/s
INFO: status: 65% (397164281856/610959097856), sparse 1% (9146302464), duration 14037, read/write 51/50 MB/s
INFO: status: 66% (403257425920/610959097856), sparse 1% (9146302464), duration 14146, read/write 55/55 MB/s
INFO: status: 67% (409369575424/610959097856), sparse 1% (9146368000), duration 14269, read/write 49/49 MB/s
INFO: status: 68% (415477923840/610959097856), sparse 1% (9146368000), duration 14387, read/write 51/51 MB/s
INFO: status: 69% (421571067904/610959097856), sparse 1% (9150464000), duration 14561, read/write 35/34 MB/s
INFO: status: 70% (427683217408/610959097856), sparse 1% (9151053824), duration 14842, read/write 21/21 MB/s
INFO: status: 71% (433787764736/610959097856), sparse 1% (9151549440), duration 15126, read/write 21/21 MB/s
INFO: status: 72% (439899914240/610959097856), sparse 1% (9152135168), duration 15408, read/write 21/21 MB/s
INFO: status: 73% (446031069184/610959097856), sparse 1% (9152618496), duration 15689, read/write 21/21 MB/s
INFO: status: 74% (452120412160/610959097856), sparse 1% (9186508800), duration 15965, read/write 22/21 MB/s
INFO: status: 75% (458236362752/610959097856), sparse 1% (9187020800), duration 16253, read/write 21/21 MB/s
INFO: status: 76% (464329506816/610959097856), sparse 1% (9187704832), duration 16539, read/write 21/21 MB/s
INFO: status: 77% (470456860672/610959097856), sparse 1% (9188347904), duration 16819, read/write 21/21 MB/s
INFO: status: 78% (476569010176/610959097856), sparse 1% (9196564480), duration 17059, read/write 25/25 MB/s
INFO: status: 79% (482673557504/610959097856), sparse 1% (9197711360), duration 17336, read/write 22/22 MB/s
INFO: status: 80% (488781905920/610959097856), sparse 1% (9201922048), duration 17574, read/write 25/25 MB/s
INFO: status: 81% (494890254336/610959097856), sparse 1% (9201922048), duration 17720, read/write 41/41 MB/s
INFO: status: 82% (501021409280/610959097856), sparse 1% (9201987584), duration 17861, read/write 43/43 MB/s
INFO: status: 83% (507133558784/610959097856), sparse 1% (9201987584), duration 18000, read/write 43/43 MB/s
INFO: status: 84% (513245708288/610959097856), sparse 1% (9201987584), duration 18100, read/write 61/61 MB/s
INFO: status: 85% (519373062144/610959097856), sparse 1% (9201987584), duration 18200, read/write 61/61 MB/s
INFO: status: 86% (525428195328/610959097856), sparse 1% (9203499008), duration 18289, read/write 68/68 MB/s
INFO: status: 87% (531559350272/610959097856), sparse 1% (9212514304), duration 18388, read/write 61/61 MB/s
INFO: status: 88% (537840779264/610959097856), sparse 1% (10231083008), duration 18499, read/write 56/47 MB/s
INFO: status: 89% (543791251456/610959097856), sparse 1% (10836664320), duration 18614, read/write 51/46 MB/s
INFO: status: 90% (549880594432/610959097856), sparse 1% (10837307392), duration 18732, read/write 51/51 MB/s
INFO: status: 91% (555977539584/610959097856), sparse 1% (10837794816), duration 18860, read/write 47/47 MB/s
INFO: status: 92% (562127699968/610959097856), sparse 1% (10837827584), duration 18961, read/write 60/60 MB/s
INFO: status: 93% (568224645120/610959097856), sparse 1% (10837860352), duration 19150, read/write 32/32 MB/s
INFO: status: 94% (574313988096/610959097856), sparse 1% (10916818944), duration 19277, read/write 47/47 MB/s
INFO: status: 95% (580429938688/610959097856), sparse 1% (10919104512), duration 19395, read/write 51/51 MB/s
INFO: status: 96% (586534486016/610959097856), sparse 1% (10928136192), duration 19517, read/write 50/49 MB/s
INFO: status: 97% (592646635520/610959097856), sparse 1% (10928136192), duration 19622, read/write 58/58 MB/s
INFO: status: 98% (598773989376/610959097856), sparse 1% (10928201728), duration 19743, read/write 50/50 MB/s
INFO: status: 99% (604863332352/610959097856), sparse 1% (10928201728), duration 19867, read/write 49/49 MB/s
INFO: status: 100% (610959097856/610959097856), sparse 2% (13892509696), duration 19936, read/write 88/45 MB/s
INFO: transferred 610959 MB in 19936 seconds (30 MB/s)
INFO: stopping kvm after backup task
INFO: archive file size: 259.75GB
INFO: Finished Backup of VM 101 (05:32:35)
INFO: Backup job finished successfully
TASK OK

This my configuration:
proxmox-ve: 5.1-32 (running kernel: 4.13.13-2-pve) pve-manager: 5.1-41 (running version: 5.1-41/0b958203) pve-kernel-4.13.13-2-pve: 4.13.13-32 libpve-http-server-perl: 2.0-8 lvm2: 2.02.168-pve6 corosync: 2.4.2-pve3 libqb0: 1.0.1-1 pve-cluster: 5.0-19 qemu-server: 5.0-18 pve-firmware: 2.0-3 libpve-common-perl: 5.0-25 libpve-guest-common-perl: 2.0-14 libpve-access-control: 5.0-7 libpve-storage-perl: 5.0-17 pve-libspice-server1: 0.12.8-3 vncterm: 1.5-3 pve-docs: 5.1-12 pve-qemu-kvm: 2.9.1-5 pve-container: 2.0-18 pve-firewall: 3.0-5 pve-ha-manager: 2.0-4 ksm-control-daemon: 1.2-2 glusterfs-client: 3.8.8-1 lxc-pve: 2.1.1-2 lxcfs: 2.0.8-1 criu: 2.11.1-1~bpo90 novnc-pve: 0.6-4 smartmontools: 6.5+svn4324-1 zfsutils-linux: 0.7.3-pve1~bpo9

# pveperf
CPU BOGOMIPS: 175994.80
REGEX/SECOND: 2789070
HD SIZE: 93.99 GB (/dev/mapper/pve-root)
BUFFERED READS: 1463.98 MB/sec
AVERAGE SEEK TIME: 0.13 ms
FSYNCS/SECOND: 804.10
DNS EXT: 55.82 ms
DNS INT: 0.72 ms (workgroup)

# fio --size=9G --bs=64K --rw=write --direct=1 --runtime=60 --name=64kwrite --grou
64kwrite: (g=0): rw=write, bs=64K-64K/64K-64K/64K-64K, ioengine=psync, iodepth=1
fio-2.16
Starting 1 process
Jobs: 1 (f=1): [W(1)] [100.0% done] [0KB/50816KB/0KB /s] [0/794/0 iops] [eta 00m:00s]
64kwrite: (groupid=0, jobs=1): err= 0: pid=8253: Fri Apr 13 17:21:16 2018
write: io=2908.4MB, bw=49634KB/s, iops=775, runt= 60002msec
clat (usec): min=564, max=8215, avg=1287.39, stdev=837.44
lat (usec): min=565, max=8215, avg=1288.25, stdev=837.44
clat percentiles (usec):
| 1.00th=[ 692], 5.00th=[ 732], 10.00th=[ 748], 20.00th=[ 780],
| 30.00th=[ 804], 40.00th=[ 844], 50.00th=[ 916], 60.00th=[ 1032],
| 70.00th=[ 1272], 80.00th=[ 1496], 90.00th=[ 2672], 95.00th=[ 3504],
| 99.00th=[ 4016], 99.50th=[ 4192], 99.90th=[ 5344], 99.95th=[ 5856],
| 99.99th=[ 7392]
lat (usec) : 750=9.41%, 1000=48.23%
lat (msec) : 2=28.50%, 4=12.75%, 10=1.10%
cpu : usr=0.28%, sys=1.19%, ctx=46536, majf=0, minf=8
IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0%
submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0%
issued : total=r=0/w=46533/d=0, short=r=0/w=0/d=0, drop=r=0/w=0/d=0
latency : target=0, window=0, percentile=100.00%, depth=1

Run status group 0 (all jobs):
WRITE: io=2908.4MB, aggrb=49633KB/s, minb=49633KB/s, maxb=49633KB/s, mint=60002msec, maxt=60002mse

Disk stats (read/write):
dm-1: ios=74/46594, merge=0/0, ticks=4/59168, in_queue=59184, util=98.61%, aggrios=10414/46585,
/65, aggrticks=836/59296, aggrin_queue=60124, aggrutil=98.65%
sda: ios=10414/46585, merge=1246/65, ticks=836/59296, in_queue=60124, util=98.65%
root@PVEserverPP:~#

The guest machine VM 101 is Windows Server 2008 R2, disk 569Gb

Someone a suggestion?
 
Try to run the backup right after a reboot of the pve host (I know this is a pain in the neck) and see if you get better backup speeds.
 

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!