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 645488 - Merged snapshot still present and throwing I/O errors after reboot
Summary: Merged snapshot still present and throwing I/O errors after reboot
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: lvm2
Version: 6.0
Hardware: x86_64
OS: Linux
high
high
Target Milestone: rc
: ---
Assignee: Mike Snitzer
QA Contact: Corey Marthaler
URL:
Whiteboard:
Depends On:
Blocks: 651007
TreeView+ depends on / blocked
 
Reported: 2010-10-21 16:06 UTC by John Ruemker
Modified: 2011-05-19 14:26 UTC (History)
13 users (show)

Fixed In Version: lvm2-2.02.82-1.el6
Doc Type: Bug Fix
Doc Text:
Clone Of:
: 650959 (view as bug list)
Environment:
Last Closed: 2011-05-19 14:26:57 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
lvmdump taken after merge and reboot (21.98 KB, application/x-gzip)
2010-10-21 16:06 UTC, John Ruemker 		no flags Details
sosreport taken after merge and reboot (236.95 KB, application/x-xz)
2010-10-21 16:07 UTC, John Ruemker 		no flags Details
boot sequence captured from serial console after merge and reboot (17.18 KB, text/plain)
2010-10-21 16:07 UTC, John Ruemker 		no flags Details
verbose output of lvremove of snap volume (19.21 KB, application/octet-stream)
2010-10-21 16:08 UTC, John Ruemker 		no flags Details
patch to fix merged snapshot cleanup, etc. (6.88 KB, patch)
2010-10-26 02:24 UTC, Mike Snitzer 		no flags Details | Diff
View All


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHBA-2011:0772 0 normal SHIPPED_LIVE lvm2 bug fix and enhancement update 2011-05-18 18:08:31 UTC

Description John Ruemker 2010-10-21 16:06:20 UTC 
Created attachment 454876 [details]
lvmdump taken after merge and reboot

Description of problem: 
After merging a snapshot of the root lv, upon reboot I/O errors are seen against the dm device for the snapshot (console-boot.log).  After this first reboot, the snapshot volume was still present and it appeared as if the merge was still in progress:

   # lvs -a
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316166656: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316224000: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 0: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 4096: Input/output error
     LV             VG          Attr   LSize   Origin  Snap%  Move Log Copy%  Convert
     lv_root        vg_dhcp5318 Owi-ao  10.54g           0.00                        
     [lv_root-snap] vg_dhcp5318 Swi-a-   1.17g lv_root 100.00                        
     lv_swap        vg_dhcp5318 -wi-ao 992.00m        


At first, the Snap% for lv_root was counting down to 0, but when it reached 0 nothing changed.  The snapshot was still present, and could not be removed:

   # lvremove vg_dhcp5318/lv_root-snap
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316166656: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316224000: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 0: Input/output error
     /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 4096: Input/output error
     Can't remove merging snapshot logical volume "lv_root-snap"

(-vvvv logs for lvremove attached as lvremove-vvvv.out).   I've now rebooted multiple times and the situation has not changed.

Version-Release number of selected component (if applicable): lvm2-2.02.72-8.el6.x86_64

How reproducible: Always (for me and my customer)

Steps to Reproduce:
Customer and I have both reproduced this problem in a KVM guest.  After installation, we add a 2nd device to the volume group and use it to create a snapshot of the root lv.  

  # pvcreate /dev/vdb
  # vgextend vg_dhcp5318 /dev/vdb
  # lvcreate -l 300 -s vg_dhcp5318/lv_root -n lv_root-snap
  
I make some changes to the system with yum, then merge the snapshot:

  # lvconvert --merge vg_dhcp5318/lv_root-snap
  Can't merge over open origin volume
  Merging of snapshot lv_root-snap will start next activation. 

Now reboot.
  
Actual results: I/O errors, and a snapshot that cannot be removed.


Expected results: No I/O errors, and the snapshot is automatically removed.


Additional info: Attaching sosreport and lvmdump.
Comment 1 John Ruemker 2010-10-21 16:07:13 UTC 
Created attachment 454877 [details]
sosreport taken after merge and reboot
Comment 2 John Ruemker 2010-10-21 16:07:52 UTC 
Created attachment 454878 [details]
boot sequence captured from serial console after merge and reboot
Comment 3 John Ruemker 2010-10-21 16:08:44 UTC 
Created attachment 454879 [details]
verbose output of lvremove of snap volume
Comment 5 Mike Snitzer 2010-10-21 20:34:23 UTC 
Looks like the lvm2 polldaemon code that tracks the snapshot% is not seeing the merge as complete even though 'dmsetup status' shows it is:

vg_dhcp5318-lv_root: 0 22102016 snapshot-merge 16/2457600 16

From Documentation/device-mapper/snapshot.txt

How to determine when a merging is complete
===========================================
The snapshot-merge and snapshot status lines end with:
  <sectors_allocated>/<total_sectors> <metadata_sectors>

Both <sectors_allocated> and <total_sectors> include both data and metadata.
During merging, the number of sectors allocated gets smaller and
smaller.  Merging has finished when the number of sectors holding data
is zero, in other words <sectors_allocated> == <metadata_sectors>.

I'll need to get back on the lvm2 snapshot-merge code bike to track down what regressed.. but I should be able to sort this out fairly quickly.


As for the IO errors, the reason you're seeing those is the various lvm commands will still try to access the old snapshot device even though it has been switched to use the "error" target (purposely done as part of the lvm's snapshot merge transaction):

