Skip to contentSkip to conversation

libdm-iface: not output error message inside retry loops

PATCH New Liuhua Wang 2 participants 8 messages Aug 27, 2015 – Aug 31, 2015

lore
Share & tools
lore
#0 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

To avoid noisy error message being output inside retry loops in case of remove failure because device busy.

---
 libdm/ioctl/libdm-iface.c | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)
libdm/ioctl/libdm-iface.c +3 -2
index 73af12b..287e917 100644
@@ -63,6 +63,8 @@
 #define MAPPER_CTRL_MINOR 236
 #define MISC_MAJOR 10
 
+#define DM_IOCTL_RETRIES 25
+
 /* dm major version no for running kernel */
 static unsigned _dm_version = DM_VERSION_MAJOR;
 static unsigned _dm_version_minor = 0;
@@ -1848,7 +1850,7 @@ static struct dm_ioctl *_do_dm_ioctl(struct dm_task *dmt, unsigned command,
 					    dmt->major > 0 && dmt->minor == 0 ? "0" : "",
 					    dmt->major > 0 ? ")" : "",
 					    strerror(dmt->ioctl_errno));
-			else
+			else if(dmt->ioctl_errno != EBUSY || retry_repeat_count == DM_IOCTL_RETRIES)
 				log_error("device-mapper: %s ioctl on %s%s%s%.0d%s%.0d%s%s "
 					  "failed: %s",
 					  _cmd_data_v4[dmt->type].name,
@@ -1901,7 +1903,6 @@ void dm_task_update_nodes(void)
 	update_devs();
 }
 
-#define DM_IOCTL_RETRIES 25
 #define DM_RETRY_USLEEP_DELAY 200000
 
 int dm_task_get_errno(struct dm_task *dmt)
Signature · 1 line
1.8.4.5
#1 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Dne 27.8.2015 v 10:30 Liuhua Wang napsal(a):

Quoted 3 lines

To avoid noisy error message being output inside retry loops in case of remove failure because device busy.
---

Hi

It's in fact made 'noisy' intentionally - we normally should detect whether retry makes sense - so what are the conditions when you experience this problem ?

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

Regards

Zdenek

#2 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Hi Zdenek,

Thanks for your reply.

Quoted 9 lines

It's in fact made 'noisy' intentionally - we normally should detect whether retry makes sense - so what are the conditions when you experience this problem ?

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

We first found this problem when we were testing lvcreate-usage.sh included in lvm2-2.02.120 package. The case always failed due to the following message:
device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by udev. Falling back to direct node removal.

Then we tested more cases and found the problem occurs in the following cases:
- lvremove/lvcreate a snap lv
- lvremove/lvcreate a thin lv
- lvremove/lvcreate a mirror lv

o Reproduce frequency:
lvremove about 80%, lvcreate occurs occasionally

With the patch I attached, the lvcreate-usage.sh will not fail due to the error message.

Regards,
Liuhua

#3 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Dne 28.8.2015 v 04:58 Liuhua Wang napsal(a):

Quoted 10 lines

Hi Zdenek,

Thanks for your reply.

Quoted 6 lines

It's in fact made 'noisy' intentionally - we normally should detect whether retry makes sense - so what are the conditions when you experience this problem ?

Common scenario:

Quoted 8 lines
Quoted 3 lines

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

We first found this problem when we were testing lvcreate-usage.sh included in lvm2-2.02.120 package. The case always failed due to the following message:
device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by udev. Falling back to direct node removal.

Looks like udev issue.

Quoted 10 lines

Then we tested more cases and found the problem occurs in the following cases:
- lvremove/lvcreate a snap lv
- lvremove/lvcreate a thin lv
- lvremove/lvcreate a mirror lv

o Reproduce frequency:
lvremove about 80%, lvcreate occurs occasionally

With the patch I attached, the lvcreate-usage.sh will not fail due to the error message.

What is your system - is it Debian/Ubuntu?

These tests depend on properly working udev rules.

Zdenek

#4 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Thanks for your reply.

Quoted 6 lines
Quoted 5 lines

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

Quoted 6 lines
Quoted 4 lines

We first found this problem when we were testing lvcreate-usage.sh included in lvm2-2.02.120 package. The case always failed due to the following message:
device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by udev. Falling >>back to direct node removal.

Looks like udev issue.

You mean udev cookie related problem? Because I see udev cookie add and remove a little weird.

Quoted 6 lines
Quoted 5 lines

Then we tested more cases and found the problem occurs in the following cases:
- lvremove/lvcreate a snap lv
- lvremove/lvcreate a thin lv
- lvremove/lvcreate a mirror lv

Quoted 8 lines
Quoted 4 lines

o Reproduce frequency:
lvremove about 80%, lvcreate occurs occasionally

With the patch I attached, the lvcreate-usage.sh will not fail due to the error message.

What is your system - is it Debian/Ubuntu?

These tests depend on properly working udev rules.

We are using SuSE SLES12.
#udev version
210

Regards,
Liuhua

#5 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Dne 28.8.2015 v 13:24 Liuhua Wang napsal(a):

Quoted 9 lines

Thanks for your reply.

Quoted 6 lines
Quoted 5 lines

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

Quoted 9 lines
Quoted 6 lines
Quoted 4 lines

We first found this problem when we were testing lvcreate-usage.sh included in lvm2-2.02.120 package. The case always failed due to the following message:
device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by udev. Falling >>back to direct node removal.

Looks like udev issue.

You mean udev cookie related problem? Because I see udev cookie add and remove a little weird.

So the question #1 - are you using upstream lvm2 udev rules ? (matching with install package)

Are there any modification made to upsteam lvm2 udev rules? (Debian is usually having problems with those)

