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 1713716

Summary: apparent xfs superblock corruption when attempting to add additional images to exclusive linear converted to mirror
Product: Red Hat Enterprise Linux 7 Reporter: Corey Marthaler <cmarthal>
Component: lvm2Assignee: Heinz Mauelshagen <heinzm>
lvm2 sub component: Clustering / clvmd QA Contact: cluster-qe <cluster-qe>
Status: CLOSED DUPLICATE Docs Contact:
Severity: high    
Priority: unspecified CC: agk, heinzm, jbrassow, msnitzer, prajnoha, zkabelac
Version: 7.7   
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-06-06 19:17:48 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:
Attachments:
Description Flags
verbose lvconvert attempt none

Description Corey Marthaler 2019-05-24 14:53:30 UTC 
Description of problem:
This scenario converts a linear volume (exclusively activated) on a clustered VG using clvmd, to an exclusively activated mirror. Then after syncing is complete, an additional 3 mimages are attempted to be added.


[root@mckinley-02 ~]# pcs status
Cluster name: MCKINLEY
Stack: corosync
Current DC: mckinley-03 (version 1.1.20-4.el7-3c4c782f70) - partition with quorum
Last updated: Fri May 24 09:50:07 2019
Last change: Thu May 23 15:06:17 2019 by root via cibadmin on mckinley-01

4 nodes configured
9 resources configured

Online: [ mckinley-01 mckinley-02 mckinley-03 mckinley-04 ]

Full list of resources:

 mckinley-apc   (stonith:fence_apc):    Started mckinley-01
 Clone Set: dlm-clone [dlm]
     Started: [ mckinley-01 mckinley-02 mckinley-03 mckinley-04 ]
 Clone Set: clvmd-clone [clvmd]
     Started: [ mckinley-01 mckinley-02 mckinley-03 mckinley-04 ]

Daemon Status:
  corosync: active/disabled
  pacemaker: active/disabled
  pcsd: active/enabled




mckinley-01: pvcreate /dev/mapper/mpatha1 /dev/mapper/mpathb1 /dev/mapper/mpathc1 /dev/mapper/mpathd1 /dev/mapper/mpathe1 /dev/mapper/mpathf1 /dev/mapper/mpathg1 /dev/mapper/mpathh1
mckinley-01: vgcreate   centipede2 /dev/mapper/mpatha1 /dev/mapper/mpathb1 /dev/mapper/mpathc1 /dev/mapper/mpathd1 /dev/mapper/mpathe1 /dev/mapper/mpathf1 /dev/mapper/mpathg1 /dev/mapper/mpathh1

================================================================================
Iteration 0.1 started at Fri May 24 09:23:24 CDT 2019
================================================================================
Scenario linear_conversion: Convert Linear volume
********* Take over hash info for this scenario *********
* from type:    linear
* to type:      mirror
* from legs:    0
* to legs:      4
* from region:  0
* to region:    0
* contiguous:   1
******************************************************


Creating original volume on mckinley-02...
mckinley-02: lvcreate -aye --type linear   -n takeover -L 2.75G centipede2
WARNING: xfs signature detected on /dev/centipede2/takeover at offset 0. Wipe it? [y/n]: [n]
  Aborted wiping of xfs.
  1 existing signature left on the device.


Current volume device structure:
  LV       Type   Attr       LSize   Cpy%Sync Devices               
  takeover linear -wi-a-----   2.75g          /dev/mapper/mpatha1(0)


Creating xfs on top of mirror(s) on mckinley-02...
warning: device is not properly aligned /dev/centipede2/takeover
Mounting mirrored xfs filesystems on mckinley-02...

Writing verification files (checkit) to mirror(s) on...
        ---- mckinley-02 ----

Sleeping 15 seconds to get some outsanding I/O locks before the failure 
Verifying files (checkit) on mirror(s) on...
        ---- mckinley-02 ----


TAKEOVER: lvconvert --force --yes  -m 1 --type mirror centipede2/takeover
Waiting until all mirror|raid volumes become fully syncd...
   1/1 mirror(s) are fully synced: ( 100.00% )
Sleeping 15 sec

