Critical - Backups are failing. Operation Not Permitted

F

firegs

New Member
Apr 8, 2013
28
0
1
Code: 
300: Feb 26 20:30:02 INFO: Starting Backup of VM 300 (qemu)300: Feb 26 20:30:02 INFO: status = running
300: Feb 26 20:30:03 INFO: update VM 300: -lock backup
300: Feb 26 20:30:03 INFO: backup mode: snapshot
300: Feb 26 20:30:03 INFO: bandwidth limit: 50000 KB/s
300: Feb 26 20:30:03 INFO: ionice priority: 7
300: Feb 26 20:30:03 INFO: skip unused drive 'vm-storage:0.0.7.scsi-36001405278e80dfd47fad45b8d8573d5' (not included into backup)
300: Feb 26 20:30:03 INFO: creating archive '/mnt/pve/VMBackup/dump/vzdump-qemu-300-2014_02_26-20_30_02.vma.lzo'
300: Feb 26 20:30:03 INFO: started backup task '45c03d57-ed53-4388-84f5-a48477cbdb9d'
300: Feb 26 20:30:06 INFO: status: 0% (101777408/53687091200), sparse 0% (32428032), duration 3, 33/23 MB/s
300: Feb 26 20:30:19 INFO: status: 1% (542179328/53687091200), sparse 0% (324239360), duration 16, 33/11 MB/s
300: Feb 26 20:30:42 INFO: status: 2% (1091239936/53687091200), sparse 0% (340078592), duration 39, 23/23 MB/s
300: Feb 26 20:31:24 INFO: status: 3% (1626472448/53687091200), sparse 0% (353800192), duration 81, 12/12 MB/s
300: Feb 26 20:31:40 INFO: status: 4% (2162622464/53687091200), sparse 0% (410157056), duration 97, 33/29 MB/s
300: Feb 26 20:32:08 INFO: status: 5% (2716008448/53687091200), sparse 1% (568016896), duration 125, 19/14 MB/s
300: Feb 26 20:32:29 INFO: status: 6% (3236888576/53687091200), sparse 1% (581734400), duration 146, 24/24 MB/s
300: Feb 26 20:33:00 INFO: status: 7% (3788767232/53687091200), sparse 1% (598761472), duration 177, 17/17 MB/s
300: Feb 26 20:33:15 INFO: status: 8% (4309909504/53687091200), sparse 2% (1085042688), duration 192, 34/2 MB/s
300: Feb 26 20:34:22 INFO: status: 9% (4852350976/53687091200), sparse 2% (1604116480), duration 259, 8/0 MB/s
300: Feb 26 20:34:42 INFO: status: 10% (5369298944/53687091200), sparse 3% (2120474624), duration 279, 25/0 MB/s
300: Feb 26 20:35:04 INFO: status: 11% (5906300928/53687091200), sparse 4% (2657083392), duration 301, 24/0 MB/s
300: Feb 26 20:35:20 INFO: status: 12% (6446972928/53687091200), sparse 5% (3197493248), duration 317, 33/0 MB/s
300: Feb 26 20:35:38 INFO: status: 13% (6984368128/53687091200), sparse 6% (3612925952), duration 335, 29/6 MB/s
300: Feb 26 20:35:57 INFO: status: 14% (7542341632/53687091200), sparse 6% (3668934656), duration 354, 29/26 MB/s
300: Feb 26 20:37:39 INFO: status: 15% (8063090688/53687091200), sparse 6% (3714490368), duration 456, 5/4 MB/s
300: Feb 26 20:38:10 INFO: status: 16% (8591310848/53687091200), sparse 7% (4242186240), duration 487, 17/0 MB/s
300: Feb 26 20:38:34 INFO: status: 17% (9134276608/53687091200), sparse 8% (4711538688), duration 511, 22/3 MB/s
300: Feb 26 20:38:51 INFO: status: 18% (9683075072/53687091200), sparse 9% (5260075008), duration 528, 32/0 MB/s
300: Feb 26 20:39:09 INFO: status: 19% (10224467968/53687091200), sparse 10% (5801271296), duration 546, 30/0 MB/s
300: Feb 26 20:39:24 INFO: status: 20% (10751508480/53687091200), sparse 11% (6328115200), duration 561, 35/0 MB/s
300: Feb 26 20:39:40 INFO: status: 21% (11301224448/53687091200), sparse 12% (6762242048), duration 577, 34/7 MB/s
300: Feb 26 20:39:57 INFO: status: 22% (11838160896/53687091200), sparse 13% (7154974720), duration 594, 31/8 MB/s
300: Feb 26 20:40:12 INFO: status: 23% (12365987840/53687091200), sparse 14% (7682408448), duration 609, 35/0 MB/s
300: Feb 26 20:40:27 INFO: status: 24% (12893487104/53687091200), sparse 15% (8209711104), duration 624, 35/0 MB/s
300: Feb 26 20:40:44 INFO: status: 25% (13437698048/53687091200), sparse 16% (8713777152), duration 641, 32/2 MB/s
300: Feb 26 20:40:59 INFO: status: 26% (13963427840/53687091200), sparse 17% (9239244800), duration 656, 35/0 MB/s
300: Feb 26 20:41:15 INFO: status: 27% (14524678144/53687091200), sparse 18% (9800232960), duration 672, 35/0 MB/s
300: Feb 26 20:41:30 INFO: status: 28% (15057485824/53687091200), sparse 19% (10332778496), duration 687, 35/0 MB/s
300: Feb 26 20:41:47 INFO: status: 29% (15599075328/53687091200), sparse 19% (10712375296), duration 704, 31/9 MB/s
300: Feb 26 20:42:03 INFO: status: 30% (16133193728/53687091200), sparse 19% (10713636864), duration 720, 33/33 MB/s
300: Feb 26 20:42:29 INFO: status: 31% (16648372224/53687091200), sparse 19% (10713944064), duration 746, 19/19 MB/s
300: Feb 26 20:42:45 INFO: status: 32% (17182031872/53687091200), sparse 19% (10729492480), duration 762, 33/32 MB/s
300: Feb 26 20:43:03 INFO: status: 33% (17722114048/53687091200), sparse 20% (10860163072), duration 780, 30/22 MB/s
300: Feb 26 20:43:20 INFO: status: 34% (18269405184/53687091200), sparse 20% (10860216320), duration 797, 32/32 MB/s
300: Feb 26 20:43:40 INFO: status: 35% (18797166592/53687091200), sparse 20% (10860257280), duration 817, 26/26 MB/s
300: Feb 26 20:43:57 INFO: status: 36% (19344326656/53687091200), sparse 20% (10860572672), duration 834, 32/32 MB/s
300: Feb 26 20:44:22 INFO: status: 37% (19867369472/53687091200), sparse 20% (11000958976), duration 859, 20/15 MB/s
300: Feb 26 20:44:38 INFO: status: 38% (20413218816/53687091200), sparse 21% (11545083904), duration 875, 34/0 MB/s
300: Feb 26 20:44:56 INFO: status: 39% (20970274816/53687091200), sparse 22% (12101222400), duration 893, 30/0 MB/s
300: Feb 26 20:45:11 INFO: status: 40% (21485977600/53687091200), sparse 23% (12616007680), duration 908, 34/0 MB/s
300: Feb 26 20:45:27 INFO: status: 41% (22035300352/53687091200), sparse 24% (13145051136), duration 924, 34/1 MB/s
300: Feb 26 20:45:42 INFO: status: 42% (22553755648/53687091200), sparse 25% (13662720000), duration 939, 34/0 MB/s
300: Feb 26 20:45:58 INFO: status: 43% (23115137024/53687091200), sparse 26% (14223380480), duration 955, 35/0 MB/s
300: Feb 26 20:46:13 INFO: status: 44% (23634706432/53687091200), sparse 27% (14742228992), duration 970, 34/0 MB/s
300: Feb 26 20:46:29 INFO: status: 45% (24159387648/53687091200), sparse 28% (15147286528), duration 986, 32/7 MB/s
300: Feb 26 20:46:46 INFO: status: 46% (24702812160/53687091200), sparse 29% (15654862848), duration 1003, 31/2 MB/s
300: Feb 26 20:47:02 INFO: status: 47% (25263341568/53687091200), sparse 30% (16215392256), duration 1019, 35/0 MB/s
300: Feb 26 20:47:17 INFO: status: 48% (25780092928/53687091200), sparse 31% (16732078080), duration 1034, 34/0 MB/s
300: Feb 26 20:47:33 INFO: status: 49% (26330202112/53687091200), sparse 31% (17146687488), duration 1050, 34/8 MB/s
300: Feb 26 20:47:49 INFO: status: 50% (26868908032/53687091200), sparse 32% (17685393408), duration 1066, 33/0 MB/s
300: Feb 26 20:48:04 INFO: status: 51% (27394834432/53687091200), sparse 33% (18211319808), duration 1081, 35/0 MB/s
300: Feb 26 20:48:19 INFO: status: 52% (27922202624/53687091200), sparse 34% (18738688000), duration 1096, 35/0 MB/s
300: Feb 26 20:48:35 INFO: status: 53% (28463792128/53687091200), sparse 35% (19208028160), duration 1112, 33/4 MB/s
300: Feb 26 20:48:51 INFO: status: 54% (29023010816/53687091200), sparse 36% (19767246848), duration 1128, 34/0 MB/s
300: Feb 26 20:49:06 INFO: status: 55% (29538058240/53687091200), sparse 37% (20282294272), duration 1143, 34/0 MB/s
300: Feb 26 20:49:22 INFO: status: 56% (30097670144/53687091200), sparse 38% (20841906176), duration 1159, 34/0 MB/s
300: Feb 26 20:49:37 INFO: status: 57% (30601904128/53687091200), sparse 39% (21297451008), duration 1174, 33/3 MB/s
300: Feb 26 20:49:53 INFO: status: 58% (31158960128/53687091200), sparse 40% (21854507008), duration 1190, 34/0 MB/s
300: Feb 26 20:50:08 INFO: status: 59% (31681085440/53687091200), sparse 41% (22376566784), duration 1205, 34/0 MB/s
300: Feb 26 20:50:27 INFO: status: 60% (32221691904/53687091200), sparse 42% (22917173248), duration 1224, 28/0 MB/s
300: Feb 26 20:50:44 INFO: status: 61% (32780517376/53687091200), sparse 43% (23436005376), duration 1241, 32/2 MB/s
300: Feb 26 20:51:00 INFO: status: 62% (33293205504/53687091200), sparse 44% (23948611584), duration 1257, 32/0 MB/s
300: Feb 26 20:51:24 INFO: status: 63% (33849212928/53687091200), sparse 45% (24504553472), duration 1281, 23/0 MB/s
300: Feb 26 20:51:40 INFO: status: 64% (34392506368/53687091200), sparse 46% (25047846912), duration 1297, 33/0 MB/s
300: Feb 26 20:52:06 INFO: status: 65% (34910175232/53687091200), sparse 47% (25543094272), duration 1323, 19/0 MB/s
300: Feb 26 20:52:26 INFO: status: 66% (35445211136/53687091200), sparse 48% (26078064640), duration 1343, 26/0 MB/s
300: Feb 26 20:52:46 INFO: status: 67% (35992698880/53687091200), sparse 49% (26625486848), duration 1363, 27/0 MB/s
300: Feb 26 20:53:04 INFO: status: 68% (36522229760/53687091200), sparse 50% (27155017728), duration 1381, 29/0 MB/s
300: Feb 26 20:53:20 INFO: status: 69% (37056741376/53687091200), sparse 51% (27594874880), duration 1397, 33/5 MB/s
300: Feb 26 20:54:02 INFO: status: 70% (37602590720/53687091200), sparse 52% (28140658688), duration 1439, 12/0 MB/s
300: Feb 26 20:54:22 INFO: status: 71% (38154731520/53687091200), sparse 53% (28692733952), duration 1459, 27/0 MB/s
300: Feb 26 20:54:42 INFO: status: 72% (38678364160/53687091200), sparse 54% (29216366592), duration 1479, 26/0 MB/s
300: Feb 26 20:55:02 INFO: status: 73% (39220281344/53687091200), sparse 55% (29696688128), duration 1499, 27/3 MB/s
300: Feb 26 20:55:21 INFO: status: 74% (39746535424/53687091200), sparse 56% (30222942208), duration 1518, 27/0 MB/s
300: Feb 26 20:55:44 INFO: status: 75% (40282554368/53687091200), sparse 57% (30758961152), duration 1541, 23/0 MB/s
300: Feb 26 20:56:03 INFO: status: 76% (40808153088/53687091200), sparse 58% (31284559872), duration 1560, 27/0 MB/s
300: Feb 26 20:56:25 INFO: status: 77% (41373335552/53687091200), sparse 59% (31814840320), duration 1582, 25/1 MB/s
300: Feb 26 20:56:44 INFO: status: 78% (41896247296/53687091200), sparse 60% (32337686528), duration 1601, 27/0 MB/s
300: Feb 26 20:56:59 INFO: status: 79% (42437705728/53687091200), sparse 61% (32879079424), duration 1616, 36/0 MB/s
300: Feb 26 20:57:18 INFO: status: 80% (42961666048/53687091200), sparse 62% (33403039744), duration 1635, 27/0 MB/s
300: Feb 26 20:57:49 INFO: status: 80% (42989846528/53687091200), sparse 62% (33431220224), duration 1666, 0/0 MB/s
300: [COLOR=red]Feb 26 20:57:49 ERROR: job failed with err -1 - Operation not permitted
[/COLOR]300: Feb 26 20:57:49 INFO: aborting backup job
300: [COLOR=red]Feb 26 21:07:49 ERROR: VM 300 qmp command 'backup-cancel' failed - got timeout 
[/COLOR]300: [COLOR=red]Feb 26 21:07:50 ERROR: Backup of VM 300 failed - job failed with err -1 - Operation not permitted[/COLOR]

