1014806 – overkill of messages when attempting to deactivate a VG containing a thin snap being written too

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 1014806 - overkill of messages when attempting to deactivate a VG containing a thin snap being written too

Summary: overkill of messages when attempting to deactivate a VG containing a thin sna...

Keywords:
Status:	CLOSED ERRATA
Alias:	None
Product:	Red Hat Enterprise Linux 6
Classification:	Red Hat
Component:	lvm2
Sub Component:
Version:	6.5
Hardware:	x86_64
OS:	Linux
Priority:	medium
Severity:	medium
Target Milestone:	rc
Target Release:	---
Assignee:	Zdenek Kabelac
QA Contact:	cluster-qe@redhat.com
Docs Contact:
URL:
Whiteboard:
Depends On:	979560
Blocks:
TreeView+	depends on / blocked

Reported:	2013-10-02 20:19 UTC by Corey Marthaler
Modified:	2016-05-11 01:14 UTC (History)
CC List:	9 users (show)
Fixed In Version:	lvm2-2.02.140-1.el6
Doc Type:	Bug Fix
Doc Text:
Clone Of:	979560
Environment:
Last Closed:	2016-05-11 01:14:51 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Links
System	ID	Private	Priority	Status	Summary	Last Updated
Red Hat Product Errata	RHBA-2016:0964	0	normal	SHIPPED_LIVE	lvm2 bug fix and enhancement update	2016-05-10 22:57:40 UTC

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

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