Current volume device structure:
  LV                  Type   Attr       LSize   Cpy%Sync Devices                                  
  takeover            mirror mwi-aom---   2.75g 100.00   takeover_mimage_0(0),takeover_mimage_1(0)
  [takeover_mimage_0] linear iwi-aom---   2.75g          /dev/mapper/mpatha1(0)                   
  [takeover_mimage_1] linear iwi-aom---   2.75g          /dev/mapper/mpathb1(0)                   
  [takeover_mlog]     linear lwi-aom---   4.00m          /dev/mapper/mpathh1(0)                   


Verifying files (checkit) on mirror(s) on...
        ---- mckinley-02 ----

RESHAPE: lvconvert --yes  -m 4 centipede2/takeover

May 24 09:25:15 mckinley-02 qarshd[7189]: Running cmdline: lvconvert --yes -m 4 centipede2/takeover
May 24 09:25:15 mckinley-02 dmeventd[6842]: No longer monitoring mirror device centipede2-takeover for events.
May 24 09:25:15 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:15 mckinley-02 kernel: device-mapper: raid1: Primary mirror (253:23) failed while out-of-sync: Reads may fail.
May 24 09:25:15 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:15 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:16 mckinley-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 09:25:30 mckinley-02 kernel: device-mapper: dm-log-userspace: [O9gON7jg] Request timed out: [9/8511] - retrying
May 24 09:25:31 mckinley-02 lvm[6842]: Monitoring mirror device centipede2-takeover_mimagetmp_2 for events.
May 24 09:25:31 mckinley-02 lvm[6842]: centipede2-takeover_mimagetmp_2 is now in-sync.
May 24 09:25:31 mckinley-02 lvm[6842]: centipede2-takeover_mimagetmp_2 is now in-sync.
May 24 09:25:31 mckinley-02 lvm[6842]: Monitoring mirror device centipede2-takeover for events.
May 24 09:25:31 mckinley-02 kernel: XFS (dm-19): metadata I/O error: block 0x2c0085 ("xlog_iodone") error 5 numblks 64
May 24 09:25:31 mckinley-02 kernel: XFS (dm-19): xfs_do_force_shutdown(0x2) called from line 1238 of file fs/xfs/xfs_log.c.  Return address = 0xffffffffc0570660
May 24 09:25:31 mckinley-02 kernel: XFS (dm-19): Log I/O Error Detected.  Shutting down filesystem
May 24 09:25:31 mckinley-02 kernel: XFS (dm-19): xfs_attr_quiesce: failed to log sb changes. Frozen image may not be consistent.
May 24 09:25:31 mckinley-02 kernel: VFS:Filesystem freeze failed
May 24 09:25:31 mckinley-02 kernel: XFS (dm-19): Please umount the filesystem and rectify the problem(s)


[root@mckinley-02 ~]# umount /mnt/takeover
[root@mckinley-02 ~]# mount /dev/centipede2/takeover /mnt/takeover
mount: /dev/mapper/centipede2-takeover: can't read superblock



[root@mckinley-02 ~]# ls /mnt/takeover 
ls: cannot access /mnt/takeover: Input/output error


Version-Release number of selected component (if applicable):
3.10.0-1048.el7.x86_64

lvm2-2.02.185-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
lvm2-libs-2.02.185-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
lvm2-cluster-2.02.185-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
lvm2-lockd-2.02.185-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
lvm2-python-boom-0.9-17.el7.2    BUILT: Mon May 13 04:37:00 CDT 2019
cmirror-2.02.185-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
device-mapper-1.02.158-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
device-mapper-libs-1.02.158-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
device-mapper-event-1.02.158-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
device-mapper-event-libs-1.02.158-1.el7    BUILT: Mon May 13 04:36:30 CDT 2019
device-mapper-persistent-data-0.8.1-1.el7    BUILT: Sat May  4 14:53:53 CDT 2019


How reproducible:
Often
Comment 2 Corey Marthaler 2019-05-24 15:08:43 UTC 
Here is how the mirror looks after this operation, and it also appears clvmd gets stuck as a result of this.

