Bug 2025527 - Refreshing LVs fail: "locking_type (4) is deprecated, using --sysinit --readonly.\', \' Operation prohibited while --readonly is set.\', " Can\'t get lock for ...."
Summary: Refreshing LVs fail: "locking_type (4) is deprecated, using --sysinit --read...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: vdsm
Classification: oVirt
Component: General
Version: 4.50
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ovirt-4.5.0
: 4.50.0.10
Assignee: Nir Soffer
QA Contact: Evelina Shames
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-11-22 13:01 UTC by Nir Soffer
Modified: 2022-04-28 09:26 UTC (History)
2 users (show)

Fixed In Version: vdsm-4.50.0.10
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-04-28 09:26:34 UTC
oVirt Team: Storage
Embargoed:
pm-rhel: ovirt-4.5?


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker RHV-44065 0 None None None 2021-11-22 13:03:24 UTC
oVirt gerrit 117743 0 master MERGED lvm: Don't use global:locking_type 2021-11-24 09:13:13 UTC
oVirt gerrit 117744 0 master MERGED tests: Don't test read only mode 2021-11-24 14:03:43 UTC
oVirt gerrit 117745 0 master MERGED lvm: Remove read_only mode 2021-11-24 14:03:45 UTC

Description Nir Soffer 2021-11-22 13:01:09 UTC
Description of problem:

Refreshing logical volumes fails with this error:

cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\']

rc=5

out=[]

err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']

Vdsm still uses locking_type=4 - this is leftover from RHEL 7 that should not have any effect
on RHEL 8, and was not removed yet from vdsm.

Looks like in 8.6, using locking_type=4 enables the --sysinit --readonly options
and these options are not compatible with lvrefresh, causing it to fail to acquire
the lock for the vg.

Version-Release number of selected component (if applicable):
Issues seen in ovirt CI, running Centos Stream 8. We don't have
information about installed lvm package.

How reproducible:
always - all CI jobs fails now with this error.

Steps to Reproduce:
Run

    lvchange --config 'global {  locking_type=4  }' --refresh vg/lv

Actual results:
lvchange --refresh should work when using locking_type=4.

Expected results:
lvchange --refresh fails when using locking_type=4.

Additional info:

Report from vdsm tests:

____________________________ test_lv_refresh[True] _____________________________

tmp_storage = <storage.tmpstorage.TemporaryStorage object at 0x7fe475241ac8>
read_only = True

    @requires_root
    @pytest.mark.root
    @pytest.mark.parametrize("read_only", [True, False])
    def test_lv_refresh(tmp_storage, read_only):
        dev_size = 10 * GiB
        dev = tmp_storage.create_device(dev_size)
        vg_name = str(uuid.uuid4())
        lv_name = str(uuid.uuid4())
        lv_fullname = "{}/{}".format(vg_name, lv_name)
    
        lvm.set_read_only(False)
    
        lvm.createVG(vg_name, [dev], "initial-tag", 128)
    
        lvm.createLV(vg_name, lv_name, 1024)
    
        lvm.set_read_only(read_only)
    
        # Simulate extending the LV on the SPM.
        commands.run([
            "lvextend",
            "--config", tmp_storage.lvm_config(),
            "-L+1g",
            lv_fullname
        ])
    
        # Refreshing LV invalidates the cache to pick up changes from storage.
>       lvm.refreshLVs(vg_name, [lv_name])

storage/lvm_test.py:1825: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
../lib/vdsm/storage/lvm.py:1816: in refreshLVs
    _refreshLVs(vgName, lvNames)
../lib/vdsm/storage/lvm.py:1827: in _refreshLVs
    raise se.LogicalVolumeRefreshError.from_lvmerror(e)
../lib/vdsm/storage/lvm.py:1824: in _refreshLVs
    _lvminfo.run_command(cmd, devices=_lvminfo._getVGDevs((vgName, )))
../lib/vdsm/storage/lvm.py:561: in run_command
    raise error
../lib/vdsm/storage/lvm.py:555: in run_command
    return self._runner.run(full_cmd)
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <vdsm.storage.lvm.LVMRunner object at 0x7fe47ae0d550>
cmd = ['/usr/sbin/lvm', 'lvchange', '--config', 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  w...ain_min=50  retain_days=0 }', '--refresh', 'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d']

    def run(self, cmd):
        """
        Run LVM command, logging warnings for successful commands.
    
        An example case is when LVM decide to fix VG metadata when running a
        command that should not change the metadata on non-SPM host. In this
        case LVM will log this warning:
    
            WARNING: Inconsistent metadata found for VG xxx-yyy-zzz - updating
            to use version 42
    
        We log warnings only for successful commands since callers are already
        handling failures.
        """
    
        rc, out, err = self._run_command(cmd)
    
        out = out.decode("utf-8").splitlines()
        err = err.decode("utf-8").splitlines()
    
        err = [s for s in err if not self.SUPPRESS_WARNINGS.search(s)]
    
        if rc == 0 and err:
            log.warning("Command %s succeeded with warnings: %s", cmd, err)
    
        if rc != 0:
