Re: [Users] Fibre channel - LVM problems
O
n 07/30/2013 06:14 PM, Łukasz Faber wrote:
On Mon, 2013-07-29 at 10:13 -0400, Ayal Baron wrote:
I have found a similar issue here:
https://www.redhat.com/archives/lvm-devel/2011-February/msg00127.html
After discussing this with Peter Rajnoha, it looks like the specific issue
in the above thread has been resolved and your issue is probably a
reincarnation of the problem. Can you manually run the pvchange with
- to get more info?
Thanks.
I'm attaching logs from manual executions of both pvcreate and pvchange.
So, looking at the logs, it looks like lvmetad might be the culprit here.
Is it reproducible if you use global/use_lvmetad=0 in /etc/lvm/lvm.conf?
No. When I set use_lvmetad to 0 everything seems to work correctly with
pvchange:
Physical volume /dev/mapper/3600a0b800074a36e06e951f14e7d changed
1 physical volume changed / 0 physical volumes not changed
Log for pvchange attached.
Thanks for your help!
Best regards,
Lukasz
WARNING: lvmetad is running but disabled. Restart lvmetad before enabling it!
WARNING: lvmetad is running but disabled. Restart lvmetad before enabling it!
#libdm-config.c:863 Setting activation/monitoring to 1
#lvmcmdline.c:1091 Processing: pvchange --config ' devices { preferred_names = [^/dev/mapper/] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ a%3600a0b800074a36e06e951f14e7d%, r%.*% ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } ' --metadataignore n /dev/mapper/3600a0b800074a36e06e951f14e7d -
#lvmcmdline.c:1094 O_DIRECT will be used
#libdm-config.c:799 Setting global/locking_type to 1
#libdm-config.c:799 Setting global/wait_for_locks to 1
#locking/locking.c:242 File-based locking selected.
#libdm-config.c:768 Setting global/locking_dir to /run/lock/lvm
#libdm-config.c:863 Setting global/prioritise_write_locks to 1
#libdm-common.c:872 Preparing SELinux context for /run/lock/lvm to system_u:object_r:lvm_lock_t:s0.
#libdm-common.c:875 Resetting SELinux context to default value.
#pvchange.c:209 Using physical volume(s) on command line
#device/dev-cache.c:332 /dev/mapper/3600a0b800074a36e06e951f14e7d: Added to device cache
#ioctl/libdm-iface.c:1724 dm version OF [16384] (*1)
#ioctl/libdm-iface.c:1724 dm status (253:2) OF [16384] (*1)
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:137 /dev/mapper/3600a0b800074a36e06e951f14e7d: block size is 4096 bytes
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#filters/filter-composite.c:31 Using /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:137 /dev/mapper/3600a0b800074a36e06e951f14e7d: block size is 4096 bytes
#label/label.c:156 /dev/mapper/3600a0b800074a36e06e951f14e7d: lvm2 label detected at sector 1
#cache/lvmcache.c:1336 lvmcache: /dev/mapper/3600a0b800074a36e06e951f14e7d: now in VG #orphans_lvm2 (#orphans_lvm2) with 0 mdas
#metadata/metadata.c:4468 Setting ignored flag for mda /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 4096.
#format_text/text_label.c:299 Ignoring mda on device /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 4096
#metadata/metadata.c:4468 Setting ignored flag for mda /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 107239964672.
#format_text/text_label.c:299 Ignoring mda on device /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 107239964672
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#label/label.c:266 Using cached label for /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-cache.c:332 /dev/sr0: Added to device cache
#device/dev-cache.c:329 /dev/cdrom: Aliased to /dev/sr0 in device cache (preferred name)
#device/dev-cache.c:329 /dev/disk/by-id/ata-MATSHITACD-RW_CW-8124: Aliased to /dev/cdrom in device cache
#device/dev-cache.c:332 /dev/sdb: Added to device cache
#device/dev-cache.c:329 /dev/disk/by-id/scsi-3600508e004ee02697aa1710f: Aliased to /dev/sdb in device cache
#device/dev-cache.c:329 /dev/disk/by-id/wwn-0x600508e004ee02697aa1710f: Aliased to /dev/sdb in device cache
#device/dev-cache.c:329 /dev/disk/by-path
Re: [Users] Fibre channel - LVM problems
Hi Ayal,
On Mon, 2013-07-29 at 10:13 -0400, Ayal Baron wrote:
I have found a similar issue here:
https://www.redhat.com/archives/lvm-devel/2011-February/msg00127.html
After discussing this with Peter Rajnoha, it looks like the specific issue in
the above thread has been resolved and your issue is probably a reincarnation
of the problem. Can you manually run the pvchange with - to get more
info?
Thanks.
I'm attaching logs from manual executions of both pvcreate and pvchange.
Regards,
Lukasz
#libdm-config.c:863 Setting activation/monitoring to 1
#lvmcmdline.c:1091 Processing: pvchange --config ' devices { preferred_names = [^/dev/mapper/] ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3 filter = [ a%3600a0b800074a36e06e951f14e7d%, r%.*% ] } global { locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50 retain_days = 0 } ' --metadataignore n /dev/mapper/3600a0b800074a36e06e951f14e7d -
#lvmcmdline.c:1094 O_DIRECT will be used
#libdm-config.c:799 Setting global/locking_type to 1
#libdm-config.c:799 Setting global/wait_for_locks to 1
#locking/locking.c:242 File-based locking selected.
#libdm-config.c:768 Setting global/locking_dir to /run/lock/lvm
#libdm-config.c:863 Setting global/prioritise_write_locks to 1
#libdm-common.c:872 Preparing SELinux context for /run/lock/lvm to system_u:object_r:lvm_lock_t:s0.
#libdm-common.c:875 Resetting SELinux context to default value.
#pvchange.c:209 Using physical volume(s) on command line
#device/dev-cache.c:332 /dev/mapper/3600a0b800074a36e06e951f14e7d: Added to device cache
#ioctl/libdm-iface.c:1724 dm version OF [16384] (*1)
#ioctl/libdm-iface.c:1724 dm status (253:2) OF [16384] (*1)
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:137 /dev/mapper/3600a0b800074a36e06e951f14e7d: block size is 4096 bytes
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#filters/filter-composite.c:31 Using /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:137 /dev/mapper/3600a0b800074a36e06e951f14e7d: block size is 4096 bytes
#label/label.c:156 /dev/mapper/3600a0b800074a36e06e951f14e7d: lvm2 label detected at sector 1
#cache/lvmcache.c:1336 lvmcache: /dev/mapper/3600a0b800074a36e06e951f14e7d: now in VG #orphans_lvm2 (#orphans_lvm2) with 0 mdas
#metadata/metadata.c:4468 Setting ignored flag for mda /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 4096.
#format_text/text_label.c:299 Ignoring mda on device /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 4096
#metadata/metadata.c:4468 Setting ignored flag for mda /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 107239964672.
#format_text/text_label.c:299 Ignoring mda on device /dev/mapper/3600a0b800074a36e06e951f14e7d at offset 107239964672
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#libdm-config.c:768 Setting response to OK
#libdm-config.c:768 Setting response to OK
#libdm-config.c:768 Setting id to wiCjbg-mYay-0NQf-r4qu-xK1Y-Lc8K-KxhmIc
#libdm-config.c:768 Setting format to lvm2
#libdm-config.c:799 Setting device to 64770
#libdm-config.c:799 Setting dev_size to 107374182400
#libdm-config.c:799 Setting label_sector to 1
#ioctl/libdm-iface.c:1724 dm status (253:2) OF [16384] (*1)
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#device/dev-io.c:271 /dev/mapper/3600a0b800074a36e06e951f14e7d: size is 209715200 sectors
#device/dev-io.c:524 Opened /dev/mapper/3600a0b800074a36e06e951f14e7d RO O_DIRECT
#device/dev-io.c:137 /dev/mapper/3600a0b800074a36e06e951f14e7d: block size is 4096 bytes
#device/dev-io.c:577 Closed /dev/mapper/3600a0b800074a36e06e951f14e7d
#filters/filter-composite.c:31 Using /dev/mapper/3600a0b800074a36e06e951f14e7d
#libdm-config.c:799 Setting size to 135262208
#libdm-config.c:799 Setting start to 4096
#libdm-config.c:799 Setting ignore to 1
[Users] Fibre channel - LVM problems
Hello,
I'm trying to set up an oVirt 3.2.1 cluster with FC storage.
However, I have encountered a problem when adding the storage to the
cluster. The action fails with the error shown in the log fragment
below.
Thread-628::DEBUG::2013-07-25
21:07:56,385::task::568::TaskManager.Task::(_updateState)
Task=`2a9c1ec3-3ab7-467c-949d-f47260e95dda`::moving from state init - state
preparing
Thread-628::INFO::2013-07-25 21:07:56,386::logUtils::41::dispatcher::(wrapper)
Run and protect: createVG(vgname='7d6f6cd0-608a-4221-aca4-67fffb874b45',
devlist=['3600a0b800074a36e06e951f14e7d'], force=False, options=None)
Thread-628::DEBUG::2013-07-25
21:07:56,387::misc::84::Storage.Misc.excCmd::(lambda) '/usr/bin/sudo -n
/sbin/lvm pvcreate --config devices { preferred_names = [\\^/dev/mapper/\\]
ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
filter = [ \\a%3600a0b800074a36e06e951f14e7d%\\, \\r%.*%\\ ] } global
{ locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
retain_min = 50 retain_days = 0 } --metadatasize 128m --metadatacopies 2
--metadataignore y /dev/mapper/3600a0b800074a36e06e951f14e7d' (cwd None)
Thread-628::DEBUG::2013-07-25
21:07:56,427::misc::84::Storage.Misc.excCmd::(lambda) SUCCESS: err = '';
rc = 0
Thread-628::DEBUG::2013-07-25
21:07:56,428::lvm::471::OperationMutex::(_invalidatepvs) Operation 'lvm
invalidate operation' got the operation mutex
Thread-628::DEBUG::2013-07-25
21:07:56,428::lvm::474::OperationMutex::(_invalidatepvs) Operation 'lvm
invalidate operation' released the operation mutex
Thread-628::DEBUG::2013-07-25
21:07:56,429::misc::84::Storage.Misc.excCmd::(lambda) '/usr/bin/sudo -n
/sbin/lvm pvchange --config devices { preferred_names = [\\^/dev/mapper/\\]
ignore_suspended_devices=1 write_cache_state=0 disable_after_error_count=3
filter = [ \\a%3600a0b800074a36e06e951f14e7d%\\, \\r%.*%\\ ] } global
{ locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup {
retain_min = 50 retain_days = 0 } --metadataignore n
/dev/mapper/3600a0b800074a36e06e951f14e7d' (cwd None)
Thread-628::DEBUG::2013-07-25
21:07:56,468::misc::84::Storage.Misc.excCmd::(lambda) FAILED: err = ' No
device found for PV W8eewg-xskW-2b4S-NJf6-6aux-ySua-1kAU9J.\n
/dev/mapper/3600a0b800074a36e06e951f14e7d: lseek 18446744073575333888
failed: Invalid argument\n /dev/mapper/3600a0b800074a36e06e951f14e7d:
lseek 18446744073575333888 failed: Invalid argument\n Failed to store physical
volume /dev/mapper/3600a0b800074a36e06e951f14e7d\n'; rc = 5
Thread-628::ERROR::2013-07-25
21:07:56,470::task::833::TaskManager.Task::(_setError)
Task=`2a9c1ec3-3ab7-467c-949d-f47260e95dda`::Unexpected error
Traceback (most recent call last):
File /usr/share/vdsm/storage/task.py, line 840, in _run
return fn(*args, **kargs)
File /usr/share/vdsm/logUtils.py, line 42, in wrapper
res = f(*args, **kwargs)
File /usr/share/vdsm/storage/hsm.py, line 1951, in createVG
(force.capitalize() == True)))
File /usr/share/vdsm/storage/lvm.py, line 865, in createVG
raise se.PhysDevInitializationError(pvs[0])
PhysDevInitializationError: Failed to initialize physical device:
('/dev/mapper/3600a0b800074a36e06e951f14e7d',)
Thread-628::DEBUG::2013-07-25 21:07:56,473::task::852::TaskManager.Task::(_run)
Task=`2a9c1ec3-3ab7-467c-949d-f47260e95dda`::Task._run:
2a9c1ec3-3ab7-467c-949d-f47260e95dda ('7d6f6cd0-608a-4221-aca4-67fffb874b45',
['3600a0b800074a36e06e951f14e7d'], False) {} failed - stopping task
As you can see, the PV is created but the next action (pvchange) fails
due to a wrong lseek parameter value. I have pinpointed the problem to the
metadatacopies parameter (a manually created PV without this parameter
works fine).
I have found a similar issue here:
https://www.redhat.com/archives/lvm-devel/2011-February/msg00127.html
List of PVs after the error:
# pvs
PVVG Fmt Attr PSize PFree
/dev/mapper/3600a0b800074a36e06e951f14e7dlvm2 a-- 100,00g 100,00g
/dev/sdb2 fedora lvm2 a-- 556,44g 0
# pvck -v /dev/mapper/3600a0b800074a36e06e951f14e7d
Scanning /dev/mapper/3600a0b800074a36e06e951f14e7d
Found label on /dev/mapper/3600a0b800074a36e06e951f14e7d, sector 1,
type=LVM2 001
Found text metadata area: offset=4096, size=135262208
Huge memory allocation (size 50003968) rejected - metadata corruption?
Bounce buffer malloc failed
Read from /dev/mapper/3600a0b800074a36e06e951f14e7d failed
Found text metadata area: offset=107239964672, size=134217728
Huge memory allocation (size 50003968) rejected - metadata corruption?
Bounce buffer malloc failed
Read from /dev/mapper/3600a0b800074a36e06e951f14e7d failed
The OS is Fedora 19.
# lvm version
LVM version: 2.02.98(2) (2012-10-15)
Library version: 1.02.77 (2012-10-15)
Driver version: 4.24.0
Best regards,