[root@mckinley-02 ~]# lvs -a -o +devices
  LV                     VG         Attr       LSize  Log             Cpy%Sync Convert                Devices                                                                               
  takeover               centipede2 cwi-a-m--- 2.75g                  0.14     [takeover_mimagetmp_2] takeover_mimagetmp_2(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0]    centipede2 iwi-aom--- 2.75g                                                  /dev/mapper/mpatha1(0)                                                                
  [takeover_mimage_1]    centipede2 iwi-aom--- 2.75g                                                  /dev/mapper/mpathb1(0)                                                                
  [takeover_mimage_2]    centipede2 Iwi-aom--- 2.75g                                                  /dev/mapper/mpathc1(0)                                                                
  [takeover_mimage_3]    centipede2 Iwi-aom--- 2.75g                                                  /dev/mapper/mpathd1(0)                                                                
  [takeover_mimage_4]    centipede2 Iwi-aom--- 2.75g                                                  /dev/mapper/mpathe1(0)                                                                
  [takeover_mimagetmp_2] centipede2 mwi-aom--- 2.75g  [takeover_mlog] 100.00                          takeover_mimage_0(0),takeover_mimage_1(0)                                             
  [takeover_mlog]        centipede2 lwi-aom--- 4.00m                                                  /dev/mapper/mpathh1(0)                                                                

[root@mckinley-02 ~]# lvs
  LV       VG               Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert               
  takeover centipede2       cwi-a-m---   2.75g                                    0.14     [takeover_mimagetmp_2]
  home     rhel_mckinley-02 -wi-ao---- 503.91g                                                                   
  root     rhel_mckinley-02 -wi-ao----  50.00g                                                                   
  swap     rhel_mckinley-02 -wi-ao----   4.00g                                                                   
[root@mckinley-02 ~]# lvremove -f centipede2
  Error locking on node 2: Command timed out
  Cannot deactivate logical volume centipede2/takeover.
  Error locking on node 2: Command timed out
  [DEADLOCK]

May 24 09:40:42 mckinley-02 kernel: device-mapper: raid1: Mirror read failed.
May 24 09:40:42 mckinley-02 kernel: XFS (dm-19): last sector read failed
May 24 09:59:53 mckinley-02 lvm[6842]: No longer monitoring mirror device centipede2-takeover_mimagetmp_2 for events.
May 24 09:59:53 mckinley-02 dmeventd[6842]: No longer monitoring mirror device centipede2-takeover for events.
May 24 10:00:39 mckinley-02 lvmpolld: W: LVMPOLLD: polling for output of the lvm cmd (PID 7308) has timed out
May 24 10:01:01 mckinley-02 systemd: Started Session 3 of user root.
May 24 10:01:40 mckinley-02 lvmpolld: W: LVMPOLLD: polling for output of the lvm cmd (PID 7308) has timed out
May 24 10:02:40 mckinley-02 lvmpolld: W: LVMPOLLD: polling for output of the lvm cmd (PID 7308) has timed out
May 24 10:02:40 mckinley-02 lvmpolld[6854]: LVMPOLLD: LVM2 cmd is unresponsive too long (PID 7308) (no output for 180 seconds)
May 24 10:03:46 mckinley-02 kernel: INFO: task clvmd:4200 blocked for more than 120 seconds.
May 24 10:03:46 mckinley-02 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
May 24 10:03:46 mckinley-02 kernel: clvmd           D ffff903a7bca41c0     0  4200      1 0x00000080
May 24 10:03:46 mckinley-02 kernel: Call Trace:
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9b1c8a0>] ? constraint_expr_eval+0x130/0x580
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f7e079>] schedule+0x29/0x70
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f7b9c1>] schedule_timeout+0x221/0x2d0
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9b1d11d>] ? context_struct_compute_av+0x38d/0x4d0
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9a23a42>] ? kmem_cache_alloc+0x1c2/0x1f0
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f7d2c7>] __down_common+0xaa/0x104
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f7d33e>] __down+0x1d/0x1f
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa98cae51>] down+0x41/0x50
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc016691b>] dm_rh_stop_recovery+0x2b/0x40 [dm_region_hash]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc017b4d6>] mirror_presuspend+0xa6/0x175 [dm_mirror]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9b089eb>] ? cred_has_capability+0x6b/0x120
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc014d23d>] dm_table_presuspend_targets+0x4d/0x60 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc0147b25>] __dm_suspend+0xe5/0x240 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc014a2fd>] dm_suspend+0xad/0xc0 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc0150193>] dev_suspend+0x1c3/0x260 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc015122e>] ctl_ioctl+0x24e/0x550 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc014ffd0>] ? table_load+0x390/0x390 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffc015153e>] dm_ctl_ioctl+0xe/0x20 [dm_mod]
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9a5e1d0>] do_vfs_ioctl+0x3a0/0x5a0
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9a4b20b>] ? __fput+0x16b/0x260
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9a5e471>] SyS_ioctl+0xa1/0xc0
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f8add5>] ? system_call_after_swapgs+0xa2/0x146
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f8ae9e>] system_call_fastpath+0x25/0x2a
May 24 10:03:46 mckinley-02 kernel: [<ffffffffa9f8ade1>] ? system_call_after_swapgs+0xae/0x146
Comment 3 Corey Marthaler 2019-05-24 15:25:49 UTC 
After all the nodes were rebooted and the cluster restarted, this volume was auto activated as a cluster mirror on all nodes and the sync was able to finish. All fs data was found to still be intact.


