* [REGRESSION] 4.11-rc: systemd doesn't see most devices
@ 2017-04-11 15:00 Theodore Ts'o
2017-04-11 15:38 ` Greg KH
0 siblings, 1 reply; 4+ messages in thread
From: Theodore Ts'o @ 2017-04-11 15:00 UTC (permalink / raw)
To: linux-kernel; +Cc: torvalds, gregkh
[-- Attachment #1: Type: text/plain, Size: 5517 bytes --]
There is a frustrating regression in 4.11 that I've been trying to
track down. The symptoms are that a large number of systemd devices
don't show up. So instead of "systemctl | grep .device | wc -l"
listing some 50+ lines which look like this:
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d7-1\x2d7:1.0-bluetooth-hci0.device loaded active plugged /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7/1-7:1.0/bluetooth/hci0
I only get 5-10 lines of devices. This is problematic because it
means that the wifi firmware is not automatically loaded. More
annoyingly, because the device mapper systemd devices are missing:
sys-devices-virtual-block-dm\x2d0.device loaded active plugged /sys/devices/virtual/block/dm-0
... the boot hangs for 90 seconds because it can't fsck devices that
systemd doesn't think exists yet. (I'm using LVM on top of an
encrypted block device, and it doesn't think the dm-crypt device is
created, although given that the root file system is an LVM volume,
obviously LVM and the LUKS setup had worked just fine --- and people
wonder why some folks hate systemd. :-)
The failure past v4.10-5879-gcaa59428971d starts starts becoming
flaky, so sometimes I have to reboot three times or more before the
failure shows up. This is why the bisect has been taking so long, and
so while I'm *faily* certain that the failure is somewhere in the
staging branch merge, it's possible that one of the earlier "git
bisect good"'s are in error. I have been trying multiple reboots
before concluding that a bisection point is "good" but this takes a
huge amount of time, since having GRUB unlock an encrypted LVM volume
takes a long time, and I have to type the decryption password twice at
each boot.
The end of the bisection doesn't make any sense, and so at this point
I've given up, and am posting this to LKML with Linus and Greg cc'ed,
in the hopes that someone else has seen this, or understands what sort
of failure would cause systemd to not think various devices are
present and/or finished initializing. I'm using a Debian testing
distribution, and it would be really good to figure out what the ?!@#
is going on, since if 4.11 releases with this, I suspect a lot of
people will be affected. Unfortunately, while it's not particularly
reliable deep into the bisection, at -rc3 or -rc5 it's **damned**
reproducible. I know how to work around the systemd brain damage for
now by using rc.local, futzing with the dependencies, manually loading
the Wifi module by hand, and (sometimes) living without Audio, but
this is requires a lot of hacking, and it's not, shall we say, a
particularly nice user experience. :-(
- Ted
P.S. I've also attached the output of "systemd | grep devices" so you
can see what happens in a good and bad case, in case that helps.
git bisect start
# good: [v4.10] Linux 4.10
git bisect good c470abd4fde40ea6a0846a2beab642a578c0b8cd
# bad: [v4.10-5879-gcaa59428971d] Merge tag 'staging-4.11-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging
git bisect bad caa59428971d5ad81d19512365c9ba580d83268c
# good: [v4.10-2518-g1e74a2eb1f5c] Merge tag 'gcc-plugins-v4.11-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/kees/linux
git bisect good 1e74a2eb1f5cc7f2f2b5aa9c9eeecbcf352220a3
# good: [v4.10-4456-g3051bf36c25d] Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next
git bisect good 3051bf36c25d5153051704291782f8d44e744d36
# good: [v4.10-5190-ge30aee9e10bb] Merge tag 'char-misc-4.11-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/char-misc
git bisect good e30aee9e10bb5168579e047f05c3d13d09e23356
# good: [v4.10-5202-gb2064617c74f] Merge tag 'driver-core-4.11-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/driver-core
git bisect good b2064617c74f301dab1448f1f9c8dbb3c8021058
# good: [v4.10-rc3-325-g994261dc8f3d] devicetree: sort the Garmin vendor prefix properly.
git bisect good 994261dc8f3dfcd19feecafae3040e932c8f90cf
# good: [v4.10-rc3-501-gc2351249f140] staging: lustre: libcfs: avoid stomping on module param cpu_pattern
git bisect good c2351249f140aebdf911d86d7a1542c40b20fca3
# good: [v4.10-rc7-589-g1b2d7f198140] staging: comedi: dt2815: usleep_range is preferred over udelay
git bisect good 1b2d7f198140aae48dd93c41abde37283312a98c
# bad: [v4.10-rc7-633-g4d0bdcb10c43] staging: rtl8192e: Aligning the * on each line in block comments
git bisect bad 4d0bdcb10c43056489b69186ee43669f2a73b8f9
# bad: [v4.10-rc7-611-g30d69ada0771] Staging: rtl8192u: r819xU_firmware.c - style fix
git bisect bad 30d69ada0771ed25b63ec56887faea31d8f551bd
# good: [v4.10-rc7-600-g8a0e4b9e469c] staging: android: ion: fix coding style issue
git bisect good 8a0e4b9e469c7bbaa206d81e2e7515e1abb1aa00
# bad: [v4.10-rc7-605-gdc223652c6de] staging: r8712u: Fix macros used to read/write the TX/RX descriptors
git bisect bad dc223652c6de409fe5e073b0f631f0413a90e69f
# good: [v4.10-rc7-602-g76b94eb1eb88] staging: set msi_domain_ops as __ro_after_init
git bisect good 76b94eb1eb882e3a8beb51b7d287a21a38a56938
# bad: [v4.10-rc7-604-g221c46d28957] staging: rtl8712u: Fix endian settings for structs describing network packets
git bisect bad 221c46d28957bd6e2158abc2179ce4a8c9ce07d3
# bad: [v4.10-rc7-603-ge2288bce8ec8] staging: rtl8712: Fix some Sparse endian messages
git bisect bad e2288bce8ec828ce36f6443e298e04d41fddff7e
# first bad commit: [v4.10-rc7-603-ge2288bce8ec8] staging: rtl8712: Fix some Sparse endian messages
[-- Attachment #2: device-4.10 --]
[-- Type: text/plain, Size: 10808 bytes --]
sys-devices-pci0000:00-0000:00:02.0-drm-card0-card0\x2deDP\x2d1-intel_backlight.device loaded active plugged /sys/devices/pci0000:00/0000:00:02.0/drm/card0/card0-eDP-1/intel_backlight
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d3-1\x2d3:1.0-net-wwp0s20f0u3.device loaded active plugged Sierra_Wireless_EM7345_4G_LTE
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d3-1\x2d3:1.2-tty-ttyACM0.device loaded active plugged Sunrise Point-LP USB 3.0 xHCI Controller
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d5.device loaded active plugged AU9540 Smartcard Reader
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d6-1\x2d6:1.0.device loaded active plugged Yubikey NEO(-N) U2F+CCID
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d6-1\x2d6:1.1.device loaded active plugged Yubikey NEO(-N) U2F+CCID
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d6.device loaded active plugged Yubikey NEO(-N) U2F+CCID
sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d7-1\x2d7:1.0-bluetooth-hci0.device loaded active plugged /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7/1-7:1.0/bluetooth/hci0
sys-devices-pci0000:00-0000:00:17.0-ata2-host1-target1:0:0-1:0:0:0-block-sda-sda1.device loaded active plugged Samsung_SSD_850_PRO_2TB 1
sys-devices-pci0000:00-0000:00:17.0-ata2-host1-target1:0:0-1:0:0:0-block-sda-sda2.device loaded active plugged Samsung_SSD_850_PRO_2TB 2
sys-devices-pci0000:00-0000:00:17.0-ata2-host1-target1:0:0-1:0:0:0-block-sda.device loaded active plugged Samsung_SSD_850_PRO_2TB
sys-devices-pci0000:00-0000:00:1c.2-0000:04:00.0-net-wlp4s0.device loaded active plugged Wireless 8260
sys-devices-pci0000:00-0000:00:1f.3-sound-card0.device loaded active plugged Sunrise Point-LP HD Audio
sys-devices-pci0000:00-0000:00:1f.6-net-enp0s31f6.device loaded active plugged Ethernet Connection I219-V
sys-devices-platform-serial8250-tty-ttyS0.device loaded active plugged /sys/devices/platform/serial8250/tty/ttyS0
sys-devices-platform-serial8250-tty-ttyS1.device loaded active plugged /sys/devices/platform/serial8250/tty/ttyS1
sys-devices-platform-serial8250-tty-ttyS2.device loaded active plugged /sys/devices/platform/serial8250/tty/ttyS2
sys-devices-platform-serial8250-tty-ttyS3.device loaded active plugged /sys/devices/platform/serial8250/tty/ttyS3
sys-devices-platform-thinkpad_acpi-leds-tpacpi::kbd_backlight.device loaded active plugged /sys/devices/platform/thinkpad_acpi/leds/tpacpi::kbd_backlight
sys-devices-virtual-block-dm\x2d0.device loaded active plugged /sys/devices/virtual/block/dm-0
sys-devices-virtual-block-dm\x2d1.device loaded active plugged /sys/devices/virtual/block/dm-1
sys-devices-virtual-block-dm\x2d10.device loaded active plugged /sys/devices/virtual/block/dm-10
sys-devices-virtual-block-dm\x2d11.device loaded active plugged /sys/devices/virtual/block/dm-11
sys-devices-virtual-block-dm\x2d2.device loaded active plugged /sys/devices/virtual/block/dm-2
sys-devices-virtual-block-dm\x2d3.device loaded active plugged /sys/devices/virtual/block/dm-3
sys-devices-virtual-block-dm\x2d4.device loaded active plugged /sys/devices/virtual/block/dm-4
sys-devices-virtual-block-dm\x2d5.device loaded active plugged /sys/devices/virtual/block/dm-5
sys-devices-virtual-block-dm\x2d6.device loaded active plugged /sys/devices/virtual/block/dm-6
sys-devices-virtual-block-dm\x2d7.device loaded active plugged /sys/devices/virtual/block/dm-7
sys-devices-virtual-block-dm\x2d8.device loaded active plugged /sys/devices/virtual/block/dm-8
sys-devices-virtual-block-dm\x2d9.device loaded active plugged /sys/devices/virtual/block/dm-9
sys-devices-virtual-block-ram0.device loaded active plugged /sys/devices/virtual/block/ram0
sys-devices-virtual-block-ram1.device loaded active plugged /sys/devices/virtual/block/ram1
sys-devices-virtual-block-ram10.device loaded active plugged /sys/devices/virtual/block/ram10
sys-devices-virtual-block-ram11.device loaded active plugged /sys/devices/virtual/block/ram11
sys-devices-virtual-block-ram12.device loaded active plugged /sys/devices/virtual/block/ram12
sys-devices-virtual-block-ram13.device loaded active plugged /sys/devices/virtual/block/ram13
sys-devices-virtual-block-ram14.device loaded active plugged /sys/devices/virtual/block/ram14
sys-devices-virtual-block-ram15.device loaded active plugged /sys/devices/virtual/block/ram15
sys-devices-virtual-block-ram2.device loaded active plugged /sys/devices/virtual/block/ram2
sys-devices-virtual-block-ram3.device loaded active plugged /sys/devices/virtual/block/ram3
sys-devices-virtual-block-ram4.device loaded active plugged /sys/devices/virtual/block/ram4
sys-devices-virtual-block-ram5.device loaded active plugged /sys/devices/virtual/block/ram5
sys-devices-virtual-block-ram6.device loaded active plugged /sys/devices/virtual/block/ram6
sys-devices-virtual-block-ram7.device loaded active plugged /sys/devices/virtual/block/ram7
sys-devices-virtual-block-ram8.device loaded active plugged /sys/devices/virtual/block/ram8
sys-devices-virtual-block-ram9.device loaded active plugged /sys/devices/virtual/block/ram9
sys-devices-virtual-misc-rfkill.device loaded active plugged /sys/devices/virtual/misc/rfkill
sys-devices-virtual-net-docker0.device loaded active plugged /sys/devices/virtual/net/docker0
sys-module-fuse.device loaded active plugged /sys/module/fuse
sys-subsystem-bluetooth-devices-hci0.device loaded active plugged /sys/subsystem/bluetooth/devices/hci0
sys-subsystem-net-devices-docker0.device loaded active plugged /sys/subsystem/net/devices/docker0
sys-subsystem-net-devices-enp0s31f6.device loaded active plugged Ethernet Connection I219-V
sys-subsystem-net-devices-wlp4s0.device loaded active plugged Wireless 8260
sys-subsystem-net-devices-wwp0s20f0u3.device loaded active plugged Sierra_Wireless_EM7345_4G_LTE
kmod-static-nodes.service loaded active exited Create list of required static device nodes for the current kernel
[-- Attachment #3: device-4.10.0-rc2-00031-g38b0a526ec33 --]
[-- Type: text/plain, Size: 745 bytes --]
sys-devices-virtual-block-dm\x2d3.device loaded active plugged /sys/devices/virtual/block/dm-3
sys-devices-virtual-block-dm\x2d4.device loaded active plugged /sys/devices/virtual/block/dm-4
sys-devices-virtual-block-dm\x2d5.device loaded active plugged /sys/devices/virtual/block/dm-5
sys-devices-virtual-net-docker0.device loaded active plugged /sys/devices/virtual/net/docker0
sys-subsystem-net-devices-docker0.device loaded active plugged /sys/subsystem/net/devices/docker0
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [REGRESSION] 4.11-rc: systemd doesn't see most devices
2017-04-11 15:00 [REGRESSION] 4.11-rc: systemd doesn't see most devices Theodore Ts'o
@ 2017-04-11 15:38 ` Greg KH
2017-04-11 20:31 ` Theodore Ts'o
0 siblings, 1 reply; 4+ messages in thread
From: Greg KH @ 2017-04-11 15:38 UTC (permalink / raw)
To: Theodore Ts'o, linux-kernel, torvalds
On Tue, Apr 11, 2017 at 11:00:40AM -0400, Theodore Ts'o wrote:
> There is a frustrating regression in 4.11 that I've been trying to
> track down. The symptoms are that a large number of systemd devices
> don't show up. So instead of "systemctl | grep .device | wc -l"
> listing some 50+ lines which look like this:
>
> sys-devices-pci0000:00-0000:00:14.0-usb1-1\x2d7-1\x2d7:1.0-bluetooth-hci0.device loaded active plugged /sys/devices/pci0000:00/0000:00:14.0/usb1/1-7/1-7:1.0/bluetooth/hci0
>
> I only get 5-10 lines of devices. This is problematic because it
> means that the wifi firmware is not automatically loaded. More
> annoyingly, because the device mapper systemd devices are missing:
>
> sys-devices-virtual-block-dm\x2d0.device loaded active plugged /sys/devices/virtual/block/dm-0
>
> ... the boot hangs for 90 seconds because it can't fsck devices that
> systemd doesn't think exists yet. (I'm using LVM on top of an
> encrypted block device, and it doesn't think the dm-crypt device is
> created, although given that the root file system is an LVM volume,
> obviously LVM and the LUKS setup had worked just fine --- and people
> wonder why some folks hate systemd. :-)
>
> The failure past v4.10-5879-gcaa59428971d starts starts becoming
> flaky, so sometimes I have to reboot three times or more before the
> failure shows up. This is why the bisect has been taking so long, and
> so while I'm *faily* certain that the failure is somewhere in the
> staging branch merge, it's possible that one of the earlier "git
> bisect good"'s are in error. I have been trying multiple reboots
> before concluding that a bisection point is "good" but this takes a
> huge amount of time, since having GRUB unlock an encrypted LVM volume
> takes a long time, and I have to type the decryption password twice at
> each boot.
>
> The end of the bisection doesn't make any sense, and so at this point
> I've given up, and am posting this to LKML with Linus and Greg cc'ed,
> in the hopes that someone else has seen this, or understands what sort
> of failure would cause systemd to not think various devices are
> present and/or finished initializing. I'm using a Debian testing
> distribution, and it would be really good to figure out what the ?!@#
> is going on, since if 4.11 releases with this, I suspect a lot of
> people will be affected. Unfortunately, while it's not particularly
> reliable deep into the bisection, at -rc3 or -rc5 it's **damned**
> reproducible. I know how to work around the systemd brain damage for
> now by using rc.local, futzing with the dependencies, manually loading
> the Wifi module by hand, and (sometimes) living without Audio, but
> this is requires a lot of hacking, and it's not, shall we say, a
> particularly nice user experience. :-(
>
> - Ted
>
> P.S. I've also attached the output of "systemd | grep devices" so you
> can see what happens in a good and bad case, in case that helps.
I haven't seen this at all, nor heard of it. As systemctl only gets
what udev reports to it, have you tried using 'udevadm' to monitor your
devices when you plug them in, to ensure it is really seeing them?
Any changes in dmesg from a working and non-working kernel?
The staging tree failure seems really odd, as I doubt you are even
running any of the staging drivers, and they are all self-contained, so
that seems really strange. Do you have any enabled in your build?
Android code perhaps accidentally?
Mess around with udevadm and see if that provides any clues.
thanks,
greg k-h
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [REGRESSION] 4.11-rc: systemd doesn't see most devices
2017-04-11 15:38 ` Greg KH
@ 2017-04-11 20:31 ` Theodore Ts'o
2017-04-12 10:33 ` Greg KH
0 siblings, 1 reply; 4+ messages in thread
From: Theodore Ts'o @ 2017-04-11 20:31 UTC (permalink / raw)
To: Greg KH; +Cc: linux-kernel, torvalds
[-- Attachment #1: Type: text/plain, Size: 1529 bytes --]
On Tue, Apr 11, 2017 at 05:38:35PM +0200, Greg KH wrote:
> I haven't seen this at all, nor heard of it. As systemctl only gets
> what udev reports to it, have you tried using 'udevadm' to monitor your
> devices when you plug them in, to ensure it is really seeing them?
The problem is that the problem happens at boot, so I can't really use
"udevadm monitor" --- so I'm not sure whats the best way to debug
this. I can seen some journalctl logs which do show that it's not
detecting the dm-crypt volume --- but that's insane, because my root
partition is also on the dm-crypt, and it was unlocked in the initrd.
So systemd and udev might not think it exists, but it most definitely
does --- or the boot wouldn't have been able to proceed at all.
In any case, here is the "udevadm info -e" output from a good and bad
boot, as well as a dmesg from a good and a bad boot. I'm not seeing
anything obvious, but it does seem interesting that "udevadm info -e"
shows a lot of devices which "systemctl | grep device" doesn't. Is
there any recent change in the kernel's interfaces that udev depends
on that might make a difference? For that matter, what does udev
depend on? Should I be looking at differences in sysfs? Or does udev
use something else?
I'd do more debugging, but there's a lot of magic these days in the
kernel to udev/systemd communications that I'm quite ignorant about.
Is this a good place I can learn more about how this all works, other
than diving into the udev and systemd sources? :-(
- Ted
[-- Attachment #2: udevadm.good.gz --]
[-- Type: application/gzip, Size: 21596 bytes --]
[-- Attachment #3: udevadm.bad.gz --]
[-- Type: application/gzip, Size: 15617 bytes --]
[-- Attachment #4: dmesg.good.gz --]
[-- Type: application/gzip, Size: 19888 bytes --]
[-- Attachment #5: dmesg.bad.gz --]
[-- Type: application/gzip, Size: 16012 bytes --]
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [REGRESSION] 4.11-rc: systemd doesn't see most devices
2017-04-11 20:31 ` Theodore Ts'o
@ 2017-04-12 10:33 ` Greg KH
0 siblings, 0 replies; 4+ messages in thread
From: Greg KH @ 2017-04-12 10:33 UTC (permalink / raw)
To: Theodore Ts'o, linux-kernel, torvalds
On Tue, Apr 11, 2017 at 04:31:48PM -0400, Theodore Ts'o wrote:
> On Tue, Apr 11, 2017 at 05:38:35PM +0200, Greg KH wrote:
> > I haven't seen this at all, nor heard of it. As systemctl only gets
> > what udev reports to it, have you tried using 'udevadm' to monitor your
> > devices when you plug them in, to ensure it is really seeing them?
>
> The problem is that the problem happens at boot, so I can't really use
> "udevadm monitor" --- so I'm not sure whats the best way to debug
> this. I can seen some journalctl logs which do show that it's not
> detecting the dm-crypt volume --- but that's insane, because my root
> partition is also on the dm-crypt, and it was unlocked in the initrd.
> So systemd and udev might not think it exists, but it most definitely
> does --- or the boot wouldn't have been able to proceed at all.
>
> In any case, here is the "udevadm info -e" output from a good and bad
> boot, as well as a dmesg from a good and a bad boot. I'm not seeing
> anything obvious, but it does seem interesting that "udevadm info -e"
> shows a lot of devices which "systemctl | grep device" doesn't. Is
> there any recent change in the kernel's interfaces that udev depends
> on that might make a difference? For that matter, what does udev
> depend on? Should I be looking at differences in sysfs? Or does udev
> use something else?
I don't know how things get from udevd to systemd, sorry, you should ask
on the systemd mailing list, it's been a long time since I looked at
that codebase.
If udevadm is showing the same data, I don't think it's a udev or kernel
issue here, and given your strange git bisect, it must be a timing thing
somewhere (as your kernel builds shouldn't have mattered if you have no
staging drivers enabled.)
udevd uses netlink to receive the hotplug events, and then feeds them
back into the kernel and uses netlink again to send the messages out to
whomever is listening for them (like systemd). As this is all failing
during boot, is this an initramfs issue somehow?
I don't think netlink has changed anything recently, but I haven't
looked at the kernel code path either in a long time, sorry.
heisenburgs, no fun to debug :(
greg k-h
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2017-04-12 10:33 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-04-11 15:00 [REGRESSION] 4.11-rc: systemd doesn't see most devices Theodore Ts'o
2017-04-11 15:38 ` Greg KH
2017-04-11 20:31 ` Theodore Ts'o
2017-04-12 10:33 ` Greg KH
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.