Bug 90041 - udevd affected by instance in early user space / does not apply udev rules as expected/logged
Summary: udevd affected by instance in early user space / does not apply udev rules as...
Status: RESOLVED NOTOURBUG
Alias: None
Product: systemd
Classification: Unclassified
Component: general (show other bugs)
Version: unspecified
Hardware: Other All
: medium normal
Assignee: Kay Sievers
QA Contact: systemd-bugs
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-04-15 19:49 UTC by Tom Yan
Modified: 2015-04-21 11:54 UTC (History)
0 users

See Also:
i915 platform:
i915 features:


Attachments
modified trigger service to capture test cases (909 bytes, text/plain)
2015-04-15 19:49 UTC, Tom Yan
Details
journalctl -b (without `sleep 1` in udev hook) (600.19 KB, text/plain)
2015-04-15 20:06 UTC, Tom Yan
Details
journalctl -b (with `sleep 1` in udev hook) (608.62 KB, text/plain)
2015-04-15 20:07 UTC, Tom Yan
Details
slightly modified systemd-udev-trigger.service used for attached journals (723 bytes, text/plain)
2015-04-15 20:13 UTC, Tom Yan
Details

Description Tom Yan 2015-04-15 19:49:39 UTC
Created attachment 115090 [details]
modified trigger service to capture test cases

So I have these two USB receivers, let's name them:
Device-13: logitech-djreceiver 0003:046D:C52B.0003: hiddev0,hidraw0: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:14.0-13/input2
Device-14: hid-generic 0003:046D:C52E.0005: input,hidraw2: USB HID v1.11 Keyboard [Logitech USB Receiver] on usb-0000:00:14.0-14/input0

I am quite certain the bug is NOT hardware-specific, but I still list them here for reference, and more importantly for some reason they have different default value for attributes {power/wakeup}:
Device-13: disabled
Device-14: enabled
I don't know if this is determined by the kernel or udev, but this is the default when there's no udev rules written to set attributes for them.

But my desired values is exactly the opposite, which are:
Device-13: enabled
Device-14: disabled

So I have the following udev rules written:
ATTR{devpath}=="13", ATTR{power/wakeup}="enabled"
ATTR{devpath}=="14", ATTR{power/wakeup}="disabled"

This reverse thing might make you a bit dizzy, so I'm gonna tell you, the bug is gonna show up on Device-14, because it has a default value of "enabled", while Device-13 makes a perfect control. So this is what happened after a fresh reboot.

[tom@localhost ~]$ sudo journalctl -b | grep wakeup
...
Apr 15 16:54:03 localhost systemd-udevd[205]: Reading rules file: /etc/udev/rules.d/wakeup.rules
Apr 15 16:54:04 localhost systemd-udevd[214]: ATTR '/sys/devices/pci0000:00/0000:00:14.0/usb3/3-13/power/wakeup' writing 'enabled' /etc/udev/rules.d/wakeup.rules:1
Apr 15 16:54:04 localhost systemd-udevd[215]: ATTR '/sys/devices/pci0000:00/0000:00:14.0/usb3/3-14/power/wakeup' writing 'disabled' /etc/udev/rules.d/wakeup.rules:2
[tom@localhost ~]$ cat /sys/bus/usb/devices/3-13/power/wakeup
enabled
[tom@localhost ~]$ cat /sys/bus/usb/devices/3-14/power/wakeup
enabled