[root@mckinley-02 checkit]# /usr/tests/sts-rhel7.7/bin/checkit -w /mnt/takeover/checkit -f /tmp/checkit_takeover -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/checkit_takeover
Working dir:        /mnt/takeover/checkit

[root@mckinley-01 checkit]# lvs -a -o +devices
  LV                  VG               Attr       LSize    Pool Origin Data%  Meta%  Move Log             Cpy%Sync Convert Devices                                                                                                 
  takeover            centipede2       mwi-aom---    2.75g                                [takeover_mlog] 100.00           takeover_mimage_0(0),takeover_mimage_1(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0] centipede2       iwi-aom---    2.75g                                                                 /dev/mapper/mpatha1(0)                                                                                  
  [takeover_mimage_1] centipede2       iwi-aom---    2.75g                                                                 /dev/mapper/mpathb1(0)                                                                                  
  [takeover_mimage_2] centipede2       iwi-aom---    2.75g                                                                 /dev/mapper/mpathc1(0)                                                                                  
  [takeover_mimage_3] centipede2       iwi-aom---    2.75g                                                                 /dev/mapper/mpathd1(0)                                                                                  
  [takeover_mimage_4] centipede2       iwi-aom---    2.75g                                                                 /dev/mapper/mpathe1(0)                                                                                  
  [takeover_mlog]     centipede2       lwi-aom---    4.00m                                                                 /dev/mapper/mpathh1(0)                                                                                  