# dmsetup status vg_dhcp5318-lv_root--snap
0 22102016 error 

So you'll get errors for any IO to that DM device:

# lvs
  /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316166656: Input/output error
  /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 11316224000: Input/output error
  /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 0: Input/output error
  /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at 4096: Input/output error
  LV      VG          Attr   LSize   Origin Snap%  Move Log Copy%  Convert
  lv_root vg_dhcp5318 Owi-ao  10.54g          0.00                        
  lv_swap vg_dhcp5318 -wi-ao 992.00m
Comment 6 Mike Snitzer 2010-10-21 20:37:49 UTC 
(In reply to comment #5)
> Looks like the lvm2 polldaemon code that tracks the snapshot% is not seeing the
> merge as complete even though 'dmsetup status' shows it is:
> 
> vg_dhcp5318-lv_root: 0 22102016 snapshot-merge 16/2457600 16
...
> I'll need to get back on the lvm2 snapshot-merge code bike to track down what
> regressed.. but I should be able to sort this out fairly quickly.

This is definitely an lvm2 polldaemon issue.  I was able to clean things up with:

 lvchange --refresh vg_dhcp5318/lv_root

before:

# dmsetup status
vg_dhcp5318-lv_root--snap: 0 22102016 error
vg_dhcp5318-lv_root-real: 0 22102016 linear
vg_dhcp5318-lv_root--snap-cow: 0 2457600 linear
vg_dhcp5318-lv_swap: 0 2031616 linear
vg_dhcp5318-lv_root: 0 22102016 snapshot-merge 16/2457600 16

after:

# dmsetup status
vg_dhcp5318-lv_swap: 0 2031616 linear 
vg_dhcp5318-lv_root: 0 22102016 linear 

# lvs
  LV      VG          Attr   LSize   Origin Snap%  Move Log Copy%  Convert
  lv_root vg_dhcp5318 -wi-ao  10.54g                                      
  lv_swap vg_dhcp5318 -wi-ao 992.00m
Comment 7 Alasdair Kergon 2010-10-22 12:09:20 UTC 
(In reply to comment #5)

> So you'll get errors for any IO to that DM device:

> # lvs
>   /dev/mapper/vg_dhcp5318-lv_root--snap: read failed after 0 of 4096 at
> 11316166656: Input/output error

This should not be happening.  If current upstream does it, it needs to be fixed.
Comment 8 Mike Snitzer 2010-10-25 20:16:47 UTC 
vgchange doesn't allow multiple actions to be taken (won't start both monitoring and polling):

# lvs -a
  LV      VG        Attr   LSize   Origin  Snap%  Move Log Copy%  Convert
  lv_root vg_f12lvm Owi-ao   7.30g           0.00                        
  [snap]  vg_f12lvm Swi-a- 200.00m lv_root 100.00                        
# /sbin/vgchange --monitor y --poll y vg_f12lvm 
  2 logical volume(s) in volume group "vg_f12lvm" monitored

# /sbin/vgchange --poll y vg_f12lvm 
  Background polling started for 1 logical volume(s) in volume group "vg_f12lvm"
# lvs
  LV      VG        Attr   LSize Origin Snap%  Move Log Copy%  Convert
  lv_root vg_f12lvm -wi-ao 7.30g


The way the code is written these options are mutually exclusive:

static int vgchange_single(...)
{
...
        else if (arg_count(cmd, monitor_ARG))
                r = _vgchange_monitoring(cmd, vg);

        else if (arg_count(cmd, poll_ARG))
                r = _vgchange_background_polling(cmd, vg);
...
}
Comment 9 Mike Snitzer 2010-10-26 02:24:16 UTC 
Created attachment 455664 [details]
patch to fix merged snapshot cleanup, etc.

Patch that provides a backport of the relevant upstream fixes to RHEL6's lvm2.
Comment 22 Corey Marthaler 2011-04-04 20:56:36 UTC 
Based on comments #13 and #15, the customer has verified that this issue is fixed in the latest rpms.

The 'reboot before merge' regression check added for this issue also passed (though it may not be the exact same case described in this bug). Marking verified.


2.6.32-128.el6.x86_64

lvm2-2.02.83-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
lvm2-libs-2.02.83-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
lvm2-cluster-2.02.83-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
udev-147-2.35.el6    BUILT: Wed Mar 30 07:32:05 CDT 2011
device-mapper-1.02.62-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
device-mapper-libs-1.02.62-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
device-mapper-event-1.02.62-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
device-mapper-event-libs-1.02.62-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011
cmirror-2.02.83-3.el6    BUILT: Fri Mar 18 09:31:10 CDT 2011



SCENARIO - [reboot_before_merge_starts]
Merge an inactive snapshot, then "reboot" the machine before the merge can take place
Making origin volume
Placing an ext filesystem on origin volume
mke2fs 1.41.12 (17-May-2010)
Mounting origin volume

Making snapshot of origin volume
Mounting snap volume

Attempt to merge snapshot snapper/merge_reboot
  Can't merge over open origin volume

  /var/lock/lvm/V_snapper: unlink failed: No such file or directory
Removing origin snapper/origin
Comment 23 errata-xmlrpc 2011-05-19 14:26:57 UTC 
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/RHBA-2011-0772.html
Note You need to log in before you can comment on or make changes to this bug.