iscsi lxc restore vzdump issue.

[RobFantini]

I ran in to this issue with a new iscsi set up.
could be something wrong done in both set ups or a bug to be fixed..


Hello.
I'm testing iscsi running on nappit/omnios . the system is working good however I may have set up lvm on iscsi incorrectly.

  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
WARNING: ext4 signature detected on /dev/iscsi-lxc-vg/vm-3102-disk-1 at offset 1080. Wipe it? [y/n]: n  <<<

  Aborted wiping of ext4.
  Logical volume "vm-3102-disk-1" created.
  1 existing signature left on the device.
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
mke2fs 1.42.12 (29-Aug-2014)
Discarding device blocks:  4096/52428  ...... done
Creating filesystem with 524288 4k blocks and 131072 inodes
Filesystem UUID: 6f7d5cb0-eac8-4bc1-a07a-2a1e9eae98ea
Superblock backups stored on blocks:
   32768, 98304, 163840, 229376, 294912

Allocating group tables:  0/16  done
Writing inode tables:  0/16  done
Creating journal (16384 blocks): done
Multiple mount protection is enabled with update interval 5 seconds.
Writing superblocks and filesystem accounting information:  0/16  done

  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
extracting archive '/bkup/dump/vzdump-lxc-3101-2016_04_10-21_05_06.tar.lzo'
...
tar: ./fbc/fbc-reports/Friday/proxmox-virtual-machines-listing.txt: Cannot open
tar: ./fbc/fbc-reports/Friday: Cannot mkdir: No space left on device
tar: ./fbc/fbc-reports/Friday/system-reports: Cannot mkdir: No such file or directory
tar: ./fbc/fbc-reports/Friday: Cannot mkdir: No space left on device
ar: ./usr/lib/python2.7/dist-packages/Crypto/Random/OSRNG/rng_base.py: Cannot create symlink to '../../../../../../share/pyshared/Crypto/Random/OSRNG/rng_base.py': No space left on device
tar: ./usr/lib/python2.7/dist-packages/Crypto/Protocol/AllOrNothing.py: Cannot create symlink to '../../../../../share/pyshared/Crypto/Protocol/AllOrNothing.py': No space left on device
Total bytes read: 2331781120 (2.2GiB, 94MiB/s)
tar: Exiting with failure status due to previous errors
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Logical volume "vm-3102-disk-1" successfully removed
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
TASK ERROR: command 'tar xpf /bkup/dump/vzdump-lxc-3101-2016_04_10-21_05_06.tar.lzo --totals --sparse --numeric-owner --acls --xattrs '--xattrs-include=user.*' '--xattrs-include=security.capability' '--warning=no-xattr-write' -C /var/lib/lxc/3102/rootfs --skip-old-files --anchored --exclude './dev/*'' failed: exit code

this is part of storage.cfg :

zfs: iscsi-sys4
  target iqn.2010-09.org.napp-it:1459891666
  iscsiprovider comstar
  blocksize 8k
  portal 10.2.2.41
  pool data
  content images
  nowritecache

iscsi: sys4-lvmvol
  target iqn.2010-09.org.napp-it:1459891666
  portal 10.2.2.41
  content none

lvm: iscsi-lvm-for-lxc
  vgname iscsi-lxc-vg
  base sys4-lvmvol:0.0.0.scsi-3600144f000000808000057056d6d0001
  content rootdir
  shared

storage for kvm's work OK.

for LXC I attempted to set up lvm backing , and have a couple of lxc systems set up and working.

1/2 of the 300GB is in use .

any suggestions to try to get this fixed?

I can post some more detailed debugging logs/info is needed.

 

[RobFantini]

this may have something to do with the issue.

sys5  ~ # lvs
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  LV  VG  Attr  LSize  Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert
  vm-3993-disk-1 iscsi-lxc-vg -wi-ao----  6.00g   
  vm-7350-disk-1 iscsi-lxc-vg -wi-ao----  4.00g   
  vm-9555-disk-1 iscsi-lxc-vg -wi-ao---- 112.00g   
  vm-9977-disk-1 iscsi-lxc-vg -wi-------  16.01g

vm-disk 9977 is for a uncompleted vzdump restore April 8-th:

ls -l /etc/pve/nodes/sys5/qemu-server/9977.conf.14151.tmp
-rw-r----- 1 root www-data 990 Apr  8 11:02 /etc/pve/nodes/sys5/qemu-server/9977.conf.14151.tmp

ls -l /var/log/pve/tasks/E/UPID:sys5:00003747:0409FDC5:5707C80E:qmrestore:9977:root@pam:
-rw-r----- 1 www-data root 3718 Apr  8 11:03 /var/log/pve/tasks/E/UPID:sys5:00003747:0409FDC5:5707C80E:qmrestore:9977:root\@pam:

# from /var/log/pve/tasks/E/UPID:sys5:00003747:0409FDC5:5707C80E:qmrestore:9977:root\@pam:
restore vma archive: lzop -d -c /bkup/dump-save/dump/vzdump-qemu-111-2016_04_08-10_51_21.vma.lzo|vma extract -v -r /var/tmp/vzdumptmp14151.fifo - /var/tmp/vzdumptmp14151
CFG: size: 1023 name: qemu-server.conf
DEV: dev_id=1 size: 17188257792 devname: drive-virtio0
CTIME: Fri Apr  8 10:51:22 2016
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Logical volume "vm-9977-disk-1" created.
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
new volume ID is 'iscsi-lvm-for-lxc:vm-9977-disk-1'
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
map 'drive-virtio0' to '/dev/iscsi-lxc-vg/vm-9977-disk-1' (write zeros = 1)
WARNING: Image format was not specified for '/dev/iscsi-lxc-vg/vm-9977-disk-1' and probing guessed raw.
  Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted.
  Specify the 'raw' format explicitly to remove the restrictions.
progress 1% (read 171900928 bytes, duration 0 sec)
progress 2% (read 343801856 bytes, duration 1 sec)
..
progress 43% (read 7390953472 bytes, duration 70 sec)
progress 44% (read 7562854400 bytes, duration 72 sec)
progress 45% (read 7734755328 bytes, duration 75 sec)
progress 46% (read 7906656256 bytes, duration 77 sec)

# log stops there.

as far as I remember I canceled the restore as the iscsi system was running slow at the time.

The leftover 9977 lvm disk and config would be good to eliminate. which may or not fix the lvm warnings and vzdump restore issue.

I am far from an expert on lvm, and could use advice on how to safely remove 9977 files.

 

[RobFantini]

I think this will fix part of the issue, changing lvm.conf to this:

# 2016-04-11   trying to deal with an iscsi lvm issue
#  filter = [ "r|/dev/zd*|"  ]
  filter = [ "a|/dev/dm-*|", "a|/dev/sda[0-9]|", "a|/dev/sdb[0-9]|", "a|/dev/sdc[0-9]|", "r|.*|" ]

If doing that is a bad idea please respond

idea came from
https://www.mail-archive.com/open-iscsi@googlegroups.com/msg04604.html
https://www.mail-archive.com/open-iscsi@googlegroups.com/msg04611.html

 

[RobFantini]

i changed back to the original lvm.conf after getting this error when trying to restore a backup: TASK ERROR: no such volume group 'iscsi-lxc-vg'

 

[RobFantini]

Question : when using lvm over iscsi should /etc/lvm/lvm.conf be adjusted?

 

[RobFantini]

I set up new iscsi storage for lxc and after restoring 10-12 lxc backups ran in to the same issue - restoring a backup fails :

Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV 4j27OuDdsJlyaiZkXR1yrcEvsAFY1bN7: using /dev/sdm5 not /dev/sdl5
Found duplicate PV bCwewzHSzYTHJOSN2pCpfp6IjrOJRo4D: using /dev/sdp not /dev/sdq
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV 4j27OuDdsJlyaiZkXR1yrcEvsAFY1bN7: using /dev/sdm5 not /dev/sdl5
Found duplicate PV bCwewzHSzYTHJOSN2pCpfp6IjrOJRo4D: using /dev/sdp not /dev/sdq
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV 4j27OuDdsJlyaiZkXR1yrcEvsAFY1bN7: using /dev/sdm5 not /dev/sdl5
Found duplicate PV bCwewzHSzYTHJOSN2pCpfp6IjrOJRo4D: using /dev/sdp not /dev/sdq
Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
Found duplicate PV 4j27OuDdsJlyaiZkXR1yrcEvsAFY1bN7: using /dev/sdm5 not /dev/sdl5
Found duplicate PV bCwewzHSzYTHJOSN2pCpfp6IjrOJRo4D: using /dev/sdp not /dev/sdq
WARNING: ext4 signature detected on /dev/lxc-iscsi-vg/vm-3102-disk-1 at offset 1080. Wipe it? [y/n]: n
Aborted wiping of ext4.
Logical volume "vm-3102-disk-1" created.
1 existing signature left on the device.
...
ar: ./usr/lib/python2.6/dist-packages/python_dateutil-1.5.egg-info/not-zip-safe: Cannot create symlink to '../../../../share/pyshared/python_dateutil-1.5.egg-info/not-zip-safe': No space left on device
tar: ./usr/lib/python2.6/dist-packages/python_dateutil-1.5.egg-info/SOURCES.txt: Cannot create symlink to '../../../../share/pyshared/python_dateutil-1.5.egg-info/SOURCES.txt': No space left on device
Total bytes read: 2275952640 (2.2GiB, 81MiB/s)
tar: Exiting with failure status due to previous errors

the above was restoring to iscsi storage.

i was able to restore to local zfs storage.

I think there is a lvm issue to fix in our iscsi set up.

pvs:

# pvs
  Found duplicate PV JxUvGzKqhYA6XZAacc4KrBYNcTq2DgDN: using /dev/sdk not /dev/sdj
  Found duplicate PV 4j27OuDdsJlyaiZkXR1yrcEvsAFY1bN7: using /dev/sdm5 not /dev/sdl5
  Found duplicate PV bCwewzHSzYTHJOSN2pCpfp6IjrOJRo4D: using /dev/sdp not /dev/sdq
  PV  VG  Fmt  Attr PSize  PFree 
  /dev/sdk  iscsi-lxc-vg lvm2 a--  300.00g 283.99g
  /dev/sdm5  turnkey  lvm2 a--  6.76g 696.00m
  /dev/sdp  lxc-iscsi-vg lvm2 a--  750.00g 622.00g
[code]

any clues to fix 'Found duplicate PV' ?      I assume that may have something to do with failed restore.

 

[omgs]

Hi.

The duplicate PV is because the volumes are mirrored, so it's not an issue to worry about.

I came here because in a new installation using proxmox 4.4-12/e71b7a74, restoring via UI fails with permission errors (I'd say for *ALL* files from the very beginning). However, "pct restore" from the command line works ok. The difference is the background issued command. At this time, I'm testing "UI behaviours" to find out how far one can get using just the UI without accessing via shell, and that's one that I've found, and I've found this. This is a excerpt of the (very long) log:

...
extracting archive '/var/lib/vz/vzdump/dump/vzdump-lxc-102-2017_02_24-00_23_40.tar.lzo'
tar: ./var/tmp: Cannot mkdir: Permission denied
tar: ./var/local: Cannot mkdir: Permission denied
tar: ./var/lib/aptitude: Cannot mkdir: Permission denied
tar: ./var/lib/mlocate: Cannot mkdir: Permission denied

(lots of this very same error)

and finally:

....
tar: ./var/lock: Cannot open: Permission denied
Total bytes read: 681881600 (651MiB, 359MiB/s)
tar: Exiting with failure status due to previous errors
TASK ERROR: command 'lxc-usernsexec -m u:0:100000:65536 -m g:0:100000:65536 -- tar xpf /var/lib/vz/vzdump/dump/vzdump-lxc-102-2017_02_24-00_23_40.tar.lzo --totals --sparse --numeric-owner --acls --xattrs '--xattrs-include=user.*' '--xattrs-include=security.capability' '--warning=no-xattr-write' -C /var/lib/lxc/102/rootfs --skip-old-files --anchored --exclude './dev/*'' failed: exit code 2


I've tried this with a .tar.gz and the result is the same, so I wonder if there's something else that could be done from the UI to restore a backup. I *think* that in previous releases this used to work, but I can't recall I have done anything different, so there must be some regression. Please provide some light about this.


Regards.