Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1738428

Summary: LVM-activate: cluster does see systemid locked volume only after reboot
Product: Red Hat Enterprise Linux 8 Reporter: michal novacek <mnovacek>
Component: resource-agentsAssignee: Oyvind Albrigtsen <oalbrigt>
Status: CLOSED ERRATA QA Contact: michal novacek <mnovacek>
Severity: high Docs Contact:
Priority: medium    
Version: 8.1CC: agk, cluster-maint, cmackows, fdinitto, heinzm, jbrassow, lvm-team, msnitzer, prajnoha, teigland, zkabelac
Target Milestone: rcKeywords: TestBlocker
Target Release: 8.0Flags: pm-rhel: mirror+
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: resource-agents-4.1.1-34.el8 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
: 1759067 (view as bug list) Environment:
Last Closed: 2020-04-28 15:24:20 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:
Bug Depends On:    
Bug Blocks: 1759067    
Attachments:
Description Flags
debug=7 lvm.log from both cluster nodes.
none
qec03m01_lvm.log
none
qec03m02_lvm.log
none
udevadm info -e
none
LVM-activate patch none

Description michal novacek 2019-08-07 07:05:39 UTC 
Description of problem:
Two nodes having common shared iscsi drive using vg systemid locking. No
locking daemons running.

This happens in one of our automated tests where it always ends up in a weird
state where one node (the one which systemid is written on the volume) sees VG
correctly where the other will never see it not with --foreign parameter and
not even after it's systemid is written on the volume.

Rebooting the node solves the problem.

Version-Release number of selected component (if applicable):
lvm2-2.03.05-2.el8.x86_64

How reproducible: always with our setup

Steps to Reproduce (also see Additional info)
1. create vg 'shared' without 'shared' property
2. configure system_id_source=uname in /etc/lvm/lvm.conf
3. write fqdn of node1 as systemid on vg
4. write fqdn of node2 as systemid on vg
5. run vgscan on node2

Actual results: node2 does not see vg 

Expected results: node2 should always see vgs with foreign systemids whet
    '--foreign' is specified and it should definitely be able to see and
    activate vg with its own hostname being systemid on vg.

Additional info:
> [root@virt-422 ~]# pvs
  PV         VG            Fmt  Attr PSize    PFree
  /dev/sda   shared        lvm2 a--  1016.00m    0 
  /dev/vda2  rhel_virt-422 lvm2 a--    <7.00g    0 
> [root@virt-422 ~]# blkid /dev/sda
/dev/sda: UUID="cvIFHe-mB2B-MYwL-tIHx-Ug7d-xlAw-1yDveb" TYPE="LVM2_member"

> [root@virt-422 ~]# dmsetup ls
rhel_virt--422-swap     (253:1)
rhel_virt--422-root     (253:0)

> [root@virt-422 ~]# lvm config global/system_id_source
system_id_source="uname"

> [root@virt-422 ~]# vgs -o+vg_systemid
  VG            #PV #LV #SN Attr   VSize    VFree System ID
  rhel_virt-422   1   2   0 wz--n-   <7.00g    0
  shared          1   1   0 wz--n- 1016.00m    0  virt-422.cluster-qe.lab.eng.brq.redhat.com

> [root@virt-422 ~]# vgs --foreign --nolocking --noheadings --nameprefixes --rows --config report/compact_output=0 -o name,clustered,lock_type,systemid,tags,vg_attr shared
  WARNING: File locking is disabled.
  LVM2_VG_NAME='shared'
  LVM2_VG_CLUSTERED=''
  LVM2_VG_LOCK_TYPE=''
  LVM2_VG_SYSTEMID='virt-422.cluster-qe.lab.eng.brq.redhat.com'
  LVM2_VG_TAGS=''
  LVM2_VG_ATTR='wz--n-'

> [root@virt-422 ~]# systemctl status lvmlockd clvmd
Unit clvmd.service could not be found.
● lvmlockd.service - LVM lock daemon
   Loaded: loaded (/usr/lib/systemd/system/lvmlockd.service; disabled; vendor preset: disabled)
   Active: inactive (dead)
     Docs: man:lvmlockd(8)

# The other nodes does not see the vg even with --foreign and --nolocking which is strange at least.
> [root@virt-423 ~]# lvm config global/system_id_source
system_id_source="uname"
> [root@virt-423 ~]# blkid /dev/sda 
/dev/sda: UUID="cvIFHe-mB2B-MYwL-tIHx-Ug7d-xlAw-1yDveb" TYPE="LVM2_member"

> [root@virt-423 ~]# vgs --foreign --nolocking shared
  WARNING: File locking is disabled.
  Volume group "shared" not found
  Cannot process volume group shared

# Lets change the systemid so virt-423 can see and use VG.
> [root@virt-422 ~]# vgchange --systemid virt-423.cluster-qe.lab.eng.brq.redhat.com shared
  WARNING: Requested system ID virt-423.cluster-qe.lab.eng.brq.redhat.com does not match local system ID virt-422.cluster-qe.lab.eng.brq.redhat.com.
  WARNING: Volume group shared might become inaccessible from this machine.
Set foreign system ID virt-423.cluster-qe.lab.eng.brq.redhat.com on volume group shared? [y/n]: y
  Volume group "shared" successfully changed

# The behaviour is as I expect it -- virt-422 does not see vg having systemid
# virt-423 without --foreign parameter.

> [root@virt-422 ~]# vgs -o+vg_systemid
  VG            #PV #LV #SN Attr   VSize  VFree System ID
  rhel_virt-422   1   2   0 wz--n- <7.00g    0

> [root@virt-422 ~]# vgs --foreign -o+vg_systemid
  VG            #PV #LV #SN Attr   VSize    VFree System ID
  rhel_virt-422   1   2   0 wz--n-   <7.00g    0
  shared          1   1   0 wz--n- 1016.00m    0  virt-423.cluster-qe.lab.eng.brq.redhat.com


# virt-423 should now see the vg but does not.
> [root@virt-423 ~]# vgs shared
  Volume group "shared" not found
  Cannot process volume group shared

> [root@virt-423 ~]# vgscan
  Found volume group "rhel_virt-423" using metadata type lvm2
  Found volume group "shared" using metadata type lvm2

> [root@virt-423 ~]# vgs shared -o+vg_systemid
  Volume group "shared" not found
  Cannot process volume group shared