>           raise se.LVMCommandError(cmd, rc, out, err)
E           vdsm.storage.exception.LogicalVolumeRefreshError: Cannot refresh Logical Volume: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']'

../lib/vdsm/storage/lvm.py:356: LogicalVolumeRefreshError
------------------------------ Captured log call -------------------------------
22:53:20,993 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 losetup --find --show /var/tmp/vdsm/test_lv_refresh_True_0/backing-file-000 (cwd None) (commands:154)
22:53:21,005 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:21,007 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm pvcreate --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --metadatasize 128m --metadatacopies 2 --metadataignore y /dev/loop2 (cwd None) (commands:154)
22:53:21,072 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:186)
22:53:21,073 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm pvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --metadataignore n /dev/loop2 (cwd None) (commands:154)
22:53:21,154 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:186)
22:53:21,156 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm vgcreate --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --physicalextentsize 128m --addtag initial-tag b4512b9d-84dc-43ba-865d-32c4a1cd148a /dev/loop2 (cwd None) (commands:154)
22:53:21,260 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:186)
22:53:21,262 DEBUG   (MainThread) [storage.lvm] Cache after createvg {'b4512b9d-84dc-43ba-865d-32c4a1cd148a': Stale(name='b4512b9d-84dc-43ba-865d-32c4a1cd148a')} (lvm:1415)
22:53:21,263 INFO    (MainThread) [storage.lvm] Creating LV (vg=b4512b9d-84dc-43ba-865d-32c4a1cd148a, lv=511d8825-e706-4b2c-bb99-51b71425525d, size=1024m, activate=True, contiguous=False, initialTags=(), device=None) (lvm:1604)
22:53:21,264 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvcreate --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=1  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --autobackup n --contiguous n --size 1024m --wipesignatures n --name 511d8825-e706-4b2c-bb99-51b71425525d b4512b9d-84dc-43ba-865d-32c4a1cd148a (cwd None) (commands:154)
22:53:21,357 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b'  WARNING: This metadata update is NOT backed up.\n'; <rc> = 0 (commands:186)
22:53:21,361 DEBUG   (MainThread) [storage.misc.exccmd] /usr/bin/taskset --cpu-list 0-1 /usr/bin/chown vdsm:qemu /dev/b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:234)
22:53:21,408 DEBUG   (MainThread) [storage.misc.exccmd] FAILED: <err> = b'/usr/bin/chown: invalid user: \xe2\x80\x98vdsm:qemu\xe2\x80\x99\n'; <rc> = 1 (commands:247)
22:53:21,409 WARNING (MainThread) [storage.lvm] Could not change ownership of one or more volumes in vg (b4512b9d-84dc-43ba-865d-32c4a1cd148a) - 511d8825-e706-4b2c-bb99-51b71425525d (lvm:1640)
22:53:21,410 INFO    (MainThread) [storage.lvm] Switching to read_only=True (lvm:455)
22:53:21,412 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 lvextend --config 'global { use_lvmetad=0 } devices { write_cache_state=0 filter=["a|^/dev/loop2$|", "r|.*|"] }' -L+1g b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:21,540 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:21,542 INFO    (MainThread) [storage.lvm] Refreshing LVs (vg=b4512b9d-84dc-43ba-865d-32c4a1cd148a, lvs=['511d8825-e706-4b2c-bb99-51b71425525d']) (lvm:1815)
22:53:21,543 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --refresh b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:21,624 DEBUG   (MainThread) [common.commands] FAILED: <err> = b"  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\n  Operation prohibited while --readonly is set.\n  Can't get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.\n  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\n"; <rc> = 5 (commands:186)
22:53:21,627 WARNING (MainThread) [storage.lvm] Retry 1 failed, retrying in 0.10 seconds: LVM command failed: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']' (lvm:548)
22:53:21,729 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --refresh b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:21,795 DEBUG   (MainThread) [common.commands] FAILED: <err> = b"  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\n  Operation prohibited while --readonly is set.\n  Can't get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.\n  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\n"; <rc> = 5 (commands:186)
22:53:21,799 WARNING (MainThread) [storage.lvm] Retry 2 failed, retrying in 0.20 seconds: LVM command failed: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']' (lvm:548)
22:53:22,001 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --refresh b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:22,064 DEBUG   (MainThread) [common.commands] FAILED: <err> = b"  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\n  Operation prohibited while --readonly is set.\n  Can't get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.\n  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\n"; <rc> = 5 (commands:186)
22:53:22,066 WARNING (MainThread) [storage.lvm] Retry 3 failed, retrying in 0.40 seconds: LVM command failed: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']' (lvm:548)
22:53:22,468 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --refresh b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:22,528 DEBUG   (MainThread) [common.commands] FAILED: <err> = b"  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\n  Operation prohibited while --readonly is set.\n  Can't get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.\n  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\n"; <rc> = 5 (commands:186)
22:53:22,530 WARNING (MainThread) [storage.lvm] Retry 4 failed, retrying in 0.80 seconds: LVM command failed: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']' (lvm:548)
22:53:23,333 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /usr/sbin/lvm lvchange --config 'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }' --refresh b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d (cwd None) (commands:154)
22:53:23,397 DEBUG   (MainThread) [common.commands] FAILED: <err> = b"  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\n  Operation prohibited while --readonly is set.\n  Can't get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.\n  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\n"; <rc> = 5 (commands:186)
22:53:23,399 WARNING (MainThread) [storage.lvm] All 5 tries have failed: LVM command failed: 'cmd=[\'/usr/sbin/lvm\', \'lvchange\', \'--config\', \'devices {  preferred_names=["^/dev/mapper/"]  ignore_suspended_devices=1  write_cache_state=0  disable_after_error_count=3  filter=["a|^/dev/loop2$|", "r|.*|"]  hints="none"  obtain_device_list_from_udev=0 } global {  locking_type=4  prioritise_write_locks=1  wait_for_locks=1  use_lvmetad=0  use_lvmpolld=1 } backup {  retain_min=50  retain_days=0 }\', \'--refresh\', \'b4512b9d-84dc-43ba-865d-32c4a1cd148a/511d8825-e706-4b2c-bb99-51b71425525d\'] rc=5 out=[] err=[\'  WARNING: locking_type (4) is deprecated, using --sysinit --readonly.\', \'  Operation prohibited while --readonly is set.\', "  Can\'t get lock for b4512b9d-84dc-43ba-865d-32c4a1cd148a.", \'  Cannot process volume group b4512b9d-84dc-43ba-865d-32c4a1cd148a\']' (lvm:559)
---------------------------- Captured log teardown -----------------------------
22:53:24,492 INFO    (MainThread) [test] LVM cache hit ratio: 12.00% (hits: 3 misses: 22) (conftest:143)
22:53:24,493 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 vgs -o name --noheadings --config 'global { use_lvmetad=0 } devices { write_cache_state=0 filter=["a|^/dev/loop2$|", "r|.*|"] }' --select 'pv_name = /dev/loop2' (cwd None) (commands:154)
22:53:24,561 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:24,563 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 vgchange -an --config 'global { use_lvmetad=0 } devices { write_cache_state=0 filter=["a|^/dev/loop2$|", "r|.*|"] }' b4512b9d-84dc-43ba-865d-32c4a1cd148a (cwd None) (commands:154)
22:53:24,651 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:24,652 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 lvremove -ff --config 'global { use_lvmetad=0 } devices { write_cache_state=0 filter=["a|^/dev/loop2$|", "r|.*|"] }' b4512b9d-84dc-43ba-865d-32c4a1cd148a (cwd None) (commands:154)
22:53:24,740 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:24,741 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 vgremove -ff --config 'global { use_lvmetad=0 } devices { write_cache_state=0 filter=["a|^/dev/loop2$|", "r|.*|"] }' b4512b9d-84dc-43ba-865d-32c4a1cd148a (cwd None) (commands:154)
22:53:24,820 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:24,821 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 losetup --detach /dev/loop2 (cwd None) (commands:154)
22:53:24,842 DEBUG   (MainThread) [common.commands] SUCCESS: <err> = b''; <rc> = 0 (commands:99)
22:53:24,844 DEBUG   (MainThread) [common.commands] /usr/bin/taskset --cpu-list 0-1 /sbin/udevadm settle --timeout=5 (cwd None) (commands:154)

