Proxmox 1.4beta2: Backup from iscsi storage didn´t finish....

valshare

Renowned Member
Jun 2, 2009
257
2
83
Germany
Hello,

i have a probleme to backup a VM from a iscsi storage. The Backup didn´t finished and is running from Oct 10 23:27 till now.

Code:
Oct 10 23:27:52 INFO: Starting Backup of VM 112 (qemu)
Oct 10 23:27:52 INFO: running
Oct 10 23:27:52 INFO: status = running
Oct 10 23:27:53 INFO: backup mode: snapshot
Oct 10 23:27:53 INFO: bandwidth limit: 10240 KB/s
Oct 10 23:27:54 INFO:   Logical volume "vzsnap-proxmox01-0" created
Oct 10 23:27:54 INFO: creating archive '/backup1/vzdump-qemu-112.tgz'

Code:
root     17228  0.0  0.0   8836  1136 ?        S    Oct10   0:00 sh -c /usr/lib/qemu-server/vmtar '/backup1/vzdump-qemu-112.tmp/qemu-server.conf' 'qemu-server.conf' '/dev/pve-kvm/vzsnap-proxmox01-0' 'vm-disk-ide0.raw' |gzip |cstream -t 10485760 >/backup1/vzdump-qemu-112.dat
root     17229 99.7  0.0   3964   796 ?        R    Oct10 1977:37 /usr/lib/qemu-server/vmtar /backup1/vzdump-qemu-112.tmp/qemu-server.conf qemu-server.conf /dev/pve-kvm/vzsnap-proxmox01-0 vm-disk-ide0.raw

Regards, Valle
 
Last edited:
Any hints in syslog? The iscsi storage is up and running? How large is the device you want to backup?
 
Hi Dietmar,

no it didn´t grow. Device is running and working without any issue. The Device is 8GB. No hints in syslog found.

Regards, Valle
 
Ok, then simply kill those backup process. Then try again to see if the bug is reproducable. If so, is it possible to get a copy of that VM disk?
 
ok, have killed the tasks and startet the backup again. now it grows.

I have checked the syslog again and found something at later time at the backup starts

Code:
Oct 10 23:32:14 proxmox01 kernel: connection1:0: iscsi: detected conn error (1011)
Oct 10 23:32:15 proxmox01 iscsid: Kernel reported iSCSI connection 1:0 error (1011) state (3)
Oct 10 23:32:18 proxmox01 kernel: iscsi: host reset succeeded
Oct 10 23:32:18 proxmox01 iscsid: connection1:0 is operational after recovery (1 attempts)
Oct 10 23:32:28 proxmox01 kernel: sd 3:0:0:0: [sdb] Result: hostbyte=DID_BUS_BUSY driverbyte=DRIVER_OK,SUGGEST_OK
Oct 10 23:32:28 proxmox01 kernel: end_request: I/O error, dev sdb, sector 19616032
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353764
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353765
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353766
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353767
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353768
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353769
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353770
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353771
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353772
Oct 10 23:32:28 proxmox01 kernel: Buffer I/O error on device dm-7, logical block 353773
Oct 10 23:32:28 proxmox01 kernel: sd 3:0:0:0: [sdb] Result: hostbyte=DID_BUS_BUSY driverbyte=DRIVER_OK,SUGGEST_OK
Oct 10 23:32:28 proxmox01 kernel: end_request: I/O error, dev sdb, sector 19615768

Looks, something didnt work correct with the iscsi device. Will check the harddrives. The iscsi device didn´t give an alarm over snmp

Regards, Valle
 
Last edited:
ok, second backup runs finde now.

Code:
Oct 12 11:21:01 INFO: Starting Backup of VM 112 (qemu)
Oct 12 11:21:01 INFO: running
Oct 12 11:21:01 INFO: status = running
Oct 12 11:21:02 INFO: backup mode: snapshot
Oct 12 11:21:02 INFO: bandwidth limit: 10240 KB/s
Oct 12 11:21:02 INFO:   Logical volume "vzsnap-proxmox01-0" created
Oct 12 11:21:02 INFO: creating archive '/backup1/vzdump-qemu-112.tgz'
Oct 12 11:21:02 INFO: adding '/backup1/vzdump-qemu-112.tmp/qemu-server.conf' to archive ('qemu-server.conf')
Oct 12 11:21:02 INFO: adding '/dev/pve-kvm/vzsnap-proxmox01-0' to archive ('vm-disk-ide0.raw')
Oct 12 11:31:13 INFO: Total bytes written: 8273095680 (12.91 MiB/s)
Oct 12 11:31:13 INFO: archive file size: 3.02GB
Oct 12 11:31:14 INFO:   Logical volume "vzsnap-proxmox01-0" successfully removed
Oct 12 11:31:14 INFO: Finished Backup of VM 112 (00:10:13)


