Backup Job Failed because VM is not running.

H

Hile

New Member
Apr 23, 2012
13
0
1
Hi all.

This a strange problem with only one VM (KVM)

I'll try to move the VM to another node today...


Code: 
121: Jun 05 04:49:51 INFO: Starting Backup of VM 121 (qemu)
121: Jun 05 04:49:51 INFO: status = running
121: Jun 05 04:49:51 INFO: backup mode: stop
121: Jun 05 04:49:51 INFO: ionice priority: 7
121: Jun 05 04:49:52 INFO: stopping vm
121: Jun 05 04:50:00 INFO: creating archive '/mnt/pve/betanfs/dump/vzdump-qemu-121-2013_06_05-04_49_51.vma.lzo'
121: Jun 05 04:50:00 INFO: starting kvm to execute backup task
121: Jun 05 04:50:01 INFO: started backup task 'd608e013-1a34-4091-b3af-e1dbb2677dae'
121: Jun 05 04:50:01 INFO: resume VM
121: Jun 05 04:50:04 INFO: status: 0% (114032640/68719476736), sparse 0% (233472), duration 3, 38/37 MB/s
121: Jun 05 04:50:22 INFO: status: 1% (687996928/68719476736), sparse 0% (1134592), duration 21, 31/31 MB/s
121: Jun 05 04:51:58 INFO: status: 2% (1398800384/68719476736), sparse 0% (4530176), duration 117, 7/7 MB/s
121: Jun 05 04:52:23 INFO: status: 3% (2082996224/68719476736), sparse 0% (4624384), duration 142, 27/27 MB/s
121: Jun 05 04:52:47 INFO: status: 4% (2774794240/68719476736), sparse 0% (4878336), duration 166, 28/28 MB/s
121: Jun 05 04:52:57 INFO: status: 5% (3443064832/68719476736), sparse 0% (383672320), duration 176, 66/28 MB/s
121: Jun 05 04:53:00 INFO: status: 6% (4236378112/68719476736), sparse 1% (1160978432), duration 179, 264/5 MB/s
121: Jun 05 04:53:58 INFO: status: 7% (4938465280/68719476736), sparse 2% (1828044800), duration 237, 12/0 MB/s
121: Jun 05 04:54:13 INFO: status: 8% (5507776512/68719476736), sparse 3% (2092740608), duration 252, 37/20 MB/s
121: Jun 05 04:54:37 INFO: status: 9% (6191972352/68719476736), sparse 3% (2101501952), duration 276, 28/28 MB/s
121: Jun 05 04:54:59 INFO: status: 10% (6879969280/68719476736), sparse 3% (2101932032), duration 298, 31/31 MB/s
121: Jun 05 04:57:14 INFO: status: 11% (7583170560/68719476736), sparse 3% (2103173120), duration 433, 5/5 MB/s
121: Jun 05 04:57:39 INFO: status: 12% (8255963136/68719476736), sparse 3% (2103418880), duration 458, 26/26 MB/s
121: Jun 05 04:58:06 INFO: status: 13% (8940158976/68719476736), sparse 3% (2103447552), duration 485, 25/25 MB/s
121: Jun 05 04:58:33 INFO: status: 14% (9631956992/68719476736), sparse 3% (2103447552), duration 512, 25/25 MB/s
121: Jun 05 04:58:56 INFO: status: 15% (10319953920/68719476736), sparse 3% (2103447552), duration 535, 29/29 MB/s
121: Jun 05 04:59:23 INFO: status: 16% (11019354112/68719476736), sparse 3% (2103685120), duration 562, 25/25 MB/s
121: Jun 05 05:03:02 INFO: status: 17% (11699748864/68719476736), sparse 3% (2103787520), duration 781, 3/3 MB/s
121: Jun 05 05:03:59 INFO: status: 18% (12372541440/68719476736), sparse 3% (2103951360), duration 838, 11/11 MB/s
121: Jun 05 05:05:04 INFO: status: 19% (13060538368/68719476736), sparse 3% (2103980032), duration 903, 10/10 MB/s
121: Jun 05 05:05:30 INFO: status: 20% (13797949440/68719476736), sparse 3% (2104127488), duration 929, 28/28 MB/s
121: Jun 05 05:06:34 INFO: status: 21% (14447935488/68719476736), sparse 3% (2104168448), duration 993, 10/10 MB/s
121: Jun 05 05:06:57 INFO: status: 22% (15124529152/68719476736), sparse 3% (2109591552), duration 1016, 29/29 MB/s
121: Jun 05 05:07:23 INFO: status: 23% (15822028800/68719476736), sparse 3% (2111393792), duration 1042, 26/26 MB/s
121: Jun 05 05:07:49 INFO: status: 24% (16542334976/68719476736), sparse 3% (2111422464), duration 1068, 27/27 MB/s
121: Jun 05 05:08:12 INFO: status: 25% (17184718848/68719476736), sparse 3% (2111422464), duration 1091, 27/27 MB/s
121: Jun 05 05:08:35 INFO: status: 26% (17876516864/68719476736), sparse 3% (2111574016), duration 1114, 30/30 MB/s
121: Jun 05 05:09:03 INFO: status: 27% (18564513792/68719476736), sparse 3% (2111582208), duration 1142, 24/24 MB/s
121: Jun 05 05:09:31 INFO: status: 28% (19256311808/68719476736), sparse 3% (2111852544), duration 1170, 24/24 MB/s
121: Jun 05 05:14:01 ERROR: VM 121 not running
121: Jun 05 05:14:01 INFO: aborting backup job
121: Jun 05 05:14:01 ERROR: VM 121 not running
121: Jun 05 05:14:02 INFO: restarting vm
121: Jun 05 05:14:05 INFO: vm is online again after 1453 seconds
121: Jun 05 05:14:26 ERROR: Backup of VM 121 failed - VM 121 not running
 