So the result is different from what is logged, but it only happens on Device-14, why? You might suggest that I probably have some quirky power management tools or scripts. But the answer is no, and I'm gonna to prove it.
(Note 1: in order to get the "ATTR" lines logged, I have to make sure that the command `udevadm trigger` for type "devices" runs before the one for type "subsystems", so I reverse them in the service file, not sure if it's another bug)

After many different tests and experiments, I found that the cause of this weird results is because of the systemd-udevd that has to be started in early user space of the initramfs is exited before it has finished all of its job.
(Note 2: here actually shows another possible bug: there is no way to make sure udevd exit only after finishing its job, despites all possible timeout parameters. I would probably file another bug report for that)
This is the initcpio "hook" in Arch Linux for starting the udevd and triggering events:
https://projects.archlinux.org/svntogit/packages.git/tree/trunk/initcpio-hook-udev?h=packages/systemd
(Note 3: `udevadm settle` is basically a no-op to this issue, not sure if it's another bug.)
In order to confirm my proposed theory, I "toggle" `sleep 1` between the trigger command and the exit command, and use the attached modified systemd-udev-trigger.service to capture what happen before and after the "later" trigger command, and to prove that giving the "early" udevd extra time to finish its job would have impact on the final results.

So if I boot with `sleep 1` in the hook, the captured results are:
Pre-trigger:
Device-13: disabled
Device-14: enabled
(same as what should be without the udev rules written above)
Post-trigger:
Device-13: enabled
Device-14: disabled
(same as what should be with the udev rules written above)

But if I boot with the original hook, which is without `sleep 1` and cause troubles, what captured are:
Pre-trigger:
Device-13: disabled
Device-14: disabled
Post-trigger:
Device-13: enabled
Device-14: enabled

I'll interpret the results as followed:
From what I captured, it seems that the "raw default" of {power/wakeup} for all devices are "disabled", and they gain their "own default" after the trigger command. Since the udev rules written above is not included in the initcpio so it does not exist in early user space, so you can see that: if the "early" udevd have time to finish its job (with `sleep 1`), Device-14 gets its "own default" which is "enabled", if not, Device-14 remains "disabled"; while for Device-13, because the two values are the same before and after anyway, so the time doesn't matter to it.

But the question is, why does this affect the final results of the "later" udevd to a degree that what happen is different from what is clearly logged?
Comment 1 Tom Yan 2015-04-15 20:06:11 UTC
Created attachment 115091 [details]
journalctl -b (without `sleep 1` in udev hook)
Comment 2 Tom Yan 2015-04-15 20:07:40 UTC
Created attachment 115092 [details]
journalctl -b (with `sleep 1` in udev hook)
Comment 3 Tom Yan 2015-04-15 20:13:33 UTC
Created attachment 115093 [details]
slightly modified systemd-udev-trigger.service used for attached journals

command order reversed from the original. see main report for reason
Comment 4 Tom Yan 2015-04-21 08:14:50 UTC
According to the discussion here: http://www.spinics.net/lists/linux-usb/msg124033.html, the hid-generic module is responsible for setting the default value to "enabled".

From my further testings, I can see that, if the hid-generic module is not loaded in early user space, either because the time is not enough, or it is excluded/blacklisted from/in the initcpio (while sufficient time is given, e.g. sleep 5), the udev rule applied would be overrided by the behaviour of the module; while if it is loaded before, that would not happen.

Then I run the following command after the udev rules are properly applied:
 # modprobe -r hid-generic; modprobe hid-generic
The result is, the value is set to "enabled" again.

So it seems that THE ACTUAL PROBLEM IS: udevd apply the udev rule before hid-generic is loaded.

BUT this is true ONLY IF if it's a fact, the module won't be loaded again later if (or loaded in the same way as) the module is loaded in the early user space, which I am not sure about.
Comment 5 Lennart Poettering 2015-04-21 11:04:49 UTC
That really feels like broken behaviour of the hid-generic kernel module, I don't think we can do much about this in the systemd context.

Please file a bug against this module in the kernel bugzilla!
Comment 6 Tom Yan 2015-04-21 11:47:54 UTC
Actually I do agree with you that it's better to fix it in the kernel. I'm also discussing this on the linux-usb mailing list.

http://lxr.free-electrons.com/ident?i=device_set_wakeup_enable
However all drivers with this (and potentially other similar functions) will probably cause the same issue, so I was wondering if there's any possiblity for udev to have a workaround.
Comment 7 Lennart Poettering 2015-04-21 11:54:33 UTC
Na, systemd/udev are not the place for workarounds around other software really. Sorry.


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.