Bug 1014806

Summary: overkill of messages when attempting to deactivate a VG containing a thin snap being written too
Product: Red Hat Enterprise Linux 6 Reporter: Corey Marthaler <cmarthal>
Component: lvm2Assignee: Zdenek Kabelac <zkabelac>
Status: CLOSED ERRATA QA Contact: cluster-qe <cluster-qe>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.5CC: agk, dwysocha, heinzm, jbrassow, msnitzer, prajnoha, prockai, thornber, zkabelac
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: lvm2-2.02.140-1.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: 979560 Environment:
Last Closed: 2016-05-11 01:14:51 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: 979560    
Bug Blocks:    

Description Corey Marthaler 2013-10-02 20:19:30 UTC 
This exists in rhel6.5 as well.

+++ This bug was initially created as a clone of Bug #979560 +++

Description of problem:
Wouldn't one easy to read "device in use" message be better when attempting to deactivate a VG containing a thin snap that's being written too?


[root@qalvm-01 ~]# lvs -a -o +devices
  LV           Attr      LSize  Pool Origin Data%  Devices
  POOL         twi-a-tz-  8.00g              19.47 POOL_tdata(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdh1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdg1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdf1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vde1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdd1(2)
  [POOL_tmeta] ewi-ao---  8.00m                    /dev/vdd1(0)
  block_snap16 Vwi-aotz-  4.00g POOL origin  24.81
  origin       Vwi-aotz-  4.00g POOL         31.90
  other1       Vwi-a-tz-  4.00g POOL          0.00
  other2       Vwi-a-tz-  4.00g POOL          0.00
  other3       Vwi-a-tz-  4.00g POOL          0.00
  other4       Vwi-a-tz-  4.00g POOL          0.00
  other5       Vwi-a-tz-  4.00g POOL          0.00

# running block I/O to snap block_snap16

[root@qalvm-01 ~]# vgchange -an snapper_thinp
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  Unable to deactivate snapper_thinp-origin (253:6)
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  device-mapper: remove ioctl on  failed: Device or resource busy
  Unable to deactivate snapper_thinp-block_snap16 (253:12)
  2 logical volume(s) in volume group "snapper_thinp" now active
[root@qalvm-01 ~]# lvs -a -o +devices
  LV           VG            Attr      LSize  Pool Origin Data%  Devices
  POOL         twi---tz-  8.00g              20.51 POOL_tdata(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdh1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdg1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdf1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vde1(0)
  [POOL_tdata] Twi-ao---  8.00g                    /dev/vdd1(2)
  [POOL_tmeta] ewi-ao---  8.00m                    /dev/vdd1(0)
  block_snap16 Vwi-aotz-  4.00g POOL origin  24.81
  origin       Vwi-aotz-  4.00g POOL         32.91
  other1       Vwi---tz-  4.00g POOL
  other2       Vwi---tz-  4.00g POOL
  other3       Vwi---tz-  4.00g POOL
  other4       Vwi---tz-  4.00g POOL



Version-Release number of selected component (if applicable):
3.8.0-0.40.el7.x86_64
lvm2-2.02.99-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
lvm2-libs-2.02.99-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
lvm2-cluster-2.02.99-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
device-mapper-1.02.78-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
device-mapper-libs-1.02.78-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
device-mapper-event-1.02.78-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
device-mapper-event-libs-1.02.78-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013
cmirror-2.02.99-0.57.el7    BUILT: Mon Jun 17 08:28:21 CDT 2013

--- Additional comment from Zdenek Kabelac on 2013-06-29 18:22:01 EDT ---

(In reply to Corey Marthaler from comment #0)
> Description of problem:
> Wouldn't one easy to read "device in use" message be better when attempting
> to deactivate a VG containing a thin snap that's being written too?
> 

Well 2 things are running here against each other.

We have the AI udev daemon in the system - which runs it's scanning rules,
and currently there is no synchronization with udev  (needs udevmonitor).

So to avoid sporadic and random failures from 'lvremove' - retry of operation has been introduced  (activation/retry_deactivation = 1)

If you disable it - it will not log so many messages, when it is enables,
with current code it's not easy to distinguish from 'short living' udev scans, and long live open from some other commands -  tools just try to detect 'mounted' filesystem (possibly the most common case) and in this case there will be no retry.

There is longterm plan to import udevmonitor support into the tool, which should allow a smarter synchronization - but it's rather in design phase.


> # running block I/O to snap block_snap16
> 
> [root@qalvm-01 ~]# vgchange -an snapper_thinp
>   device-mapper: remove ioctl on  failed: Device or resource busy
>   device-mapper: remove ioctl on  failed: Device or resource busy
>   device-mapper: remove ioctl on  failed: Device or resource busy

Severity of log message though is questionable.
IMHO 'log_error()' is too scary and for all non-final logs I'd prefer rather debug level - but then user could be wondering why it takes so long to finish the command....

So it needs some decision to be made upstream.

--- Additional comment from Peter Rajnoha on 2013-07-01 04:26:16 EDT ---

(In reply to Zdenek Kabelac from comment #1)
> (In reply to Corey Marthaler from comment #0)
> > Description of problem:
> > Wouldn't one easy to read "device in use" message be better when attempting
> > to deactivate a VG containing a thin snap that's being written too?
> > 
> 
> Well 2 things are running here against each other.
> 
> We have the AI udev daemon in the system - which runs it's scanning rules,
> and currently there is no synchronization with udev  (needs udevmonitor).

(...currently there *is* synchronization, but not for the events coming from the WATCH udev rule - happenning on each close of the device opened for read-write before... just to make things clear and not to mystify if someone else is reading this by chance)
Comment 6 Corey Marthaler 2016-03-28 23:19:49 UTC 
Fix verified in the latest rpms.

2.6.32-633.el6.x86_64
lvm2-2.02.143-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
lvm2-libs-2.02.143-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
lvm2-cluster-2.02.143-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
udev-147-2.72.el6    BUILT: Tue Mar  1 06:14:05 CST 2016
device-mapper-1.02.117-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
device-mapper-libs-1.02.117-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
device-mapper-event-1.02.117-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
device-mapper-event-libs-1.02.117-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016
device-mapper-persistent-data-0.6.2-0.1.rc7.el6    BUILT: Tue Mar 22 08:58:09 CDT 2016
cmirror-2.02.143-3.el6    BUILT: Tue Mar 22 09:26:10 CDT 2016



[root@host-118 ~]# vgchange -an snapper
  Logical volume snapper/block_snap16 in use.
  Can't deactivate volume group "snapper" with 2 open logical volume(s)
Comment 8 errata-xmlrpc 2016-05-11 01:14:51 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://rhn.redhat.com/errata/RHBA-2016-0964.html