as the VM backup is using KVM, the VM must be running, otherwise it does not work.

e.g. if your VM is stopped and you make a backup, the VM is started (but to NOT boot) during the backup.

see also http://pve.proxmox.com/wiki/Backup_and_Restore
 
121: Jun 05 04:49:51 INFO: Starting Backup of VM 121 (qemu)
121: Jun 05 04:49:51 INFO: status = running
121: Jun 05 04:49:51 INFO: backup mode: stop
121: Jun 05 04:49:51 INFO: ionice priority: 7
121: Jun 05 04:49:52 INFO: stopping vm
121: Jun 05 04:50:00 INFO: creating archive '/mnt/pve/betanfs/dump/vzdump-qemu-121-2013_06_05-04_49_51.vma.lzo'
121: Jun 05 04:50:00 INFO: starting kvm to execute backup task
121: Jun 05 04:50:01 INFO: started backup task 'd608e013-1a34-4091-b3af-e1dbb2677dae'
121: Jun 05 04:50:01 INFO: resume VM

other VM backups fine

Code: 
INFO: Starting Backup of VM 100 (qemu)
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: stopping vm
INFO: creating archive '/mnt/pve/betanfs/dump/vzdump-qemu-100-2013_06_05-01_00_02.vma.lzo'
INFO: starting kvm to execute backup task
INFO: started backup task 'b0dd1705-e5b4-4811-97a1-0b52ab56ea36'
INFO: resume VM
INFO: status: 0% (83623936/72461844480), sparse 0% (176128), duration 3, 27/27 MB/s
INFO: status: 1% (771620864/72461844480), sparse 0% (12664832), duration 19, 42/42 MB/s
INFO: status: 2% (1452015616/72461844480), sparse 0% (38440960), duration 35, 42/40 MB/s
INFO: status: 3% (2178875392/72461844480), sparse 0% (90726400), duration 181, 4/4 MB/s
INFO: status: 4% (2911633408/72461844480), sparse 0% (160600064), duration 198, 43/38 MB/s
INFO: status: 5% (3694460928/72461844480), sparse 0% (460091392), duration 334, 5/3 MB/s
INFO: status: 8% (5952503808/72461844480), sparse 3% (2718134272), duration 337, 752/0 MB/s
INFO: status: 9% (6582239232/72461844480), sparse 4% (3344617472), duration 371, 18/0 MB/s
INFO: status: 11% (8233680896/72461844480), sparse 6% (4978159616), duration 374, 550/5 MB/s
INFO: status: 13% (9556262912/72461844480), sparse 8% (6272782336), duration 377, 440/9 MB/s
INFO: status: 16% (11750539264/72461844480), sparse 11% (8462929920), duration 380, 731/1 MB/s
INFO: status: 17% (12494176256/72461844480), sparse 12% (9134518272), duration 383, 247/24 MB/s
INFO: status: 18% (13374193664/72461844480), sparse 13% (9751539712), duration 393, 88/26 MB/s
INFO: status: 22% (15974400000/72461844480), sparse 17% (12351680512), duration 396, 866/0 MB/s
INFO: status: 25% (18799722496/72461844480), sparse 20% (15177003008), duration 399, 941/0 MB/s
INFO: status: 29% (21355429888/72461844480), sparse 24% (17732710400), duration 402, 851/0 MB/s
INFO: status: 31% (23089577984/72461844480), sparse 26% (19419484160), duration 405, 578/15 MB/s
INFO: status: 32% (23232249856/72461844480), sparse 26% (19420884992), duration 451, 3/3 MB/s
INFO: status: 33% (23912644608/72461844480), sparse 26% (19421184000), duration 474, 29/29 MB/s
INFO: status: 34% (24653856768/72461844480), sparse 26% (19421765632), duration 577, 7/7 MB/s
INFO: status: 35% (25383665664/72461844480), sparse 26% (19429588992), duration 598, 34/34 MB/s
INFO: status: 36% (26090668032/72461844480), sparse 26% (19469160448), duration 793, 3/3 MB/s
INFO: status: 37% (26828079104/72461844480), sparse 26% (19513675776), duration 809, 46/43 MB/s
INFO: status: 38% (27569291264/72461844480), sparse 27% (19581861888), duration 828, 39/35 MB/s
INFO: status: 39% (28310503424/72461844480), sparse 27% (19654025216), duration 844, 46/41 MB/s
INFO: status: 40% (28991815680/72461844480), sparse 27% (19698397184), duration 856, 56/53 MB/s
INFO: status: 41% (29732110336/72461844480), sparse 27% (19782840320), duration 871, 49/43 MB/s
INFO: status: 42% (30450515968/72461844480), sparse 27% (19803926528), duration 889, 39/38 MB/s
INFO: status: 43% (31176523776/72461844480), sparse 27% (19816333312), duration 905, 45/44 MB/s
INFO: status: 44% (31887327232/72461844480), sparse 27% (19818598400), duration 922, 41/41 MB/s
INFO: status: 45% (32613335040/72461844480), sparse 27% (19820441600), duration 1154, 3/3 MB/s
INFO: status: 46% (33377353728/72461844480), sparse 27% (19820736512), duration 1173, 40/40 MB/s
INFO: status: 47% (34133770240/72461844480), sparse 27% (19821498368), duration 1184, 68/68 MB/s
INFO: status: 48% (34825568256/72461844480), sparse 27% (19821498368), duration 1237, 13/13 MB/s
INFO: status: 49% (35543973888/72461844480), sparse 27% (19822370816), duration 1256, 37/37 MB/s
INFO: status: 50% (36235771904/72461844480), sparse 27% (19822428160), duration 1264, 86/86 MB/s
INFO: status: 51% (37034000384/72461844480), sparse 27% (19824058368), duration 1273, 88/88 MB/s
INFO: status: 52% (37714395136/72461844480), sparse 27% (19825225728), duration 1282, 75/75 MB/s
INFO: status: 53% (38448005120/72461844480), sparse 27% (19825979392), duration 1365, 8/8 MB/s
INFO: status: 54% (39181615104/72461844480), sparse 27% (19826016256), duration 1373, 91/91 MB/s
INFO: status: 55% (39892418560/72461844480), sparse 27% (19826384896), duration 1382, 78/78 MB/s
INFO: status: 56% (40618426368/72461844480), sparse 27% (19829555200), duration 1392, 72/72 MB/s
INFO: status: 57% (41317826560/72461844480), sparse 27% (19846631424), duration 1407, 46/45 MB/s
INFO: status: 58% (42028630016/72461844480), sparse 27% (19854802944), duration 1480, 9/9 MB/s
INFO: status: 59% (42762240000/72461844480), sparse 27% (19854835712), duration 1503, 31/31 MB/s
INFO: status: 60% (43503452160/72461844480), sparse 27% (19854835712), duration 1532, 25/25 MB/s
INFO: status: 61% (44221857792/72461844480), sparse 27% (19854835712), duration 1559, 26/26 MB/s
INFO: status: 62% (44959268864/72461844480), sparse 27% (19854835712), duration 1588, 25/25 MB/s
INFO: status: 63% (45666271232/72461844480), sparse 27% (19855310848), duration 1605, 41/41 MB/s
INFO: status: 64% (46380875776/72461844480), sparse 27% (19856359424), duration 1617, 59/59 MB/s
INFO: status: 65% (47106883584/72461844480), sparse 27% (19862200320), duration 1804, 3/3 MB/s
INFO: status: 66% (47848095744/72461844480), sparse 27% (19863330816), duration 1821, 43/43 MB/s
INFO: status: 67% (48558702592/72461844480), sparse 27% (19864928256), duration 1841, 35/35 MB/s
INFO: status: 68% (49294606336/72461844480), sparse 27% (19864928256), duration 1870, 25/25 MB/s
INFO: status: 69% (50008948736/72461844480), sparse 27% (19864965120), duration 1894, 29/29 MB/s
INFO: status: 70% (50740723712/72461844480), sparse 27% (19865120768), duration 1922, 26/26 MB/s
INFO: status: 71% (51466731520/72461844480), sparse 27% (19865137152), duration 1951, 25/25 MB/s
INFO: status: 72% (52178780160/72461844480), sparse 27% (19865227264), duration 1976, 28/28 MB/s
INFO: status: 73% (52911144960/72461844480), sparse 27% (19865227264), duration 2004, 26/26 MB/s
INFO: status: 74% (53704392704/72461844480), sparse 28% (20505640960), duration 2011, 113/21 MB/s
INFO: status: 77% (56124112896/72461844480), sparse 31% (22925361152), duration 2014, 806/0 MB/s
INFO: status: 79% (57493094400/72461844480), sparse 33% (24294342656), duration 2276, 5/0 MB/s
INFO: status: 84% (60879667200/72461844480), sparse 38% (27680915456), duration 2279, 1128/0 MB/s
INFO: status: 89% (64762085376/72461844480), sparse 43% (31563333632), duration 2282, 1294/0 MB/s
INFO: status: 92% (66974318592/72461844480), sparse 46% (33775562752), duration 2285, 737/0 MB/s
INFO: status: 95% (69078482944/72461844480), sparse 49% (35879727104), duration 2288, 701/0 MB/s
INFO: status: 98% (71337115648/72461844480), sparse 52% (38138359808), duration 2291, 752/0 MB/s
INFO: status: 100% (72461844480/72461844480), sparse 54% (39263084544), duration 2294, 374/0 MB/s
INFO: transferred 72461 MB in 2294 seconds (31 MB/s)
INFO: archive file size: 19.02GB
INFO: delete old backup '/mnt/pve/betanfs/dump/vzdump-qemu-100-2013_05_28-01_00_02.vma.lzo'
INFO: vm is online again after 2378 seconds
INFO: Finished Backup of VM 100 (00:39:38)
 