[root@mckinley-02 checkit]# lvs -a -o +devices
  LV                  VG               Attr       LSize   Pool Origin Data%  Meta%  Move Log             Cpy%Sync Convert Devices                                                                                                 
  takeover            centipede2       mwi-aom---   2.75g                                [takeover_mlog] 100.00           takeover_mimage_0(0),takeover_mimage_1(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpatha1(0)                                                                                  
  [takeover_mimage_1] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathb1(0)                                                                                  
  [takeover_mimage_2] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathc1(0)                                                                                  
  [takeover_mimage_3] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathd1(0)                                                                                  
  [takeover_mimage_4] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathe1(0)                                                                                  
  [takeover_mlog]     centipede2       lwi-aom---   4.00m                                                                 /dev/mapper/mpathh1(0)                                                                                  

[root@mckinley-03 ~]# lvs -a -o +devices
  LV                  VG               Attr       LSize   Pool Origin Data%  Meta%  Move Log             Cpy%Sync Convert Devices                                                                                                 
  takeover            centipede2       mwi-a-m---   2.75g                                [takeover_mlog] 100.00           takeover_mimage_0(0),takeover_mimage_1(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpatha1(0)                                                                                  
  [takeover_mimage_1] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathb1(0)                                                                                  
  [takeover_mimage_2] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathc1(0)                                                                                  
  [takeover_mimage_3] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathd1(0)                                                                                  
  [takeover_mimage_4] centipede2       iwi-aom---   2.75g                                                                 /dev/mapper/mpathe1(0)                                                                                  
  [takeover_mlog]     centipede2       lwi-aom---   4.00m                                                                 /dev/mapper/mpathh1(0)
Comment 4 Corey Marthaler 2019-05-24 15:41:55 UTC 
When running the lvm cmds alone, the reshape operation does "work", but messages show that something isn't quite right.

[root@mckinley-04 ~]# lvcreate -aye --type linear   -n takeover -L 2.75G centipede2
WARNING: xfs signature detected on /dev/centipede2/takeover at offset 0. Wipe it? [y/n]: y
  Wiping xfs signature on /dev/centipede2/takeover.
  Logical volume "takeover" created.

[root@mckinley-04 ~]# lvs -a -o +devices
  LV       VG          Attr       LSize   Pool Origin Data%  Meta%  Move Log Cpy%Sync Convert Devices               
  takeover centipede2  -wi-a-----   2.75g                                                     /dev/mapper/mpatha1(0)

[root@mckinley-04 ~]# lvconvert --force --yes  -m 1 --type mirror centipede2/takeover
  Logical volume centipede2/takeover being converted.
  centipede2/takeover: Converted: 0.14%
  centipede2/takeover: Converted: 45.45%
  centipede2/takeover: Converted: 100.00%

[root@mckinley-04 ~]# lvs -a -o +devices
  LV                  VG          Attr       LSize Log             Cpy%Sync Convert Devices
  takeover            centipede2  mwi-a-m--- 2.75g [takeover_mlog] 100.00           takeover_mimage_0(0),takeover_mimage_1(0)
  [takeover_mimage_0] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpatha1(0)
  [takeover_mimage_1] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpathb1(0)
  [takeover_mlog]     centipede2  lwi-aom--- 4.00m                                  /dev/mapper/mpathh1(0)

[root@mckinley-04 ~]# lvconvert --yes  -m 4 centipede2/takeover
  Logical volume centipede2/takeover being converted.
  centipede2/takeover: Converted: 0.14%
  centipede2/takeover: Converted: 45.74%
  centipede2/takeover: Converted: 100.00%

May 24 10:35:45 mckinley-04 dmeventd[4564]: No longer monitoring mirror device centipede2-takeover for events.
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Primary mirror (253:23) failed while out-of-sync: Reads may fail.
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Mirror read failed.
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Mirror read failed.
May 24 10:35:45 mckinley-04 kernel: Buffer I/O error on dev dm-19, logical block 720880, async page read
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Mirror read failed.
May 24 10:35:45 mckinley-04 kernel: device-mapper: raid1: Mirror read failed.
May 24 10:35:45 mckinley-04 lvm[4564]: Monitoring mirror device centipede2-takeover_mimagetmp_2 for events.
May 24 10:35:45 mckinley-04 kernel: Buffer I/O error on dev dm-19, logical block 720880, async page read
May 24 10:35:45 mckinley-04 lvm[4564]: centipede2-takeover_mimagetmp_2 is now in-sync.
May 24 10:35:45 mckinley-04 lvm[4564]: Monitoring mirror device centipede2-takeover for events.
May 24 10:35:45 mckinley-04 systemd: Started LVM2 poll daemon.
May 24 10:36:14 mckinley-04 lvm[4564]: centipede2-takeover is now in-sync.
May 24 10:36:15 mckinley-04 lvm[4564]: No longer monitoring mirror device centipede2-takeover_mimagetmp_2 for events.
May 24 10:36:16 mckinley-04 dmeventd[4564]: No longer monitoring mirror device centipede2-takeover for events.
May 24 10:36:16 mckinley-04 lvm[4564]: Monitoring mirror device centipede2-takeover for events.
May 24 10:36:16 mckinley-04 lvm[4564]: centipede2-takeover is now in-sync.
May 24 10:36:16 mckinley-04 lvmpolld: W: #011LVPOLL: PID 8410: STDERR: '  WARNING: This metadata update is NOT backed up.'
May 24 10:36:16 mckinley-04 multipathd: dm-23: remove map (uevent)
May 24 10:36:16 mckinley-04 multipathd: dm-23: devmap not registered, can't remove
May 24 10:36:16 mckinley-04 multipathd: dm-23: remove map (uevent)
May 24 10:36:16 mckinley-04 dmeventd[4564]: No longer monitoring mirror device centipede2-takeover for events.
May 24 10:36:16 mckinley-04 lvm[4564]: Monitoring mirror device centipede2-takeover for events.
May 24 10:36:16 mckinley-04 lvm[4564]: centipede2-takeover is now in-sync.

[root@mckinley-04 ~]# lvs -a -o +devices
  LV                  VG          Attr       LSize Log             Cpy%Sync Convert Devices
  takeover            centipede2  mwi-a-m--- 2.75g [takeover_mlog] 100.00           takeover_mimage_0(0),takeover_mimage_1(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpatha1(0)
  [takeover_mimage_1] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpathb1(0)
  [takeover_mimage_2] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpathc1(0)
  [takeover_mimage_3] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpathd1(0)
  [takeover_mimage_4] centipede2  iwi-aom--- 2.75g                                  /dev/mapper/mpathe1(0)
  [takeover_mlog]     centipede2  lwi-aom--- 4.00m                                  /dev/mapper/mpathh1(0)
Comment 5 Corey Marthaler 2019-05-24 15:59:53 UTC 
Created attachment 1572957 [details]
verbose lvconvert attempt
Comment 6 Corey Marthaler 2019-06-03 19:58:03 UTC 
This is *not* a regression and existed in rhel7.6 as well.

3.10.0-957.el7.x86_64

lvm2-2.02.180-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
lvm2-libs-2.02.180-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
lvm2-cluster-2.02.180-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
lvm2-lockd-2.02.180-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
lvm2-python-boom-0.9-11.el7    BUILT: Mon Sep 10 04:49:22 CDT 2018
cmirror-2.02.180-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
device-mapper-1.02.149-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
device-mapper-libs-1.02.149-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
device-mapper-event-1.02.149-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
device-mapper-event-libs-1.02.149-8.el7    BUILT: Mon Sep 10 04:45:22 CDT 2018
device-mapper-persistent-data-0.7.3-3.el7    BUILT: Tue Nov 14 05:07:18 CST 2017

TAKEOVER: lvconvert --force --yes  -m 1 --type mirror centipede2/takeover

Current volume device structure:
  LV                  Type   Attr       LSize    Cpy%Sync Devices                                  
  lvol0               linear -wi-a-----   20.00m          /dev/mapper/mpatha1(704)                 
  takeover            mirror mwi-aom---    2.80g 100.00   takeover_mimage_0(0),takeover_mimage_1(0)
  [takeover_mimage_0] linear iwi-aom---    2.80g          /dev/mapper/mpatha1(0)                   
  [takeover_mimage_0] linear iwi-aom---    2.80g          /dev/mapper/mpatha1(709)                 
  [takeover_mimage_1] linear iwi-aom---    2.80g          /dev/mapper/mpathb1(0)                   
  [takeover_mlog]     linear lwi-aom---    4.00m          /dev/mapper/mpathh1(0)                   

RESHAPE: lvconvert --yes  -m 4 centipede2/takeover

Jun  3 14:34:31 harding-02 qarshd[42737]: Running cmdline: lvconvert --yes -m 4 centipede2/takeover
Jun  3 14:34:31 harding-02 dmeventd[42220]: No longer monitoring mirror device centipede2-takeover for events.
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Primary mirror (253:24) failed while out-of-sync: Reads may fail.
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:31 harding-02 kernel: device-mapper: raid1: Unable to read primary mirror during recovery
Jun  3 14:34:46 harding-02 kernel: device-mapper: dm-log-userspace: [LbifeTDI] Request timed out: [9/29898] - retrying
Jun  3 14:34:46 harding-02 lvm[42220]: Monitoring mirror device centipede2-takeover_mimagetmp_2 for events.
Jun  3 14:34:46 harding-02 lvm[42220]: centipede2-takeover_mimagetmp_2 is now in-sync.
Jun  3 14:34:46 harding-02 lvm[42220]: Monitoring mirror device centipede2-takeover for events.
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7422, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7423, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7424, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7425, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7426, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7427, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7428, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7429, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7430, lost async page write
Jun  3 14:34:46 harding-02 kernel: Buffer I/O error on dev dm-19, logical block 7431, lost async page write
Jun  3 14:34:46 harding-02 kernel: XFS (dm-19): metadata I/O error: block 0x2cd091 ("xlog_iodone") error 5 numblks 64
Jun  3 14:34:46 harding-02 kernel: XFS (dm-19): xfs_do_force_shutdown(0x2) called from line 1221 of file fs/xfs/xfs_log.c.  Return address = 0xffffffffc071dc30
Jun  3 14:34:46 harding-02 kernel: XFS (dm-19): Log I/O Error Detected.  Shutting down filesystem
Jun  3 14:34:46 harding-02 kernel: VFS:Filesystem freeze failed
Jun  3 14:34:46 harding-02 kernel: XFS (dm-19): Please umount the filesystem and rectify the problem(s)

[root@harding-02 ~]# lvs -a -o +devices
  LV                     VG         Attr       LSize  Log             Cpy%Sync Convert                Devices
  lvol0                  centipede2 -wi-a----- 20.00m                                                 /dev/mapper/mpatha1(704)
  takeover               centipede2 cwi-aom---  2.80g                 0.42     [takeover_mimagetmp_2] takeover_mimagetmp_2(0),takeover_mimage_2(0),takeover_mimage_3(0),takeover_mimage_4(0)
  [takeover_mimage_0]    centipede2 iwi-aom---  2.80g                                                 /dev/mapper/mpatha1(0)
  [takeover_mimage_0]    centipede2 iwi-aom---  2.80g                                                 /dev/mapper/mpatha1(709)
  [takeover_mimage_1]    centipede2 iwi-aom---  2.80g                                                 /dev/mapper/mpathb1(0)
  [takeover_mimage_2]    centipede2 Iwi-aom---  2.80g                                                 /dev/mapper/mpathc1(0)
  [takeover_mimage_3]    centipede2 Iwi-aom---  2.80g                                                 /dev/mapper/mpathd1(0)
  [takeover_mimage_4]    centipede2 Iwi-aom---  2.80g                                                 /dev/mapper/mpathe1(0)
  [takeover_mimagetmp_2] centipede2 mwi-aom---  2.80g [takeover_mlog] 100.00                          takeover_mimage_0(0),takeover_mimage_1(0)
  [takeover_mlog]        centipede2 lwi-aom---  4.00m                                                 /dev/mapper/mpathh1(0)
Comment 7 Jonathan Earl Brassow 2019-06-04 22:44:07 UTC 
this scenario should never trigger dm-log-userspace to be used.  That is a cluster mirror component.  From what I can tell, you are activating the mirror exclusively initially.  Comment 3 seems to switch to non-exclusive activation.  This is fine, but I want to point out that there are probably two bugs here, 1) an undesired switch from exclusive to non-exclusive and 2) whatever is going wrong with the mirror conversion.

I'm not sure what is going wrong with the mirror after conversion... the primary is obviously misbehaving.  At that point, all bets are off.
Comment 8 Jonathan Earl Brassow 2019-06-06 19:11:00 UTC 
couple bizarre things:

1) I'm pretty sure a linear -> mirror didn't have to be exclusively activated before... (unrelated to this bug, of course)
[root@bp-01 ~]# lvconvert -m1 vg/lv
Are you sure you want to convert linear LV vg/lv to raid1 with 2 images enhancing resilience? [y/n]: y
  vg/lv must be active exclusive locally to perform this operation.
