[SOLVED] One VM need to backup up a lot of time

fireon

Distinguished Member
Oct 25, 2010
4,520
489
153
Austria/Graz
deepdoc.at
Hello,

since a view weeks on VM from us clusternode need a lot of time to backup up, but only this one from this server. The backup takes 04:24:49 to copy 53,68GB to ZFS Storagebackup. But another server on this host with 64GB needs only 48 minutes. Here is the strange log:

Code:
131: Mar 26 03:57:49 INFO: Starting Backup of VM 131 (qemu)
131: Mar 26 03:57:49 INFO: status = running
131: Mar 26 03:57:49 INFO: update VM 131: -lock backup
131: Mar 26 03:57:50 INFO: backup mode: snapshot
131: Mar 26 03:57:50 INFO: ionice priority: 7
131: Mar 26 03:57:50 INFO: creating archive '/mnt/pve/zfs_backup_vm/dump/vzdump-qemu-131-2015_03_26-03_57_49.vma.lzo'
131: Mar 26 03:57:50 INFO: started backup task 'dc929960-2939-4757-8fed-1aa827340137'
131: Mar 26 03:57:53 INFO: status: 0% (174850048/107374182400), sparse 0% (70942720), duration 3, 58/34 MB/s
131: Mar 26 03:57:58 INFO: status: 1% (1073807360/107374182400), sparse 0% (591175680), duration 8, 179/75 MB/s
131: Mar 26 03:58:11 INFO: status: 2% (2206072832/107374182400), sparse 0% (664870912), duration 21, 87/81 MB/s
131: Mar 26 03:58:44 INFO: status: 3% (3237019648/107374182400), sparse 0% (675794944), duration 54, 31/30 MB/s
131: Mar 26 03:58:53 INFO: status: 4% (4326359040/107374182400), sparse 0% (710344704), duration 63, 121/117 MB/s
131: Mar 26 03:59:25 INFO: status: 5% (5462163456/107374182400), sparse 0% (735723520), duration 95, 35/34 MB/s
131: Mar 26 03:59:33 INFO: status: 6% (6444548096/107374182400), sparse 0% (737497088), duration 103, 122/122 MB/s
131: Mar 26 03:59:50 INFO: status: 7% (7590772736/107374182400), sparse 0% (802795520), duration 120, 67/63 MB/s
131: Mar 26 04:00:03 INFO: status: 8% (8594259968/107374182400), sparse 0% (804519936), duration 133, 77/77 MB/s
131: Mar 26 04:00:20 INFO: status: 9% (9726984192/107374182400), sparse 0% (856465408), duration 150, 66/63 MB/s
131: Mar 26 04:00:34 INFO: status: 10% (10745675776/107374182400), sparse 0% (864313344), duration 164, 72/72 MB/s
131: Mar 26 04:00:55 INFO: status: 11% (11844190208/107374182400), sparse 0% (920137728), duration 185, 52/49 MB/s
131: Mar 26 04:01:11 INFO: status: 12% (12949192704/107374182400), sparse 0% (972263424), duration 201, 69/65 MB/s
131: Mar 26 04:01:20 INFO: status: 13% (13972799488/107374182400), sparse 0% (983252992), duration 210, 113/112 MB/s
131: Mar 26 04:01:28 INFO: status: 14% (15086583808/107374182400), sparse 0% (1034174464), duration 218, 139/132 MB/s
131: Mar 26 04:01:45 INFO: status: 15% (16166027264/107374182400), sparse 0% (1041526784), duration 235, 63/63 MB/s
131: Mar 26 04:01:53 INFO: status: 16% (17238327296/107374182400), sparse 1% (1098309632), duration 243, 134/126 MB/s
131: Mar 26 04:02:04 INFO: status: 17% (18256429056/107374182400), sparse 1% (1107288064), duration 254, 92/91 MB/s
131: Mar 26 04:02:14 INFO: status: 18% (19383582720/107374182400), sparse 1% (1158705152), duration 264, 112/107 MB/s
131: Mar 26 04:03:10 INFO: status: 19% (20487733248/107374182400), sparse 1% (1167380480), duration 320, 19/19 MB/s
131: Mar 26 04:03:23 INFO: status: 20% (21534998528/107374182400), sparse 1% (1214676992), duration 333, 80/76 MB/s
131: Mar 26 04:03:48 INFO: status: 21% (22586195968/107374182400), sparse 1% (1242902528), duration 358, 42/40 MB/s
131: Mar 26 04:04:05 INFO: status: 22% (23652728832/107374182400), sparse 1% (1263198208), duration 375, 62/61 MB/s
131: Mar 26 04:04:21 INFO: status: 23% (24712249344/107374182400), sparse 1% (1290371072), duration 391, 66/64 MB/s
131: Mar 26 04:04:31 INFO: status: 24% (25776160768/107374182400), sparse 1% (1290477568), duration 401, 106/106 MB/s
131: Mar 26 04:04:51 INFO: status: 25% (26978549760/107374182400), sparse 1% (1340764160), duration 421, 60/57 MB/s
131: Mar 26 04:04:59 INFO: status: 26% (27929935872/107374182400), sparse 1% (1340989440), duration 429, 118/118 MB/s
131: Mar 26 04:05:22 INFO: status: 27% (29010952192/107374182400), sparse 1% (1362702336), duration 452, 47/46 MB/s
131: Mar 26 04:05:31 INFO: status: 28% (30069686272/107374182400), sparse 1% (1382678528), duration 461, 117/115 MB/s
131: Mar 26 04:05:56 INFO: status: 29% (31138512896/107374182400), sparse 1% (1421770752), duration 486, 42/41 MB/s
131: Mar 26 04:06:18 INFO: status: 30% (32218021888/107374182400), sparse 1% (1423118336), duration 508, 49/49 MB/s
131: Mar 26 04:06:42 INFO: status: 31% (33362149376/107374182400), sparse 1% (1468743680), duration 532, 47/45 MB/s
131: Mar 26 04:06:50 INFO: status: 32% (34421407744/107374182400), sparse 1% (1517707264), duration 540, 132/126 MB/s
131: Mar 26 04:07:16 INFO: status: 33% (35578183680/107374182400), sparse 1% (1543528448), duration 566, 44/43 MB/s
131: Mar 26 04:07:23 INFO: status: 34% (36530356224/107374182400), sparse 1% (1543663616), duration 573, 136/136 MB/s
131: Mar 26 04:07:58 INFO: status: 35% (37582077952/107374182400), sparse 1% (1561985024), duration 608, 30/29 MB/s
131: Mar 26 04:08:14 INFO: status: 36% (38655361024/107374182400), sparse 1% (1563979776), duration 624, 67/66 MB/s
131: Mar 26 04:08:35 INFO: status: 37% (39763181568/107374182400), sparse 1% (1599762432), duration 645, 52/51 MB/s
131: Mar 26 04:08:42 INFO: status: 38% (40802451456/107374182400), sparse 1% (1599905792), duration 652, 148/148 MB/s
131: Mar 26 04:08:54 INFO: status: 39% (41889890304/107374182400), sparse 1% (1637343232), duration 664, 90/87 MB/s
131: Mar 26 04:09:28 INFO: status: 40% (43006296064/107374182400), sparse 1% (1679609856), duration 698, 32/31 MB/s
131: Mar 26 04:09:48 INFO: status: 41% (44065751040/107374182400), sparse 1% (1681227776), duration 718, 52/52 MB/s
131: Mar 26 04:10:03 INFO: status: 42% (45164920832/107374182400), sparse 1% (1739567104), duration 733, 73/69 MB/s
131: Mar 26 04:10:18 INFO: status: 43% (46289649664/107374182400), sparse 1% (1746649088), duration 748, 74/74 MB/s
131: Mar 26 04:10:26 INFO: status: 44% (47302311936/107374182400), sparse 1% (1793085440), duration 756, 126/120 MB/s
131: Mar 26 04:10:35 INFO: status: 45% (48342237184/107374182400), sparse 1% (1964285952), duration 765, 115/96 MB/s
131: Mar 26 04:10:44 INFO: status: 46% (49393893376/107374182400), sparse 1% (1972371456), duration 774, 116/115 MB/s
131: Mar 26 04:10:53 INFO: status: 47% (50512658432/107374182400), sparse 2% (2406117376), duration 783, 124/76 MB/s
131: Mar 26 04:11:01 INFO: status: 48% (51560513536/107374182400), sparse 2% (2571280384), duration 791, 130/110 MB/s
131: Mar 26 04:11:15 INFO: status: 49% (52725940224/107374182400), sparse 2% (2613125120), duration 805, 83/80 MB/s
131: Mar 26 04:11:40 INFO: status: 50% (53687091200/107374182400), sparse 2% (2632192000), duration 830, 38/37 MB/s
131: Mar 26 04:17:02 INFO: status: 51% (54762799104/107374182400), sparse 2% (2813677568), duration 1152, 3/2 MB/s
131: Mar 26 04:22:22 INFO: status: 52% (55835361280/107374182400), sparse 2% (2882576384), duration 1472, 3/3 MB/s
131: Mar 26 04:27:39 INFO: status: 53% (56910741504/107374182400), sparse 2% (3101908992), duration 1789, 3/2 MB/s
131: Mar 26 04:32:55 INFO: status: 54% (57982517248/107374182400), sparse 3% (3221823488), duration 2105, 3/3 MB/s
131: Mar 26 04:38:11 INFO: status: 55% (59057831936/107374182400), sparse 3% (3414265856), duration 2421, 3/2 MB/s
131: Mar 26 04:43:26 INFO: status: 56% (60130787328/107374182400), sparse 3% (3492859904), duration 2736, 3/3 MB/s
131: Mar 26 04:48:31 INFO: status: 57% (61204987904/107374182400), sparse 3% (3657736192), duration 3041, 3/2 MB/s
131: Mar 26 04:53:37 INFO: status: 58% (62277156864/107374182400), sparse 3% (3701628928), duration 3347, 3/3 MB/s
131: Mar 26 04:58:45 INFO: status: 59% (63353585664/107374182400), sparse 3% (3843928064), duration 3655, 3/3 MB/s
131: Mar 26 05:03:52 INFO: status: 60% (64424640512/107374182400), sparse 3% (3852500992), duration 3962, 3/3 MB/s
131: Mar 26 05:09:01 INFO: status: 61% (65500217344/107374182400), sparse 3% (4065587200), duration 4271, 3/2 MB/s
131: Mar 26 05:14:07 INFO: status: 62% (66572320768/107374182400), sparse 3% (4140806144), duration 4577, 3/3 MB/s
131: Mar 26 05:19:13 INFO: status: 63% (67645800448/107374182400), sparse 4% (4332417024), duration 4883, 3/2 MB/s
131: Mar 26 05:24:22 INFO: status: 64% (68722098176/107374182400), sparse 4% (4378165248), duration 5192, 3/3 MB/s
131: Mar 26 05:29:29 INFO: status: 65% (69794660352/107374182400), sparse 4% (4544536576), duration 5499, 3/2 MB/s
131: Mar 26 05:34:38 INFO: status: 66% (70868926464/107374182400), sparse 4% (4598652928), duration 5808, 3/3 MB/s
131: Mar 26 05:39:45 INFO: status: 67% (71941488640/107374182400), sparse 4% (4791660544), duration 6115, 3/2 MB/s
131: Mar 26 05:44:53 INFO: status: 68% (73015296000/107374182400), sparse 4% (4864622592), duration 6423, 3/3 MB/s
131: Mar 26 05:49:59 INFO: status: 69% (74089496576/107374182400), sparse 4% (5027618816), duration 6729, 3/2 MB/s
131: Mar 26 05:55:00 INFO: status: 70% (75164942336/107374182400), sparse 5% (5738729472), duration 7030, 3/1 MB/s
131: Mar 26 05:59:55 INFO: status: 71% (76237701120/107374182400), sparse 6% (6811488256), duration 7325, 3/0 MB/s
131: Mar 26 06:04:49 INFO: status: 72% (77310590976/107374182400), sparse 7% (7884369920), duration 7619, 3/0 MB/s
131: Mar 26 06:09:44 INFO: status: 73% (78383284224/107374182400), sparse 8% (8957063168), duration 7914, 3/0 MB/s
131: Mar 26 06:14:38 INFO: status: 74% (79459319808/107374182400), sparse 9% (10033086464), duration 8208, 3/0 MB/s
131: Mar 26 06:19:34 INFO: status: 75% (80533323776/107374182400), sparse 10% (10973089792), duration 8504, 3/0 MB/s
131: Mar 26 06:24:28 INFO: status: 76% (81607000064/107374182400), sparse 11% (12046757888), duration 8798, 3/0 MB/s
131: Mar 26 06:29:23 INFO: status: 77% (82678579200/107374182400), sparse 12% (13118337024), duration 9093, 3/0 MB/s
131: Mar 26 06:34:19 INFO: status: 78% (83755532288/107374182400), sparse 13% (14194249728), duration 9389, 3/0 MB/s
131: Mar 26 06:39:23 INFO: status: 79% (84826390528/107374182400), sparse 13% (14324285440), duration 9693, 3/3 MB/s
131: Mar 26 06:44:26 INFO: status: 80% (85899935744/107374182400), sparse 13% (14691774464), duration 9996, 3/2 MB/s
131: Mar 26 06:49:21 INFO: status: 81% (86973677568/107374182400), sparse 14% (15765372928), duration 10291, 3/0 MB/s
131: Mar 26 06:54:15 INFO: status: 82% (88047484928/107374182400), sparse 15% (16839172096), duration 10585, 3/0 MB/s
131: Mar 26 06:59:10 INFO: status: 83% (89121292288/107374182400), sparse 16% (17912979456), duration 10880, 3/0 MB/s
131: Mar 26 07:04:04 INFO: status: 84% (90197393408/107374182400), sparse 17% (18989072384), duration 11174, 3/0 MB/s
131: Mar 26 07:08:58 INFO: status: 85% (91269300224/107374182400), sparse 18% (20060979200), duration 11468, 3/0 MB/s
131: Mar 26 07:13:53 INFO: status: 86% (92341862400/107374182400), sparse 19% (21133533184), duration 11763, 3/0 MB/s
131: Mar 26 07:18:48 INFO: status: 87% (93418618880/107374182400), sparse 20% (22210289664), duration 12058, 3/0 MB/s
131: Mar 26 07:23:43 INFO: status: 88% (94492622848/107374182400), sparse 21% (23284285440), duration 12353, 3/0 MB/s
131: Mar 26 07:28:37 INFO: status: 89% (95564333056/107374182400), sparse 22% (24355995648), duration 12647, 3/0 MB/s
131: Mar 26 07:33:32 INFO: status: 90% (96639320064/107374182400), sparse 23% (25430663168), duration 12942, 3/0 MB/s
131: Mar 26 07:38:27 INFO: status: 91% (97713192960/107374182400), sparse 24% (26480263168), duration 13237, 3/0 MB/s
131: Mar 26 07:43:20 INFO: status: 92% (98786082816/107374182400), sparse 25% (27553140736), duration 13530, 3/0 MB/s
131: Mar 26 07:48:14 INFO: status: 93% (99857989632/107374182400), sparse 26% (28625027072), duration 13824, 3/0 MB/s
131: Mar 26 07:53:09 INFO: status: 94% (100933304320/107374182400), sparse 27% (29700333568), duration 14119, 3/0 MB/s
131: Mar 26 07:58:03 INFO: status: 95% (102007767040/107374182400), sparse 28% (30774796288), duration 14413, 3/0 MB/s
131: Mar 26 08:02:57 INFO: status: 96% (103079542784/107374182400), sparse 29% (31846563840), duration 14707, 3/0 MB/s
131: Mar 26 08:07:52 INFO: status: 97% (104156364800/107374182400), sparse 30% (32923385856), duration 15002, 3/0 MB/s
131: Mar 26 08:12:46 INFO: status: 98% (105226829824/107374182400), sparse 31% (33993838592), duration 15296, 3/0 MB/s
131: Mar 26 08:17:42 INFO: status: 99% (106303979520/107374182400), sparse 32% (35070988288), duration 15592, 3/0 MB/s
131: Mar 26 08:22:35 INFO: status: 100% (107374182400/107374182400), sparse 33% (36141191168), duration 15885, 3/0 MB/s
131: Mar 26 08:22:35 INFO: transferred 107374 MB in 15885 seconds (6 MB/s)
131: Mar 26 08:22:35 INFO: archive file size: 53.68GB
131: Mar 26 08:22:35 INFO: delete old backup '/mnt/pve/zfs_backup_vm/dump/vzdump-qemu-131-2015_03_22-04_02_49.vma.lzo'
131: Mar 26 08:22:38 INFO: Finished Backup of VM 131 (04:24:49)

