#409875 libdevmapper should provide more helpful error messages

Package:
src:lvm2
Source:
lvm2
Submitter:
Johannes Schlumberger
Date:
2015-06-30 05:13:01 UTC
Severity:
minor
#409875#5
Date:
2007-02-06 03:18:15 UTC
From:
To:
Hi,
when trying to create a mapping for /dev/md0 cryptsetup fails to do so.

[04:11:35][root@asso:/home/spjsschl]# cryptsetup -c aes -s 256 -d /dev/stdin
create root /dev/md0 < /key
Command failed: device-mapper: reload ioctl failed: Invalid argument

[04:12:57][root@asso:/home/spjsschl]# dmesg | tail -n 3
device-mapper: table: 253:2: crypt: Device lookup failed
device-mapper: ioctl: error adding target to table
device-mapper: ioctl: device doesn't appear to be in the dev hash table.

creating a mapping on a loop-device or my swap-partitions works just fine, as it
always did.

[04:12:58][root@asso:/home/spjsschl]# cat /proc/mdstat
Personalities : [raid1]
md0 : active raid1 hdd5[0] hdc1[1]
      19542976 blocks [2/2] [UU]

unused devices: <none>

I have attached my kernelconfig, if you need any other piece of information,
please let me know!
best regards,
        Johannes

#409875#10
Date:
2007-02-06 10:17:44 UTC
From:
To:
Hi,
after catching a little sleep I made a stacktrace of the cryptsetup call in my
initial mail. It is attached.

I think the Problem is in line 105 of the trace, since I do not have much
knowledge about devicemapper internas I am not able to see what is going wrong
exactly.
regards,
    Johannes

#409875#15
Date:
2007-02-06 21:45:30 UTC
From:
To:
Hi,

and thanks for the trace, the problem is indeed here:

that means that "crypt" is not a valid device-mapper target.

That in turn means that dm-crypt was not loaded and could not be
dynamically loaded by the kernel.

Could you please verify this by trying to run "modprobe dm-crypt"
and make sure that the dm-crypt module is loaded (check with "lsmod").

#409875#18
Date:
2007-02-06 21:45:30 UTC
From:
To:
Hi,

and thanks for the trace, the problem is indeed here:

that means that "crypt" is not a valid device-mapper target.

That in turn means that dm-crypt was not loaded and could not be
dynamically loaded by the kernel.

Could you please verify this by trying to run "modprobe dm-crypt"
and make sure that the dm-crypt module is loaded (check with "lsmod").

#409875#23
Date:
2007-02-06 22:02:21 UTC
From:
To:
Hi,

As you should be able to observe from my sent kernel config i have built
dm_crypt into the kernel, therefore it cannot (and has not to) be loaded
as a module.
regards,
    Johannes

#409875#28
Date:
2007-02-06 22:02:21 UTC
From:
To:
Hi,

As you should be able to observe from my sent kernel config i have built
dm_crypt into the kernel, therefore it cannot (and has not to) be loaded
as a module.
regards,
    Johannes

#409875#31
Date:
2007-02-06 22:02:21 UTC
From:
To:
Hi,

As you should be able to observe from my sent kernel config i have built
dm_crypt into the kernel, therefore it cannot (and has not to) be loaded
as a module.
regards,
    Johannes

#409875#36
Date:
2007-02-06 23:46:26 UTC
From:
To:
Sorry, I missed the attached kernel config.

Unfortunately I am not able to reproduce this. Using a qemu machine with
two virtual disks in a RAID set, the crypt mapping is setup correctly.

If I do make sure that the dm-crypt.ko module is not available, the
error messages and strace exactly match yours.

What output do you get from "dmsetup targets"?

#409875#41
Date:
2007-02-06 23:51:52 UTC
From:
To:
Hi,

[00:50:29][root@asso:/home/spjsschl]# dmsetup targets
crypt            v1.3.0
striped          v1.0.2
linear           v1.0.2
error            v1.0.1
regards,
    Johannes

#409875#46
Date:
2007-02-07 21:24:57 UTC
From:
To:
0 10000 crypt aes-cbc-essiv:sha256 0123456789abcdef0123456789abcdef 0 /dev/md0 0

