Weird race-like problem in udev

Weird race-like problem in udev

[Ozan Çağlayan]

Hi,

I have a bug report from a user which complains about udev not correctly hotplugging the devices. The symptoms are quite racy and random:

* When he starts the OS and plugs a USB device, udev doesn't load the necessary kernel driver,
* He then unplugs/plugs it several times:
  * Sometimes it starts to work correctly, the module gets inserted
  * Sometimes it still doesn't modprobe the module
* He discovered that spawning a 2nd udevd by hand resolves the issue

I suggested him to set the udevd log level to "debug" and we've found out that setting the log level through udevadm control heals the issue as well. So I proposed to edit the udev.conf and set the log level there and reboot. Upon reboot, after a cycle of 2-3 failed plug/unplug attempt, the problem seems fixed/disappeared too.

I grabbed full syslog with udevd running log-priorityfibug, took a look and found out that the events are correctly dispatched to the worker threads but the modprobe is called on a very late plug/unplug attempt.

Here's the full log:
  http://bugs.pardus.org.tr/attachment.cgi?idT50

* The device is first plugged @ 16:50:54 (VENDOR=_USB_MF_)
* worker[541] being able to spawn modprobe is @ 16:53:21
* Between those timestamps you can see several "seq xxxx queued 'add' 'usb' which doesn't lead to a modprobe.

udev version is 146. I know that it's a little bit outdated but I'd be glad if you can help me debugging the issue. Any commit id from the git tree that is known to fix the issue is also very appreciated.

Thanks,
Ozan Caglayan
--

http://www.pardus.org.tr/eng
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: Weird race-like problem in udev

[Kay Sievers]

On Mon, Jun 21, 2010 at 18:47, Ozan Çağlayan <ozan@pardus.org.tr> wrote:
> I have a bug report from a user which complains about udev not correctly hotplugging the devices. The symptoms are quite racy and random:
>
> * When he starts the OS and plugs a USB device, udev doesn't load the necessary kernel driver,

Please, this isn't a quiz here, so provide the needed basic
information that goes beyond "a device" and " the driver". :)

> * He then unplugs/plugs it several times:
>  * Sometimes it starts to work correctly, the module gets inserted
>  * Sometimes it still doesn't modprobe the module

Check 'udevadm monitor' for the difference of both cases.

> * He discovered that spawning a 2nd udevd by hand resolves the issue

That's not possible, udevd will refuse to start a second time, and not
do anything. It lets this report look suspicious that something is
wrong with the way the behavior is described.

Kay

Re: Weird race-like problem in udev

[Ozan Çağlayan]

Salı 22 Haziran 2010 günü (saat 14:31:57) Kay Sievers şunları yazmıştı:

> 
> Please, this isn't a quiz here, so provide the needed basic
> information that goes beyond "a device" and " the driver". :)

Ok, I'm very suspicious about the report and what the user describes, too. 
I'll try to detail in here.

What he's talking about in its bug report is a USB mass storage device:

[ 4741.302054] usb 1-2: new high speed USB device using ehci_hcd and address 3
[ 4743.914330] usb 1-2: New USB device found, idVendor\x066f, idProduct€00
[ 4743.914343] usb 1-2: New USB device strings: Mfr=1, Product=2, 
SerialNumber=3
[ 4743.914353] usb 1-2: Product: <USB PRODUCT>
[ 4743.914360] usb 1-2: Manufacturer: <USB MF>
[ 4743.914367] usb 1-2: SerialNumber: 0002F68C0A104E19
[ 4743.914623] usb 1-2: configuration #1 chosen from 1 choice

He also mentions that its webcam driver doesn't get loaded too. He posted the 
test-webcam output which complains about a non existing /dev/video0 node.

If the devices are plugged and then the system is rebooted, all the related 
drivers are loaded and he tells that he has no problems at all.


> 
> > * He discovered that spawning a 2nd udevd by hand resolves the issue
> 
> That's not possible, udevd will refuse to start a second time, and not
> do anything. It lets this report look suspicious that something is
> wrong with the way the behavior is described.

I misunderstood this. He was talking about killing and respawning udevd, not 
spawning a 2nd or a 3rd one, sorry. But yes he says that killing and 
respawning it resolves the issue.

I am not really hopeful to get this resolved as trying to ask him and waiting 
for an answer is very hard for that kind of standard users who are not 
familiar at all with udev, kernel, etc. Sorry for the inconvenience, I will 
report back here if I get something valuable.

Regards,


---
Ozan Çağlayan
TUBITAK/UEKAE - Pardus Linux
http://www.pardus.org.tr/eng

Re: Weird race-like problem in udev

[Kay Sievers]

On Tue, Jun 22, 2010 at 14:06, Ozan Çağlayan <ozan@pardus.org.tr> wrote:
> Salı 22 Haziran 2010 günü (saat 14:31:57) Kay Sievers şunları yazmıştı:
>> > * He discovered that spawning a 2nd udevd by hand resolves the issue
>>
>> That's not possible, udevd will refuse to start a second time, and not
>> do anything. It lets this report look suspicious that something is
>> wrong with the way the behavior is described.
>
> I misunderstood this. He was talking about killing and respawning udevd, not
> spawning a 2nd or a 3rd one, sorry. But yes he says that killing and
> respawning it resolves the issue.

Hmm, restarting udevd does not cause a single event to run. Only
unplugging/re-plugging would do that, but I doubt that this makes a
difference with the originally started daemon.

Kay