Proxmox Enterpriserepo with 3.4

Thanks for help
 
Last edited:
Hello,

since a view weeks on VM from us clusternode need a lot of time to backup up, but only this one from this server. The backup takes 04:24:49 to copy 53,68GB to ZFS Storagebackup. But another server on this host with 64GB needs only 48 minutes. Here is the strange log:

Code:
131: Mar 26 03:57:49 INFO: Starting Backup of VM 131 (qemu)
131: Mar 26 03:57:49 INFO: status = running
131: Mar 26 03:57:49 INFO: update VM 131: -lock backup
131: Mar 26 03:57:50 INFO: backup mode: snapshot
131: Mar 26 03:57:50 INFO: ionice priority: 7
131: Mar 26 03:57:50 INFO: creating archive '/mnt/pve/zfs_backup_vm/dump/vzdump-qemu-131-2015_03_26-03_57_49.vma.lzo'
131: Mar 26 03:57:50 INFO: started backup task 'dc929960-2939-4757-8fed-1aa827340137'
131: Mar 26 03:57:53 INFO: status: 0% (174850048/107374182400), sparse 0% (70942720), duration 3, 58/34 MB/s
131: Mar 26 03:57:58 INFO: status: 1% (1073807360/107374182400), sparse 0% (591175680), duration 8, 179/75 MB/s
131: Mar 26 03:58:11 INFO: status: 2% (2206072832/107374182400), sparse 0% (664870912), duration 21, 87/81 MB/s
131: Mar 26 03:58:44 INFO: status: 3% (3237019648/107374182400), sparse 0% (675794944), duration 54, 31/30 MB/s
...
131: Mar 26 04:11:15 INFO: status: 49% (52725940224/107374182400), sparse 2% (2613125120), duration 805, 83/80 MB/s
131: Mar 26 04:11:40 INFO: status: 50% (53687091200/107374182400), sparse 2% (2632192000), duration 830, 38/37 MB/s
131: Mar 26 04:17:02 INFO: status: 51% (54762799104/107374182400), sparse 2% (2813677568), duration 1152, 3/2 MB/s
131: Mar 26 04:22:22 INFO: status: 52% (55835361280/107374182400), sparse 2% (2882576384), duration 1472, 3/3 MB/s
....
131: Mar 26 08:17:42 INFO: status: 99% (106303979520/107374182400), sparse 32% (35070988288), duration 15592, 3/0 MB/s
131: Mar 26 08:22:35 INFO: status: 100% (107374182400/107374182400), sparse 33% (36141191168), duration 15885, 3/0 MB/s
131: Mar 26 08:22:35 INFO: transferred 107374 MB in 15885 seconds (6 MB/s)
131: Mar 26 08:22:35 INFO: archive file size: 53.68GB
131: Mar 26 08:22:35 INFO: delete old backup '/mnt/pve/zfs_backup_vm/dump/vzdump-qemu-131-2015_03_22-04_02_49.vma.lzo'
131: Mar 26 08:22:38 INFO: Finished Backup of VM 131 (04:24:49)

Is it always the same pattern (i.e. after approx. 50% the data rate decreases suddenly)?
 
You need check the sparse counter.

sparse is zero blocks, so it's really fast to backup.


for example, a sparse 100% 60GB drive wil take around 1s to backup

the same 60GB drive with 0% sparse, need a lot more time to backup.



(Also, if in your 60GB drive you write a 60GB file, then delete the file, the datas are always on the disk, so sparse 0%)
 
Found the problem. On harddrive (are only portage packages on it) are attached to this vm. And this disk has his place at the NAS, so backup from NAS to NAS. That was the problem. I checked the "nobackup" function at the virtual harddrive.

Thanks!
 

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!