The rules are quite complex and any 'touch 'to them should be consulted with upstream authors.

Could you create / remove snapshots without any problems.

I guess you should probably post failing logs for better diagnostic.

Zdenek

#6 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Hi Zdenek,

Quoted 1 line
Quoted 1 line
Quoted 1 line

On 8/28/2015 at 07:52 PM, in message <[email protected]>, Zdenek

Quoted 27 lines · Kabelac

Dne 28.8.2015 v 13:24 Liuhua Wang napsal(a):

Quoted 10 lines

Thanks for your reply.

Quoted 7 lines
Quoted 7 lines

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

We first found this problem when we were testing lvcreate-usage.sh

included in

Quoted 1 line
Quoted 1 line
Quoted 1 line

lvm2-2.02.120 package. The case always failed due to the following

message:

Quoted 2 lines
Quoted 2 lines
Quoted 2 lines

device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by

udev. Falling >>back to direct node removal.

Quoted 3 lines
Quoted 2 lines

Looks like udev issue.

You mean udev cookie related problem? Because I see udev cookie add and

remove

Quoted 2 lines

a little weird.

So the question #1 - are you using upstream lvm2 udev rules ? (matching with install package)

Quoted 6 lines

Are there any modification made to upsteam lvm2 udev rules? (Debian is usually having problems with those)

The rules are quite complex and any 'touch 'to them should be consulted with

upstream authors.

Yes, udev rules have been modified a little, but even I replace them all with upstream rules and reloaded, still has the issue.

Quoted 3 lines

Could you create / remove snapshots without any problems.

I guess you should probably post failing logs for better diagnostic.

I attached my test log.

# lvcreate -s -L20M -nsnap vg/lv
  Logical volume "snap" created.
# lsblk 
NAME          MAJ:MIN RM  SIZE RO TYPE MOUNTPOINT
[...]
loop1           7:1    0   50M  0 loop 
??vg-lv-real  253:1    0   32M  0 lvm  
  ??vg-lv     253:0    0   32M  0 lvm  
  ??vg-snap   253:3    0   32M  0 lvm  
loop2           7:2    0   50M  0 loop 
??vg-snap-cow 253:2    0   20M  0 lvm  
  ??vg-snap   253:3    0   32M  0 lvm  
 # lvremove -ff vg/snap -vvvvv >lvremove-snap-failed.log 2>&1

Please see the detailed log attatched.
Thank you very much.

Regards,
Liuhua
-------------- next part --------------
A non-text attachment was scrubbed...
Name: lvremove-snap-failed.log
Type: application/octet-stream
Size: 61887 bytes
Desc: not available
URL: <http://listman.redhat.com/archives/lvm-devel/attachments/20150831/0af6c74f/attachment.obj>

#7 lore raw

PATCH 1/1 libdm-iface: not output error message inside retry loops

Dne 31.8.2015 v 10:39 Liuhua Wang napsal(a):

Quoted 31 lines

Hi Zdenek,

Quoted 1 line
Quoted 1 line
Quoted 1 line

On 8/28/2015 at 07:52 PM, in message <[email protected]>, Zdenek

Quoted 27 lines · Kabelac

Dne 28.8.2015 v 13:24 Liuhua Wang napsal(a):

Quoted 10 lines

Thanks for your reply.

Quoted 7 lines
Quoted 7 lines

Common scenario:

The major reason for retry is 'unpredictable' udev event processing i.e. you run 'umount' -> fires watch-rule -> lvremove could have failed - retry fixes this problem.

We first found this problem when we were testing lvcreate-usage.sh

included in

Quoted 1 line
Quoted 1 line
Quoted 1 line

lvm2-2.02.120 package. The case always failed due to the following

message:

Quoted 2 lines
Quoted 2 lines
Quoted 2 lines

device-mapper: remove ioctl on (253:6) failed: Device or resource busy
[ 0:01] Node @TESTDIR@/dev/mapper/@PREFIX at vg-LV2-cow was not removed by

udev. Falling >>back to direct node removal.

Quoted 3 lines
Quoted 2 lines

Looks like udev issue.

You mean udev cookie related problem? Because I see udev cookie add and

remove

Quoted 2 lines

a little weird.

So the question #1 - are you using upstream lvm2 udev rules ? (matching with install package)

Quoted 8 lines
Quoted 6 lines

Are there any modification made to upsteam lvm2 udev rules? (Debian is usually having problems with those)

The rules are quite complex and any 'touch 'to them should be consulted with

upstream authors.

Yes, udev rules have been modified a little, but even I replace them all with upstream rules and reloaded, still has the issue.

I'm afraid full audit of your udev rules is necessary then.

Upstream is developed on Fedora - so rules are checked there.

If your system has different rules - then more careful check is needed. (and it's btw reason why we show those errors)

Quoted 3 lines
  # lvremove -ff vg/snap -vvvvv >lvremove-snap-failed.log 2>&1

vg-snap-cow is resumed with:

DISABLE_SUBSYSTEM_RULES DISABLE_DISK_RULES DISABLE_OTHER_RULES DISABLE_LIBRARY_FALLBACK

these rule flag's normally ensure udev will not even try to look on these volumes - however you get:

device-mapper: remove ioctl on (253:2) failed: Device or resource busy

So clearly something holds this open.

To trace out this case - you need to run 'udevd' in 'debug/verbose' mode and capture which rule is accessing DM device (since normally upstream udev actually skips anything 'dm' related and only we provide rules accessing dm devices)

Udev tracing however slows down processing of udev rules so it might be trickier to capture error - but anyway - you should find out which rule cause read of -cow volume - such volume should never be scanned by udev.

As a side note - I do plan to rewrite snapshot deactivation code - but it will take a while - this could would eliminate resume of -cow completely.

Regards

Zdenek