Re: [dm-crypt] LuksOpen hangs ?

Hello,

Sorry for the delay. Since the locking problem means we then have to
reboot the machine, we had to wait for a slot without too much activity.

On 29/06/2020 16:34, Ondrej Kozina wrote:
> Could you please send debug output also for particular hanging lvm2
> command? Just add -vvvv to the command. Syslog output would also help.
>
> I can't tell you more than the cryptsetup command is stuck in I/O.
> Perhaps hosting LV is suspended due to some error but I can't tell for
> sure.

So... First the cryptsetup command on the « relevant » LV :

cryptsetup --verbose --debug open /dev/v03/E192-X E192
# cryptsetup 2.3.2 processing "cryptsetup --verbose --debug open
/dev/v03/E192-X E192"
# Running command open.
# Locking memory.
# Installing SIGINT/SIGTERM handler.
# Unblocking interruption on signal.
# Allocating context for crypt device /dev/v03/E192-X.
# Trying to open and read device /dev/v03/E192-X with direct-io.
# Initialising device-mapper backend library.
# Trying to load any crypt type from device /dev/v03/E192-X.
# Crypto backend (OpenSSL 1.1.1g  21 Apr 2020) initialized in cryptsetup
library version 2.3.2.
# Detected kernel Linux 5.4.38-gentoo-LTS x86_64.
# PBKDF pbkdf2-sha256, time_ms 2000 (iterations 0).
# Reading LUKS header of size 1024 from device /dev/v03/E192-X
# Key length 32, device size 2147483648 sectors, header size 2050 sectors.
# Activating volume E192 using token -1.
# Interactive passphrase entry requested.
Enter passphrase for /dev/v03/E192-X:
# Activating volume E192 [keyslot -1] using passphrase.
# dm version   [ opencount flush ]   [16384] (*1)
# dm versions   [ opencount flush ]   [16384] (*1)
# Detected dm-ioctl version 4.41.0.
# Detected dm-crypt version 1.19.0.
# Device-mapper backend running with UDEV support enabled.
# dm status E192  [ opencount noflush ]   [16384] (*1)
# Trying to open key slot 0 [ACTIVE_LAST].
# Reading key slot 0 area.
# Using userspace crypto wrapper to access keyslot area.
# Reusing open ro fd on device /dev/v03/E192-X

The command does not give control back, last displayed message as above.

Syslog gives this very quickly after the cryptsetup :

kernel: [31628.245265] usb 4-1.3.4: reset SuperSpeed Gen 1 USB device
number 7 using xhci_hcd

So there may be some hardware problem.

We did a simple lvscan -vvvv (names have been altered for
confidentiality, and we have suppressed a lot of the disk scanning
messages) :

#device/dev-cache.c:761           Found dev 253:3
/dev/disk/by-id/dm-name-X-E246-X- - new alias.
#device/dev-cache.c:761           Found dev 253:3
/dev/disk/by-id/dm-uuid-LVM-TOUXYrO3Bntbs45SGEDLrcjT1fqwDLfpflLwNkbvdkJLiZXBov0W3CrVcY30XXMd
- new alias.
#device/dev-cache.c:761           Found dev 253:3
/dev/disk/by-uuid/30cb5aef-c58f-40e9-9e44-d37e113c3ea6 - new alias.
#device/dev-cache.c:761           Found dev 253:3 /dev/mapper/X-E246--X
- new alias.
#device/dev-cache.c:721           Found dev 253:4 /dev/dm-4 - new.
#device/dev-cache.c:761           Found dev 253:4
/dev/disk/by-id/dm-name-v03-E192-X - new alias.
#device/dev-cache.c:761           Found dev 253:4
/dev/disk/by-id/dm-uuid-LVM-ppvRwREaX6hj9inWWjaKEsTnvT42WhF2MCddbrQjgxA2n3gOQByeWjqdD43kJFbZ
- new alias.
#device/dev-cache.c:761           Found dev 253:4
/dev/disk/by-uuid/9bcee5de-aa79-42f1-bcd2-9ecfc0acc30f - new alias.
#device/dev-cache.c:761           Found dev 253:4 /dev/mapper/v03-E192-X
- new alias.
#device/dev-cache.c:761           Found dev 253:4 /dev/v03/E192-X - new
alias.
#filters/filter-persistent.c:346           filter caching good /dev/sdf
#cache/lvmcache.c:2080          lvmcache /dev/sdf: now in VG
#orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
#filters/filter-persistent.c:346           filter caching good /dev/sde
#cache/lvmcache.c:2080          lvmcache /dev/sde: now in VG
#orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
#filters/filter-persistent.c:346           filter caching good /dev/sdg
#cache/lvmcache.c:2080          lvmcache /dev/sdg: now in VG
#orphans_lvm2 (#orphans_lvm2) with 0 mda(s).
#metadata/vg.c:67            Allocated VG v03 at 0x55bec1b74110.
#format_text/import_vsn1.c:591           Importing logical volume
v03/E192-X.
#format_text/import_vsn1.c:591           Importing logical volume v03/P50-X.
#cache/lvmcache.c:754           lvmcache has no info for vgname "v03"
with VGID ppvRwREaX6hj9inWWjaKEsTnvT42WhF2.
#cache/lvmcache.c:754           lvmcache has no info for vgname "v03".
#cache/lvmcache.c:2080          lvmcache /dev/sdf: now in VG v03 with 1
mda(s).
#cache/lvmcache.c:1908          lvmcache /dev/sdf: VG v03: set VGID to
ppvRwREaX6hj9inWWjaKEsTnvT42WhF2.
#cache/lvmcache.c:2080          lvmcache /dev/sde: now in VG v03
(ppvRwREaX6hj9inWWjaKEsTnvT42WhF2) with 1 mda(s).
#cache/lvmcache.c:2080          lvmcache /dev/sdg: now in VG v03
(ppvRwREaX6hj9inWWjaKEsTnvT42WhF2) with 1 mda(s).
#cache/lvmetad.c:2510          Sending lvmetad vg_clear_outdated_pvs

And nothing more, lvscan hangs there.

Sincerely,
-- 
B&A Consultants - Sécurité informatique - Conseils et audits
www.ba-consultants.fr
Tél : (0) 563 277 241 - Fax : (0) 567 737 829