What i have found on the iscsi device is, that proxmox server permanent lout out and login again and again. Is this correct?

Code:
INFO:Mon, 12 Oct 2009 11:31:17 CEST
admin login from 192.168.1.94 via Web UIINFO:Mon, 12 Oct 2009 11:15:17 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:52509) succeeds.INFO:Mon, 12 Oct 2009 11:15:15 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41621) was received, reason [close the connection].INFO:Mon, 12 Oct 2009 11:14:35 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41621) succeeds.INFO:Mon, 12 Oct 2009 11:14:32 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41562) was received, reason [close the connection].INFO:Mon, 12 Oct 2009 11:13:52 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41562) succeeds.INFO:Mon, 12 Oct 2009 11:13:49 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41508) was received, reason [close the connection].INFO:Mon, 12 Oct 2009 11:13:09 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41508) succeeds.INFO:Mon, 12 Oct 2009 11:13:06 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41455) was received, reason [close the connection].INFO:Mon, 12 Oct 2009 11:12:26 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41455) succeeds.INFO:Mon, 12 Oct 2009 11:12:23 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41395) was received, reason [close the connection].INFO:Mon, 12 Oct 2009 11:11:43 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:41395) succeeds.INFO:Mon, 12 Oct 2009 11:11:40 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54594) was received, reason [close the connection].INFO:Sat, 10 Oct 2009 23:32:12 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54594) succeeds.INFO:Sat, 10 Oct 2009 23:32:09 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54588) was received, reason [close the connection].INFO:Sat, 10 Oct 2009 23:31:29 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54588) succeeds.INFO:Sat, 10 Oct 2009 23:31:26 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54582) was received, reason [close the connection].INFO:Sat, 10 Oct 2009 23:30:46 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:54582) succeeds.INFO:Sat, 10 Oct 2009 23:30:43 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:42753) was received, reason [close the connection].INFO:Sat, 10 Oct 2009 23:30:03 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:42753) succeeds.INFO:Sat, 10 Oct 2009 23:30:00 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:42750) was received, reason [close the connection].INFO:Sat, 10 Oct 2009 23:29:20 CEST
iSCSI login from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:42750) succeeds.INFO:Sat, 10 Oct 2009 23:29:17 CEST
iSCSI logout from iqn.2009-10.org.proxmox01:01:e3ebcab4716 (192.168.1.2:42745) was received, reason [close the connection].
 
no storage are disabled but the storage "KVM-DATA-02" is unused because the VM is stopped that use the KVM-DATA-02


Code:
cat /etc/pve/storage.cfg
 
iscsi: i4500.eth1
        portal 192.168.1.95
        target iqn.2004-10.com.thecus:iseries-000a40e50:default-target
        content none
lvm: KVM-DATA-01
        vgname pve-kvm
        base i4500.eth1:0.0.0.scsi-3202b001378a40e50
        shared
        content images
lvm: KVM-DATA-02
        vgname test
        base i4500.eth1:0.0.1.scsi-3202d001378a40e50
        shared
        content images
 
We do not issue 'logout' then. Where do you get thos logs - i assume on the iscsi storage (what vendor)? How frequent are they (logs contain no time)?
 
log out/in time stand at the end of the logfile. The log is from the iscsi storage.

Ah, I see it now. There are several hours between the logs - does it relate to some actions you have done on the PVE admin interface?
 
I guess that is related to the IO errors you got:

Code:
Oct 10 23:32:18 proxmox01 kernel: iscsi: host reset succeeded
 
ok, found the problem.

If i make a backup

vzdump --snapshot --compress --dumpdir /var/lib/vz/dump/ 112

Where dumpdir lies on the local hdd in an lvm

When i make

vzdump --snapshot --compress --dumpdir /backup/ 112

Where dumpdir here is on the local proxmox HDD, the backup never finished and it comes to the errors that i have posted.

Cant i make backups on local hdd or is it a bug in vzdump?

Regards, Valle
 
Last edited:
vzdump --snapshot --compress --dumpdir /backup/ 112

Where dumpdir here is on the local proxmox HDD, the backup never finished and it comes to the errors that i have posted.

Cant i make backups on local hdd or is it a bug in vzdump?

Well, so you get iSCSI error when you write to the iSCSI storage - I would ask the storage vendor if that is a known issue.