Code: 
proxmox-ve-2.6.32: 3.1-121 (running kernel: 2.6.32-27-pve)
pve-manager: 3.1-43 (running version: 3.1-43/1d4b0dfb)
pve-kernel-2.6.32-20-pve: 2.6.32-100
pve-kernel-2.6.32-27-pve: 2.6.32-121
pve-kernel-2.6.32-19-pve: 2.6.32-96
pve-kernel-2.6.32-16-pve: 2.6.32-82
pve-kernel-2.6.32-23-pve: 2.6.32-109
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-15
pve-firmware: 1.1-2
libpve-common-perl: 3.0-13
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-1pve4
vzprocps: 2.0.11-2
vzquota: 3.1-2
pve-qemu-kvm: 1.7-4
ksm-control-daemon: 1.1-1
glusterfs-client: 3.4.2-1

This also locks the VM, and even using "qm unlock <vmid>" doesnt make the VM come back or respond. Only stopping and starting the VM works.

"VMBackup" is an NFS Server. Other nodes have no issue backing up to this same server.

The VM's Disk drive is living on a GlusterFS cluster.

HALP!
 
I've got exactly the same problem, it just appeared when i added a new VM after updating to Proxmox Version 3.2:
Code: 
230: Mar 19 03:24:41 INFO: status: 40% (257718681600/644245094400), sparse 11% (73886679040), duration 2151, 136/61 MB/s230: Mar 19 03:26:00 INFO: status: 41% (264163622912/644245094400), sparse 11% (74924113920), duration 2230, 81/68 MB/s230: Mar 19 03:27:19 INFO: status: 42% (270731968512/644245094400), sparse 11% (76401618944), duration 2309, 83/64 MB/s230: Mar 19 03:27:59 INFO: status: 43% (277136015360/644245094400), sparse 12% (79566807040), duration 2349, 160/80 MB/s230: Mar 19 03:28:49 INFO: status: 44% (283630436352/644245094400), sparse 12% (82852474880), duration 2399, 129/64 MB/s230: Mar 19 03:29:57 INFO: status: 45% (290005581824/644245094400), sparse 13% (83852685312), duration 2467, 93/79 MB/s230: Mar 19 03:31:26 INFO: status: 46% (296434139136/644245094400), sparse 13% (83992969216), duration 2556, 72/70 MB/s230: Mar 19 03:32:15 INFO: status: 46% (299628429312/644245094400), sparse 13% (84051824640), duration 2605, 65/63 MB/s230: Mar 19 03:32:15 ERROR: job failed with err -1 - Operation not permitted\n230: Mar 19 03:32:15 INFO: aborting backup job230: Mar 19 03:32:16 ERROR: Backup of VM 230 failed - job failed with err -1 - Operation not permitted
VM is stored in RAW format on LVM2 Volume, Backup target is NFS mounted. My VM doesn't get locked though, it's running just fine.
 
