Backup Stops working

Danielc1234

Active Member
Jan 10, 2010
82
0
26
Hi all. For some reason I set up my backup for all my VMs and at a certain time of night.
It will back up for a few days and then all of a sudden stop. With no warnings or anything.
What can I do to try and trouble shoot this? A side note, the last time I had to restart the server, the mysql VM would not start because it was locked, from a backup or something.

Can someone tell me how to start to look into this and what to do?
Thanks. Daniel
 
Hi all. For some reason I set up my backup for all my VMs and at a certain time of night.
It will back up for a few days and then all of a sudden stop. With no warnings or anything.

Any hint in the logs? /var/log/syslog or /var/log/vzdump/*
 
syslog says...the backup is set to run at 1am.

Code:
Jul 10 00:55:33 zicominc2 proxwww[4233]: Starting new child 4233
Jul 10 00:56:03 zicominc2 proxwww[4265]: Starting new child 4265
Jul 10 00:56:19 zicominc2 pvedaemon[2618]: WARNING: Cannot encode 'meminfo' element as 'hash'. Will be encoded as 'map' instead
Jul 10 00:56:24 zicominc2 pvedaemon[2618]: WARNING: Cannot encode 'meminfo' element as 'hash'. Will be encoded as 'map' instead
Jul 10 00:56:25 zicominc2 proxwww[4272]: Starting new child 4272
Jul 10 00:56:38 zicominc2 proxwww[4277]: Starting new child 4277
Jul 10 00:56:53 zicominc2 proxwww[4293]: Starting new child 4293
Jul 10 00:57:19 zicominc2 proxwww[4293]: update ticket
Jul 10 00:58:01 zicominc2 /usr/sbin/cron[2764]: (*system*vzdump) RELOAD (/etc/cron.d/vzdump)
Jul 10 01:00:01 zicominc2 /USR/SBIN/CRON[4307]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:00:01 zicominc2 /USR/SBIN/CRON[4306]: (root) CMD (vzdump --quiet --snapshot --compress --storage nas --mailto xxxxx@xxxx.com --all)
Jul 10 01:00:01 zicominc2 /USR/SBIN/CRON[4308]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:00:01 zicominc2 /USR/SBIN/CRON[4309]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:00:01 zicominc2 vzdump[4306]: INFO: trying to get global lock - waiting...
Jul 10 01:05:01 zicominc2 /USR/SBIN/CRON[4340]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:05:01 zicominc2 /USR/SBIN/CRON[4341]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:10:01 zicominc2 /USR/SBIN/CRON[4368]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:10:01 zicominc2 /USR/SBIN/CRON[4369]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:10:01 zicominc2 /USR/SBIN/CRON[4370]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:15:01 zicominc2 /USR/SBIN/CRON[4395]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:15:01 zicominc2 /USR/SBIN/CRON[4396]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:17:01 zicominc2 /USR/SBIN/CRON[4416]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jul 10 01:20:01 zicominc2 /USR/SBIN/CRON[4428]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:20:01 zicominc2 /USR/SBIN/CRON[4429]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:20:01 zicominc2 /USR/SBIN/CRON[4430]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:25:01 zicominc2 /USR/SBIN/CRON[4462]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:25:01 zicominc2 /USR/SBIN/CRON[4463]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:30:01 zicominc2 /USR/SBIN/CRON[4491]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:30:01 zicominc2 /USR/SBIN/CRON[4492]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:30:01 zicominc2 /USR/SBIN/CRON[4493]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:35:01 zicominc2 /USR/SBIN/CRON[4535]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:35:01 zicominc2 /USR/SBIN/CRON[4536]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:40:01 zicominc2 /USR/SBIN/CRON[4566]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:40:01 zicominc2 /USR/SBIN/CRON[4567]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:40:01 zicominc2 /USR/SBIN/CRON[4568]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:45:01 zicominc2 /USR/SBIN/CRON[4599]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:45:01 zicominc2 /USR/SBIN/CRON[4600]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:45:54 zicominc2 ntpd[2646]: kernel time sync status change 4001
Jul 10 01:50:01 zicominc2 /USR/SBIN/CRON[4631]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:50:01 zicominc2 /USR/SBIN/CRON[4630]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 01:50:01 zicominc2 /USR/SBIN/CRON[4632]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
Jul 10 01:55:01 zicominc2 /USR/SBIN/CRON[4664]: (root) CMD (/usr/share/vzctl/scripts/vpsreboot)
Jul 10 01:55:01 zicominc2 /USR/SBIN/CRON[4665]: (root) CMD (/usr/share/vzctl/scripts/vpsnetclean)
Jul 10 02:00:01 zicominc2 /USR/SBIN/CRON[4694]: (root) CMD (test -x /usr/lib/atsar/atsa1 && /usr/lib/atsar/atsa1)
As far as the vzdump files, there is only files on the days that the backup was successful. Nothing in there that shows any of the dates that the backups did not work.

Do you see anything in the file above that I need to be concerned with or a reason why it may not be working? Oh and when it does not work, I do not get an email letting me know that the back up was successful.
 
Last edited by a moderator:
Code:
Jul 10 01:00:01 zicominc2 vzdump[4306]: INFO: trying to get global lock - waiting...
Seems there is another backup process running? (check with 'ps auxww')
 
Since I'm very new to proxmox, I am assuming that the pw is a command to run, which I did and here are the results.

Here is a pastbin copy to that results of that commands. http://pastebin.com/phHYGKBU

The thing is, that is what I believe is happening. For some reason the backup must be getting hung up or acts as if an instance is running, but it is not. Any more thoughts for me to try or look at?
 
Yes, there is files there...there are qemu-101.log, qemu-102.log, qemu-103.log and qemu-104.log. See below.

qemu-101.log
Code:
Jul 04 02:00:02 INFO: Starting Backup of VM 101 (qemu)
Jul 04 02:00:02 INFO: running
Jul 04 02:00:02 INFO: status = running
Jul 04 02:00:02 INFO: backup mode: snapshot
Jul 04 02:00:02 INFO: ionice priority: 7
Jul 04 02:00:04 INFO:   Logical volume "vzsnap-zicominc2-0" created
Jul 04 02:00:04 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-101-2011_07_04$
Jul 04 02:00:04 INFO: adding '/mnt/pve/nas/vzdump-qemu-101-2011_07_04-02_00_01.$
Jul 04 02:00:04 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk-1.raw' to arc$
Jul 04 03:27:39 INFO: Total bytes written: 66872787968 (12.14 MiB/s)
Jul 04 03:27:40 INFO: archive file size: 27.08GB
Jul 04 03:27:43 INFO: delete old backup '/mnt/pve/nas/vzdump-qemu-101-2011_07_0$
Jul 04 03:27:54 INFO:   Logical volume "vzsnap-zicominc2-0" successfully removed
Jul 04 03:27:54 INFO: Finished Backup of VM 101 (01:27:53)

102
Code:
Jul 04 03:27:55 INFO: Starting Backup of VM 102 (qemu)
Jul 04 03:27:55 INFO: running
Jul 04 03:27:55 INFO: status = running
Jul 04 03:27:55 INFO: backup mode: snapshot
Jul 04 03:27:55 INFO: ionice priority: 7
Jul 04 03:27:55 INFO:   Logical volume "vzsnap-zicominc2-0" created
Jul 04 03:27:56 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-102-2011_07_04$

103
Code:
Jul 03 04:57:51 INFO: Starting Backup of VM 103 (qemu)
Jul 03 04:57:51 INFO: running
Jul 03 04:57:51 INFO: status = running
Jul 03 04:57:52 INFO: backup mode: snapshot
Jul 03 04:57:52 INFO: ionice priority: 7
Jul 03 04:57:52 INFO:   Logical volume "vzsnap-zicominc2-0" created
Jul 03 04:57:52 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-103-2011_07_03$
Jul 03 04:57:52 INFO: adding '/mnt/pve/nas/vzdump-qemu-103-2011_07_03-04_57_51.$
Jul 03 04:57:52 INFO: adding '/mnt/vzsnap0/images/103/vm-103-disk-1.raw' to arc$
Jul 03 05:13:45 INFO: Total bytes written: 12035446272 (12.04 MiB/s)
Jul 03 05:13:48 INFO: archive file size: 5.17GB
Jul 03 05:13:48 INFO: delete old backup '/mnt/pve/nas/vzdump-qemu-103-2011_07_0$
Jul 03 05:13:54 INFO:   Logical volume "vzsnap-zicominc2-0" successfully removed
Jul 03 05:13:54 INFO: Finished Backup of VM 103 (00:16:03)

104
Code:
Jul 03 05:13:54 INFO: Starting Backup of VM 104 (qemu)
Jul 03 05:13:54 INFO: running
Jul 03 05:13:54 INFO: status = running
Jul 03 05:13:54 INFO: backup mode: snapshot
Jul 03 05:13:54 INFO: ionice priority: 7
Jul 03 05:13:54 INFO:   Logical volume "vzsnap-zicominc2-0" created
Jul 03 05:13:54 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-104-2011_07_03$
Jul 03 05:13:54 INFO: adding '/mnt/pve/nas/vzdump-qemu-104-2011_07_03-05_13_54.$
Jul 03 05:13:54 INFO: adding '/mnt/vzsnap0/images/104/vm-104-disk-1.raw' to arc$
Jul 03 05:27:00 INFO: Total bytes written: 9427966464 (11.44 MiB/s)
Jul 03 05:27:07 INFO: archive file size: 3.86GB
Jul 03 05:27:07 INFO: delete old backup '/mnt/pve/nas/vzdump-qemu-104-2011_07_0$
Jul 03 05:27:15 INFO:   Logical volume "vzsnap-zicominc2-0" successfully removed
Jul 03 05:27:15 INFO: Finished Backup of VM 104 (00:13:21)

I believe that July 4th was the last time the backup worked.

Does this show anything?
 
Job for VM 102 hangs - maby a problem with the nas? TRy to kill the backup process manually

# killall vzdump

and unlock the VM if necessarry

# qm unlock 102
 
I can definitely do this, but that is the VM that was hung up before when I had the same issue. So there must be something happening that is causing this.

What would you suggest to try and find the cause of this?

Thanks for all your help by the way!

Update..immediately after running the commands you gave me, I got an error report email. Please see below...

Code:
[TABLE]
[TR]
[TD]VMID[/TD]
[TD]NAME[/TD]
[TD]STATUS[/TD]
[TD]TIME[/TD]
[TD]SIZE[/TD]
[TD]FILENAME[/TD]
[/TR]
[TR]
[TD]101[/TD]
[TD]Zicom-Webs[/TD]
[TD]OK[/TD]
[TD]01:27:53[/TD]
[TD]27.08GB[/TD]
[TD]/mnt/pve/nas/vzdump-qemu-101-2011_07_04-02_00_01.tgz[/TD]
[/TR]
[TR]
[TD]102[/TD]
[TD]Zicom-Databases[/TD]
[TD]FAILED[/TD]
[TD]196:32:19[/TD]
[TD="colspan: 2"]interrupted by signal[/TD]
[/TR]
[TR]
[TD]103[/TD]
[TD]VM 103[/TD]
[TD]FAILED[/TD]
[TD]00:00:00[/TD]
[TD="colspan: 2"]aborted[/TD]
[/TR]
[TR]
[TD]104[/TD]
[TD]VM 104[/TD]
[TD]FAILED[/TD]
[TD]00:00:00[/TD]
[TD="colspan: 2"]aborted[/TD]
[/TR]
[TR]
[TD="colspan: 3"]TOTAL[/TD]
[TD]198:00:12[/TD]
[TD]27.08GB[/TD]
[TD][/TD]
[/TR]
[/TABLE]



Detailed backup logs:

 
vzdump --quiet --snapshot --compress --storage nas --mailto [EMAIL="danielc1234@gmail.com"]danielc1234@gmail.com[/EMAIL] --all
 
101: Jul 04 02:00:02 INFO: Starting Backup of VM 101 (qemu)
101: Jul 04 02:00:02 INFO: running
101: Jul 04 02:00:02 INFO: status = running
101: Jul 04 02:00:02 INFO: backup mode: snapshot
101: Jul 04 02:00:02 INFO: ionice priority: 7
101: Jul 04 02:00:04 INFO:   Logical volume "vzsnap-zicominc2-0" created
101: Jul 04 02:00:04 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-101-2011_07_04-02_00_01.tgz'
101: Jul 04 02:00:04 INFO: adding '/mnt/pve/nas/vzdump-qemu-101-2011_07_04-02_00_01.tmp/qemu-server.conf' to archive ('qemu-server.conf')
101: Jul 04 02:00:04 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk-1.raw' to archive ('vm-disk-ide0.raw')
101: Jul 04 03:27:39 INFO: Total bytes written: 66872787968 (12.14 MiB/s)
101: Jul 04 03:27:40 INFO: archive file size: 27.08GB
101: Jul 04 03:27:43 INFO: delete old backup '/mnt/pve/nas/vzdump-qemu-101-2011_07_03-02_00_02.tgz'
101: Jul 04 03:27:54 INFO:   Logical volume "vzsnap-zicominc2-0" successfully removed
101: Jul 04 03:27:54 INFO: Finished Backup of VM 101 (01:27:53)
 
102: Jul 04 03:27:55 INFO: Starting Backup of VM 102 (qemu)
102: Jul 04 03:27:55 INFO: running
102: Jul 04 03:27:55 INFO: status = running
102: Jul 04 03:27:55 INFO: backup mode: snapshot
102: Jul 04 03:27:55 INFO: ionice priority: 7
102: Jul 04 03:27:55 INFO:   Logical volume "vzsnap-zicominc2-0" created
102: Jul 04 03:27:56 INFO: creating archive '/mnt/pve/nas/vzdump-qemu-102-2011_07_04-03_27_54.tgz'
102: Jul 04 03:27:56 INFO: adding '/mnt/pve/nas/vzdump-qemu-102-2011_07_04-03_27_54.tmp/qemu-server.conf' to archive ('qemu-server.conf')
102: Jul 04 03:27:56 INFO: adding '/mnt/vzsnap0/images/102/vm-102-disk-1.raw' to archive ('vm-disk-ide0.raw')
102: Jul 12 08:00:12 INFO: umount: /mnt/vzsnap0: device is busy
102: Jul 12 08:00:12 INFO: umount: /mnt/vzsnap0: device is busy
102: Jul 12 08:00:12 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
102: Jul 12 08:00:13 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
102: Jul 12 08:00:13 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
102: Jul 12 08:00:13 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
102: Jul 12 08:00:13 ERROR: Backup of VM 102 failed - interrupted by signal
 
103: no log available
 
104: no log available
 
Last edited:
So you feel it has nothing to do with Proxmox and just the storage? I was wondering why this would be happening and on the same VM's backup. This has already happened like 2 -3 times so far.
I can try another backup, I was just hoping to get to the bottom of the issue so we could fix it.

Thanks!
 
I can try another backup, I was just hoping to get to the bottom of the issue so we could fix it.

You need to track down the issue until you find the reason. I can only fix things if you find a reliable way to reproduce the behavior.
 
I got another failed attempt from last nights backup. I've copied the report, just in case you can see anything happening. The nas we are backing up to has plenty of room and is working fine.

Code:
[TABLE]
[TR]
[TD]VMID
[/TD]
[TD]NAME
[/TD]
[TD]STATUS
[/TD]
[TD]TIME
[/TD]
[TD]SIZE
[/TD]
[TD]FILENAME
[/TD]
[/TR]
[TR]
[TD]101
[/TD]
[TD]Zicom-Webs
[/TD]
[TD]FAILED
[/TD]
[TD]00:00:01
[/TD]
[TD="colspan: 2"]command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
[/TD]
[/TR]
[TR]
[TD]102
[/TD]
[TD]Zicom-Databases
[/TD]
[TD]FAILED
[/TD]
[TD]00:00:01
[/TD]
[TD="colspan: 2"]command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
[/TD]
[/TR]
[TR]
[TD]103
[/TD]
[TD]webserver2
[/TD]
[TD]FAILED
[/TD]
[TD]00:00:00
[/TD]
[TD="colspan: 2"]command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
[/TD]
[/TR]
[TR]
[TD]104
[/TD]
[TD]mail
[/TD]
[TD]FAILED
[/TD]
[TD]00:00:01
[/TD]
[TD="colspan: 2"]command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
[/TD]
[/TR]
[TR]
[TD="colspan: 3"]TOTAL
[/TD]
[TD]00:00:03
[/TD]
[TD]0KB
[/TD]
[TD][/TD]
[/TR]
[/TABLE]


Detailed backup logs:

 
vzdump --quiet --snapshot --compress --storage nas --mailto [EMAIL="danielc1234@gmail.com"]myemail@gmail.com[/EMAIL] --all
 
101: Jul 13 01:00:02 INFO: Starting Backup of VM 101 (qemu)
101: Jul 13 01:00:02 INFO: running
101: Jul 13 01:00:02 INFO: status = running
101: Jul 13 01:00:03 INFO: backup mode: snapshot
101: Jul 13 01:00:03 INFO: ionice priority: 7
101: Jul 13 01:00:03 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-zicominc2-0'
101: Jul 13 01:00:03 INFO: umount: /mnt/vzsnap0: device is busy
101: Jul 13 01:00:03 INFO: umount: /mnt/vzsnap0: device is busy
101: Jul 13 01:00:03 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
101: Jul 13 01:00:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 13 01:00:03 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
101: Jul 13 01:00:03 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
101: Jul 13 01:00:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 13 01:00:03 INFO:   Logical volume "vzsnap-zicominc2-0" already exists in volume group "pve"
101: Jul 13 01:00:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 13 01:00:03 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
101: Jul 13 01:00:03 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
101: Jul 13 01:00:03 ERROR: Backup of VM 101 failed - command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
 
102: Jul 13 01:00:03 INFO: Starting Backup of VM 102 (qemu)
102: Jul 13 01:00:03 INFO: running
102: Jul 13 01:00:03 INFO: status = running
102: Jul 13 01:00:03 INFO: backup mode: snapshot
102: Jul 13 01:00:03 INFO: ionice priority: 7
102: Jul 13 01:00:03 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-zicominc2-0'
102: Jul 13 01:00:03 INFO: umount: /mnt/vzsnap0: device is busy
102: Jul 13 01:00:03 INFO: umount: /mnt/vzsnap0: device is busy
102: Jul 13 01:00:03 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
102: Jul 13 01:00:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
102: Jul 13 01:00:03 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
102: Jul 13 01:00:03 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
102: Jul 13 01:00:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
102: Jul 13 01:00:03 INFO:   Logical volume "vzsnap-zicominc2-0" already exists in volume group "pve"
102: Jul 13 01:00:04 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
102: Jul 13 01:00:04 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
102: Jul 13 01:00:04 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
102: Jul 13 01:00:04 ERROR: Backup of VM 102 failed - command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
 
103: Jul 13 01:00:04 INFO: Starting Backup of VM 103 (qemu)
103: Jul 13 01:00:04 INFO: running
103: Jul 13 01:00:04 INFO: status = running
103: Jul 13 01:00:04 INFO: backup mode: snapshot
103: Jul 13 01:00:04 INFO: ionice priority: 7
103: Jul 13 01:00:04 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-zicominc2-0'
103: Jul 13 01:00:04 INFO: umount: /mnt/vzsnap0: device is busy
103: Jul 13 01:00:04 INFO: umount: /mnt/vzsnap0: device is busy
103: Jul 13 01:00:04 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
103: Jul 13 01:00:04 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
103: Jul 13 01:00:04 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
103: Jul 13 01:00:04 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
103: Jul 13 01:00:04 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
103: Jul 13 01:00:04 INFO:   Logical volume "vzsnap-zicominc2-0" already exists in volume group "pve"
103: Jul 13 01:00:04 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
103: Jul 13 01:00:04 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
103: Jul 13 01:00:04 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
103: Jul 13 01:00:04 ERROR: Backup of VM 103 failed - command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
 
104: Jul 13 01:00:04 INFO: Starting Backup of VM 104 (qemu)
104: Jul 13 01:00:04 INFO: running
104: Jul 13 01:00:04 INFO: status = running
104: Jul 13 01:00:05 INFO: backup mode: snapshot
104: Jul 13 01:00:05 INFO: ionice priority: 7
104: Jul 13 01:00:05 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-zicominc2-0'
104: Jul 13 01:00:05 INFO: umount: /mnt/vzsnap0: device is busy
104: Jul 13 01:00:05 INFO: umount: /mnt/vzsnap0: device is busy
104: Jul 13 01:00:05 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
104: Jul 13 01:00:05 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
104: Jul 13 01:00:05 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
104: Jul 13 01:00:05 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
104: Jul 13 01:00:05 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
104: Jul 13 01:00:05 INFO:   Logical volume "vzsnap-zicominc2-0" already exists in volume group "pve"
104: Jul 13 01:00:05 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
104: Jul 13 01:00:05 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
104: Jul 13 01:00:05 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5
104: Jul 13 01:00:05 ERROR: Backup of VM 104 failed - command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5
 
Well, an 'Input/output error' usually indicate a problem with the storage/network. Are you able to remove that snapshot manually:

# lvremove /dev/pve/vzsnap-zicominc2-0
 
Got an error with that command.

Code:
 lvremove /dev/pve/vzsnap-zicominc2-0
  /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
  Can't remove open logical volume "vzsnap-zicominc2-0"
Anything else I should try?
 
Hence this post. :)

Initially from any other machine accessing the NAS, there is a user name and password. When setting up the backup, it didn't ask for this information. I wonder if that is causing the backup to fail?
Is there a way to see the nas during the setup or creation of the backup? The strange thing is, this did work for a while.
 
Initially from any other machine accessing the NAS, there is a user name and password. When setting up the backup, it didn't ask for this information. I wonder if that is causing the backup to fail?

I do not know you NAS setup. But pve does not support name/password auth by default.
 
On the other side, you created a VM on that storage, so it was at least accessible by that time.
 
I tried to setup a new backup with just one VM and got the following error. It seems as if there is something in the system left behind that the backup process doesnt like. Can you tell me how to force remove what it trying to do? Maybe there is an old failed backup that will not allow this to work. When I created the new backup, I was able to get and see the NAS fine, so I dont think that is the problem.


Code:
101: Jul 16 08:55:02 INFO: Starting Backup of VM 101 (qemu)
101: Jul 16 08:55:02 INFO: running
101: Jul 16 08:55:02 INFO: status = running
101: Jul 16 08:55:02 INFO: backup mode: snapshot
101: Jul 16 08:55:02 INFO: ionice priority: 7
101: Jul 16 08:55:02 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-zicominc2-0'
101: Jul 16 08:55:02 INFO: umount: /mnt/vzsnap0: device is busy
101: Jul 16 08:55:02 INFO: umount: /mnt/vzsnap0: device is busy
101: [COLOR=red]Jul 16 08:55:02 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1[/COLOR]
101: Jul 16 08:55:02 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 16 08:55:02 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
101: [COLOR=red]Jul 16 08:55:02 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5[/COLOR]
101: Jul 16 08:55:02 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 16 08:55:02 INFO:   Logical volume "vzsnap-zicominc2-0" already exists in volume group "pve"
101: Jul 16 08:55:03 INFO:   /dev/dm-2: read failed after 0 of 4096 at 0: Input/output error
101: Jul 16 08:55:03 INFO:   Can't remove open logical volume "vzsnap-zicominc2-0"
101: [COLOR=red]Jul 16 08:55:03 ERROR: command 'lvremove -f '/dev/pve/vzsnap-zicominc2-0'' failed with exit code 5[/COLOR]
101: [COLOR=red]Jul 16 08:55:03 ERROR: Backup of VM 101 failed - command 'lvcreate --size 1024M --snapshot --name 'vzsnap-zicominc2-0' '/dev/pve/data'' failed with exit code 5[/COLOR]
 

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!