eudev-3.2.5 waits 10 seconds before processing an event

[l29ah]

w/o apparent reason. udevadm monitor:

KERNEL[876589.458024] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
KERNEL[876589.458633] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
KERNEL[876590.510536] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/input/input36 (input)
KERNEL[876590.510795] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/input/input36/event15 (input)
KERNEL[876590.511723] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/video4linux/video1 (video4linux)
UDEV  [876600.603832] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
UDEV  [876600.604990] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/input/input36 (input)
UDEV  [876600.651205] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/input/input36/event15 (input)
UDEV  [876610.706723] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
UDEV  [876610.708952] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/video4linux/video1 (video4linux)

[blueness]

Unfortunately that information doesn't say much beyond the timestamps. What's the device that triggers this?

[l29ah]

I've tried plugging in two different usb webcams, usb bluetooth adapter and usb sound card with similar results.

[blueness]

Okay it doesn't sound device specific. What distro are you using. What kernel? If you configured the kernel yourself, please attach it to the bug.

[l29ah]

Gentoo Hardened. 4.9.52-unofficial+grsec
https://dump.bitcheese.net/files/buhudom/config.gz

[blueness]

I strongly suspect the hardening. Having maintained the hardened kernel for many years, if I'm right, I can tell you this is not going to be easy to nail down. The cycle of "disable this option and see if it fixes it" based on guess work is probably going to take too long.

The best approach here is to rule out the hardened kernel first by seeing if the problem goes away with a vanilla kernel.

[l29ah]

On Thu, Dec 14, 2017 at 04:37:54PM +0000, Anthony G. Basile wrote: I strongly suspect the hardening. Having maintained the hardened kernel for many years, if I'm right, I can tell you this is not going to be easy to nail down. The cycle of "disable this option and see if it fixes it" based on guess work is probably going to take too long. The best approach here is to rule out the hardened kernel first by seeing if the problem goes away with a vanilla kernel.

I've rebooted into vanilla and it kinda fixed itself both in vanilla and in grsec: the delay is about 0.5s now. I guess i should've tried restarting eudev first.

…

-- () ascii ribbon campaign - against html mail /\ http://arc.pasp.de/ - against proprietary attachments

[blueness]

I don't think restart eudev did it. You're running kernel was probably in a bad state.

[l29ah]

Reproduced on (non-hardened) 4.16.9, yet restarting udev didn't affect the behaviour.

[l29ah]

KERNEL[115247.063164] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
KERNEL[115247.063508] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
KERNEL[115247.072029] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6 (scsi)
KERNEL[115247.072058] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/scsi_host/host6 (scsi_host)
KERNEL[115247.072079] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
KERNEL[115247.072102] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
KERNEL[115248.097484] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0 (scsi)
KERNEL[115248.097515] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0 (scsi)
KERNEL[115248.097532] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_disk/6:0:0:0 (scsi_disk)
KERNEL[115248.097547] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0 (scsi)
KERNEL[115248.097561] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_device/6:0:0:0 (scsi_device)
KERNEL[115248.097622] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_generic/sg1 (scsi_generic)
KERNEL[115248.097809] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/bsg/6:0:0:0 (bsg)
KERNEL[115248.103371] add      /devices/virtual/bdi/8:16 (bdi)
UDEV  [115248.108787] add      /devices/virtual/bdi/8:16 (bdi)
KERNEL[115248.111066] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/block/sdb (block)
KERNEL[115248.111099] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/block/sdb/sdb1 (block)
UDEV  [115257.284056] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
UDEV  [115267.478525] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
UDEV  [115267.478557] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6 (scsi)
UDEV  [115267.478805] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/scsi_host/host6 (scsi_host)
UDEV  [115267.479236] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0 (usb)
UDEV  [115267.536926] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2 (usb)
UDEV  [115267.536961] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0 (scsi)
UDEV  [115267.537439] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0 (scsi)
UDEV  [115267.537654] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_disk/6:0:0:0 (scsi_disk)
UDEV  [115267.537992] bind     /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0 (scsi)
UDEV  [115267.538184] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_device/6:0:0:0 (scsi_device)
UDEV  [115267.538690] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/scsi_generic/sg1 (scsi_generic)
UDEV  [115267.542961] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/bsg/6:0:0:0 (bsg)
UDEV  [115267.630923] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/block/sdb (block)
UDEV  [115267.704832] add      /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.2/1-1.2:1.0/host6/target6:0:0/6:0:0:0/block/sdb/sdb1 (block)

[blueness]

Looks like this is still an issue.

[l29ah]

Yeah, and 4.17.11 is here.

[l29ah]

Found a better culprit: rickysarraf/laptop-mode-tools#138