11:15 p.m.
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=['3600a0b800074a36e000006e951f14e7d'], 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%3600a0b800074a36e000006e951f14e7d%\\", \\"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/3600a0b800074a36e000006e951f14e7d' (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%3600a0b800074a36e000006e951f14e7d%\\", \\"r%.*%\\" ] } global {
locking_type=1 prioritise_write_locks=1 wait_for_locks=1 } backup { retain_min = 50
retain_days = 0 } " --metadataignore n
/dev/mapper/3600a0b800074a36e000006e951f14e7d' (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/3600a0b800074a36e000006e951f14e7d: lseek 18446744073575333888 failed: Invalid
argument\n /dev/mapper/3600a0b800074a36e000006e951f14e7d: lseek 18446744073575333888
failed: Invalid argument\n Failed to store physical volume
"/dev/mapper/3600a0b800074a36e000006e951f14e7d"\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/3600a0b800074a36e000006e951f14e7d',)
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',
['3600a0b800074a36e000006e951f14e7d'], 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
PV VG Fmt Attr PSize PFree
/dev/mapper/3600a0b800074a36e000006e951f14e7d lvm2 a-- 100,00g 100,00g
/dev/sdb2 fedora lvm2 a-- 556,44g 0
# pvck -v /dev/mapper/3600a0b800074a36e000006e951f14e7d
Scanning /dev/mapper/3600a0b800074a36e000006e951f14e7d
Found label on /dev/mapper/3600a0b800074a36e000006e951f14e7d, 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/3600a0b800074a36e000006e951f14e7d 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/3600a0b800074a36e000006e951f14e7d 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,
Łukasz