Bug 468911 - RHEL5 cmirror tracker: Invalid "fully synced" copy percent after up conversion from core to disk log
RHEL5 cmirror tracker: Invalid "fully synced" copy percent after up conversio...
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: cmirror (Show other bugs)
5.3
All Linux
medium Severity medium
: rc
: ---
Assigned To: Jonathan Earl Brassow
Cluster QE
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2008-10-28 15:09 EDT by Corey Marthaler
Modified: 2010-01-11 21:08 EST (History)
8 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2009-01-20 16:26:22 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Corey Marthaler 2008-10-28 15:09:20 EDT
Description of problem:
This may be a side effect of the fix for bz 464550 or may even be bz 387601 showing up again, but since I don't know I'm going to file a new bug.

Scenario: Kill disk log of synced 2 leg mirror(s)                               

****** Mirror hash info for this scenario ******
* name:         syncd_log_2legs                 
* sync:         1                               
* num mirrors:  3                               
* disklog:      /dev/sdh1                       
* failpv:       /dev/sdh1                       
* leg devices:  /dev/sdf1 /dev/sdg1             
************************************************

Creating mirror(s) on taft-02...
taft-02: lvcreate -m 1 -n syncd_log_2legs_1 -L 600M helter_skelter /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150
taft-02: lvcreate -m 1 -n syncd_log_2legs_2 -L 600M helter_skelter /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150
taft-02: lvcreate -m 1 -n syncd_log_2legs_3 -L 600M helter_skelter /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150

Waiting until all mirrors become fully syncd...
        0/3 mirror(s) are fully synced: ( 1=21.92% 2=12.50% 3=1.92% )
        0/3 mirror(s) are fully synced: ( 1=48.42% 2=38.58% 3=29.75% )
        0/3 mirror(s) are fully synced: ( 1=74.58% 2=64.75% 3=57.33% )
        1/3 mirror(s) are fully synced: ( 1=100.00% 2=91.08% 3=85.42% )
        3/3 mirror(s) are fully synced: ( 1=100.00% 2=100.00% 3=100.00% )

Creating gfs on top of mirror(s) on taft-01...
Mounting mirrored gfs filesystems on taft-01...
Mounting mirrored gfs filesystems on taft-02...
Mounting mirrored gfs filesystems on taft-03...
Mounting mirrored gfs filesystems on taft-04...

Writing verification files (checkit) to mirror(s) on...
        ---- taft-01 ----    
        ---- taft-02 ----
        ---- taft-03 ----
        ---- taft-04 ----


<start name="taft-01_1" pid="16692" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-01_2" pid="16694" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-01_3" pid="16696" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-02_1" pid="16698" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-02_2" pid="16700" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-02_3" pid="16702" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-03_1" pid="16704" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-03_2" pid="16706" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-03_3" pid="16708" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-04_1" pid="16710" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-04_2" pid="16712" time="Mon Oct 27 18:45:42 2008" type="cmd" />
<start name="taft-04_3" pid="16714" time="Mon Oct 27 18:45:42 2008" type="cmd" />
Sleeping 10 seconds to get some outsanding GFS I/O locks before the failure      
Verifying files (checkit) on mirror(s) on...                                     
        ---- taft-01 ----   
        ---- taft-02 ----
        ---- taft-03 ----
        ---- taft-04 ----

Disabling device sdh on taft-01
Disabling device sdh on taft-02
Disabling device sdh on taft-03
Disabling device sdh on taft-04

Attempting I/O to cause mirror down conversion(s) on taft-02
10+0 records in                                             
10+0 records out                                            
41943040 bytes (42 MB) copied, 19.5788 seconds, 2.1 MB/s    
Verifying the down conversion of the failed mirror(s)       
  /dev/sdh1: open failed: No such device or address         
Verifying FAILED device /dev/sdh1 is *NOT* in the volume(s) 
  /dev/sdh1: open failed: No such device or address         
Verifying LEG device /dev/sdf1 *IS* in the volume(s)        
  /dev/sdh1: open failed: No such device or address         