This occurs because RAID1 (the default type) does not support cluster operation... This could be tough for a user to figure out.  However, it's not very important since cluster mirroring goes away in RHEL8.

2) WTF?  In REHL7.7?
[root@bp-01 ~]# lvconvert --type mirror -m1 vg/lv
  Shared cluster mirrors are not available.
2.1) Works just fine if switching to exclusive...
[root@bp-01 ~]# lvchange -an vg
[root@bp-01 ~]# lvchange -aey vg/lv
[root@bp-01 ~]# lvconvert --type mirror -m1 vg/lv
  Logical volume vg/lv being converted.
  vg/lv: Converted: 1.60%
  vg/lv: Converted: 100.00%
[root@bp-01 ~]# dmsetup table | grep vg-
vg-lv: 0 1024000 mirror disk 2 253:4 4096 2 253:5 0 253:6 0 1 handle_errors
vg-lv_mimage_1: 0 1024000 linear 8:33 2048
vg-lv_mimage_0: 0 1024000 linear 8:17 2048
vg-lv_mlog: 0 8192 linear 8:129 2048
... tables are correct, but the log entries are not right!
[104885.306295] device-mapper: dm-log-userspace: version 1.3.0 loaded
[104885.312750] device-mapper: dm-log-userspace: Unable to send log request [1] to userspace: -3
[104885.321288] device-mapper: dm-log-userspace: Userspace log server not found
[104885.328333] device-mapper: table: 253:3: mirror: Error creating mirror dirty log
[104885.335810] device-mapper: ioctl: error adding target to table
^^^ This should not be happening.

We should probably stop at problem #2 before moving on to a mirror-to-mirror upconvert... something is already pretty messed up.
Comment 9 Jonathan Earl Brassow 2019-06-06 19:17:48 UTC 

*** This bug has been marked as a duplicate of bug 1711427 ***