Bug 809231

Summary: merged back raid image (with change tracking) doesn't appear to get synced properly
Product: Red Hat Enterprise Linux 6 Reporter: Corey Marthaler <cmarthal>
Component: kernelAssignee: Jonathan Earl Brassow <jbrassow>
Status: CLOSED ERRATA QA Contact: Cluster QE <mspqa-list>
Severity: high Docs Contact:
Priority: high    
Version: 6.3CC: agk, dwysocha, heinzm, jbrassow, mbroz, msnitzer, prajnoha, prockai, thornber, zkabelac
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32-269.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-06-20 08:45:15 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Corey Marthaler 2012-04-02 19:16:28 UTC
Description of problem:

SCENARIO - [split_w_tracking_io_merge]
Create a 3-way raid1 with fs data, verify data, split image with tracking, change data on raid vol, merge split image data back, then verify again
taft-01: lvcreate --type raid1 -m 2 -n split_tracking -L 1G split_image
Waiting until all mirror|raid volumes become fully syncd...
   0/1 mirror(s) are fully synced: ( 27.23% )
   0/1 mirror(s) are fully synced: ( 61.99% )
   1/1 mirror(s) are fully synced: ( 100.00% )

Placing an ext filesystem on raid1 volume
mke2fs 1.41.12 (17-May-2010)
Mounting raid1 volume


# INITIAL WRITE AND VERIFY
Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingA.27391 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        25299
Verify XIOR Stream: /tmp/split_trackingA.27391
Working dir:        /mnt/split_tracking

Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingA.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.27391
Working dir:        /mnt/split_tracking


# ISSUE A SYNC DUE TO BUG 808189
Issuing a sync to force data to disk
splitting off leg from raid with tracking...
taft-01: lvconvert --splitmirrors 1 --trackchanges split_image/split_tracking


# VERIFY INITIAL DATA ON SPLIT LEG
+++ Mounting and verifying split image data +++
mount: block device /dev/mapper/split_image-split_tracking_rimage_2 is write-protected, mounting read-only
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingA.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.27391
Working dir:        /mnt/split_tracking_rimage_2


# ADD NEW DATA TO MIRROR W/ SPLIT OFF LEG
Writing new data to the raid and then merging back the split off image
Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingB.27391 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        25360
Verify XIOR Stream: /tmp/split_trackingB.27391
Working dir:        /mnt/split_tracking
Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingB.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingB.27391
Working dir:        /mnt/split_tracking
Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingC.27391 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        25364
Verify XIOR Stream: /tmp/split_trackingC.27391
Working dir:        /mnt/split_tracking
Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingC.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingC.27391
Working dir:        /mnt/split_tracking



# ADD SPLIT OFF LEG BACK TO RAID (ASSUMPTION IS THAT IT WOULD BE PUT BACK IN SYNC WITH OTHER LEGS)
Merge split off image split_image/split_tracking_rimage_2 back into the raid
lvconvert --merge split_image/split_tracking_rimage_2
out=  split_image/split_tracking_rimage_2 successfully merged back into split_image/split_tracking


# SPLIT OFF SAME IMAGE AGAIN AND VERIFY OLD AND NEW DATA
Issuing a sync to force data to disk
AGAIN, splitting off leg from raid with tracking...
taft-01: lvconvert --splitmirrors 1 --trackchanges split_image/split_tracking

# INITIAL DATA IS THERE
+++ Mounting and verifying split image data +++
mount: block device /dev/mapper/split_image-split_tracking_rimage_2 is write-protected, mounting read-only
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingA.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.27391
Working dir:        /mnt/split_tracking_rimage_2


# THE NEW DATA IS NOT HOWEVER
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingB.27391 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingB.27391
Working dir:        /mnt/split_tracking_rimage_2
Can not stat rbjooktiubqtktnuskxsympjhuuyggjxhu: No such file or directory
checkit verify failed

Apr  2 14:06:37 taft-01 qarshd[25477]: Running cmdline: /usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trv
Apr  2 14:06:37 taft-01 kernel: attempt to access beyond end of device
Apr  2 14:06:37 taft-01 kernel: dm-7: rw=0, want=7545668040, limit=2097152


Version-Release number of selected component (if applicable):
2.6.32-251.el6.x86_64