then run "dmsetup create root map" and see if that fails?

#409875#51
Date:
2007-02-07 21:31:27 UTC
From:
To:
Hi,

shure.
[22:28:31][root@asso:/tmp]# echo '0 10000 crypt aes-cbc-essiv:sha256 \
0123456789abcdef0123456789abcdef 0 /dev/md0 0' > map
[22:28:46][root@asso:/tmp]# dmsetup create root map
device-mapper: reload ioctl failed: Invalid argument
Command failed

the dmesg output differs though, its missing one line.

[22:28:57][root@asso:/tmp]# dmesg | tail -n 3
agpgart: Putting AGP V3 device at 0000:01:00.0 into 8x mode
device-mapper: table: 253:2: crypt: Device lookup failed
device-mapper: ioctl: error adding target to table
best regards,
    Johannes

#409875#56
Date:
2007-02-07 22:03:43 UTC
From:
To:
This would suggest that the problem is not with cryptsetup at least.
Something seems wonky with device-mapper in general.

I've updated the testing machine I was using so that it has the same
package versions as your machine and it still works for me.

Just to make sure, do you think you could install the Debian packaged
kernel, boot it and try to setup the mapping with that kernel? (but do
the things mentioned below first)

If it tries to setup 253:2, that suggests that there are two other
device-mapper devices already setup...what is the output of "ls -al
/dev/mapper", "dmsetup table" and "cat /proc/mounts"? Also, are you
using udev?

#409875#61
Date:
2007-02-07 22:26:16 UTC
From:
To:
Hi,

Whom should I be talking to about this?

[23:18:42][root@asso:~]# uname -r
2.6.18-4-486
[23:18:47][root@asso:~]# apt-cache policy linux-image-2.6.18-4-486
linux-image-2.6.18-4-486:
  Installed: 2.6.18.dfsg.1-10
  Candidate: 2.6.18.dfsg.1-10
  Version table:
 *** 2.6.18.dfsg.1-10 0
        500 http://debian.informatik.uni-erlangen.de sid/main Packages
        100 /var/lib/dpkg/status
[23:19:02][root@asso:~]# modprobe dm-crypt
[23:19:14][root@asso:~]# lsmod | grep !$
lsmod | grep dm-crypt
[23:19:19][root@asso:~]# lsmod | grep dm_crypt
dm_crypt               10888  1
dm_mod                 48952  7 dm_crypt,dm_snapshot,dm_mirror
[23:19:29][root@asso:~]# cryptsetup -c aes -s 256 -d /dev/stdin create root /dev/md0 </key
Command failed: device-mapper: reload ioctl failed: Invalid argument
[23:19:36][root@asso:~]# dmesg | tail -n 3
device-mapper: table: 253:2: crypt: Device lookup failed
device-mapper: ioctl: error adding target to table
device-mapper: ioctl: device doesn't appear to be in the dev hash table.
[23:19:42][root@asso:~]#

[23:21:59][spjsschl@asso:~]$ ls -al /dev/mapper/
total 0
drwxr-xr-x  2 root root     100 2007-02-07 23:21 .
drwxr-xr-x 14 root root    4520 2007-02-07 23:21 ..
crw-rw----  1 root root  10, 63 2007-02-08 00:21 control
brw-rw----  1 root disk 253,  0 2007-02-07 23:21 swap1
brw-rw----  1 root disk 253,  1 2007-02-07 23:21 swap2
[23:23:52][spjsschl@asso:~]$ su
Password:
[23:24:04][root@asso:/home/spjsschl]# dmsetup table
swap2: 0 995967 crypt aes-cbc-plain
8fd07cf5cecac858cdd2c0ce673449b4c1734cecbe8a24e5be629d542c975cf1 0 22:5 0
swap1: 0 6458067 crypt aes-cbc-plain
dde5fec1ee7146100bc83af997171ce196c2d1c453134d21e574f85ccc296588 0 22:65 0
[23:24:11][root@asso:/home/spjsschl]# cat /proc/mounts
rootfs / rootfs rw 0 0
/dev/root / ext3 rw,data=ordered 0 0
tmpfs /lib/init/rw tmpfs rw,nosuid 0 0
proc /proc proc rw,nosuid,nodev,noexec 0 0
sysfs /sys sysfs rw,nosuid,nodev,noexec 0 0
usbfs /proc/bus/usb usbfs rw,nosuid,nodev,noexec 0 0
/dev/root /dev/.static/dev ext3 rw,data=ordered 0 0
tmpfs /dev tmpfs rw 0 0
tmpfs /dev/shm tmpfs rw,nosuid,nodev 0 0
devpts /dev/pts devpts rw,nosuid,noexec 0 0
/dev/hdc6 /home/spjsschl/data-scratch xfs rw 0 0
/dev/hdc3 /home/spjsschl/c vfat
rw,fmask=0022,dmask=0022,codepage=cp437,iocharset=iso8859-1 0 0
/dev/hdc2 /home/spjsschl/winspace ext3 rw,data=ordered 0 0
none /tmp tmpfs rw 0 0
none /var/tmp tmpfs rw 0 0
none /sys/fs/fuse/connections fusectl rw 0 0