Comment 1 David Teigland 2019-08-07 18:23:38 UTC 
I'm not able to reproduce this (see below).  Could you add -vvvv to the vgs commands which should display the VG but don't?  After that could you add hints="none" to lvm.conf to see if that has any effect (it shouldn't).


[root@null-02 ~]# vgs -o+systemid
  VG           #PV #LV #SN Attr   VSize   VFree   System ID
  cc             1   0   0 wz--n- 931.01g 931.01g null-02
  rhel_null-02   1   3   0 wz--n- 465.27g      0

[root@null-03 lvm.git]# vgs -o+systemid
  VG           #PV #LV #SN Attr   VSize   VFree
  rhel_null-03   1   3   0 wz--n- 465.27g    0

[root@null-03 lvm.git]# vgs -o+systemid --foreign
  VG           #PV #LV #SN Attr   VSize   VFree   System ID
  cc             1   0   0 wz--n- 931.01g 931.01g null-02
  rhel_null-03   1   3   0 wz--n- 465.27g      0

[root@null-02 ~]# vgchange --systemid "null-03" cc
  WARNING: Requested system ID null-03 does not match local system ID null-02.
  WARNING: Volume group cc might become inaccessible from this machine.
Set foreign system ID null-03 on volume group cc? [y/n]: y
  Volume group "cc" successfully changed

[root@null-02 ~]# vgs -o+systemid
  VG           #PV #LV #SN Attr   VSize   VFree 
  rhel_null-02   1   3   0 wz--n- 465.27g    0 

[root@null-02 ~]# vgs -o+systemid --foreign
  VG           #PV #LV #SN Attr   VSize   VFree   System ID
  cc             1   0   0 wz--n- 931.01g 931.01g null-03  
  rhel_null-02   1   3   0 wz--n- 465.27g      0           

[root@null-03 lvm.git]# vgs -o+systemid
  VG           #PV #LV #SN Attr   VSize   VFree   System ID
  cc             1   0   0 wz--n- 931.01g 931.01g null-03  
  rhel_null-03   1   3   0 wz--n- 465.27g      0
Comment 2 David Teigland 2019-08-07 18:25:43 UTC 
The subject mentions "only after reboot", but the description doesn't say anything about rebooting.
Comment 3 michal novacek 2019-08-12 11:05:08 UTC 
[root@virt-042 ~]# vgs -o+vg_systemid
  VG            #PV #LV #SN Attr   VSize    VFree System ID
  rhel_virt-042   1   2   0 wz--n-   <7.00g    0
  shared          1   1   0 wz--n- 1020.00m    0  virt-042.cluster-qe.lab.eng.brq.redhat.com


It seems that devices/hints have influence on the output:

> [root@virt-043 ~]# vgs --foreign --config devices/hints=none
  VG            #PV #LV #SN Attr   VSize    VFree
  rhel_virt-043   1   2   0 wz--n-   <7.00g    0
  shared          1   1   0 wz--n- 1020.00m    0

> [root@virt-043 ~]# vgs --foreign --config devices/hints=all
  VG            #PV #LV #SN Attr   VSize  VFree
  rhel_virt-043   1   2   0 wz--n- <7.00g    0


The same commands with -vvvv.

> [root@virt-043 ~]# vgs --foreign --config devices/hints=all -vvvv
13:01:51.87706 vgs[17818] lvmcmdline.c:2896  Parsing: vgs --foreign --config devices/hints=all -vvvv
13:01:51.87752 vgs[17818] lvmcmdline.c:1887  Recognised command vgs_general (id 147 / enum 132).
13:01:51.87784 vgs[17818] commands/toolcontext.c:1814  Reloading config files
13:01:51.87802 vgs[17818] activate/fs.c:492  Syncing device names
13:01:51.87832 vgs[17818] cache/lvmcache.c:1936  Dropping VG info
13:01:51.87856 vgs[17818] metadata/vg.c:79  Freeing VG #orphans_lvm2 at 0x55eeb27ac680.
13:01:51.87889 vgs[17818] config/config.c:283  Loading config file: /etc/lvm/lvm.conf
13:01:51.87910 vgs[17818] device/dev-io.c:430  Opened /etc/lvm/lvm.conf RO
13:01:51.88252 vgs[17818] device/dev-io.c:469  Closed /etc/lvm/lvm.conf
13:01:51.88961 vgs[17818] lvmcmdline.c:2953  DEGRADED MODE. Incomplete RAID LVs will be processed.
13:01:51.88983 vgs[17818] lvmcmdline.c:2959  Processing command: vgs --foreign --config devices/hints=all -vvvv
13:01:51.88994 vgs[17818] lvmcmdline.c:2960  Command pid: 17818
13:01:51.89003 vgs[17818] lvmcmdline.c:2961  System ID: virt-043.cluster-qe.lab.eng.brq.redhat.com
13:01:51.89012 vgs[17818] lvmcmdline.c:2964  O_DIRECT will be used
13:01:51.89030 vgs[17818] device_mapper/libdm-config.c:1014  global/locking_type not found in config: defaulting to 1
13:01:51.89049 vgs[17818] locking/locking.c:143  File locking settings: readonly:0 sysinit:0 ignorelockingfailure:0 global/metadata_read_only:0 global/wait_for_locks:1.
13:01:51.97405 vgs[17818] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm to system_u:object_r:lvm_lock_t:s0.
13:01:51.97534 vgs[17818] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:51.97571 vgs[17818] device_mapper/libdm-config.c:987  devices/md_component_checks not found in config: defaulting to auto
13:01:51.97583 vgs[17818] lvmcmdline.c:2804  Using md_component_checks auto use_full_md_check 0
13:01:51.97602 vgs[17818] device_mapper/libdm-config.c:987  report/output_format not found in config: defaulting to basic
13:01:51.97615 vgs[17818] device_mapper/libdm-config.c:1086  log/report_command_log not found in config: defaulting to 0
13:01:51.97629 vgs[17818] device_mapper/libdm-config.c:1086  report/aligned not found in config: defaulting to 1
13:01:51.97640 vgs[17818] device_mapper/libdm-config.c:1086  report/buffered not found in config: defaulting to 1
13:01:51.97651 vgs[17818] device_mapper/libdm-config.c:1086  report/headings not found in config: defaulting to 1
13:01:51.97661 vgs[17818] device_mapper/libdm-config.c:987  report/separator not found in config: defaulting to
13:01:51.97680 vgs[17818] device_mapper/libdm-config.c:1086  report/prefixes not found in config: defaulting to 0
13:01:51.97690 vgs[17818] device_mapper/libdm-config.c:1086  report/quoted not found in config: defaulting to 1
13:01:51.97700 vgs[17818] device_mapper/libdm-config.c:1086  report/columns_as_rows not found in config: defaulting to 0
13:01:51.97713 vgs[17818] device_mapper/libdm-config.c:987  report/vgs_sort not found in config: defaulting to vg_name
13:01:51.97731 vgs[17818] device_mapper/libdm-config.c:987  report/vgs_cols_verbose not found in config: defaulting to vg_name,vg_attr,vg_extent_size,pv_count,lv_count,snap_count,vg_size,vg_free,vg_uuid,vg_profile
13:01:51.97743 vgs[17818] device_mapper/libdm-config.c:987  report/compact_output_cols not found in config: defaulting to
13:01:51.97919 vgs[17818] toollib.c:2214  Processing each VG
13:01:51.97934 vgs[17818] misc/lvm-flock.c:230  Locking /run/lock/lvm/P_global RB
13:01:51.99839 vgs[17818] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm/P_global to system_u:object_r:lvm_lock_t:s0.
13:01:51.99881 vgs[17818] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/P_global:aux WB
13:01:51.99950 vgs[17818] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/P_global:aux
13:01:51.99985 vgs[17818] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/P_global RB
13:01:51.100023 vgs[17818] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:51.100049 vgs[17818] cache/lvmcache.c:857  Finding VG info
13:01:51.100081 vgs[17818] filters/filter-sysfs.c:328  Sysfs filter initialised.
13:01:51.100091 vgs[17818] filters/filter-internal.c:79  Internal filter initialised.
13:01:51.100104 vgs[17818] filters/filter-type.c:58  LVM type filter initialised.
13:01:51.100116 vgs[17818] filters/filter-usable.c:202  Usable device filter initialised (scan_lvs 0).
13:01:51.100138 vgs[17818] filters/filter-mpath.c:343  mpath filter initialised.
13:01:51.100158 vgs[17818] filters/filter-partitioned.c:71  Partitioned filter initialised.
13:01:51.100168 vgs[17818] filters/filter-signature.c:86  signature filter initialised.
13:01:51.100179 vgs[17818] filters/filter-md.c:150  MD filter initialised.
13:01:51.100190 vgs[17818] filters/filter-composite.c:100  Composite filter initialised.
13:01:51.100204 vgs[17818] filters/filter-persistent.c:190  Persistent filter initialised.
13:01:51.100214 vgs[17818] label/label.c:889  Finding devices to scan
13:01:51.100224 vgs[17818] device/dev-cache.c:1172  Creating list of system devices.
13:01:51.102244 vgs[17818] device/dev-cache.c:711  Found dev 252:0 /dev/vda - new.
13:01:51.102445 vgs[17818] device/dev-cache.c:748  Found dev 252:0 /dev/disk/by-path/pci-0000:00:04.0 - new alias.
13:01:51.102482 vgs[17818] device/dev-cache.c:748  Found dev 252:0 /dev/disk/by-path/virtio-pci-0000:00:04.0 - new alias.
13:01:51.102604 vgs[17818] device/dev-cache.c:711  Found dev 252:1 /dev/vda1 - new.
13:01:51.102688 vgs[17818] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-partuuid/8330ca52-01 - new alias.
13:01:51.102717 vgs[17818] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-path/pci-0000:00:04.0-part1 - new alias.
13:01:51.102737 vgs[17818] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-path/virtio-pci-0000:00:04.0-part1 - new alias.
13:01:51.102756 vgs[17818] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-uuid/7f2149ce-65c6-462e-a474-58ad0b3e30d9 - new alias.
13:01:51.102888 vgs[17818] device/dev-cache.c:711  Found dev 252:2 /dev/vda2 - new.
13:01:51.102978 vgs[17818] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-id/lvm-pv-uuid-Kpn5xP-D2Dw-gFWh-0AcV-LcKJ-9Mxb-Gju3LM - new alias.
13:01:51.103007 vgs[17818] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-partuuid/8330ca52-02 - new alias.
13:01:51.103027 vgs[17818] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-path/pci-0000:00:04.0-part2 - new alias.
13:01:51.103046 vgs[17818] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-path/virtio-pci-0000:00:04.0-part2 - new alias.
13:01:51.103186 vgs[17818] device/dev-cache.c:711  Found dev 8:0 /dev/sda - new.
13:01:51.103275 vgs[17818] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-id/scsi-36001405dcde3394ccc24cf2bcd9627fc - new alias.
13:01:51.103305 vgs[17818] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-id/wwn-0x6001405dcde3394ccc24cf2bcd9627fc - new alias.
13:01:51.103324 vgs[17818] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-path/ip-10.37.166.15:3260-iscsi-iqn.2013-05.com.redhat.beaker.cluster-qe:cluster104397.disk-001-path-001-lun-0 - new alias.
13:01:51.103463 vgs[17818] device/dev-cache.c:711  Found dev 253:0 /dev/dm-0 - new.
13:01:51.103547 vgs[17818] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-id/dm-name-rhel_virt--043-root - new alias.
13:01:51.103568 vgs[17818] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-id/dm-uuid-LVM-s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo15xHYmy3HMs5UNvtLFUc1usUK6GtlwgKE - new alias.
13:01:51.103596 vgs[17818] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-uuid/5c33dfcf-b7d6-4527-a830-82946fd2e890 - new alias.
13:01:51.103634 vgs[17818] device/dev-cache.c:748  Found dev 253:0 /dev/mapper/rhel_virt--043-root - new alias.
13:01:51.103669 vgs[17818] device/dev-cache.c:748  Found dev 253:0 /dev/rhel_virt-043/root - new alias.
13:01:51.103772 vgs[17818] device/dev-cache.c:711  Found dev 253:1 /dev/dm-1 - new.
13:01:51.103866 vgs[17818] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-id/dm-name-rhel_virt--043-swap - new alias.
13:01:51.103886 vgs[17818] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-id/dm-uuid-LVM-s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo10byl1JwCNmmESVydQAdFvcAt8TdDgJz7 - new alias.
13:01:51.103931 vgs[17818] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-uuid/66c225bf-7023-4257-8caa-130b1c810045 - new alias.
13:01:51.103966 vgs[17818] device/dev-cache.c:748  Found dev 253:1 /dev/mapper/rhel_virt--043-swap - new alias.
13:01:51.103985 vgs[17818] device/dev-cache.c:748  Found dev 253:1 /dev/rhel_virt-043/swap - new alias.
13:01:51.104455 vgs[17818] label/label.c:912  Filtering devices to scan
13:01:51.104743 vgs[17818] device/dev-io.c:430  Opened /dev/sda RO O_DIRECT
13:01:51.104765 vgs[17818] device/dev-io.c:185  /dev/sda: size is 2097152 sectors
13:01:51.104790 vgs[17818] device/dev-io.c:469  Closed /dev/sda
13:01:51.104836 vgs[17818] filters/filter-partitioned.c:31  filter partitioned deferred /dev/sda
13:01:51.104847 vgs[17818] filters/filter-signature.c:32  filter signature deferred /dev/sda
13:01:51.105071 vgs[17818] filters/filter-md.c:101  filter md deferred /dev/sda
13:01:51.105092 vgs[17818] filters/filter-persistent.c:125  filter cache deferred /dev/sda
13:01:51.105113 vgs[17818] device/dev-io.c:430  Opened /dev/vda RO O_DIRECT
13:01:51.105125 vgs[17818] device/dev-io.c:185  /dev/vda: size is 16777216 sectors
13:01:51.105136 vgs[17818] device/dev-io.c:469  Closed /dev/vda
13:01:51.105156 vgs[17818] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda
13:01:51.105166 vgs[17818] filters/filter-signature.c:32  filter signature deferred /dev/vda
13:01:51.105372 vgs[17818] filters/filter-md.c:101  filter md deferred /dev/vda
13:01:51.105385 vgs[17818] filters/filter-persistent.c:125  filter cache deferred /dev/vda
13:01:51.105443 vgs[17818] device_mapper/ioctl/libdm-iface.c:1872  dm version   [ opencount flush ]   [16384] (*1)
13:01:51.105471 vgs[17818] device_mapper/ioctl/libdm-iface.c:1872  dm status   (253:0) [ noopencount noflush ]   [16384] (*1)
13:01:51.105512 vgs[17818] filters/filter-usable.c:146  /dev/rhel_virt-043/root: Skipping unusable device.
13:01:51.105523 vgs[17818] filters/filter-persistent.c:134  filter caching bad /dev/rhel_virt-043/root
13:01:51.105545 vgs[17818] device/dev-io.c:430  Opened /dev/vda1 RO O_DIRECT
13:01:51.105556 vgs[17818] device/dev-io.c:185  /dev/vda1: size is 2097152 sectors
13:01:51.105568 vgs[17818] device/dev-io.c:469  Closed /dev/vda1
13:01:51.105577 vgs[17818] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda1
13:01:51.105594 vgs[17818] filters/filter-signature.c:32  filter signature deferred /dev/vda1
13:01:51.105804 vgs[17818] filters/filter-md.c:101  filter md deferred /dev/vda1
13:01:51.105816 vgs[17818] filters/filter-persistent.c:125  filter cache deferred /dev/vda1
13:01:51.105830 vgs[17818] device_mapper/ioctl/libdm-iface.c:1872  dm status   (253:1) [ noopencount noflush ]   [16384] (*1)
13:01:51.105860 vgs[17818] filters/filter-usable.c:146  /dev/rhel_virt-043/swap: Skipping unusable device.
13:01:51.105871 vgs[17818] filters/filter-persistent.c:134  filter caching bad /dev/rhel_virt-043/swap
13:01:51.105893 vgs[17818] device/dev-io.c:430  Opened /dev/vda2 RO O_DIRECT
13:01:51.105904 vgs[17818] device/dev-io.c:185  /dev/vda2: size is 14678016 sectors
13:01:51.105915 vgs[17818] device/dev-io.c:469  Closed /dev/vda2
13:01:51.105925 vgs[17818] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda2
13:01:51.105935 vgs[17818] filters/filter-signature.c:32  filter signature deferred /dev/vda2
13:01:51.106168 vgs[17818] filters/filter-md.c:101  filter md deferred /dev/vda2
13:01:51.106180 vgs[17818] filters/filter-persistent.c:125  filter cache deferred /dev/vda2
13:01:51.106504 vgs[17818] label/hints.c:613  Reading hint file
13:01:51.106545 vgs[17818] config/config.c:1481  devices/global_filter not found in config: defaulting to global_filter = [ "a|.*/|" ]
13:01:51.106563 vgs[17818] config/config.c:1481  devices/filter not found in config: defaulting to filter = [ "a|.*/|" ]
13:01:51.106580 vgs[17818] label/hints.c:724  add hint /dev/vda2 Kpn5xPD2DwgFWh0AcVLcKJ9MxbGju3LM 252:2 vg:rhel_virt-043
13:01:51.106600 vgs[17818] device/dev-io.c:162  /dev/sda: using cached size 2097152 sectors
13:01:51.106613 vgs[17818] device/dev-io.c:162  /dev/vda: using cached size 16777216 sectors
13:01:51.106650 vgs[17818] device/dev-io.c:162  /dev/vda1: using cached size 2097152 sectors
13:01:51.106683 vgs[17818] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:51.106694 vgs[17818] label/hints.c:764  accept hints found 1
13:01:51.106707 vgs[17818] label/hints.c:1297  get_hints: applied using 1 other 3
13:01:51.106717 vgs[17818] label/label.c:983  Will scan 1 devices skip 3
13:01:51.106726 vgs[17818] label/label.c:656  Scanning 1 devices for VG info
13:01:51.106920 vgs[17818] label/label.c:692  Scanning submitted 1 reads
13:01:51.107571 vgs[17818] label/label.c:711  Processing data from device /dev/vda2 252:2 fd 5 block 0x55eeb28b2310
13:01:51.107591 vgs[17818] label/label.c:377  Scan filtering /dev/vda2
13:01:51.107602 vgs[17818] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:51.107624 vgs[17818] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:51.107867 vgs[17818] filters/filter-persistent.c:134  filter caching good /dev/vda2
13:01:51.107884 vgs[17818] label/label.c:321  /dev/vda2: lvm2 label detected at sector 1
13:01:51.107901 vgs[17818] cache/lvmcache.c:1312  lvmcache /dev/vda2: now in VG #orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
13:01:51.107914 vgs[17818] format_text/text_label.c:466  /dev/vda2: PV header extension version 2 found
13:01:51.107925 vgs[17818] format_text/text_label.c:499  Scanning /dev/vda2 mda1 summary.
13:01:51.107935 vgs[17818] format_text/format-text.c:168  Reading mda header sector from /dev/vda2 at 4096
13:01:51.107954 vgs[17818] format_text/import.c:58  Reading metadata summary from /dev/vda2 at 7168 size 1441 (+0)
13:01:51.108016 vgs[17818] format_text/format-text.c:1444  Found metadata summary on /dev/vda2 at 7168 size 1441 for VG rhel_virt-043
13:01:51.108032 vgs[17818] cache/lvmcache.c:264  lvmcache has no info for vgname "rhel_virt-043" with VGID s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1.
13:01:51.108044 vgs[17818] cache/lvmcache.c:264  lvmcache has no info for vgname "rhel_virt-043".
13:01:51.108055 vgs[17818] cache/lvmcache.c:1312  lvmcache /dev/vda2: now in VG rhel_virt-043 with 1 mda(s).
13:01:51.108065 vgs[17818] cache/lvmcache.c:1137  lvmcache /dev/vda2: VG rhel_virt-043: set VGID to s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1.
13:01:51.108075 vgs[17818] cache/lvmcache.c:1499  lvmcache /dev/vda2 mda1 VG rhel_virt-043 set seqno 3 checksum a22e5305 mda_size 1441
13:01:51.108086 vgs[17818] cache/lvmcache.c:1349  lvmcache /dev/vda2: VG rhel_virt-043: set creation host to virt-043.cluster-qe.lab.eng.brq.redhat.com.
13:01:51.108097 vgs[17818] format_text/text_label.c:519  Scanned /dev/vda2 mda1 seqno 3
13:01:51.108107 vgs[17818] label/label.c:790  Scanned devices: read errors 0 process errors 0 failed 0
13:01:51.108119 vgs[17818] cache/lvmcache.c:945  Found VG info for 1 VGs
13:01:51.108129 vgs[17818] toollib.c:2263  Obtaining the complete list of VGs to process
13:01:51.108140 vgs[17818] toollib.c:1975  Processing VG rhel_virt-043 s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:51.108168 vgs[17818] misc/lvm-flock.c:230  Locking /run/lock/lvm/V_rhel_virt-043 RB
13:01:51.108896 vgs[17818] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm/V_rhel_virt-043 to system_u:object_r:lvm_lock_t:s0.
13:01:51.108945 vgs[17818] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_rhel_virt-043:aux WB
13:01:51.108988 vgs[17818] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_rhel_virt-043:aux
13:01:51.109015 vgs[17818] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_rhel_virt-043 RB
13:01:51.109045 vgs[17818] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:51.109070 vgs[17818] metadata/metadata.c:4514  Reading VG rhel_virt-043 s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1
13:01:51.109082 vgs[17818] metadata/metadata.c:4558  Skipped rescanning devices for rhel_virt-043
13:01:51.109121 vgs[17818] metadata/metadata.c:4660  Reading VG rhel_virt-043 metadata from /dev/vda2 4096
13:01:51.109132 vgs[17818] format_text/format-text.c:168  Reading mda header sector from /dev/vda2 at 4096
13:01:51.109166 vgs[17818] format_text/format-text.c:304  VG rhel_virt-043 metadata check /dev/vda2 mda 4096 slot0 offset 3072 size 1441
13:01:51.109180 vgs[17818] format_text/import.c:154  Reading metadata from /dev/vda2 at 7168 size 1441 (+0)
13:01:51.109224 vgs[17818] metadata/vg.c:64  Allocated VG rhel_virt-043 at 0x55eeb28d21c0.
13:01:51.109263 vgs[17818] format_text/import_vsn1.c:541  Importing logical volume rhel_virt-043/swap.
13:01:51.109278 vgs[17818] format_text/import_vsn1.c:541  Importing logical volume rhel_virt-043/root.
13:01:51.109307 vgs[17818] format_text/format-text.c:459  Found metadata on /dev/vda2 at 7168 size 1441 for VG rhel_virt-043
13:01:51.109320 vgs[17818] cache/lvmcache.c:1675  lvmcache_update_vg rhel_virt-043 for info /dev/vda2
13:01:51.109335 vgs[17818] device_mapper/libdm-config.c:1014  metadata/lvs_history_retention_time not found in config: defaulting to 0
13:01:51.109373 vgs[17818] metadata/pv_manip.c:417  /dev/vda2 0:      0    205: swap(0:0)
13:01:51.109386 vgs[17818] metadata/pv_manip.c:417  /dev/vda2 1:    205   1586: root(0:0)
13:01:51.109398 vgs[17818] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:51.109412 vgs[17818] toollib.c:2005  Running command for VG rhel_virt-043 s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:51.109579 vgs[17818] metadata/vg.c:79  Freeing VG rhel_virt-043 at 0x55eeb28d61d0.
13:01:51.109596 vgs[17818] mm/memlock.c:594  Unlock: Memlock counters: prioritized:0 locked:0 critical:0 daemon:0 suspended:0
13:01:51.109607 vgs[17818] activate/fs.c:492  Syncing device names
13:01:51.109623 vgs[17818] misc/lvm-flock.c:84  Unlocking /run/lock/lvm/V_rhel_virt-043
13:01:51.109635 vgs[17818] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_rhel_virt-043
13:01:51.109662 vgs[17818] metadata/vg.c:79  Freeing VG rhel_virt-043 at 0x55eeb28d21c0.
13:01:51.109677 vgs[17818] device_mapper/libdm-config.c:1086  report/compact_output not found in config: defaulting to 0
13:01:51.109694 vgs[17818] device_mapper/libdm-report.c:4220  VG            Attr   Ext   #PV #LV #SN VSize  VFree VG UUID                                VProfile
13:01:51.109713 vgs[17818] device_mapper/libdm-report.c:4683  rhel_virt-043 wz--n- 4.00m   1   2   0 <7.00g    0  s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:51.109722 vgs[17818] misc/lvm-flock.c:84  Unlocking /run/lock/lvm/P_global
13:01:51.109734 vgs[17818] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/P_global
13:01:51.109759 vgs[17818] cache/lvmcache.c:1936  Dropping VG info
13:01:51.109777 vgs[17818] cache/lvmcache.c:264  lvmcache has no info for vgname "#orphans_lvm2" with VGID #orphans_lvm2.
13:01:51.109789 vgs[17818] cache/lvmcache.c:264  lvmcache has no info for vgname "#orphans_lvm2".
13:01:51.109799 vgs[17818] cache/lvmcache.c:1314  lvmcache: Initialised VG #orphans_lvm2.
13:01:51.113408 vgs[17818] commands/toolcontext.c:1814  Reloading config files
13:01:51.113433 vgs[17818] activate/fs.c:492  Syncing device names
13:01:51.113444 vgs[17818] cache/lvmcache.c:1936  Dropping VG info
13:01:51.113466 vgs[17818] metadata/vg.c:79  Freeing VG #orphans_lvm2 at 0x55eeb27bd040.
13:01:51.113505 vgs[17818] config/config.c:283  Loading config file: /etc/lvm/lvm.conf
13:01:51.113528 vgs[17818] device/dev-io.c:430  Opened /etc/lvm/lvm.conf RO
13:01:51.113866 vgs[17818] device/dev-io.c:469  Closed /etc/lvm/lvm.conf

> [root@virt-043 ~]# vgs --foreign --config devices/hints=none -vvvv
13:01:55.778873 vgs[17819] lvmcmdline.c:2896  Parsing: vgs --foreign --config devices/hints=none -vvvv
13:01:55.778920 vgs[17819] lvmcmdline.c:1887  Recognised command vgs_general (id 147 / enum 132).
13:01:55.778940 vgs[17819] commands/toolcontext.c:1814  Reloading config files
13:01:55.778958 vgs[17819] activate/fs.c:492  Syncing device names
13:01:55.778982 vgs[17819] cache/lvmcache.c:1936  Dropping VG info
13:01:55.779007 vgs[17819] metadata/vg.c:79  Freeing VG #orphans_lvm2 at 0x55f2959a1680.
13:01:55.779035 vgs[17819] config/config.c:283  Loading config file: /etc/lvm/lvm.conf
13:01:55.779058 vgs[17819] device/dev-io.c:430  Opened /etc/lvm/lvm.conf RO
13:01:55.779425 vgs[17819] device/dev-io.c:469  Closed /etc/lvm/lvm.conf
13:01:55.780103 vgs[17819] lvmcmdline.c:2953  DEGRADED MODE. Incomplete RAID LVs will be processed.
13:01:55.780126 vgs[17819] lvmcmdline.c:2959  Processing command: vgs --foreign --config devices/hints=none -vvvv
13:01:55.780137 vgs[17819] lvmcmdline.c:2960  Command pid: 17819
13:01:55.780163 vgs[17819] lvmcmdline.c:2961  System ID: virt-043.cluster-qe.lab.eng.brq.redhat.com
13:01:55.780175 vgs[17819] lvmcmdline.c:2964  O_DIRECT will be used
13:01:55.780186 vgs[17819] device_mapper/libdm-config.c:1014  global/locking_type not found in config: defaulting to 1
13:01:55.780198 vgs[17819] locking/locking.c:143  File locking settings: readonly:0 sysinit:0 ignorelockingfailure:0 global/metadata_read_only:0 global/wait_for_locks:1.
13:01:55.789947 vgs[17819] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm to system_u:object_r:lvm_lock_t:s0.
13:01:55.790102 vgs[17819] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:55.790164 vgs[17819] device_mapper/libdm-config.c:987  devices/md_component_checks not found in config: defaulting to auto
13:01:55.790179 vgs[17819] lvmcmdline.c:2804  Using md_component_checks auto use_full_md_check 0
13:01:55.790206 vgs[17819] device_mapper/libdm-config.c:987  report/output_format not found in config: defaulting to basic
13:01:55.790221 vgs[17819] device_mapper/libdm-config.c:1086  log/report_command_log not found in config: defaulting to 0
13:01:55.790237 vgs[17819] device_mapper/libdm-config.c:1086  report/aligned not found in config: defaulting to 1
13:01:55.790248 vgs[17819] device_mapper/libdm-config.c:1086  report/buffered not found in config: defaulting to 1
13:01:55.790259 vgs[17819] device_mapper/libdm-config.c:1086  report/headings not found in config: defaulting to 1
13:01:55.790269 vgs[17819] device_mapper/libdm-config.c:987  report/separator not found in config: defaulting to
13:01:55.790280 vgs[17819] device_mapper/libdm-config.c:1086  report/prefixes not found in config: defaulting to 0
13:01:55.790290 vgs[17819] device_mapper/libdm-config.c:1086  report/quoted not found in config: defaulting to 1
13:01:55.790300 vgs[17819] device_mapper/libdm-config.c:1086  report/columns_as_rows not found in config: defaulting to 0
13:01:55.790313 vgs[17819] device_mapper/libdm-config.c:987  report/vgs_sort not found in config: defaulting to vg_name
13:01:55.790323 vgs[17819] device_mapper/libdm-config.c:987  report/vgs_cols_verbose not found in config: defaulting to vg_name,vg_attr,vg_extent_size,pv_count,lv_count,snap_count,vg_size,vg_free,vg_uuid,vg_profile
13:01:55.790336 vgs[17819] device_mapper/libdm-config.c:987  report/compact_output_cols not found in config: defaulting to
13:01:55.790537 vgs[17819] toollib.c:2214  Processing each VG
13:01:55.790557 vgs[17819] misc/lvm-flock.c:230  Locking /run/lock/lvm/P_global RB
13:01:55.792493 vgs[17819] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm/P_global to system_u:object_r:lvm_lock_t:s0.
13:01:55.792533 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/P_global:aux WB
13:01:55.792593 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/P_global:aux
13:01:55.792628 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/P_global RB
13:01:55.792659 vgs[17819] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:55.792685 vgs[17819] cache/lvmcache.c:857  Finding VG info
13:01:55.792731 vgs[17819] filters/filter-sysfs.c:328  Sysfs filter initialised.
13:01:55.792741 vgs[17819] filters/filter-internal.c:79  Internal filter initialised.
13:01:55.792755 vgs[17819] filters/filter-type.c:58  LVM type filter initialised.
13:01:55.792767 vgs[17819] filters/filter-usable.c:202  Usable device filter initialised (scan_lvs 0).
13:01:55.792781 vgs[17819] filters/filter-mpath.c:343  mpath filter initialised.
13:01:55.792791 vgs[17819] filters/filter-partitioned.c:71  Partitioned filter initialised.
13:01:55.792800 vgs[17819] filters/filter-signature.c:86  signature filter initialised.
13:01:55.792812 vgs[17819] filters/filter-md.c:150  MD filter initialised.
13:01:55.792823 vgs[17819] filters/filter-composite.c:100  Composite filter initialised.
13:01:55.792837 vgs[17819] filters/filter-persistent.c:190  Persistent filter initialised.
13:01:55.792847 vgs[17819] label/label.c:889  Finding devices to scan
13:01:55.792857 vgs[17819] device/dev-cache.c:1172  Creating list of system devices.
13:01:55.794527 vgs[17819] device/dev-cache.c:711  Found dev 252:0 /dev/vda - new.
13:01:55.794603 vgs[17819] device/dev-cache.c:748  Found dev 252:0 /dev/disk/by-path/pci-0000:00:04.0 - new alias.
13:01:55.794643 vgs[17819] device/dev-cache.c:748  Found dev 252:0 /dev/disk/by-path/virtio-pci-0000:00:04.0 - new alias.
13:01:55.794762 vgs[17819] device/dev-cache.c:711  Found dev 252:1 /dev/vda1 - new.
13:01:55.794847 vgs[17819] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-partuuid/8330ca52-01 - new alias.
13:01:55.794868 vgs[17819] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-path/pci-0000:00:04.0-part1 - new alias.
13:01:55.794888 vgs[17819] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-path/virtio-pci-0000:00:04.0-part1 - new alias.
13:01:55.794909 vgs[17819] device/dev-cache.c:748  Found dev 252:1 /dev/disk/by-uuid/7f2149ce-65c6-462e-a474-58ad0b3e30d9 - new alias.
13:01:55.795060 vgs[17819] device/dev-cache.c:711  Found dev 252:2 /dev/vda2 - new.
13:01:55.795197 vgs[17819] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-id/lvm-pv-uuid-Kpn5xP-D2Dw-gFWh-0AcV-LcKJ-9Mxb-Gju3LM - new alias.
13:01:55.795223 vgs[17819] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-partuuid/8330ca52-02 - new alias.
13:01:55.795243 vgs[17819] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-path/pci-0000:00:04.0-part2 - new alias.
13:01:55.795262 vgs[17819] device/dev-cache.c:748  Found dev 252:2 /dev/disk/by-path/virtio-pci-0000:00:04.0-part2 - new alias.
13:01:55.795422 vgs[17819] device/dev-cache.c:711  Found dev 8:0 /dev/sda - new.
13:01:55.795516 vgs[17819] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-id/scsi-36001405dcde3394ccc24cf2bcd9627fc - new alias.
13:01:55.795540 vgs[17819] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-id/wwn-0x6001405dcde3394ccc24cf2bcd9627fc - new alias.
13:01:55.795559 vgs[17819] device/dev-cache.c:748  Found dev 8:0 /dev/disk/by-path/ip-10.37.166.15:3260-iscsi-iqn.2013-05.com.redhat.beaker.cluster-qe:cluster104397.disk-001-path-001-lun-0 - new alias.
13:01:55.795658 vgs[17819] device/dev-cache.c:711  Found dev 253:0 /dev/dm-0 - new.
13:01:55.795741 vgs[17819] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-id/dm-name-rhel_virt--043-root - new alias.
13:01:55.795763 vgs[17819] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-id/dm-uuid-LVM-s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo15xHYmy3HMs5UNvtLFUc1usUK6GtlwgKE - new alias.
13:01:55.795792 vgs[17819] device/dev-cache.c:748  Found dev 253:0 /dev/disk/by-uuid/5c33dfcf-b7d6-4527-a830-82946fd2e890 - new alias.
13:01:55.795823 vgs[17819] device/dev-cache.c:748  Found dev 253:0 /dev/mapper/rhel_virt--043-root - new alias.
13:01:55.795849 vgs[17819] device/dev-cache.c:748  Found dev 253:0 /dev/rhel_virt-043/root - new alias.
13:01:55.795944 vgs[17819] device/dev-cache.c:711  Found dev 253:1 /dev/dm-1 - new.
13:01:55.796026 vgs[17819] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-id/dm-name-rhel_virt--043-swap - new alias.
13:01:55.796047 vgs[17819] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-id/dm-uuid-LVM-s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo10byl1JwCNmmESVydQAdFvcAt8TdDgJz7 - new alias.
13:01:55.796075 vgs[17819] device/dev-cache.c:748  Found dev 253:1 /dev/disk/by-uuid/66c225bf-7023-4257-8caa-130b1c810045 - new alias.
13:01:55.796103 vgs[17819] device/dev-cache.c:748  Found dev 253:1 /dev/mapper/rhel_virt--043-swap - new alias.
13:01:55.796122 vgs[17819] device/dev-cache.c:748  Found dev 253:1 /dev/rhel_virt-043/swap - new alias.
13:01:55.796587 vgs[17819] label/label.c:912  Filtering devices to scan
13:01:55.796835 vgs[17819] device/dev-io.c:430  Opened /dev/sda RO O_DIRECT
13:01:55.796851 vgs[17819] device/dev-io.c:185  /dev/sda: size is 2097152 sectors
13:01:55.796874 vgs[17819] device/dev-io.c:469  Closed /dev/sda
13:01:55.796919 vgs[17819] filters/filter-partitioned.c:31  filter partitioned deferred /dev/sda
13:01:55.796930 vgs[17819] filters/filter-signature.c:32  filter signature deferred /dev/sda
13:01:55.797179 vgs[17819] filters/filter-md.c:101  filter md deferred /dev/sda
13:01:55.797191 vgs[17819] filters/filter-persistent.c:125  filter cache deferred /dev/sda
13:01:55.797213 vgs[17819] device/dev-io.c:430  Opened /dev/vda RO O_DIRECT
13:01:55.797225 vgs[17819] device/dev-io.c:185  /dev/vda: size is 16777216 sectors
13:01:55.797236 vgs[17819] device/dev-io.c:469  Closed /dev/vda
13:01:55.797246 vgs[17819] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda
13:01:55.797255 vgs[17819] filters/filter-signature.c:32  filter signature deferred /dev/vda
13:01:55.797463 vgs[17819] filters/filter-md.c:101  filter md deferred /dev/vda
13:01:55.797475 vgs[17819] filters/filter-persistent.c:125  filter cache deferred /dev/vda
13:01:55.797510 vgs[17819] device_mapper/ioctl/libdm-iface.c:1872  dm version   [ opencount flush ]   [16384] (*1)
13:01:55.797535 vgs[17819] device_mapper/ioctl/libdm-iface.c:1872  dm status   (253:0) [ noopencount noflush ]   [16384] (*1)
13:01:55.797575 vgs[17819] filters/filter-usable.c:146  /dev/rhel_virt-043/root: Skipping unusable device.
13:01:55.797586 vgs[17819] filters/filter-persistent.c:134  filter caching bad /dev/rhel_virt-043/root
13:01:55.797607 vgs[17819] device/dev-io.c:430  Opened /dev/vda1 RO O_DIRECT
13:01:55.797618 vgs[17819] device/dev-io.c:185  /dev/vda1: size is 2097152 sectors
13:01:55.797629 vgs[17819] device/dev-io.c:469  Closed /dev/vda1
13:01:55.797639 vgs[17819] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda1
13:01:55.797648 vgs[17819] filters/filter-signature.c:32  filter signature deferred /dev/vda1
13:01:55.797856 vgs[17819] filters/filter-md.c:101  filter md deferred /dev/vda1
13:01:55.797868 vgs[17819] filters/filter-persistent.c:125  filter cache deferred /dev/vda1
13:01:55.797882 vgs[17819] device_mapper/ioctl/libdm-iface.c:1872  dm status   (253:1) [ noopencount noflush ]   [16384] (*1)
13:01:55.797904 vgs[17819] filters/filter-usable.c:146  /dev/rhel_virt-043/swap: Skipping unusable device.
13:01:55.797914 vgs[17819] filters/filter-persistent.c:134  filter caching bad /dev/rhel_virt-043/swap
13:01:55.797935 vgs[17819] device/dev-io.c:430  Opened /dev/vda2 RO O_DIRECT
13:01:55.797946 vgs[17819] device/dev-io.c:185  /dev/vda2: size is 14678016 sectors
13:01:55.797957 vgs[17819] device/dev-io.c:469  Closed /dev/vda2
13:01:55.797966 vgs[17819] filters/filter-partitioned.c:31  filter partitioned deferred /dev/vda2
13:01:55.797976 vgs[17819] filters/filter-signature.c:32  filter signature deferred /dev/vda2
13:01:55.798213 vgs[17819] filters/filter-md.c:101  filter md deferred /dev/vda2
13:01:55.798225 vgs[17819] filters/filter-persistent.c:125  filter cache deferred /dev/vda2
13:01:55.798320 vgs[17819] label/label.c:983  Will scan 4 devices skip 0
13:01:55.798332 vgs[17819] label/label.c:656  Scanning 4 devices for VG info
13:01:55.800421 vgs[17819] label/label.c:692  Scanning submitted 4 reads
13:01:55.801256 vgs[17819] label/label.c:711  Processing data from device /dev/sda 8:0 fd 5 block 0x55f295aa77f0
13:01:55.801276 vgs[17819] label/label.c:377  Scan filtering /dev/sda
13:01:55.801289 vgs[17819] device/dev-io.c:162  /dev/sda: using cached size 2097152 sectors
13:01:55.801430 vgs[17819] device/dev-io.c:162  /dev/sda: using cached size 2097152 sectors
13:01:55.801692 vgs[17819] filters/filter-persistent.c:134  filter caching good /dev/sda
13:01:55.801711 vgs[17819] label/label.c:321  /dev/sda: lvm2 label detected at sector 1
13:01:55.801732 vgs[17819] cache/lvmcache.c:1312  lvmcache /dev/sda: now in VG #orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
13:01:55.801746 vgs[17819] format_text/text_label.c:466  /dev/sda: PV header extension version 2 found
13:01:55.801756 vgs[17819] format_text/text_label.c:499  Scanning /dev/sda mda1 summary.
13:01:55.801767 vgs[17819] format_text/format-text.c:168  Reading mda header sector from /dev/sda at 4096
13:01:55.801789 vgs[17819] format_text/import.c:58  Reading metadata summary from /dev/sda at 5632 size 1249 (+0)
13:01:55.801859 vgs[17819] format_text/format-text.c:1444  Found metadata summary on /dev/sda at 5632 size 1249 for VG shared
13:01:55.801874 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "shared" with VGID 1D2zIrkWaJlm6VS7G5dmYQKKuqZOYY41.
13:01:55.801886 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "shared".
13:01:55.801897 vgs[17819] cache/lvmcache.c:1312  lvmcache /dev/sda: now in VG shared with 1 mda(s).
13:01:55.801908 vgs[17819] cache/lvmcache.c:1137  lvmcache /dev/sda: VG shared: set VGID to 1D2zIrkWaJlm6VS7G5dmYQKKuqZOYY41.
13:01:55.801918 vgs[17819] cache/lvmcache.c:1499  lvmcache /dev/sda mda1 VG shared set seqno 2 checksum 6ef1d3e5 mda_size 1249
13:01:55.801929 vgs[17819] cache/lvmcache.c:1349  lvmcache /dev/sda: VG shared: set creation host to virt-042.cluster-qe.lab.eng.brq.redhat.com.
13:01:55.801939 vgs[17819] cache/lvmcache.c:1385  lvmcache /dev/sda: VG shared: set system_id to virt-042.cluster-qe.lab.eng.brq.redhat.com.
13:01:55.801949 vgs[17819] format_text/text_label.c:519  Scanned /dev/sda mda1 seqno 2
13:01:55.801958 vgs[17819] label/label.c:711  Processing data from device /dev/vda 252:0 fd 6 block 0x55f295aa7830
13:01:55.801969 vgs[17819] label/label.c:377  Scan filtering /dev/vda
13:01:55.801978 vgs[17819] device/dev-io.c:162  /dev/vda: using cached size 16777216 sectors
13:01:55.801992 vgs[17819] filters/filter-partitioned.c:38  /dev/vda: Skipping: Partition table signature found
13:01:55.802001 vgs[17819] filters/filter-persistent.c:134  filter caching bad /dev/vda
13:01:55.802011 vgs[17819] label/label.c:389  /dev/vda: Not processing filtered
13:01:55.802020 vgs[17819] label/label.c:392  <backtrace>
13:01:55.802037 vgs[17819] label/label.c:711  Processing data from device /dev/vda1 252:1 fd 7 block 0x55f295aa7870
13:01:55.802048 vgs[17819] label/label.c:377  Scan filtering /dev/vda1
13:01:55.802057 vgs[17819] device/dev-io.c:162  /dev/vda1: using cached size 2097152 sectors
13:01:55.802089 vgs[17819] device/dev-io.c:162  /dev/vda1: using cached size 2097152 sectors
13:01:55.802327 vgs[17819] filters/filter-persistent.c:134  filter caching good /dev/vda1
13:01:55.802341 vgs[17819] label/label.c:413  /dev/vda1: No lvm label detected
13:01:55.802380 vgs[17819] label/label.c:418  <backtrace>
13:01:55.802393 vgs[17819] label/label.c:711  Processing data from device /dev/vda2 252:2 fd 8 block 0x55f295aa78b0
13:01:55.802403 vgs[17819] label/label.c:377  Scan filtering /dev/vda2
13:01:55.802413 vgs[17819] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:55.802444 vgs[17819] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:55.802665 vgs[17819] filters/filter-persistent.c:134  filter caching good /dev/vda2
13:01:55.802679 vgs[17819] label/label.c:321  /dev/vda2: lvm2 label detected at sector 1
13:01:55.802693 vgs[17819] cache/lvmcache.c:1312  lvmcache /dev/vda2: now in VG #orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
13:01:55.802704 vgs[17819] format_text/text_label.c:466  /dev/vda2: PV header extension version 2 found
13:01:55.802713 vgs[17819] format_text/text_label.c:499  Scanning /dev/vda2 mda1 summary.
13:01:55.802722 vgs[17819] format_text/format-text.c:168  Reading mda header sector from /dev/vda2 at 4096
13:01:55.802740 vgs[17819] format_text/import.c:58  Reading metadata summary from /dev/vda2 at 7168 size 1441 (+0)
13:01:55.802795 vgs[17819] format_text/format-text.c:1444  Found metadata summary on /dev/vda2 at 7168 size 1441 for VG rhel_virt-043
13:01:55.802807 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "rhel_virt-043" with VGID s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1.
13:01:55.802818 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "rhel_virt-043".
13:01:55.802828 vgs[17819] cache/lvmcache.c:1312  lvmcache /dev/vda2: now in VG rhel_virt-043 with 1 mda(s).
13:01:55.802839 vgs[17819] cache/lvmcache.c:1137  lvmcache /dev/vda2: VG rhel_virt-043: set VGID to s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1.
13:01:55.802848 vgs[17819] cache/lvmcache.c:1499  lvmcache /dev/vda2 mda1 VG rhel_virt-043 set seqno 3 checksum a22e5305 mda_size 1441
13:01:55.802859 vgs[17819] cache/lvmcache.c:1349  lvmcache /dev/vda2: VG rhel_virt-043: set creation host to virt-043.cluster-qe.lab.eng.brq.redhat.com.
13:01:55.802869 vgs[17819] format_text/text_label.c:519  Scanned /dev/vda2 mda1 seqno 3
13:01:55.802878 vgs[17819] label/label.c:790  Scanned devices: read errors 0 process errors 0 failed 0
13:01:55.802889 vgs[17819] cache/lvmcache.c:945  Found VG info for 2 VGs
13:01:55.802899 vgs[17819] toollib.c:2263  Obtaining the complete list of VGs to process
13:01:55.802911 vgs[17819] toollib.c:1975  Processing VG rhel_virt-043 s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:55.802926 vgs[17819] misc/lvm-flock.c:230  Locking /run/lock/lvm/V_rhel_virt-043 RB
13:01:55.803728 vgs[17819] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm/V_rhel_virt-043 to system_u:object_r:lvm_lock_t:s0.
13:01:55.803783 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_rhel_virt-043:aux WB
13:01:55.803832 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_rhel_virt-043:aux
13:01:55.803861 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_rhel_virt-043 RB
13:01:55.803892 vgs[17819] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:55.803917 vgs[17819] metadata/metadata.c:4514  Reading VG rhel_virt-043 s4GMfRtsrEcELMI7oXuzCmDOUxXZxTo1
13:01:55.803929 vgs[17819] metadata/metadata.c:4558  Skipped rescanning devices for rhel_virt-043
13:01:55.803961 vgs[17819] metadata/metadata.c:4660  Reading VG rhel_virt-043 metadata from /dev/vda2 4096
13:01:55.803972 vgs[17819] format_text/format-text.c:168  Reading mda header sector from /dev/vda2 at 4096
13:01:55.803988 vgs[17819] format_text/format-text.c:304  VG rhel_virt-043 metadata check /dev/vda2 mda 4096 slot0 offset 3072 size 1441
13:01:55.804001 vgs[17819] format_text/import.c:154  Reading metadata from /dev/vda2 at 7168 size 1441 (+0)
13:01:55.804045 vgs[17819] metadata/vg.c:64  Allocated VG rhel_virt-043 at 0x55f295abff40.
13:01:55.804091 vgs[17819] format_text/import_vsn1.c:541  Importing logical volume rhel_virt-043/swap.
13:01:55.804107 vgs[17819] format_text/import_vsn1.c:541  Importing logical volume rhel_virt-043/root.
13:01:55.804138 vgs[17819] format_text/format-text.c:459  Found metadata on /dev/vda2 at 7168 size 1441 for VG rhel_virt-043
13:01:55.804169 vgs[17819] cache/lvmcache.c:1675  lvmcache_update_vg rhel_virt-043 for info /dev/vda2
13:01:55.804186 vgs[17819] device_mapper/libdm-config.c:1014  metadata/lvs_history_retention_time not found in config: defaulting to 0
13:01:55.804198 vgs[17819] metadata/pv_manip.c:417  /dev/vda2 0:      0    205: swap(0:0)
13:01:55.804209 vgs[17819] metadata/pv_manip.c:417  /dev/vda2 1:    205   1586: root(0:0)
13:01:55.804222 vgs[17819] device/dev-io.c:162  /dev/vda2: using cached size 14678016 sectors
13:01:55.804237 vgs[17819] toollib.c:2005  Running command for VG rhel_virt-043 s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:55.804434 vgs[17819] metadata/vg.c:79  Freeing VG rhel_virt-043 at 0x55f295ac3f50.
13:01:55.804450 vgs[17819] mm/memlock.c:594  Unlock: Memlock counters: prioritized:0 locked:0 critical:0 daemon:0 suspended:0
13:01:55.804462 vgs[17819] activate/fs.c:492  Syncing device names
13:01:55.804480 vgs[17819] misc/lvm-flock.c:84  Unlocking /run/lock/lvm/V_rhel_virt-043
13:01:55.804491 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_rhel_virt-043
13:01:55.804518 vgs[17819] metadata/vg.c:79  Freeing VG rhel_virt-043 at 0x55f295abff40.
13:01:55.804530 vgs[17819] toollib.c:1975  Processing VG shared 1D2zIr-kWaJ-lm6V-S7G5-dmYQ-KKuq-ZOYY41
13:01:55.804541 vgs[17819] misc/lvm-flock.c:230  Locking /run/lock/lvm/V_shared RB
13:01:55.805081 vgs[17819] device_mapper/libdm-common.c:986  Preparing SELinux context for /run/lock/lvm/V_shared to system_u:object_r:lvm_lock_t:s0.
13:01:55.805119 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_shared:aux WB
13:01:55.805171 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_shared:aux
13:01:55.805195 vgs[17819] misc/lvm-flock.c:114  _do_flock /run/lock/lvm/V_shared RB
13:01:55.805225 vgs[17819] device_mapper/libdm-common.c:989  Resetting SELinux context to default value.
13:01:55.805249 vgs[17819] metadata/metadata.c:4514  Reading VG shared 1D2zIrkWaJlm6VS7G5dmYQKKuqZOYY41
13:01:55.805261 vgs[17819] metadata/metadata.c:4558  Skipped rescanning devices for shared
13:01:55.805275 vgs[17819] metadata/metadata.c:4660  Reading VG shared metadata from /dev/sda 4096
13:01:55.805286 vgs[17819] format_text/format-text.c:168  Reading mda header sector from /dev/sda at 4096
13:01:55.805300 vgs[17819] format_text/format-text.c:304  VG shared metadata check /dev/sda mda 4096 slot0 offset 1536 size 1249
13:01:55.805312 vgs[17819] format_text/import.c:154  Reading metadata from /dev/sda at 5632 size 1249 (+0)
13:01:55.805380 vgs[17819] metadata/vg.c:64  Allocated VG shared at 0x55f295abff40.
13:01:55.805401 vgs[17819] format_text/import_vsn1.c:541  Importing logical volume shared/shared0.
13:01:55.805422 vgs[17819] format_text/format-text.c:459  Found metadata on /dev/sda at 5632 size 1249 for VG shared
13:01:55.805434 vgs[17819] cache/lvmcache.c:1675  lvmcache_update_vg shared for info /dev/sda
13:01:55.805447 vgs[17819] device_mapper/libdm-config.c:1014  metadata/lvs_history_retention_time not found in config: defaulting to 0
13:01:55.805458 vgs[17819] metadata/pv_manip.c:417  /dev/sda 0:      0    255: shared0(0:0)
13:01:55.805474 vgs[17819] device/dev-io.c:185  /dev/sda: size is 2097152 sectors
13:01:55.805485 vgs[17819] toollib.c:2005  Running command for VG shared 1D2zIr-kWaJ-lm6V-S7G5-dmYQ-KKuq-ZOYY41
13:01:55.805821 vgs[17819] metadata/vg.c:79  Freeing VG shared at 0x55f295ac3f50.
13:01:55.805837 vgs[17819] mm/memlock.c:594  Unlock: Memlock counters: prioritized:0 locked:0 critical:0 daemon:0 suspended:0
13:01:55.805847 vgs[17819] activate/fs.c:492  Syncing device names
13:01:55.805859 vgs[17819] misc/lvm-flock.c:84  Unlocking /run/lock/lvm/V_shared
13:01:55.805870 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/V_shared
13:01:55.805898 vgs[17819] metadata/vg.c:79  Freeing VG shared at 0x55f295abff40.
13:01:55.805913 vgs[17819] device_mapper/libdm-config.c:1086  report/compact_output not found in config: defaulting to 0
13:01:55.805932 vgs[17819] device_mapper/libdm-report.c:4220  VG            Attr   Ext   #PV #LV #SN VSize    VFree VG UUID                                VProfile
13:01:55.805955 vgs[17819] device_mapper/libdm-report.c:4683  rhel_virt-043 wz--n- 4.00m   1   2   0   <7.00g    0  s4GMfR-tsrE-cELM-I7oX-uzCm-DOUx-XZxTo1
13:01:55.805965 vgs[17819] device_mapper/libdm-report.c:4683  shared        wz--n- 4.00m   1   1   0 1020.00m    0  1D2zIr-kWaJ-lm6V-S7G5-dmYQ-KKuq-ZOYY41
13:01:55.805976 vgs[17819] misc/lvm-flock.c:84  Unlocking /run/lock/lvm/P_global
13:01:55.805988 vgs[17819] misc/lvm-flock.c:47  _undo_flock /run/lock/lvm/P_global
13:01:55.806016 vgs[17819] cache/lvmcache.c:1936  Dropping VG info
13:01:55.806036 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "#orphans_lvm2" with VGID #orphans_lvm2.
13:01:55.806047 vgs[17819] cache/lvmcache.c:264  lvmcache has no info for vgname "#orphans_lvm2".
13:01:55.806058 vgs[17819] cache/lvmcache.c:1314  lvmcache: Initialised VG #orphans_lvm2.
13:01:55.810407 vgs[17819] commands/toolcontext.c:1814  Reloading config files
13:01:55.810435 vgs[17819] activate/fs.c:492  Syncing device names
13:01:55.810447 vgs[17819] cache/lvmcache.c:1936  Dropping VG info
13:01:55.810472 vgs[17819] metadata/vg.c:79  Freeing VG #orphans_lvm2 at 0x55f2959b2040.
13:01:55.810516 vgs[17819] config/config.c:283  Loading config file: /etc/lvm/lvm.conf
13:01:55.810540 vgs[17819] device/dev-io.c:430  Opened /etc/lvm/lvm.conf RO
13:01:55.810891 vgs[17819] device/dev-io.c:469  Closed /etc/lvm/lvm.conf
Comment 4 David Teigland 2019-08-12 16:51:35 UTC 
Thanks, it's a mystery how the hints are being created without sda being included (the hints should include foreign PVs, and if sda is being added to the system after the hints are created, then the hints should be refreshed to include it.)  

Please do the following:

- include the current /run/lvm/hints file
- run 'pvscan --cache -vvvv' (which refreshes the hints file)
- include the pvscan output and the new /run/lvm/hints file
Comment 5 michal novacek 2019-08-14 06:53:35 UTC 
> [root@virt-423 ~]#  vgs --foreign --config devices/hints=none
  VG            #PV #LV #SN Attr   VSize  VFree
  rhel_virt-423   1   2   0 wz--n- <7.00g    0
  shared          6   1   0 wz--n-  5.95g    0

> [root@virt-423 ~]#  vgs --foreign --config devices/hints=all
  VG            #PV #LV #SN Attr   VSize  VFree
  rhel_virt-423   1   2   0 wz--n- <7.00g    0

> [root@virt-423 ~]# file /run/lvm/hints
/run/lvm/hints: ASCII text

> [root@virt-423 ~]# cat /run/lvm/hints
# Created by lvs pid 10020 Tue Aug 13 10:46:05 2019
hints_version: 1.1
global_filter:a|.*/|
filter:a|.*/|
scan_lvs:0
scan:/dev/vda2 pvid:1lUn14ZsqFg2KsOXL1OT01R2KFNSzOu4 devn:252:2 vg:rhel_virt-423
devs_hash: 2662401870 21


> [root@virt-423 ~]# pvscan --cache -vvvv
...
08:49:06.994946 pvscan[21910] lvmcmdline.c:3065  Completed: pvscan --cache -vvvv

> [root@virt-423 ~]# cat /run/lvm/hints
# Created by pvscan pid 21910 Wed Aug 14 08:49:06 2019
hints_version: 1.1
global_filter:a|.*/|
filter:a|.*/|
scan_lvs:0
scan:/dev/vda2 pvid:1lUn14ZsqFg2KsOXL1OT01R2KFNSzOu4 devn:252:2 vg:rhel_virt-423
scan:/dev/mapper/mpatha pvid:d3fuij2MTV8xBxMoSJA9EQhrMockznpy devn:253:2 vg:shared
scan:/dev/mapper/mpathb pvid:XjoCGsRRR8YQJ6IdbJ7pchesTNlAHhyv devn:253:3 vg:shared
scan:/dev/mapper/mpathc pvid:yqsytzn9h8usz7O4S91jGLVtymOP2yPd devn:253:4 vg:shared
scan:/dev/mapper/mpathd pvid:chT5DwKjnuMobZNh5ZwQgIKH0tM5HBVv devn:253:5 vg:shared
scan:/dev/mapper/mpathe pvid:bO0nTqkLrnNGai6lPgKaCY8gJNCpjGL5 devn:253:6 vg:shared
scan:/dev/mapper/mpathf pvid:gnlot3blMPNm7k0YWzeObAYJNlQCZUu9 devn:253:7 vg:shared
devs_hash: 2662401870 21


After having run pvscan '--foreign' shows correctly the shared cache.
Comment 6 David Teigland 2019-08-14 15:55:31 UTC 
Thanks, I suspect this is related to mpath devices being different somehow. If you tried it with plain scsi devices I'm guessing it would work.

When the hints were created here:
# Created by lvs pid 10020 Tue Aug 13 10:46:05 2019

the mpath devices existed with non-zero size, but when they were scanned they did not look like PVs.

Then when the hints were recreated here:
# Created by pvscan pid 21910 Wed Aug 14 08:49:06 2019

the mpath devices still existed, but when they were scanned they did look like PVs.

I don't yet understand how/why an mpath device could have non-zero size, be scanned, and not return LVM headers.  I wonder if it's an mpath state that I'm not familiar with; do you know if there's anything special being done with the mpath devices?  When I put a simple mpath wrapper around a scsi devices on my system it works fine.

If there was a way for you to collect the -vvvv/debug output of the command which created the earlier hints file, that might show us what's happening with the mpath devs.  You probably don't know exactly which command will create the earlier faulty hint file, so to capture this, you could enable log file debugging for all lvm commands via lvm.conf log/level=7 log/file="/tmp/lvm.log".  Then once this happens we can look back in that log file to find which command created the wrong hints.
Comment 7 michal novacek 2019-08-15 09:44:56 UTC 
I set log/level=7 and log/file=/var/log/lvm.conf.

VG have "virt-372" system_id written.

virt-372 saw the vg while virt-371 did not it with devices/hints=none. It did not even see (multipath) block devices.[1]

I rebooted both nodes (~11:30)

After reboot virt-372 does even see block devices where virt-371 does correctly see vg and even have correct /run/lvm/hints.

I run appropriate commands so you should be able to see all that in attached logs.

If that helps I can arrange access to those machines (disposable vms with appropriate
multipath setup).

-----

[1]
> [root@virt-372 ~]# vgs -o+vg_systemid
  VG            #PV #LV #SN Attr   VSize  VFree System ID
  rhel_virt-372   1   2   0 wz--n- <7.00g    0
  shared          6   1   0 wz--n-  5.95g    0  virt-372.cluster-qe.lab.eng.brq.redhat.com

> [root@virt-372 ~]# cat /run/lvm/hints
# Created by vgs pid 3156 Thu Aug 15 11:15:51 2019
hints_version: 1.1
global_filter:a|.*/|
filter:a|.*/|
scan_lvs:0
scan:/dev/vda2 pvid:Bhie743OZXPjuTd69M9qoT3TfXIH69a8 devn:252:2 vg:rhel_virt-372
scan:/dev/mapper/mpathc pvid:CEFxB7XAh8DXVg1r3UrWzBkIxREwIAJY devn:253:2 vg:shared
scan:/dev/mapper/mpathf pvid:lBqRTEQ4TcYJA3dFC3bekT7WP5qciw6n devn:253:3 vg:shared
scan:/dev/mapper/mpathd pvid:c8MLsFg7bG6AlXfGmAd7HrYnfYgQsqbY devn:253:4 vg:shared
scan:/dev/mapper/mpatha pvid:9OAjE4ME8ExlwqnGeWUuTd0iqY9NKtL7 devn:253:5 vg:shared
scan:/dev/mapper/mpathe pvid:a9NKcz7fvsVtyJRuPOZ8pnbQ1ONoQhiI devn:253:6 vg:shared
scan:/dev/mapper/mpathb pvid:9wXQPrtnyA6K5vXGogDp6i2pd9c2tqbK devn:253:7 vg:shared
devs_hash: 311218141 21


> [root@virt-371 ~]# vgs -o+vg_systemid --foreign --config devices/hints=none
  VG            #PV #LV #SN Attr   VSize  VFree System ID
  rhel_virt-371   1   2   0 wz--n- <7.00g    0

> [root@virt-371 ~]# cat /run/lvm/hints
# Created by vgs pid 2084 Thu Aug 15 11:15:28 2019
hints_version: 1.1
global_filter:a|.*/|
filter:a|.*/|
scan_lvs:0
scan:/dev/vda2 pvid:3B71ywgshqwIft9Ysn0FDs81mBY2Fr56 devn:252:2 vg:rhel_virt-371
devs_hash: 231327202 3
Comment 8 michal novacek 2019-08-15 09:46:19 UTC 
Created attachment 1604049 [details]
debug=7 lvm.log from both cluster nodes.
Comment 9 David Teigland 2019-08-15 15:29:35 UTC 
I wonder if you are looking for the VGs before the PVs have appeared on the system?  The log from virt-371 shows the following sequence of commands:

$ grep -e Parsing virt-371-var-log-lvm.log
11:25:12.308366 lvs[3097] lvmcmdline.c:2896  Parsing: lvs
11:26:51.421887 vgs[3570] lvmcmdline.c:2896  Parsing: vgs -o+vg_systemid --foreign --config devices/hints=none
11:27:52.630772 pvscan[661] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 252:2
11:28:03.337495 vgs[2352] lvmcmdline.c:2896  Parsing: vgs --noheadings -o pv_name rhel_virt-371
11:28:11.319233 pvscan[3011] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:2
11:28:12.645104 pvscan[3082] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:5
11:28:12.659994 pvscan[3083] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:4
11:28:12.671139 pvscan[3080] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:7
11:28:12.681770 pvscan[3084] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:3
11:28:12.692163 pvscan[3081] lvmcmdline.c:2896  Parsing: pvscan --cache --activate ay 253:6
11:30:42.428967 vgs[3428] lvmcmdline.c:2896  Parsing: vgs
11:30:47.835857 vgs[3446] lvmcmdline.c:2896  Parsing: vgs --foreign
11:31:44.715935 vgs[3505] lvmcmdline.c:2896  Parsing: vgs --foreign -o+vg_system_id
11:39:42.780598 vgs[4015] lvmcmdline.c:2896  Parsing: vgs
11:39:44.723567 pvs[4030] lvmcmdline.c:2896  Parsing: pvs
11:39:45.697744 lvs[4034] lvmcmdline.c:2896  Parsing: lvs

Those pvscan commands are run when the mpath devices appear on the system (253:2-7 are mpatha-f) at 11:28.
All the commands that run before this will not see the devices since they don't exist yet.
All the commands that run after the devices appear do include the mpath devices.

This command:
> [root@virt-371 ~]# vgs -o+vg_systemid --foreign --config devices/hints=none
>  VG            #PV #LV #SN Attr   VSize  VFree System ID
>  rhel_virt-371   1   2   0 wz--n- <7.00g  

occurs in the list above before the devices appear, so it won't display them.

The vgs command (pid 2084) that created the hint file you copied:
> [root@virt-371 ~]# cat /run/lvm/hints
> # Created by vgs pid 2084 Thu Aug 15 11:15:28 2019

was run ten minutes prior to the log starting, so it's not clear how this relates to the system bootup, but I'm guessing that this vgs command was run when the devices had not yet appeared.

Can you adjust your tests so that you're certain that the devices have all appeared on the system prior to running lvm commands to look for them?
Comment 11 Chris Mackowski 2019-09-11 22:24:59 UTC 
Created attachment 1614259 [details]
qec03m01_lvm.log
Comment 12 Chris Mackowski 2019-09-11 22:25:24 UTC 
Created attachment 1614260 [details]
qec03m02_lvm.log
Comment 14 David Teigland 2019-09-12 15:02:15 UTC 
Is there a problem you are trying to diagnose with the logs in comments 11 and 12?  If so could you explain what you expect and what you're seeing instead?  There is some strange and incorrect usage in the log.  Some commands treat the VG as shared (via lvmlockd), and others treat the VG has having a system ID.  Also 'vgchange -y --systemid= ' is a syntax error.
Comment 16 Chris Mackowski 2019-09-12 15:49:44 UTC 
Comment on attachment 1614259 [details]
qec03m01_lvm.log

Please disregard
Comment 17 Chris Mackowski 2019-09-12 15:50:08 UTC 
Comment on attachment 1614260 [details]
qec03m02_lvm.log

Please disregard
Comment 18 michal novacek 2019-09-17 11:20:46 UTC 
> Can you adjust your tests so that you're certain that the devices have all
> appeared on the system prior to running lvm commands to look for them?

It seems that 'pvscan --cache' is run before mpath devices are available. The system is unable to see them until 'pvscan --cache' is re-run.

Is there a way how to order pvscan only after the devices have appeared in the system?
Comment 19 David Teigland 2019-09-17 13:42:33 UTC 
The way it is supposed to work is that systemd/udev runs the lvm2-pvscan service for each mpath device that appears on the system.  It should not run the lvm2-pvscan service on the mpath component devices.

Note that shared and foreign VGs are ignored by pvscan.  Foreign VGs cannot be activated at all (by definition), and shared VGs can only be activated after they are "started" (which is generally handled by the LVM-activate resource agent.)

Can you check which lvm2-pvscan services have run and what the status of each is?
Comment 20 michal novacek 2019-09-18 12:40:26 UTC 
I checked and at the time of vgs not being visible there is only one lvm2-pvscan for the root drive and none for the multipath devices. After the reboot there is one also for multipathed devices and everything seems to be working correctly.

How do I make sure that they are created?
Comment 21 David Teigland 2019-09-18 16:01:38 UTC 
> I checked and at the time of vgs not being visible there is only one
> lvm2-pvscan for the root drive and none for the multipath devices. After the
> reboot there is one also for multipathed devices and everything seems to be
> working correctly.
> 
> How do I make sure that they are created?

When when the devices are attached to the system, systemd/udev automatically generates the lvm2-pvscan services.

In the state where the vgs were not visible, and the lvm2-pvscan services did not exist, how did you verify that the multipath devices were present on the system?  In that state could you collect: /proc/partitions, multipath -l, udevadm info -e, pvs.  Also, when things
are correct, could you include a list of mpath devices and their components (multiapth -l should do this).
Comment 22 michal novacek 2019-09-25 15:12:44 UTC 
I have found the following:

 * You start with no pvs and no mpath* devices in /run/lvm/hints file.
 * Creating pvs/vg/lv on node1 wil not create new lvm2-pvscan* unitfiles. LV can be seen and activated.
 * After the previous step node2 does not know about new pv/vg/lv being created
 * Running 'pvscan --cache' will:
    * complain about foreign ids
    * not create
    * not create lvm2-pvscan* unitfile
    * will allow activating of lv using LVM-activate resource agent.

As I see it the problem seems to be node2 not knowing about new pv/vg/lv being
created on node1 untill 'pvscan --cache' is run. Then all seems to be good even
when pvs are deleted and recreated.



Requested data from node2.

The other node (the one not seing vg at all):
[root@virt-137 ~]# pvs
  PV         VG            Fmt  Attr PSize  PFree
  /dev/vda2  rhel_virt-137 lvm2 a--  <7.00g    0
[root@virt-137 ~]# multipath -l
mpathe (36001405bf7db5f385cf4370b657d0060) dm-2 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 34:0:0:0 sdk 8:160 active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 35:0:0:0 sdc 8:32  active undef running
mpathd (360014057c7e0936e83f4bdd9514f4318) dm-5 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 27:0:0:0 sdj 8:144 active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 26:0:0:0 sdl 8:176 active undef running
mpathc (3600140588e7287f2e164d9b9bb7d0db2) dm-7 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 33:0:0:0 sdd 8:48  active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 32:0:0:0 sdf 8:80  active undef running
mpathb (360014057b263618f9f04bcc8c7c55321) dm-6 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 30:0:0:0 sdg 8:96  active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 31:0:0:0 sde 8:64  active undef running
mpatha (3600140568ff43168d81450382bc88b61) dm-4 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 29:0:0:0 sdh 8:112 active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 28:0:0:0 sdi 8:128 active undef running
mpathf (36001405b04262f10c5a49f4985e5825e) dm-3 LIO-ORG,cluster105661-d
size=1.0G features='0' hwhandler='1 alua' wp=rw
|-+- policy='service-time 0' prio=0 status=active
| `- 37:0:0:0 sda 8:0   active undef running
`-+- policy='service-time 0' prio=0 status=enabled
  `- 36:0:0:0 sdb 8:16  active undef running

[root@virt-137 ~]# cat /proc/partitions
major minor  #blocks  name

 252        0    8388608 vda
 252        1    1048576 vda1
 252        2    7339008 vda2
 253        0    6496256 dm-0
 253        1     839680 dm-1
   8       48    1048576 sdd
   8      176    1048576 sdl
   8       96    1048576 sdg
   8      160    1048576 sdk
   8       32    1048576 sdc
   8      144    1048576 sdj
   8      112    1048576 sdh
   8       80    1048576 sdf
   8        0    1048576 sda
   8       16    1048576 sdb
   8      128    1048576 sdi
   8       64    1048576 sde
 253        2    1048576 dm-2
 253        3    1048576 dm-3
 253        4    1048576 dm-4
 253        5    1048576 dm-5
 253        6    1048576 dm-6
 253        7    1048576 dm-7
Comment 23 michal novacek 2019-09-25 15:13:28 UTC 
Created attachment 1619093 [details]
udevadm info -e
Comment 24 David Teigland 2019-09-25 17:24:08 UTC 
>  * You start with no pvs and no mpath* devices in /run/lvm/hints file.
>  * Creating pvs/vg/lv on node1 wil not create new lvm2-pvscan* unitfiles.
> LV can be seen and activated.

We can set aside the lvm2-pvscan details because it's not the issue here (lvm2-pvscan services are strictly related to device attachment during system startup to drive autoactivation.)

>  * After the previous step node2 does not know about new pv/vg/lv being created

Right, the hints on node2 will not include any devices that you ran pvcreate on from node1 in the previous step.  As you show below, the way to force node2 to become aware of the pvcreate from node1 is to run pvscan --cache.  That rescans all devs, sees the new foreign PV, and includes it in the hints.

>  * Running 'pvscan --cache' will:
>     * complain about foreign ids
>     * not create
>     * not create lvm2-pvscan* unitfile
>     * will allow activating of lv using LVM-activate resource agent.

OK, sounds corrrect.

> As I see it the problem seems to be node2 not knowing about new pv/vg/lv being
> created on node1 untill 'pvscan --cache' is run. Then all seems to be good even
> when pvs are deleted and recreated.

Yes, I now see what's happening, the key here is where pvcreate is being called within the entire sequence.  The LVM-activate agent is usually handling existing VGs, and what you're dealing with here is an initialization situation.  You're moving directly from initializing a new PV/VG into using LVM-activate, and the addition of hints is exposing a problem with LVM-activate not recognizing newly created PVs from other hosts.

The LVM-activate agent is already running 'pvscan --cache' in lvm_start()/systemid_activate()  But, that turns out to be too late for this scenario, because before lvm_start(), lvm_validate() needs to see the VG to know how it's accessed (in this case using system ID).  Because of hints, and because the pvscan --cache is too late, lvm_validate can't see the VG on the newly created PV, and we don't get to lvm_start.  The solution is to call pvscan --cache ealier so it's available for lvm_validate.
Comment 25 David Teigland 2019-09-25 18:02:12 UTC 
Created attachment 1619198 [details]
LVM-activate patch

You can apply this patch directly to the LVM-activate script to see if it helps.
Comment 26 Oyvind Albrigtsen 2019-09-26 11:11:05 UTC 
https://github.com/ClusterLabs/resource-agents/pull/1407
Comment 27 michal novacek 2019-09-27 09:10:41 UTC 
qa_ack+: pacemaker,resource,LVMactivate,system_id,* tests must pass.
Comment 29 michal novacek 2020-01-23 10:31:51 UTC 
Internal tests passed:

pacemaker,resource,LVMactivate,system_id,exclusive,no-multipath
pacemaker,resource,LVMactivate,system_id,exclusive,multipath
Comment 32 errata-xmlrpc 2020-04-28 15:24:20 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, 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-2020:1565
Comment 33 BugMasta 2021-08-06 03:38:35 UTC Comment hidden (spam)
Comment 34 David Teigland 2021-08-10 15:13:09 UTC 
This fix was in the LVM-activate agent, not in the vgchange command.  If you are not using the LVM-activate agent, an alternative to pvscan --cache is disabling the hints file (lvm.conf hints=none for all commands, or --config devices/hints=none for just the vgchange command.)