lvm2-2.02.95-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
lvm2-libs-2.02.95-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
lvm2-cluster-2.02.95-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
udev-147-2.40.el6    BUILT: Fri Sep 23 07:51:13 CDT 2011
device-mapper-1.02.74-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
device-mapper-libs-1.02.74-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
device-mapper-event-1.02.74-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
device-mapper-event-libs-1.02.74-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012
cmirror-2.02.95-2.el6    BUILT: Fri Mar 16 08:39:54 CDT 2012


How reproducible:
Everytime

Comment 2 RHEL Program Management 2012-04-18 19:30:09 UTC
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux maintenance release. Product Management has 
requested further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed 
products. This request is not yet committed for inclusion in an Update release.

Comment 3 Jonathan Earl Brassow 2012-04-18 22:11:25 UTC
Before patch:
[root@bp-01 ~]# lvcreate --type raid1 -m 2 -L 1G -n lv vg
  Logical volume "lv" created
[root@bp-01 ~]# devices vg
  LV            Copy%  Devices                                     
  lv            100.00 lv_rimage_0(0),lv_rimage_1(0),lv_rimage_2(0)
  [lv_rimage_0]        /dev/sde1(1)                                
  [lv_rimage_1]        /dev/sdc1(1)                                
  [lv_rimage_2]        /dev/sdf1(1)                                
  [lv_rmeta_0]         /dev/sde1(0)                                
  [lv_rmeta_1]         /dev/sdc1(0)                                
  [lv_rmeta_2]         /dev/sdf1(0)                                
[root@bp-01 ~]# lvconvert --splitmirrors 1 --trackchanges vg/lv
  lv_rimage_2 split from lv for read-only purposes.
  Use 'lvconvert --merge vg/lv_rimage_2' to merge back into lv
[root@bp-01 ~]# dd if=/dev/zero of=/dev/vg/lv bs=4M
dd: writing `/dev/vg/lv': No space left on device
257+0 records in
256+0 records out
1073741824 bytes (1.1 GB) copied, 241.313 s, 4.4 MB/s
[root@bp-01 ~]# sync
[root@bp-01 ~]# lvconvert --merge vg/lv_rimage_2; dmsetup status vg-lv
  vg/lv_rimage_2 successfully merged back into vg/lv
0 2097152 raid raid1 3 AAA 2097152/2097152
^^^^^^^^^^^^^^^^ SHOULD NOT BE FULLY SYNC'ED - INDICATES RECOVERY IS SKIPPED


After patch:
[root@bp-01 ~]# lvcreate --type raid1 -m 2 -L 1G -n lv vg
  Logical volume "lv" created
[root@bp-01 ~]# devices vg
  LV            Copy%  Devices                                     
  lv            100.00 lv_rimage_0(0),lv_rimage_1(0),lv_rimage_2(0)
  [lv_rimage_0]        /dev/sde1(1)                                
  [lv_rimage_1]        /dev/sdc1(1)                                
  [lv_rimage_2]        /dev/sdf1(1)                                
  [lv_rmeta_0]         /dev/sde1(0)                                
  [lv_rmeta_1]         /dev/sdc1(0)                                
  [lv_rmeta_2]         /dev/sdf1(0)                                
[root@bp-01 ~]# lvconvert --splitmirrors 1 --trackchanges vg/lv
  lv_rimage_2 split from lv for read-only purposes.
  Use 'lvconvert --merge vg/lv_rimage_2' to merge back into lv
[root@bp-01 ~]# dd if=/dev/zero of=/dev/vg/lv bs=4M
dd: writing `/dev/vg/lv': No space left on device
257+0 records in
256+0 records out
1073741824 bytes (1.1 GB) copied, 237.336 s, 4.5 MB/s
[root@bp-01 ~]# sync
[root@bp-01 ~]# lvconvert --merge vg/lv_rimage_2; dmsetup status vg-lv
  vg/lv_rimage_2 successfully merged back into vg/lv
0 2097152 raid raid1 3 AAa 0/2097152
^^^^^^^^^^^^^^^^^^ Device is properly signified as out-of-sync

[root@bp-01 ~]# dmsetup status vg-lv
0 2097152 raid raid1 3 AAA 2097152/2097152
^^^^^^^^^^^^^^^^^^ And goes on to recover properly.