I am using udev.

best regards,
    Johannes

#409875#66
Date:
2007-02-07 23:14:35 UTC
From:
To:
That would be the dmsetup package maintainer, but lets keep at it for a
while before we call him in

Which devices are 22:5 and 22:65? I'm guessing /dev/hdc5 and /dev/hdd2?

Could you provide me with the output from "ls -al /dev/hd*" and "fdisk -l
/dev/hd?"

(BTW, the above keys are random keys, right?)

#409875#71
Date:
2007-02-07 23:21:30 UTC
From:
To:
Also...which device is / on? I.e. /dev/root is an alias of
/dev/hd<what>?

#409875#76
Date:
2007-02-07 23:20:57 UTC
From:
To:
Hi,

hdc5 and hdd1.
brw-rw---- 1 root cdrom  3,  0 2007-02-08 00:21 /dev/hda
brw-rw---- 1 root cdrom  3, 64 2007-02-08 00:21 /dev/hdb
brw-rw---- 1 root disk  22,  0 2007-02-08 00:21 /dev/hdc
brw-rw---- 1 root disk  22,  1 2007-02-08 00:21 /dev/hdc1
brw-rw---- 1 root disk  22,  2 2007-02-07 23:21 /dev/hdc2
brw-rw---- 1 root disk  22,  3 2007-02-08 00:21 /dev/hdc3
brw-rw---- 1 root disk  22,  4 2007-02-08 00:21 /dev/hdc4
brw-rw---- 1 root disk  22,  5 2007-02-08 00:21 /dev/hdc5
brw-rw---- 1 root disk  22,  6 2007-02-08 00:21 /dev/hdc6
brw-rw---- 1 root disk  22, 64 2007-02-08 00:21 /dev/hdd
brw-rw---- 1 root disk  22, 65 2007-02-08 00:21 /dev/hdd1
brw-rw---- 1 root disk  22, 66 2007-02-08 00:21 /dev/hdd2
brw-rw---- 1 root disk  22, 69 2007-02-08 00:21 /dev/hdd5
brw-rw---- 1 root disk  22, 70 2007-02-08 00:21 /dev/hdd6
[00:18:25][root@asso:/home/spjsschl]# fdisk -l /dev/hd?

Disk /dev/hdc: 163.9 GB, 163928604672 bytes
255 heads, 63 sectors/track, 19929 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

   Device Boot      Start         End      Blocks   Id  System
/dev/hdc1               1        2433    19543041   fd  Linux raid autodetect
/dev/hdc2            2434        3650     9775552+  83  Linux
/dev/hdc3   *        3651        4867     9775552+   c  W95 FAT32 (LBA)
/dev/hdc4            4868       19929   120985515    5  Extended
/dev/hdc5            4868        4929      497983+  82  Linux swap / Solaris
/dev/hdc6            4930       19929   120487468+  83  Linux

Disk /dev/hdd: 120.0 GB, 120034123776 bytes
255 heads, 63 sectors/track, 14593 cylinders
Units = cylinders of 16065 * 512 = 8225280 bytes

   Device Boot      Start         End      Blocks   Id  System