I assume you use a qcow2 file somewhere? Most likely that file has errors (use 'qemu-img check' to verify)
 
I use RAW for my VMs :rolleyes:


Upd

[root@pmnode2 121]# qemu-img check vm-121-disk-1.raw
qemu-img: This image format does not support checks
 
I have similar problem with snapshot mode:

Code: 
[COLOR=#000000][FONT=tahoma]INFO: Starting Backup of VM 208 (qemu)[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status = running[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: update VM 208: -lock backup[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: backup mode: snapshot[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: ionice priority: 7[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: creating archive '/mnt/pve/begemot-nfs/dump/vzdump-qemu-208-2013_09_08-02_38_13.vma.gz'[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: started backup task '8921e99d-8c88-4d71-9b4c-a7a6c7a9ea7a'[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 0% (102629376/34363932672), sparse 0% (4202496), duration 3, 34/32 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 1% (361103360/34363932672), sparse 0% (16740352), duration 15, 21/20 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 2% (691798016/34363932672), sparse 0% (37609472), duration 27, 27/25 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 3% (1045299200/34363932672), sparse 0% (50147328), duration 38, 32/30 MB/s[/FONT][/COLOR]
[FONT=tahoma][COLOR=#000000]....[/COLOR][/FONT]
[COLOR=#000000][FONT=tahoma]INFO: status: 36% (12380143616/34363932672), sparse 1% (426352640), duration 1001, 12/12 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 37% (12718440448/34363932672), sparse 1% (434704384), duration 1065, 5/5 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]ERROR: VM 208 not running[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: aborting backup job[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]ERROR: unable to find configuration file for VM 208 - no such machine[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: no such VM ('208')[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]command 'qm unlock 208' failed: exit code 2[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]ERROR: Backup of VM 208 failed - VM 208 not running[/FONT][/COLOR]

There was no actions on this VM during backup
 
Code: 
[COLOR=#000000][FONT=tahoma]INFO: Starting Backup of VM 208 (qemu)[/FONT][/COLOR]

[FONT=tahoma][COLOR=#000000]....[/COLOR][/FONT]
[COLOR=#000000][FONT=tahoma]INFO: status: 36% (12380143616/34363932672), sparse 1% (426352640), duration 1001, 12/12 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: status: 37% (12718440448/34363932672), sparse 1% (434704384), duration 1065, 5/5 MB/s[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]ERROR: VM 208 not running[/FONT][/COLOR]
[COLOR=#000000][FONT=tahoma]INFO: aborting backup job[/FONT][/COLOR]

Maybe your disk image is damaged - try to use 'qemu-img check' to verify that.
 
perhaps it was a problem with nfs backup storage. There is no problem with the new nfs
 
Hile said:
I use RAW for my VMs :rolleyes:


Upd

[root@pmnode2 121]# qemu-img check vm-121-disk-1.raw
qemu-img: This image format does not support checks
Click to expand...

I tried the same:

root@proxmox 113# qemu-img check -f raw vm-113-disk-1.raw
qemu-img: This image format does not support checks

VM won't boot. This just happened out of the blue. :(

Suggestions?
 
Hello,

this happened for me tonight.

VM on logical volume.

Backup startet manually:
Code: 
#vzdump --mailto <mail@address> --mode snapshot --compress lzo --storage backup 11015

Log:
Code: 
11015: Jul 21 23:40:57 INFO: Starting Backup of VM 11015 (qemu)
11015: Jul 21 23:40:57 INFO: status = running
11015: Jul 21 23:40:57 INFO: update VM 11015: -lock backup
11015: Jul 21 23:41:01 INFO: backup mode: snapshot
11015: Jul 21 23:41:01 INFO: ionice priority: 7
..
11015: Jul 22 01:28:19 INFO: status: 97% (106346315776/109521666048), sparse 13% (14594850816), duration 6438, 64/0 MB/s
11015: [COLOR=red]Jul 22 01:28:41 ERROR: VM 11015 qmp command 'query-backup' failed - client closed connection
[/COLOR]11015: Jul 22 01:28:41 INFO: aborting backup job
11015: [COLOR=red]Jul 22 01:28:41 ERROR: VM 11015 not running
[/COLOR]11015: [COLOR=red]Jul 22 01:28:47 ERROR: Backup of VM 11015 failed - VM 11015 qmp command 'query-backup' failed - client closed connection[/COLOR]
#pveversion -v
Code: 
proxmox-ve-2.6.32: 3.2-129 (running kernel: 2.6.32-29-pve)
pve-manager: 3.2-4 (running version: 3.2-4/e24a91c1)
pve-kernel-2.6.32-30-pve: 2.6.32-130
pve-kernel-2.6.32-29-pve: 2.6.32-126
pve-kernel-2.6.32-26-pve: 2.6.32-114
lvm2: 2.02.98-pve4
clvm: 2.02.98-pve4
corosync-pve: 1.4.5-1
openais-pve: 1.1.4-3
libqb0: 0.11.1-2
redhat-cluster-pve: 3.2.0-2
resource-agents-pve: 3.9.2-4
fence-agents-pve: 4.0.5-1
pve-cluster: 3.0-12
qemu-server: 3.1-16
pve-firmware: 1.1-3
libpve-common-perl: 3.0-18
libpve-access-control: 3.0-11
libpve-storage-perl: 3.0-19
pve-libspice-server1: 0.12.4-3
vncterm: 1.1-6
vzctl: 4.0-1pve5
vzprocps: 2.0.11-2
vzquota: 3.1-2
pve-qemu-kvm: 1.7-8
ksm-control-daemon: 1.1-1
glusterfs-client: 3.4.2-1

esco
 
Last edited:
same problem here, VM not running during backup:

Code: 
Feb 26 03:36:45 INFO: status: 17% (5682626560/32215400448), sparse 6% (1979052032), duration 30, 109/109 MB/s
Feb 26 03:37:19 ERROR: VM 230 not running
Feb 26 03:37:19 INFO: aborting backup job
Feb 26 03:37:19 ERROR: VM 230 not running
Feb 26 03:37:21 ERROR: Backup of VM 230 failed - VM 230 not running


the VM230 image used to be a QCOW2 image, but since this error got very annoying I converted it to RAW (after making an image-check). Still have the same problem. Does the fix from March 2014 work on this issue?

Code: 
proxmox-ve-2.6.32: 3.3-147 (running kernel: 2.6.32-33-pve)
pve-manager: 3.4-1 (running version: 3.4-1/3f2d890e)
pve-kernel-2.6.32-20-pve: 2.6.32-100
pve-kernel-2.6.32-32-pve: 2.6.32-136
pve-kernel-2.6.32-33-pve: 2.6.32-138
pve-kernel-2.6.32-30-pve: 2.6.32-130
pve-kernel-2.6.32-37-pve: 2.6.32-147
pve-kernel-2.6.32-22-pve: 2.6.32-107
pve-kernel-2.6.32-29-pve: 2.6.32-126
pve-kernel-2.6.32-31-pve: 2.6.32-132
pve-kernel-2.6.32-26-pve: 2.6.32-114
lvm2: 2.02.98-pve4
clvm: 2.02.98-pve4
corosync-pve: 1.4.7-1
openais-pve: 1.1.4-3
libqb0: 0.11.1-2
redhat-cluster-pve: 3.2.0-2
resource-agents-pve: 3.9.2-4
fence-agents-pve: 4.0.10-2
pve-cluster: 3.0-16
qemu-server: 3.3-20
pve-firmware: 1.1-3
libpve-common-perl: 3.0-24
libpve-access-control: 3.0-16
libpve-storage-perl: 3.0-31
pve-libspice-server1: 0.12.4-3
vncterm: 1.1-8
vzctl: 4.0-1pve6
vzprocps: 2.0.11-2
vzquota: 3.1-2
pve-qemu-kvm: 2.1-12
ksm-control-daemon: 1.1-1
glusterfs-client: 3.5.2-1
 
Last edited:
You must log in or register to reply here.
Top Bottom