Comment 4 Jarod Wilson 2012-05-02 16:20:04 UTC
Patch(es) available on kernel-2.6.32-269.el6

Comment 7 Corey Marthaler 2012-05-02 23:41:17 UTC
Fix appears to work in the latest kernel.


2.6.32-269.el6.x86_64
lvm2-2.02.95-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
lvm2-libs-2.02.95-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
lvm2-cluster-2.02.95-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
udev-147-2.41.el6    BUILT: Thu Mar  1 13:01:08 CST 2012
device-mapper-1.02.74-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
device-mapper-libs-1.02.74-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
device-mapper-event-1.02.74-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
device-mapper-event-libs-1.02.74-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012
cmirror-2.02.95-7.el6    BUILT: Wed May  2 05:14:03 CDT 2012


SCENARIO - [split_w_tracking_io_merge]
Create a 3-way raid1 with fs data, verify data, split image with tracking, change data on raid vol, merge split image data back, verify origin data
taft-01: lvcreate --type raid1 -m 2 -n split_tracking -L 1G split_image
Waiting until all mirror|raid volumes become fully syncd...
   0/1 mirror(s) are fully synced: ( 28.72% )
   0/1 mirror(s) are fully synced: ( 61.51% )
   0/1 mirror(s) are fully synced: ( 94.91% )
   1/1 mirror(s) are fully synced: ( 100.00% )

Placing an ext filesystem on raid1 volume
mke2fs 1.41.12 (17-May-2010)
Mounting raid1 volume

Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingA.26258 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        17282
Verify XIOR Stream: /tmp/split_trackingA.26258
Working dir:        /mnt/split_tracking

Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingA.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.26258
Working dir:        /mnt/split_tracking


Issuing a sync to force data to disk
splitting off leg from raid with tracking...
taft-01: lvconvert --splitmirrors 1 --trackchanges split_image/split_tracking

+++ Mounting and verifying split image data +++
mount: block device /dev/mapper/split_image-split_tracking_rimage_2 is write-protected, mounting read-only
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingA.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.26258
Working dir:        /mnt/split_tracking_rimage_2

Writing new data to the raid and then merging back the split off image
Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingB.26258 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        17347
Verify XIOR Stream: /tmp/split_trackingB.26258
Working dir:        /mnt/split_tracking
Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingB.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingB.26258
Working dir:        /mnt/split_tracking
Writing files to /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingC.26258 -n 500
checkit starting with:
CREATE
Num files:          500
Random Seed:        17351
Verify XIOR Stream: /tmp/split_trackingC.26258
Working dir:        /mnt/split_tracking
Checking files on /mnt/split_tracking
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking -f /tmp/split_trackingC.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingC.26258
Working dir:        /mnt/split_tracking
Merge split off image split_image/split_tracking_rimage_2 back into the raid
lvconvert --merge split_image/split_tracking_rimage_2

Waiting until all mirror|raid volumes become fully syncd...
   1/1 mirror(s) are fully synced: ( 100.00% )
Issuing a sync to force data to disk
AGAIN, splitting off leg from raid with tracking...
taft-01: lvconvert --splitmirrors 1 --trackchanges split_image/split_tracking

+++ Mounting and verifying split image data +++
mount: block device /dev/mapper/split_image-split_tracking_rimage_2 is write-protected, mounting read-only
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingA.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingA.26258
Working dir:        /mnt/split_tracking_rimage_2
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingB.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingB.26258
Working dir:        /mnt/split_tracking_rimage_2
Checking files on /mnt/split_tracking_rimage_2
/usr/tests/sts-rhel6.3/bin/checkit -w /mnt/split_tracking_rimage_2 -f /tmp/split_trackingC.26258 -v
checkit starting with:
VERIFY
Verify XIOR Stream: /tmp/split_trackingC.26258
Working dir:        /mnt/split_tracking_rimage_2

Merge split off image split_image/split_tracking_rimage_2 back so it can be deleted
lvconvert --merge split_image/split_tracking_rimage_2

Deactivating mirror split_tracking... and removing

Comment 9 errata-xmlrpc 2012-06-20 08:45:15 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.

http://rhn.redhat.com/errata/RHSA-2012-0862.html