/dev/hdd1   *           1         402     3229033+  82  Linux swap / Solaris
/dev/hdd2             403       14593   113989207+   f  W95 Ext'd (LBA)
/dev/hdd5   *         403        2952    20482843+  fd  Linux raid autodetect
/dev/hdd6            2953       14592    93498268+  83  Linux

Hehe, of course :-)
regards,
        Johannes

#409875#81
Date:
2007-02-07 23:22:38 UTC
From:
To:
Hi,

It is hdd6 at the moment, i am going to copy it back to md0 once i got the
cryptlayer on it working.
regards,
    Johannes

#409875#86
Date:
2007-02-08 00:49:35 UTC
From:
To:
Ok, one more test...could you deallocate both swap mappings and then try
to setup your root mapping?

That is, run something like
"swapoff -a && cryptsetup remove swap1 && cryptsetup remove swap2"

and then try the "cryptsetup create..." invocation

#409875#91
Date:
2007-02-08 00:51:44 UTC
From:
To:
Hi,
cryptsetup remove swap2 && cryptsetup -c aes -s 256 -d /dev/stdin create root
/dev/md0 </key
Command failed: device-mapper: reload ioctl failed: Invalid argument
[01:49:42][root@asso:/home/spjsschl]# dmesg | tail -n 3
device-mapper: table: 253:0: crypt: Device lookup failed
device-mapper: ioctl: error adding target to table
device-mapper: ioctl: device doesn't appear to be in the dev hash table.
[01:49:49][root@asso:/home/spjsschl]# cat /proc/swaps
[01:49:56][root@asso:/home/spjsschl]# ls -al /dev/mapper/
total 0
drwxr-xr-x  2 root root     60 2007-02-08 01:49 .
drwxr-xr-x 14 root root   4480 2007-02-08 01:49 ..
crw-rw----  1 root root 10, 63 2007-02-08 00:21 control

regards,
        Johannes

#409875#96
Date:
2007-02-08 00:53:42 UTC
From:
To:
And while we're at it, "cat /proc/partitions" to make sure that the
kernel and fdisk agree on partition sizes.

#409875#101
Date:
2007-02-08 00:54:53 UTC
From:
To:
Hi,

[01:53:38][root@asso:/home/spjsschl]# cat /proc/partitions
major minor  #blocks  name

  22     0  160086528 hdc
  22     1   19543041 hdc1
  22     2    9775552 hdc2
  22     3    9775552 hdc3
  22     4          1 hdc4
  22     5     497983 hdc5
  22     6  120487468 hdc6
  22    64  117220824 hdd
  22    65    3229033 hdd1
  22    66          1 hdd2
  22    69   20482843 hdd5
  22    70   93498268 hdd6
   9     0   19542976 md0
 253     0    3229033 dm-0
 253     1     497983 dm-1
best regards,
	Johannes

#409875#106
Date:
2007-02-08 12:38:04 UTC
From:
To:
On Wed, February 7, 2007 22:31, Johannes Schlumberger said:

Could you try this again with a couple of "-v" arguments added to the
dmsetup command -> "dmsetup -v -v -v -v -v -v -v -v -v -v create root map"
and see if you get some additional output?

#409875#111
Date:
2007-02-08 18:52:53 UTC
From:
To:
Hi,

[19:51:19][root@asso:/tmp]# dmsetup -v -v -v -v -v -v -v -v -v -v create root \
map
dm version   OF   [16384]
dm create root  OF   [16384]
dm reload root  OF   [16384]
device-mapper: reload ioctl failed: Invalid argument
dm remove root  OF   [16384]
Command failed
[19:51:22][root@asso:/tmp]# cat map
0 10000 crypt aes-cbc-essiv:sha256 0123456789abcdef0123456789abcdef 0 /dev/md0 0

Sorry for the delay, I was stuck at university and my PC at home was not
running.
best regards,
    Johannes

#409875#116
Date:
2007-02-08 21:36:09 UTC
From:
To:
It would be great if you could download the devmapper source package
("apt-get source libdevmapper1.02"), edit the file
devmapper-1.02.12/lib/ioctl/libdm-iface.c and add the line:

"fwrite(dmi, dmi->data_size, 1, stderr);"

at line 1553 (just before the "log_debug" statement).

Then build it ("dpkg-buildpackage -us -uc -rfakeroot"), install the
generated debs and try to run dmsetup again (without the -v flags).

