Bug 2085078

Summary:	MThreadRunner: exception - KeyError: '/com/redhat/lvmdbus1/Pv/16' while attempting to force delete in-use PV
Product:	Red Hat Enterprise Linux 9	Reporter:	Corey Marthaler <cmarthal>
Component:	lvm2	Assignee:	Tony Asleson <tasleson>
lvm2 sub component:	lvmdbusd	QA Contact:	cluster-qe <cluster-qe>
Status:	CLOSED ERRATA	Docs Contact:
Severity:	low
Priority:	unspecified	CC:	agk, heinzm, jbrassow, mcsontos, msnitzer, prajnoha, tasleson, zkabelac
Version:	9.1	Keywords:	Triaged
Target Milestone:	rc	Flags:	pm-rhel: mirror+
Target Release:	---
Hardware:	x86_64
OS:	Linux
Whiteboard:
Fixed In Version:	lvm2-2.03.17-1.el9	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2023-05-09 08:23:40 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Corey Marthaler 2022-05-12 18:21:27 UTC

Description of problem:
This test was attempting to force delete a single device that was still in-use and a part of a partial VG that was missing all its other PVs.


SCENARIO - duplicate_vg_uuids_with_devicesfile_enabled:  Test how LVM reacts to PVs having the same pv and vg uuids while devicesfile is enabled (bug 2040456) 
adding entry to the devices file for /dev/sdd1
creating PV on hayes-03 using device /dev/sdd1
pvcreate --yes -ff   /dev/sdd1
  Can't open /dev/sdd1 exclusively.  Mounted filesystem?
  Can't open /dev/sdd1 exclusively.  Mounted filesystem?