Verifying LEG device /dev/sdg1 *IS* in the volume(s)        
  /dev/sdh1: open failed: No such device or address         
Verify the dm devices associated with /dev/sdh1 are no longer present
Verify the order of legs didn't shift after the down conversion      
  /dev/sdh1: open failed: No such device or address                  
  /dev/sdh1: open failed: No such device or address                  
  /dev/sdh1: open failed: No such device or address                  
  /dev/sdh1: open failed: No such device or address                  
  /dev/sdh1: open failed: No such device or address                  
  /dev/sdh1: open failed: No such device or address                  

Verifying files (checkit) on mirror(s) on...
        ---- taft-01 ----
        ---- taft-02 ----
        ---- taft-03 ----
        ---- taft-04 ----

Enabling device sdh on taft-01
Enabling device sdh on taft-02
Enabling device sdh on taft-03
Enabling device sdh on taft-04

Recreating PV /dev/sdh1
  WARNING: Volume group helter_skelter is not consistent
  WARNING: Volume Group helter_skelter is not consistent
  WARNING: Volume group helter_skelter is not consistent
Extending the recreated PV back into VG helter_skelter
Up converting linear(s) back to mirror(s) on taft-02...
taft-02: lvconvert -m 1 -b helter_skelter/syncd_log_2legs_1 /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150
taft-02: lvconvert -m 1 -b helter_skelter/syncd_log_2legs_2 /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150
taft-02: lvconvert -m 1 -b helter_skelter/syncd_log_2legs_3 /dev/sdf1:0-1000 /dev/sdg1:0-1000 /dev/sdh1:0-150
Verifying the up conversion from linear(s) to mirror(s)
Verifying device /dev/sdf1 *IS* one of the legs in the mirror(s)
Verifying device /dev/sdg1 *IS* one of the legs in the mirror(s)

Waiting until all mirrors become fully syncd...
        3/3 mirror(s) are fully synced: ( 1=100.00% 2=100.00% 3=100.00% )
syncd_log_2legs_3 is not fully sync'ed on taft-01 (101.33%)
run_iteration() method failed at /home/msp/cmarthal/work/rhel5/sts-root/lib/FI_engine.pm line 21.

I only see this "oversync'ed" issue on taft-01. All other nodes in the cluster are where they should be.