Capture stderr to a file and mail it to me (it will contain the
passphrase you used, but for this test that would just be the dummy pass
from the map file).

The command to execute would be:
"dmsetup create root map 2> /tmp/dmsetup.stderr"

#409875#121
Date:
2007-02-08 22:43:33 UTC
From:
To:
The stderr stream is fine. When you run it without redirection, bash
will helpfully mask the null characters that are printed (which is not
done when they are redirected to a file).

However, everything looks ok after studying that file, the first two
ioctl's are executed (i.e. the device-mapper version is checked and the
"root" mapping name is reserved).

Then when it is time to pass the actual parameters for the mapping using
the "reload" ioctl, everything goes south. I'm quickly running out of
ideas what might cause this or what the best way to debug it would be.

So I'm CC:ing this mail to some different people with the hope that
someone other than me can spot the error.

Quoting from previous mails:
dmsetup / cryptsetup both fail to create a mapping on top of a raid
device (/dev/md0 in this case).

For much more details, see the bug report, any help appreciated:
http://bugs.debian.org/409875

#409875#126
Date:
2007-02-08 21:51:50 UTC
From:
To:
Hi,

I built the packages and installed them.
The attached file contains the generated stderr stream (which looks a bit
strange to me). Just to make shure, here is also the output generated from the
command without the redirection.

[22:48:05][root@asso:/tmp]# dmsetup create root map
@4@4root@4root'lcryptaes-cbc-essiv:sha256 0123456789abcdef0123456789abcdef 0
/dev/md0 0device-mapper: reload ioctl failed: Invalid argument
@4root'lcryptaes-cbc-essiv:sha256 0123456789abcdef0123456789abcdef 0 /dev/md0
0Command failed

regards,
    Johannes

#409875#131
Date:
2007-02-09 10:00:50 UTC
From:
To:
Executive summary:
dmsetup / cryptsetup both fail to create a mapping on top of a raid
device (/dev/md0 in this case).

For much more details, see the bug report, any help appreciated as I'm out
of ideas on how to diagnose the error:

http://bugs.debian.org/409875

#409875#136
Date:
2007-02-09 10:45:37 UTC
From:
To:
 I don't know where the error lies, but I created two loop devices loop0
 and loop1, added them to a new RAID 1 md0 device, and ran cryptsetup on
 the resulting md0 successfully.

 bee:~# dmsetup  ls
 ...
 crypt0  (253, 6)

 bee:~# dmsetup table crypt0
 0 65408 crypt aes-cbc-plain
 42cfa211018ea492fdee45ac637b7972a0ad687380f9a6d0484900ad8cca2d8f 0 9:0
 0

 bee:~# mdadm --detail /dev/md0
 ...
    Number   Major   Minor   RaidDevice State
       0       7        0        0      active sync   /dev/loop0
       1       7        1        1      active sync   /dev/loop1

#409875#141
Date:
2007-02-09 12:00:53 UTC
From:
To:
On Fri, February 9, 2007 11:45, Loic Minier said:

Ditto. I've succesfully setup a crypto mapping on a raid1 device under
qemu, which leads me to believe that it is something specific to Johannes
setup.

So I'm hoping that someone will come up with some suggestions on how to
troubleshoot it further on his machine.

(This is my last cross-post on this subject, I promise, please keep
further discussions to the bug report address only -
409875@bugs.debian.org)

#409875#146
Date:
2007-02-09 12:45:26 UTC
From:
To:
On Thu, February 8, 2007 22:51, Johannes Schlumberger said:

Could you build a new kernel which includes the patch attached to bug
report #304507 and try again?

http://bugs.debian.org/cgi-bin/bugreport.cgi/2.6-bd-claim.patch?bug=304507;msg=5;att=1

#409875#151
Date:
2007-02-09 13:22:46 UTC
From:
To:
Hi,

I have tried and I can successfully run cryptsetup on another raiddevice (md1)
made from loopdevices without any problems.
best regars,
    Johannes

#409875#156
Date:
2007-02-09 13:40:52 UTC
From:
To:
Hi,
inital bugreport mail) with the above patch applied.