Are any other backups running simultaneously from other Proxmox nodes or the error occurred while only one backup job was running in the whole cluster?

In my case i sometimes get this error during simultaneous backups to a single storage. When the backups are on different subnet, even though the overall I/O in the backup server goes down per Proxmox node, it never crashes.....Yet.
backup.png
 
symmcom said:
Are any other backups running simultaneously from other Proxmox nodes or the error occurred while only one backup job was running in the whole cluster?

In my case i sometimes get this error during simultaneous backups to a single storage. When the backups are on different subnet, even though the overall I/O in the backup server goes down per Proxmox node, it never crashes.....Yet.
View attachment 2076
Click to expand...

Although I think you may be replying to the OP, I will still weigh in with this: No, there are no other VM's being backed up at that time.. More importantly, the backup is mounted on the same node (locally) as the running VM's and I have only one node.

Just backed up 6 other VM's witout problems. There is something with the CentOS VM. Other than its size (50+ GB's) I cant think of a reason for it to fail. Operation not permitted!?
 
lpallard said:
Just backed up 6 other VM's witout problems. There is something with the CentOS VM. Other than its size (50+ GB's) I cant think of a reason for it to fail. Operation not permitted!?
Click to expand...
Any CentOS among those 6 successful backups? May be create a new CentOS VM on same storage same node and see if that causes any error.
 
You must log in or register to reply here.

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!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

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!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back