TAFT-01:
[root@taft-01 tmp]# lvs -a -o +devices
  LV                           VG             Attr   LSize   Origin Snap%  Move Log                    Copy%  Convert Devices                                                    
  LogVol00                     VolGroup00     -wi-ao  66.19G                                                          /dev/sda2(0)                                               
  LogVol01                     VolGroup00     -wi-ao   1.94G                                                          /dev/sda2(2118)                                            
  syncd_log_2legs_1            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_1_mlog 100.00         syncd_log_2legs_1_mimage_0(0),syncd_log_2legs_1_mimage_1(0)
  [syncd_log_2legs_1_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(0)                                               
  [syncd_log_2legs_1_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(0)                                               
  [syncd_log_2legs_1_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(0)                                               
  syncd_log_2legs_2            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_2_mlog 100.00         syncd_log_2legs_2_mimage_0(0),syncd_log_2legs_2_mimage_1(0)
  [syncd_log_2legs_2_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(150)                                             
  [syncd_log_2legs_2_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(150)                                             
  [syncd_log_2legs_2_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(1)                                               
  syncd_log_2legs_3            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_3_mlog 101.33         syncd_log_2legs_3_mimage_0(0),syncd_log_2legs_3_mimage_1(0)
  [syncd_log_2legs_3_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(300)                                             
  [syncd_log_2legs_3_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(300)                                             
  [syncd_log_2legs_3_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(2)                                               


[root@taft-01 tmp]# dmsetup status
helter_skelter-syncd_log_2legs_3_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_1_mlog: 0 8192 linear 
helter_skelter-syncd_log_2legs_3_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2_mlog: 0 8192 linear 
helter_skelter-syncd_log_2legs_2_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_1_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_3: 0 1228800 mirror 2 253:11 253:12 1216/1200 1 AA 3 clustered_disk 253:10 A
helter_skelter-syncd_log_2legs_1_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2: 0 1228800 mirror 2 253:7 253:8 1200/1200 1 AA 3 clustered_disk 253:6 A
helter_skelter-syncd_log_2legs_3_mlog: 0 8192 linear 
VolGroup00-LogVol01: 0 4063232 linear 
helter_skelter-syncd_log_2legs_1: 0 1228800 mirror 2 253:3 253:4 1200/1200 1 AA 3 clustered_disk 253:2 A
VolGroup00-LogVol00: 0 138805248 linear 


TAFT-02:
[root@taft-02 tmp]# dmsetup status
helter_skelter-syncd_log_2legs_3_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_1_mlog: 0 8192 linear 
helter_skelter-syncd_log_2legs_3_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2_mlog: 0 8192 linear 
helter_skelter-syncd_log_2legs_2_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_1_mimage_1: 0 1228800 linear 
helter_skelter-syncd_log_2legs_3: 0 1228800 mirror 2 253:11 253:12 1200/1200 1 AA 3 clustered_disk 253:10 A
helter_skelter-syncd_log_2legs_1_mimage_0: 0 1228800 linear 
helter_skelter-syncd_log_2legs_2: 0 1228800 mirror 2 253:7 253:8 1200/1200 1 AA 3 clustered_disk 253:6 A
helter_skelter-syncd_log_2legs_3_mlog: 0 8192 linear 
VolGroup00-LogVol01: 0 4063232 linear 
helter_skelter-syncd_log_2legs_1: 0 1228800 mirror 2 253:3 253:4 1200/1200 1 AA 3 clustered_disk 253:2 A
VolGroup00-LogVol00: 0 138805248 linear 

[root@taft-02 tmp]# lvs -a -o +devices
  LV                           VG             Attr   LSize   Origin Snap%  Move Log                    Copy%  Convert Devices                                                    
  LogVol00                     VolGroup00     -wi-ao  66.19G                                                          /dev/sda2(0)                                               
  LogVol01                     VolGroup00     -wi-ao   1.94G                                                          /dev/sda2(2118)                                            
  syncd_log_2legs_1            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_1_mlog 100.00         syncd_log_2legs_1_mimage_0(0),syncd_log_2legs_1_mimage_1(0)
  [syncd_log_2legs_1_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(0)                                               
  [syncd_log_2legs_1_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(0)                                               
  [syncd_log_2legs_1_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(0)                                               
  syncd_log_2legs_2            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_2_mlog 100.00         syncd_log_2legs_2_mimage_0(0),syncd_log_2legs_2_mimage_1(0)
  [syncd_log_2legs_2_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(150)                                             
  [syncd_log_2legs_2_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(150)                                             
  [syncd_log_2legs_2_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(1)                                               
  syncd_log_2legs_3            helter_skelter mwi-ao 600.00M                    syncd_log_2legs_3_mlog 100.00         syncd_log_2legs_3_mimage_0(0),syncd_log_2legs_3_mimage_1(0)
  [syncd_log_2legs_3_mimage_0] helter_skelter iwi-ao 600.00M                                                          /dev/sdf1(300)                                             
  [syncd_log_2legs_3_mimage_1] helter_skelter iwi-ao 600.00M                                                          /dev/sdg1(300)                                             
  [syncd_log_2legs_3_mlog]     helter_skelter lwi-ao   4.00M                                                          /dev/sdh1(2) 


Version-Release number of selected component (if applicable):
[root@taft-02 tmp]# /usr/tests/sts-rhel5.3/lvm2/bin/lvm_rpms 
2.6.18-117.el5

lvm2-2.02.40-6.el5    BUILT: Fri Oct 24 07:37:33 CDT 2008
lvm2-cluster-2.02.40-6.el5    BUILT: Fri Oct 24 07:38:44 CDT 2008
device-mapper-1.02.28-2.el5    BUILT: Fri Sep 19 02:50:32 CDT 2008
cmirror-1.1.33-1.el5    BUILT: Mon Oct 27 14:10:34 CDT 2008
kmod-cmirror-0.1.20-1.el5    BUILT: Mon Oct 20 14:13:37 CDT 2008
Comment 1 Corey Marthaler 2008-10-28 15:11:33 EDT
FYI - clogd is still running on all nodes:

[root@taft-01 tmp]# ps -elf | grep clogd
5 S root      6850     1  0  75   0 -  4564 -      Oct27 ?        00:07:00 clogd

[root@taft-02 tmp]# ps -elf | grep clogd
5 S root      6840     1  0  75   0 -  4567 923284 Oct27 ?        00:04:55 clogd

[root@taft-03 tmp]# ps -elf | grep clogd
5 S root      6836     1  0  75   0 -  4559 923284 Oct27 ?        00:05:07 clogd

[root@taft-04 tmp]# ps -elf | grep clogd
5 S root      6832     1  0  75   0 -  4594 923284 Oct27 ?        00:05:07 clogd
Comment 2 Corey Marthaler 2008-10-29 10:36:39 EDT
Reproduced this again last night. Again it was just one node in the cluster
with the invalid "full" percent (this time it was taft-04 instead of taft-01).


[Helter_skelter]
Enabling device sdf on taft-01
Enabling device sdf on taft-02
Enabling device sdf on taft-03
Enabling device sdf on taft-04

Recreating PV /dev/sdf1
  WARNING: Volume group helter_skelter is not consistent
  WARNING: Volume Group helter_skelter is not consistent
  WARNING: Volume group helter_skelter is not consistent
Extending the recreated PV back into VG helter_skelter
Up converting linear(s) back to mirror(s) on taft-02...
taft-02: lvconvert -m 1 -b helter_skelter/syncd_log_2legs_1 /dev/sde1:0-1000
/dev/sdh1:0-1000 /dev/sdf1:0-150
taft-02: lvconvert -m 1 -b helter_skelter/syncd_log_2legs_2 /dev/sde1:0-1000
/dev/sdh1:0-1000 /dev/sdf1:0-150
Verifying the up conversion from linear(s) to mirror(s)
Verifying device /dev/sde1 *IS* one of the legs in the mirror(s)
Verifying device /dev/sdh1 *IS* one of the legs in the mirror(s)

Waiting until all mirrors become fully syncd...
        2/2 mirror(s) are fully synced: ( 1=100.00% 2=100.00% )
syncd_log_2legs_2 is not fully sync'ed on taft-04 (101.33%)
run_iteration() method failed at
/home/msp/cmarthal/work/rhel5/sts-root/lib/FI_engine.pm line 21.


helter_skelter-syncd_log_2legs_2: 0 1228800 mirror 2 253:7 253:8 1216/1200 1 AA
3 clustered_disk 253:6 A


2.6.18-117.el5

lvm2-2.02.40-6.el5    BUILT: Fri Oct 24 07:37:33 CDT 2008
lvm2-cluster-2.02.40-6.el5    BUILT: Fri Oct 24 07:38:44 CDT 2008
device-mapper-1.02.28-2.el5    BUILT: Fri Sep 19 02:50:32 CDT 2008
cmirror-1.1.33-1.el5    BUILT: Mon Oct 27 14:10:34 CDT 2008
kmod-cmirror-0.1.20-1.el5    BUILT: Mon Oct 20 14:13:37 CDT 2008
Comment 3 Jonathan Earl Brassow 2008-11-05 16:17:49 EST
commit 4e799d9133c420aff721887308a0f38fcf995a03
Author: Jonathan Brassow <jbrassow@redhat.com>
Date:   Mon Nov 3 09:39:37 2008 -0600

    clogd:  Fix for bug 468911 - sync %'age can go over 100%

    Bitmaps are created in 32-bit chunk sizes, but the needed
    number of bits is not always a multiple of this.  Sometimes,
    the extra remaining bits could be set and erroneously
    counted.  Generally a harmless error, but for those looking
    for 100% completion, it might surprise them (or scripts) to
    get something larger.
Comment 8 errata-xmlrpc 2009-01-20 16:26:22 EST
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHEA-2009-0158.html

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