[14:36:53][root@asso:/home/spjsschl]# cryptsetup -c aes -s 256 -d /dev/stdin
create root /dev/md0 </key
Command failed: device-mapper: reload ioctl failed: Invalid argument
[14:37:06][root@asso:/home/spjsschl]# dmesg | tail -n 3
device-mapper: table: 253:2: crypt: Device lookup failed
device-mapper: ioctl: error adding target to table
device-mapper: ioctl: device doesn't appear to be in the dev hash table.

best regards,
    Johannes

#409875#161
Date:
2007-02-09 13:42:51 UTC
From:
To:
Hi,
I just want to point out, so far after each test I brought the system back
into the beginning state (kernel, dmsetup-package, etc).
regards,
    Johannes

#409875#166
Date:
2007-02-09 14:33:36 UTC
From:
To:
recent flow of patches from the md maintainer in LKML.  I don't know if they
all landed on 2.6.16.y and 2.6.19.y and 2.6.20 yet.

#409875#171
Date:
2007-02-09 15:58:57 UTC
From:
To:
Hi,

I just wanted to make shure, we are stil talking about the same setup :)

It is attached; the way I see it, 9:0 is claimed during the setup of the
md-device but never released.
regarrds,
    Johannes

#409875#176
Date:
2007-02-09 15:32:40 UTC
From:
To:
On Fri, February 9, 2007 14:42, Johannes Schlumberger said:

Yes, that's good.

Could you please try a new compile, this time, skip the previously
mentioned patch and instead do the following changes:

In fs/block_dev.c, add the following at the end of the function bd_claim()
(just before the return):

printk("claim: %d:%d %p -> %d\n",
       MAJOR(bdev->bd_dev), MINOR(bdev->bd_dev), holder, res);

In the same file, add to the end of the function bd_release():

printk("release: %d:%d\n",
       MAJOR(bdev->bd_dev), MINOR(bdev->bd_dev));

Recompile, install, reboot, try cryptsetup, and then send me the entire
dmesg output

#409875#181
Date:
2007-02-09 18:13:59 UTC
From:
To:
On Fri, February 9, 2007 16:58, Johannes Schlumberger said:

Yes, that indeed seems to be the problem (which is why we tried this
debugging output)...and later device-mapper tries to claim md0 again as it
tries to setup the crypto mapping. Which fails. What bothers me though is
that the previous patch that we tried should have allowed such situations,
I might have to take another look at it.

Meanwhile, could you add the following to the above mentioned debugging
output:

printk("dumping stack for %s:\n", current->comm);
dump_stack();

(right after the above printk in bd_claim())

And then send another dmesg this way...this should tell us which
process/kernel thread it is that locks md0...

#409875#186
Date:
2007-02-09 18:35:46 UTC
From:
To:
Hi,

As it turns out, dmesg is to small, so i have attached the relevant part of my
syslog file.
regards,
    Johannes

#409875#191
Date:
2007-02-09 20:32:47 UTC
From:
To:
Thanks, this looks mighty suspicious...it looks like /dev/md0 is mounted
as your root partition by the initramfs? Please provide me with "ls -al
/dev/root" and "cat /proc/cmdline" as well as the contents of your grub
or lilo config file.

#409875#196
Date:
2007-02-09 20:44:32 UTC
From:
To:
Hi,

I am so sorry for stealing yours and other persons time like this. I had
root=/dev/md0 in my menu.lst and / as /dev/hdd6 in my fstab. I have to say I am
strongly embarassed.
Thank you a lot for figuring this out and all your patience.
best regards,
    Johannes

#409875#201
Date:
2007-02-09 21:28:26 UTC
From:
To:
reassign 409875 libdevmapper1.02
retitle 409875 libdevmapper should provide more helpful error messages
severity 409875 minor
thanks

No problem, it happends to all of us. There still is a bug here
though...the error messages from libdevmapper are obtuse to say the
least.

libdevmapper explained that /dev/md0 is in use with the message:
"Command failed: device-mapper: reload ioctl failed: Invalid argument"

That is a bug in my book.

I'll reassign this bug to libdevmapper (and retitle it accordingly).

I'll also CC all people that I've bugged earlier so that they know that
this issue is no more.

That's ok, you just owe me a beer.