Bug 979560

Summary: overkill of messages when attempting to deactivate a VG containing a thin snap being written too
Product: Red Hat Enterprise Linux 7 Reporter: Corey Marthaler <cmarthal>
Component: lvm2Assignee: LVM and device-mapper development team <lvm-team>
lvm2 sub component: Default / Unclassified QA Contact: cluster-qe <cluster-qe>
Status: CLOSED CURRENTRELEASE Docs Contact:
Severity: medium    
Priority: medium CC: agk, heinzm, jbrassow, msnitzer, prajnoha, prockai, thornber, zkabelac
Version: 7.0Keywords: Triaged
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: lvm2-2.02.105-2.el7 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 1014806 (view as bug list) Environment:
Last Closed: 2014-06-13 11:26:42 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:    
Bug Blocks: 1014806    

Description Corey Marthaler 2013-06-28 20:03:33 UTC
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

Comment 1 Zdenek Kabelac 2013-06-29 22:22:01 UTC
(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.

Comment 2 Peter Rajnoha 2013-07-01 08:26:16 UTC
(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 3 Alasdair Kergon 2013-10-02 23:58:50 UTC
For now, I suggest a solution that just fixes the log message problem, rather than changing any of the actual behaviour.

They way to do this is to decide what the best output for the user to see in these circumstances would be, then to work out how to change the code to produce something close to that.

Comment 7 Ludek Smid 2014-06-13 11:26:42 UTC
This request was resolved in Red Hat Enterprise Linux 7.0.

Contact your manager or support representative in case you have further questions about the request.