Comment 1 Nir Soffer 2021-11-22 13:05:07 UTC
David, is this a regression in rhel 8.6? in previous version using locking_type=4
was not effective but harmless.

Comment 2 Nir Soffer 2021-11-22 13:27:06 UTC
Issue seen with lvm2-2.03.14-1.el8.x86_64. Looks like this version was released
in Centos Stream few days ago. We never had this issue with the previous version.

Comment 3 Nir Soffer 2021-11-22 13:33:52 UTC
Checking the code show that vdsm never uses the read_only mode. This failure happens
only in the tests for read_only mode, which are left over from rhel 7.

Lowering severity since this cannot affect a real system.

Comment 4 David Teigland 2021-11-22 15:46:25 UTC
For better or worse, lvm still recognizes locking_type 4 and translates it into --readonly --sysinit.  The readonly option should prevent activation and refresh, although until very recently an LV refresh bug allowed it to work without a write lock.  See bug 2025367

Comment 6 Nir Soffer 2022-02-10 23:21:19 UTC
This was fixed few month ago, but for some reason the bug was not 
updated.

Comment 10 Sandro Bonazzola 2022-04-28 09:26:34 UTC
This bugzilla is included in oVirt 4.5.0 release, published on April 20th 2022.

Since the problem described in this bug report should be resolved in oVirt 4.5.0 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.


Note You need to log in before you can comment on or make changes to this bug.