May 12 11:46:27 hayes-03 qarshd[7506]: Running cmdline: lvmdevices -y --config devices/scan_lvs=1 --adddev /dev/sdd1
May 12 11:46:27 hayes-03 systemd[1]: qarshd.104.51:5016-10.2.17.247:58794.service: Deactivated successfully.
May 12 11:46:27 hayes-03 systemd[1]: Started qarsh Per-Connection Server (10.2.17.247:58796).
May 12 11:46:27 hayes-03 qarshd[7510]: Talking to peer ::ffff:10.2.17.247:58796 (IPv6)
May 12 11:46:28 hayes-03 qarshd[7510]: Running cmdline: pvcreate --yes -ff /dev/sdd1
May 12 11:46:28 hayes-03 lvmdbusd[5943]: 5943:5943 - MThreadRunner: exception
May 12 11:46:28 hayes-03 lvmdbusd[5943]: Traceback (most recent call last):
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/utils.py", line 667, in _run
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    self.rc = self.f(*self.args)
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/fetch.py", line 25, in _main_thread_load
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    (changes, remove) = load_pvs(
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/pv.py", line 46, in load_pvs
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    return common(
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/loader.py", line 55, in common
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    del existing_paths[dbus_object.dbus_object_path()]
May 12 11:46:28 hayes-03 lvmdbusd[5943]: KeyError: '/com/redhat/lvmdbus1/Pv/16'
May 12 11:46:28 hayes-03 lvmdbusd[5943]: 5943:5943 - Exception will be raised in calling thread!
May 12 11:46:28 hayes-03 lvmdbusd[5943]: 5943:5949 - update_thread exception:
May 12 11:46:28 hayes-03 lvmdbusd[5943]: Traceback (most recent call last):
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/fetch.py", line 167, in update_thread
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    num_changes = load(refresh, emit_signal, cache_refresh, log,
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/fetch.py", line 83, in load
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    rc = MThreadRunner(_main_thread_load, refresh, emit_signal).done()
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/utils.py", line 661, in done
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    raise self.exception
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/utils.py", line 667, in _run
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    self.rc = self.f(*self.args)
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/fetch.py", line 25, in _main_thread_load
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    (changes, remove) = load_pvs(
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/pv.py", line 46, in load_pvs
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    return common(
May 12 11:46:28 hayes-03 lvmdbusd[5943]:  File "/usr/lib/python3.9/site-packages/lvmdbusd/loader.py", line 55, in common
May 12 11:46:28 hayes-03 lvmdbusd[5943]:    del existing_paths[dbus_object.dbus_object_path()]
May 12 11:46:28 hayes-03 lvmdbusd[5943]: KeyError: '/com/redhat/lvmdbus1/Pv/16'
May 12 11:46:28 hayes-03 lvmdbusd[5943]: 5943:5949 - LVM dbus flight recorder START



Version-Release number of selected component (if applicable):
kernel-5.14.0-87.el9_0    BUILT: Wed May 11 07:25:00 AM CDT 2022
lvm2-2.03.14-4.el9    BUILT: Wed Feb 16 06:01:21 AM CST 2022
lvm2-libs-2.03.14-4.el9    BUILT: Wed Feb 16 06:01:21 AM CST 2022
lvm2-dbusd-2.03.14-4.el9    BUILT: Wed Feb 16 07:23:08 AM CST 2022

Comment 2 Tony Asleson 2022-05-17 15:48:58 UTC

Please let me know steps to reproduce or location of unit test itself.  I followed the steps in bug 2040456 but the dameon did not raise an exception.

Comment 3 Corey Marthaler 2022-05-17 17:59:14 UTC

Correct, the steps in comment #0 are just a single pvcreate that would not be enough to reproduce this. There were labels left on these devices from prior test runs that I need to dig into and hopefully figure out a reproducer for. 

I filed this a both a place holder to do just that and to maybe see if exception rang a bell for you as to how it might be possible.

Comment 4 Corey Marthaler 2022-09-13 16:54:29 UTC

Saw this again today with the latest 8.7 rpms. I'll post the full log as well.

kernel-4.18.0-424.el8    BUILT: Mon Sep  5 20:11:49 CDT 2022
lvm2-2.03.14-6.el8    BUILT: Fri Jul 29 05:40:53 CDT 2022
lvm2-libs-2.03.14-6.el8    BUILT: Fri Jul 29 05:40:53 CDT 2022
lvm2-dbusd-2.03.14-6.el8    BUILT: Fri Jul 29 05:42:09 CDT 2022


SCENARIO - vgimportdevices_from_incomplete_vg_w_removed_entry_and_offline_device:  Test importing from incomplete VG with an offline and removed entry device (bug 2124970) 
adding entry to the devices file for /dev/sdc1
creating PV on hayes-01 using device /dev/sdc1
pvcreate --yes -ff   /dev/sdc1
  Physical volume "/dev/sdc1" successfully created.
adding entry to the devices file for /dev/sdb1
creating PV on hayes-01 using device /dev/sdb1
pvcreate --yes -ff   /dev/sdb1
  Physical volume "/dev/sdb1" successfully created.
adding entry to the devices file for /dev/sdj1
creating PV on hayes-01 using device /dev/sdj1
pvcreate --yes -ff   /dev/sdj1
  Physical volume "/dev/sdj1" successfully created.
adding entry to the devices file for /dev/sdd1
creating PV on hayes-01 using device /dev/sdd1
pvcreate --yes -ff   /dev/sdd1
  Physical volume "/dev/sdd1" successfully created.
adding entry to the devices file for /dev/sde1
creating PV on hayes-01 using device /dev/sde1
pvcreate --yes -ff   /dev/sde1
  Physical volume "/dev/sde1" successfully created.
adding entry to the devices file for /dev/sdf1
creating PV on hayes-01 using device /dev/sdf1
pvcreate --yes -ff   /dev/sdf1
  Physical volume "/dev/sdf1" successfully created.
adding entry to the devices file for /dev/sdg1
creating PV on hayes-01 using device /dev/sdg1
pvcreate --yes -ff   /dev/sdg1
  Physical volume "/dev/sdg1" successfully created.
adding entry to the devices file for /dev/sdh1
creating PV on hayes-01 using device /dev/sdh1
pvcreate --yes -ff   /dev/sdh1
  Physical volume "/dev/sdh1" successfully created.
adding entry to the devices file for /dev/sdi1
creating PV on hayes-01 using device /dev/sdi1
pvcreate --yes -ff   /dev/sdi1
  Physical volume "/dev/sdi1" successfully created.
creating VG on hayes-01 using PV(s) /dev/sdc1 /dev/sdb1
vgcreate    incomplete /dev/sdc1 /dev/sdb1
  Volume group "incomplete" successfully created
creating VG on hayes-01 using PV(s) /dev/sdj1 /dev/sdd1
vgcreate    complete /dev/sdj1 /dev/sdd1
  Volume group "complete" successfully created
Removing the devicesfile completely
pvscan
  PV /dev/sdj1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdd1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdc1   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdb1   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sde1                      lvm2 [<1.82 TiB]
  PV /dev/sdf1                      lvm2 [<1.82 TiB]
  PV /dev/sdg1                      lvm2 [<1.82 TiB]
  PV /dev/sdh1                      lvm2 [<1.82 TiB]
  PV /dev/sdi1                      lvm2 [<1.82 TiB]
  Total: 9 [<16.37 TiB] / in use: 4 [<7.28 TiB] / in no VG: 5 [9.09 TiB]
Disabling device sdc on hayes-01
'echo offline > /sys/block/sdc/device/state'
pvscan
  PV /dev/sdj1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdd1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV [unknown]   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdb1   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  WARNING: Couldn't find device with uuid ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb.
  WARNING: VG incomplete is missing PV ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb (last written to /dev/sdc1).
  PV /dev/sde1                      lvm2 [<1.82 TiB]
  PV /dev/sdf1                      lvm2 [<1.82 TiB]
  PV /dev/sdg1                      lvm2 [<1.82 TiB]
  PV /dev/sdh1                      lvm2 [<1.82 TiB]
  PV /dev/sdi1                      lvm2 [<1.82 TiB]
  Total: 9 [<16.37 TiB] / in use: 4 [<7.28 TiB] / in no VG: 5 [9.09 TiB]

vgimportdevices -a
  WARNING: Couldn't find device with uuid ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb.
  WARNING: VG incomplete is missing PV ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb (last written to /dev/sdc1).
  WARNING: Couldn't find device with uuid ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb.
  Not importing devices for VG incomplete with missing PV ISyGyd0fckUr9tS45sISL2xzlz3BNFtb.
vgimportdevices SHOULD have imported the device entries for the complete VG's PVs (possible regression of bug 2124970)
Enabling device sdc on hayes-01
'echo running > /sys/block/sdc/device/state'
Verify that all removed devices file entries can be recreated using vgimportdevices
Checking devicesfile entries for the complete VG
A valid devicesfile entry SHOULD exist for /dev/sdj1 (possible regression of bug 2124970)
adding entry to the devices file for /dev/sdj1

Adding back the devicesfile entries for the incomplete VG
adding entry to the devices file for /dev/sdc1
adding entry to the devices file for /dev/sdb1
pvcreate --yes -ff /dev/sdc1
  Physical volume "/dev/sdc1" successfully created.

removing vg incomplete from hayes-01
  WARNING: Couldn't find device with uuid ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb.
  WARNING: VG incomplete is missing PV ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb (last written to /dev/sdc1).
  WARNING: Couldn't find device with uuid ISyGyd-0fck-Ur9t-S45s-ISL2-xzlz-3BNFtb.
  Volume group "incomplete" successfully removed
removing vg complete from hayes-01
  WARNING: Couldn't find device with uuid R92e6a-LM1j-7pIM-4mZ7-yfL7-A8OS-DDxW68.
  WARNING: VG complete is missing PV R92e6a-LM1j-7pIM-4mZ7-yfL7-A8OS-DDxW68 (last written to /dev/sdd1).
  WARNING: Couldn't find device with uuid R92e6a-LM1j-7pIM-4mZ7-yfL7-A8OS-DDxW68.
  Volume group "complete" successfully removed
adding entry to the devices file for /dev/sdc1
removing pv /dev/sdc1 on hayes-01
  Labels on physical volume "/dev/sdc1" successfully wiped.
removing entry from the devices file for /dev/sdc1
adding entry to the devices file for /dev/sdb1
removing pv /dev/sdb1 on hayes-01
  Labels on physical volume "/dev/sdb1" successfully wiped.
removing entry from the devices file for /dev/sdb1
adding entry to the devices file for /dev/sdj1
removing pv /dev/sdj1 on hayes-01
  Labels on physical volume "/dev/sdj1" successfully wiped.
removing entry from the devices file for /dev/sdj1
adding entry to the devices file for /dev/sdd1
removing pv /dev/sdd1 on hayes-01
  PV /dev/sdd1 is used by VG complete so please use vgreduce first.
  (If you are certain you need pvremove, then confirm by using --force twice.)
  /dev/sdd1: physical volume label not removed.
Traceback (most recent call last):
  File "./devicesfile", line 3243, in <module>
    scenario.run(s)
  File "/home/msp/cmarthal/work/r9/sts/sts-root/lvm2/bin/../lib/lvmlib/scenario.py", line 35, in run
    return _scenarios[name]["function"]()
  File "./devicesfile", line 1178, in vgimportdevices_from_incomplete_vg_w_removed_entry_and_offline_device
    p.remove()
  File "/home/msp/cmarthal/work/r9/sts/sts-root/lvm2/bin/../lib/lvmlib/lvmlib.py", line 427, in remove
    check=True,
  File "/usr/lib64/python3.7/subprocess.py", line 512, in run
    output=stdout, stderr=stderr)
subprocess.CalledProcessError: Command 'qarsh -l root hayes-01 pvremove  /dev/sdd1' returned non-zero exit status 5.





Sep 13 11:47:13 hayes-01 qarshd[148480]: Running cmdline: lvmdevices -y --config devices/scan_lvs=1 --adddev /dev/sdj1
Sep 13 11:47:13 hayes-01 systemd[1]: qarshd.104.49:5016-10.2.17.165:53928.service: Succeeded.
Sep 13 11:47:14 hayes-01 systemd[1]: Started qarsh Per-Connection Server (10.2.17.165:53930).
Sep 13 11:47:14 hayes-01 qarshd[148485]: Talking to peer ::ffff:10.2.17.165:53930 (IPv6)
Sep 13 11:47:14 hayes-01 qarshd[148485]: Running cmdline: lvmdevices -y --config devices/scan_lvs=1 --adddev /dev/sdc1
Sep 13 11:47:14 hayes-01 systemd[1]: qarshd.104.49:5016-10.2.17.165:53930.service: Succeeded.
Sep 13 11:47:15 hayes-01 systemd[1]: Started qarsh Per-Connection Server (10.2.17.165:53932).
Sep 13 11:47:15 hayes-01 qarshd[148490]: Talking to peer ::ffff:10.2.17.165:53932 (IPv6)
Sep 13 11:47:15 hayes-01 qarshd[148490]: Running cmdline: lvmdevices -y --config devices/scan_lvs=1 --adddev /dev/sdb1
Sep 13 11:47:15 hayes-01 systemd[1]: qarshd.104.49:5016-10.2.17.165:53932.service: Succeeded.
Sep 13 11:47:16 hayes-01 systemd[1]: Started qarsh Per-Connection Server (10.2.17.165:53934).
Sep 13 11:47:16 hayes-01 qarshd[148495]: Talking to peer ::ffff:10.2.17.165:53934 (IPv6)
Sep 13 11:47:21 hayes-01 qarshd[148495]: Running cmdline: pvcreate --yes -ff /dev/sdc1
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: 4046:4046 - MThreadRunner: exception
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: Traceback (most recent call last):
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/utils.py", line 667, in _run
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    self.rc = self.f(*self.args)
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/fetch.py", line 28, in _main_thread_load
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    cache_refresh=False)[1:]
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/pv.py", line 48, in load_pvs
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    emit_signal, cache_refresh)
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/loader.py", line 55, in common
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    del existing_paths[dbus_object.dbus_object_path()]
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: KeyError: '/com/redhat/lvmdbus1/Pv/605'
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: 4046:4046 - Exception will be raised in calling thread!
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: 4046:4061 - update_thread exception:
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: Traceback (most recent call last):
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/fetch.py", line 168, in update_thread
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    need_main_thread)
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/fetch.py", line 83, in load
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    rc = MThreadRunner(_main_thread_load, refresh, emit_signal).done()
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/utils.py", line 661, in done
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    raise self.exception
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/utils.py", line 667, in _run
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    self.rc = self.f(*self.args)
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/fetch.py", line 28, in _main_thread_load
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    cache_refresh=False)[1:]
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/pv.py", line 48, in load_pvs
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    emit_signal, cache_refresh)
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:  File "/usr/lib/python3.6/site-packages/lvmdbusd/loader.py", line 55, in common
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]:    del existing_paths[dbus_object.dbus_object_path()]
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: KeyError: '/com/redhat/lvmdbus1/Pv/605'
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: 4046:4061 - LVM dbus flight recorder START
Sep 13 11:47:21 hayes-01 lvmdbusd[4046]: 4046:4061 - EC= 0 for ['/usr/sbin/lvm', 'fullreport', '--noheading', '--separator', '{|}', '--nosuffix', '--unbuffered', '--units',

Comment 6 Tony Asleson 2022-09-20 21:41:08 UTC

Correction committed upstream: https://sourceware.org/git/?p=lvm2.git;a=commit;h=d88998f5163f84aa7305edfeb9ec51dc5b0c6733

Thanks for posting the journal, allowed me to correct this one.

Comment 9 Corey Marthaler 2022-11-21 21:51:20 UTC

Marking Verified:Tested with the latest rpms.

lvm2-2.03.17-1.el9    BUILT: Thu Nov 10 10:02:16 AM CST 2022
lvm2-libs-2.03.17-1.el9    BUILT: Thu Nov 10 10:02:16 AM CST 2022
lvm2-dbusd-2.03.17-1.el9    BUILT: Thu Nov 10 10:01:55 AM CST 2022


SCENARIO - vgimportdevices_from_incomplete_vg_w_removed_entry_and_offline_device:  Test importing from incomplete VG with an offline and removed entry device (bug 2124970) 
adding entry to the devices file for /dev/sdm1
creating PV on hayes-03 using device /dev/sdm1
pvcreate --yes -ff   /dev/sdm1
  Physical volume "/dev/sdm1" successfully created.
adding entry to the devices file for /dev/sde1
creating PV on hayes-03 using device /dev/sde1
pvcreate --yes -ff   /dev/sde1
  Physical volume "/dev/sde1" successfully created.
adding entry to the devices file for /dev/sdf1
creating PV on hayes-03 using device /dev/sdf1
pvcreate --yes -ff   /dev/sdf1
  Physical volume "/dev/sdf1" successfully created.
adding entry to the devices file for /dev/sdg1
creating PV on hayes-03 using device /dev/sdg1
pvcreate --yes -ff   /dev/sdg1
  Physical volume "/dev/sdg1" successfully created.
adding entry to the devices file for /dev/sdl1
creating PV on hayes-03 using device /dev/sdl1
pvcreate --yes -ff   /dev/sdl1
  Physical volume "/dev/sdl1" successfully created.
adding entry to the devices file for /dev/sda
creating PV on hayes-03 using device /dev/sda
pvcreate --yes -ff   /dev/sda
  Physical volume "/dev/sda" successfully created.
creating VG on hayes-03 using PV(s) /dev/sdm1 /dev/sde1
vgcreate    incomplete /dev/sdm1 /dev/sde1
  Volume group "incomplete" successfully created
creating VG on hayes-03 using PV(s) /dev/sdf1 /dev/sdg1
vgcreate    complete /dev/sdf1 /dev/sdg1
  Volume group "complete" successfully created

* Removing the devicesfile completely *
pvscan
  PV /dev/sdf1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdg1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdm1   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sde1   VG incomplete      lvm2 [446.62 GiB / 446.62 GiB free]
  PV /dev/sda                       lvm2 [446.62 GiB]
  PV /dev/sdl1                      lvm2 [<1.82 TiB]
  Total: 6 [<8.15 TiB] / in use: 4 [5.89 TiB] / in no VG: 2 [<2.26 TiB]
Disabling device sdm on hayes-03
'echo offline > /sys/block/sdm/device/state'
pvscan
  PV /dev/sdf1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sdg1   VG complete        lvm2 [<1.82 TiB / <1.82 TiB free]
  WARNING: Couldn't find device with uuid Pyn0Rb-ahft-JkWF-gZ6R-PyCk-3fnd-vYEhlp.
  WARNING: VG incomplete is missing PV Pyn0Rb-ahft-JkWF-gZ6R-PyCk-3fnd-vYEhlp (last written to /dev/sdm1).
  PV [unknown]   VG incomplete      lvm2 [<1.82 TiB / <1.82 TiB free]
  PV /dev/sde1   VG incomplete      lvm2 [446.62 GiB / 446.62 GiB free]
  PV /dev/sda                       lvm2 [446.62 GiB]
  PV /dev/sdl1                      lvm2 [<1.82 TiB]
  Total: 6 [<8.15 TiB] / in use: 4 [5.89 TiB] / in no VG: 2 [<2.26 TiB]

* Only devices in the complete VG are to be restored *
vgimportdevices -a
  Not importing devices for VG incomplete with missing PV Pyn0RbahftJkWFgZ6RPyCk3fndvYEhlp.
  Added 2 devices to devices file.

removing vg complete from hayes-03
  Volume group "complete" successfully removed

* No devices will be restored with just the incomplete VG remaining*
vgimportdevices -a
  Not importing devices for VG incomplete with missing PV Pyn0RbahftJkWFgZ6RPyCk3fndvYEhlp.

Enabling device sdm on hayes-03
'echo running > /sys/block/sdm/device/state'
Verify that all removed devices file entries can be recreated using vgimportdevices
Checking devicesfile entries for the incomplete VG
adding entry to the devices file for /dev/sdm1
adding entry to the devices file for /dev/sde1

Checking devicesfile entries for the complete VG
IDTYPE=sys_wwid IDNAME=naa.6d09466083d8e100233c180321c0e570 DEVNAME=/dev/sdf1 PVID=S1v2QvJxQ1XhRN9SsWM18fv7h3lfdL3T PART=1
IDTYPE=sys_wwid IDNAME=naa.6d09466083d8e100233c1809221dc983 DEVNAME=/dev/sdg1 PVID=nbInRueBXzR7vDjtJQ6OfrPJ51mvujcY PART=1

removing vg incomplete from hayes-03
  Volume group "incomplete" successfully removed
adding entry to the devices file for /dev/sdm1
removing pv /dev/sdm1 on hayes-03
  Labels on physical volume "/dev/sdm1" successfully wiped.
removing entry from the devices file for /dev/sdm1
adding entry to the devices file for /dev/sde1
removing pv /dev/sde1 on hayes-03
  Labels on physical volume "/dev/sde1" successfully wiped.
removing entry from the devices file for /dev/sde1
adding entry to the devices file for /dev/sdf1
removing pv /dev/sdf1 on hayes-03
  Labels on physical volume "/dev/sdf1" successfully wiped.
removing entry from the devices file for /dev/sdf1
adding entry to the devices file for /dev/sdg1
removing pv /dev/sdg1 on hayes-03
  Labels on physical volume "/dev/sdg1" successfully wiped.
removing entry from the devices file for /dev/sdg1
adding entry to the devices file for /dev/sdl1
removing pv /dev/sdl1 on hayes-03
  Labels on physical volume "/dev/sdl1" successfully wiped.
removing entry from the devices file for /dev/sdl1
adding entry to the devices file for /dev/sda
removing pv /dev/sda on hayes-03
  Labels on physical volume "/dev/sda" successfully wiped.
removing entry from the devices file for /dev/sda


Nov 21 15:34:20.250072: 64543:64548 - Processing _external_event= pvremove
Nov 21 15:34:20.250269: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:20.296386: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:20.297521: 64543:64543 - SIGNAL: InterfacesRemoved(/com/redhat/lvmdbus1/Pv/14, ['com.redhat.lvmdbus1.Pv'])
Nov 21 15:34:20.297783: 64543:64548 - Method complete: <function Manager._external_event at 0x7fcf42fcb1f0>
Nov 21 15:34:20.297925: 64543:64548 - Method start: <function _udev_event at 0x7fcf42fac0d0> with args () (callback = None)
Nov 21 15:34:20.297978: 64543:64548 - Processing udev event
Nov 21 15:34:20.298145: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:20.336143: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:20.337379: 64543:64548 - Method complete: <function _udev_event at 0x7fcf42fac0d0>
Nov 21 15:34:22.651209: 64543:64543 - ExternalEvent pvremove
Nov 21 15:34:22.651435: 64543:64548 - Method start: <function Manager._external_event at 0x7fcf42fcb1f0> with args (dbus.String('pvremove'),) (callback = None)
Nov 21 15:34:22.651516: 64543:64548 - Processing _external_event= pvremove
Nov 21 15:34:22.651690: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:22.696415: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:22.697421: 64543:64543 - SIGNAL: InterfacesRemoved(/com/redhat/lvmdbus1/Pv/10, ['com.redhat.lvmdbus1.Pv'])
Nov 21 15:34:22.697681: 64543:64548 - Method complete: <function Manager._external_event at 0x7fcf42fcb1f0>
Nov 21 15:34:22.697813: 64543:64548 - Method start: <function _udev_event at 0x7fcf42fac0d0> with args () (callback = None)
Nov 21 15:34:22.697866: 64543:64548 - Processing udev event
Nov 21 15:34:22.698092: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:22.743102: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:22.744013: 64543:64548 - Method complete: <function _udev_event at 0x7fcf42fac0d0>
Nov 21 15:34:24.759364: 64543:64543 - ExternalEvent pvremove
Nov 21 15:34:24.759583: 64543:64548 - Method start: <function Manager._external_event at 0x7fcf42fcb1f0> with args (dbus.String('pvremove'),) (callback = None)
Nov 21 15:34:24.759657: 64543:64548 - Processing _external_event= pvremove
Nov 21 15:34:24.759834: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:24.807337: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:24.807827: 64543:64543 - SIGNAL: InterfacesRemoved(/com/redhat/lvmdbus1/Pv/11, ['com.redhat.lvmdbus1.Pv'])
Nov 21 15:34:24.808114: 64543:64548 - Method complete: <function Manager._external_event at 0x7fcf42fcb1f0>
Nov 21 15:34:24.808252: 64543:64548 - Method start: <function _udev_event at 0x7fcf42fac0d0> with args () (callback = None)
Nov 21 15:34:24.808312: 64543:64548 - Processing udev event
Nov 21 15:34:24.808518: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:24.854268: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:24.854647: 64543:64548 - Method complete: <function _udev_event at 0x7fcf42fac0d0>
Nov 21 15:34:27.027501: 64543:64543 - ExternalEvent pvremove
Nov 21 15:34:27.027754: 64543:64548 - Method start: <function Manager._external_event at 0x7fcf42fcb1f0> with args (dbus.String('pvremove'),) (callback = None)
Nov 21 15:34:27.027846: 64543:64548 - Processing _external_event= pvremove
Nov 21 15:34:27.028041: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:27.076361: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:27.076776: 64543:64548 - Method complete: <function Manager._external_event at 0x7fcf42fcb1f0>
Nov 21 15:34:29.169484: 64543:64543 - ExternalEvent pvremove
Nov 21 15:34:29.169718: 64543:64548 - Method start: <function Manager._external_event at 0x7fcf42fcb1f0> with args (dbus.String('pvremove'),) (callback = None)
Nov 21 15:34:29.169806: 64543:64548 - Processing _external_event= pvremove
Nov 21 15:34:29.169985: 64543:64549 - lvmdb - refresh entry
Nov 21 15:34:29.227339: 64543:64549 - lvmdb - refresh exit
Nov 21 15:34:29.227730: 64543:64548 - Method complete: <function Manager._external_event at 0x7fcf42fcb1f0>

Comment 13 Corey Marthaler 2023-01-18 18:17:48 UTC

Marking VERIFIED in the latest rpms as well.

kernel-5.14.0-231.el9    BUILT: Mon Jan  9 08:32:41 PM CET 2023
lvm2-2.03.17-4.el9    BUILT: Tue Jan 10 06:40:12 PM CET 2023
lvm2-libs-2.03.17-4.el9    BUILT: Tue Jan 10 06:40:12 PM CET 2023
lvm2-dbusd-2.03.17-4.el9    BUILT: Tue Jan 10 06:40:33 PM CET 2023


SCENARIO - vgimportdevices_from_incomplete_vg_w_removed_entry_and_offline_device:  Test importing from incomplete VG with an offline and removed entry device (bug 2124970|2139512|2085078) 
Ensuring lvm2-lvmdbusd is started to verify bug 2085078
lvm2-lvmdbusd is not currently running, starting...
systemctl start lvm2-lvmdbusd

adding entry to the devices file for /dev/sda
creating PV on virt-558.cluster-qe.lab.eng.brq.redhat.com using device /dev/sda
pvcreate --yes -ff   /dev/sda
  Physical volume "/dev/sda" successfully created.
adding entry to the devices file for /dev/sdb
creating PV on virt-558.cluster-qe.lab.eng.brq.redhat.com using device /dev/sdb
pvcreate --yes -ff   /dev/sdb
  Physical volume "/dev/sdb" successfully created.
adding entry to the devices file for /dev/sdc
creating PV on virt-558.cluster-qe.lab.eng.brq.redhat.com using device /dev/sdc
pvcreate --yes -ff   /dev/sdc
  Physical volume "/dev/sdc" successfully created.
adding entry to the devices file for /dev/sdd
creating PV on virt-558.cluster-qe.lab.eng.brq.redhat.com using device /dev/sdd
pvcreate --yes -ff   /dev/sdd
  Physical volume "/dev/sdd" successfully created.
adding entry to the devices file for /dev/sde
creating PV on virt-558.cluster-qe.lab.eng.brq.redhat.com using device /dev/sde
pvcreate --yes -ff   /dev/sde
  Physical volume "/dev/sde" successfully created.
creating VG on virt-558.cluster-qe.lab.eng.brq.redhat.com using PV(s) /dev/sda /dev/sdb
vgcreate    incomplete /dev/sda /dev/sdb
  Volume group "incomplete" successfully created
creating VG on virt-558.cluster-qe.lab.eng.brq.redhat.com using PV(s) /dev/sdc /dev/sdd
vgcreate    complete /dev/sdc /dev/sdd
  Volume group "complete" successfully created

* Removing the devicesfile completely *
pvscan
  PV /dev/sdc    VG complete        lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/sdd    VG complete        lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/vda2   VG rhel_virt-558   lvm2 [<7.00 GiB / 0    free]
  PV /dev/sda    VG incomplete      lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/sdb    VG incomplete      lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/sde                       lvm2 [80.00 GiB]
  Total: 6 [406.98 GiB] / in use: 5 [326.98 GiB] / in no VG: 1 [80.00 GiB]
Disabling device sda on virt-558.cluster-qe.lab.eng.brq.redhat.com
'echo offline > /sys/block/sda/device/state'
pvscan
  PV /dev/sdc    VG complete        lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/sdd    VG complete        lvm2 [<80.00 GiB / <80.00 GiB free]
  WARNING: Couldn't find device with uuid ndoUM6-bkSg-6qqv-To8M-IZPc-zOfR-cK9BX4.
  WARNING: VG incomplete is missing PV ndoUM6-bkSg-6qqv-To8M-IZPc-zOfR-cK9BX4 (last written to /dev/sda).
  PV [unknown]   VG incomplete      lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/sdb    VG incomplete      lvm2 [<80.00 GiB / <80.00 GiB free]
  PV /dev/vda2   VG rhel_virt-558   lvm2 [<7.00 GiB / 0    free]
  PV /dev/sde                       lvm2 [80.00 GiB]
  Total: 6 [406.98 GiB] / in use: 5 [326.98 GiB] / in no VG: 1 [80.00 GiB]

* Only devices in the complete VG are to be restored *
vgimportdevices -a
  Not importing devices for VG incomplete with missing PV ndoUM6bkSg6qqvTo8MIZPczOfRcK9BX4.
  Added 3 devices to devices file.

removing vg complete from virt-558.cluster-qe.lab.eng.brq.redhat.com
  Volume group "complete" successfully removed

* No devices will be restored when attempted on *just* the remaining incomplete VG *
vgimportdevices incomplete
  Not importing devices for VG incomplete with missing PV ndoUM6bkSg6qqvTo8MIZPczOfRcK9BX4.

* No devices should be restored when attempted on *all* with just the incomplete VG remaining (except for a potential root device) *
vgimportdevices -a
  Not importing devices for VG incomplete with missing PV ndoUM6bkSg6qqvTo8MIZPczOfRcK9BX4.
  Added 1 devices to devices file.

  WARNING: Couldn't find device with uuid ndoUM6-bkSg-6qqv-To8M-IZPc-zOfR-cK9BX4.
  WARNING: VG incomplete is missing PV ndoUM6-bkSg-6qqv-To8M-IZPc-zOfR-cK9BX4 (last written to /dev/sda).
  WARNING: Couldn't find device with uuid ndoUM6-bkSg-6qqv-To8M-IZPc-zOfR-cK9BX4.

Enabling device sda on virt-558.cluster-qe.lab.eng.brq.redhat.com
'echo running > /sys/block/sda/device/state'
WARNING: Heartbeat did not respond at start of command.  Check btimed service on remote host
Verify that all removed devices file entries can be recreated using vgimportdevices
Checking devicesfile entries for the incomplete VG
WARNING: Heartbeat did not respond at start of command.  Check btimed service on remote host
adding entry to the devices file for /dev/sda
adding entry to the devices file for /dev/sdb

Checking devicesfile entries for the complete VG
IDTYPE=sys_wwid IDNAME=naa.6001405424137e80a274455bb40752b1 DEVNAME=/dev/sdc PVID=TGClgYh12X5At4vhE3SadYUqnQg2Pmy9
IDTYPE=sys_wwid IDNAME=naa.6001405257c9efab3c24e1381d3cd692 DEVNAME=/dev/sdd PVID=AMKQI8AxApQNpR1VbLpmi04Fi169OBu3

removing vg incomplete from virt-558.cluster-qe.lab.eng.brq.redhat.com
  Volume group "incomplete" successfully removed
adding entry to the devices file for /dev/sda
removing pv /dev/sda on virt-558.cluster-qe.lab.eng.brq.redhat.com
  Labels on physical volume "/dev/sda" successfully wiped.
removing entry from the devices file for /dev/sda
adding entry to the devices file for /dev/sdb
removing pv /dev/sdb on virt-558.cluster-qe.lab.eng.brq.redhat.com
  Labels on physical volume "/dev/sdb" successfully wiped.
removing entry from the devices file for /dev/sdb
adding entry to the devices file for /dev/sdc
removing pv /dev/sdc on virt-558.cluster-qe.lab.eng.brq.redhat.com
  Labels on physical volume "/dev/sdc" successfully wiped.
removing entry from the devices file for /dev/sdc
adding entry to the devices file for /dev/sdd
removing pv /dev/sdd on virt-558.cluster-qe.lab.eng.brq.redhat.com
WARNING: Heartbeat did not respond at start of command.  Check btimed service on remote host
  Labels on physical volume "/dev/sdd" successfully wiped.
removing entry from the devices file for /dev/sdd
adding entry to the devices file for /dev/sde
removing pv /dev/sde on virt-558.cluster-qe.lab.eng.brq.redhat.com
  Labels on physical volume "/dev/sde" successfully wiped.
removing entry from the devices file for /dev/sde

Searching for MThreadRunner: exception in syslog
systemctl stop lvm2-lvmdbusd

Comment 15 errata-xmlrpc 2023-05-09 08:23:40 UTC

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory (lvm2 bug fix and enhancement update), and where to find the updated
files, follow the link below.

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

https://access.redhat.com/errata/RHBA-2023:2544