Bug 181346 - udevd_event errors during boot
udevd_event errors during boot
Status: CLOSED RAWHIDE
Product: Fedora
Classification: Fedora
Component: kernel (Show other bugs)
5
i686 Linux
medium Severity medium
: ---
: ---
Assigned To: Dave Jones
Brian Brock
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2006-02-13 11:31 EST by Jason
Modified: 2015-01-04 17:25 EST (History)
4 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2006-08-28 12:38:43 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
lspci -vvv output (8.32 KB, text/plain)
2006-03-10 09:17 EST, Jason
no flags Details
dmesg output (15.93 KB, text/plain)
2006-03-10 09:19 EST, Jason
no flags Details

  None (edit)
Description Jason 2006-02-13 11:31:57 EST
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.0.1) Gecko/20060210 Fedora/1.5.0.1-3 Firefox/1.5.0.1

Description of problem:
Since the massive rebuild last week I have been getting udevd_event error messages during boot.  These messages do NOT appear in /var/log/messages they only show on the console.  Here are the messages:
udevd_event [1133]: wait_for_sysfs: waiting for '/sys/devices/pci0000:00/0000:00:10:0/usb2/2-3/bus' failed
udevd_event [1271]: wait_for_sysfs: waiting for '/sys/devices/pci0000:00/0000:00:10:0/usb2/2-3/2-3:1.0/bus' failed


Version-Release number of selected component (if applicable):
udev-084-1.1

How reproducible:
Always

Steps to Reproduce:
1. install rawhide
2. boot kerenel
3.
  

Additional info:
Comment 1 Jason 2006-02-13 11:38:31 EST
More information.  These messages only occur when my kanaguru thumb drive is
plugged in during boot.  If I boot without the drive plugged in the messages go
away.
Comment 2 Kay Sievers 2006-02-14 08:53:45 EST
The drive is usable after a bootup with it while you see
the messages?

Can you check if the failed symlink in the error message
exists after the box is booted? (Maybe for some odd reason
the USB device needs longer than 3 seconds to initialize
during bootup.)

Do you see the same messages in /var/log/messages when
connecting the device after the box is already booted?
(They only show up on the console, when syslog is not
available like during bootup)

How fast is the box you see this?
Comment 3 Jason 2006-02-14 09:34:41 EST
The drive is usable after a bootup with it in and I see the messages.

[root@pcjason usb2]# pwd
/sys/devices/pci0000:00/0000:00:10.0/usb2
[root@pcjason usb2]# ls -l
total 0
drwxr-xr-x 4 root root    0 Feb 14 08:04 2-0:1.0
-r--r--r-- 1 root root 4096 Feb 14 08:35 bcdDevice
-rw-r--r-- 1 root root 4096 Feb 14 08:35 bConfigurationValue
-r--r--r-- 1 root root 4096 Feb 14 08:35 bDeviceClass
-r--r--r-- 1 root root 4096 Feb 14 08:35 bDeviceProtocol
-r--r--r-- 1 root root 4096 Feb 14 08:35 bDeviceSubClass
-r--r--r-- 1 root root 4096 Feb 14 08:35 bmAttributes
-r--r--r-- 1 root root 4096 Feb 14 08:35 bMaxPacketSize0
-r--r--r-- 1 root root 4096 Feb 14 08:35 bMaxPower
-r--r--r-- 1 root root 4096 Feb 14 08:35 bNumConfigurations
-r--r--r-- 1 root root 4096 Feb 14 08:35 bNumInterfaces
lrwxrwxrwx 1 root root    0 Feb 14 08:35 bus -> ../../../../bus/usb
-r--r--r-- 1 root root 4096 Feb 14 08:35 configuration
-r--r--r-- 1 root root 4096 Feb 14 08:35 devnum
lrwxrwxrwx 1 root root    0 Feb 14 08:35 driver -> ../../../../bus/usb/drivers/usb
drwxr-xr-x 2 root root    0 Feb 14 08:04 ep_00
-r--r--r-- 1 root root 4096 Feb 14 08:35 idProduct
-r--r--r-- 1 root root 4096 Feb 14 08:35 idVendor
-r--r--r-- 1 root root 4096 Feb 14 08:35 manufacturer
-r--r--r-- 1 root root 4096 Feb 14 08:35 maxchild
drwxr-xr-x 2 root root    0 Feb 14 08:04 power
-r--r--r-- 1 root root 4096 Feb 14 08:35 product
-r--r--r-- 1 root root 4096 Feb 14 08:35 serial
-r--r--r-- 1 root root 4096 Feb 14 08:35 speed
--w------- 1 root root 4096 Feb 14 08:35 uevent
lrwxrwxrwx 1 root root    0 Feb 14 08:35 usb_device:usbdev2.1 ->
../../../../class/usb_device/usbdev2.1
-r--r--r-- 1 root root 4096 Feb 14 08:35 version

I don't the udevd_event messages in /var/log/messages.  If I plugin the drive
after the PC is booted I don't see the messages.  The PC is a P3 850Mhz with
384MB of RAM.
Comment 4 Kay Sievers 2006-02-14 20:25:31 EST
Ok, such a box should not take 3 seconds for sysfs. Care to remove all external
usb devices, reboot and look if the message still appears, to find the device
that causes this?

I've seen this on one box too now and it seems that the device is going away
while we wait for the attribute cause the whole device we see the error for and
waited for the attribute did not exist after the bootup has finished.
Comment 5 Kay Sievers 2006-02-14 20:40:27 EST
If you run:
  dmesg
do you see in something like this?
  ...
  hub 1-1:1.0: hub_port_status failed (err = -71)
  hub 1-1:1.0: hub_port_status failed (err = -71)
  hub 1-1:1.0: hub_port_status failed (err = -71)
  usb 1-1: USB disconnect, address 2
  ...

That's the reason for the udev error. Seems like a USB problem,
several people see, but we don't have an idea what's going wrong.
Comment 6 Jason 2006-02-15 07:54:42 EST
It is the kanguru thumb drive that is causing the problem.  The only other USB
device I have is a MS Intellimouse explorer.

Here is a part of the dmesg output.  The short version is I don't see any
failures.  This was working fine before the massive rebuild last week.  My two
guesses for the issue are: Udev got broken, or more likely the kernel got
broken.  I got bit by the ehci (or ohci) bug that caused my system to freeze at
starting udev a few kernels ago.

ohci_hcd: 2005 April 22 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
PCI: setting IRQ 10 as level-triggered
ACPI: PCI Interrupt 0000:00:10.0[A] -> Link [LNKA] -> GSI 10 (level, low) -> IRQ
 10
ohci_hcd 0000:00:10.0: OHCI Host Controller
ohci_hcd 0000:00:10.0: new USB bus registered, assigned bus number 1
ohci_hcd 0000:00:10.0: irq 10, io mem 0xffafc000
USB Universal Host Controller Interface driver v2.3
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 3 ports detected
ACPI: PCI Interrupt 0000:00:10.1[B] -> Link [LNKB] -> GSI 11 (level, low) -> IRQ
 11
ohci_hcd 0000:00:10.1: OHCI Host Controller
ohci_hcd 0000:00:10.1: new USB bus registered, assigned bus number 2
ohci_hcd 0000:00:10.1: irq 11, io mem 0xffafd000
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:07.2[D] -> Link [LNKD] -> GSI 9 (level, low) -> IRQ
9
uhci_hcd 0000:00:07.2: UHCI Host Controller
uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:07.2: irq 9, io base 0x0000ef80
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:10.2[C] -> Link [LNKC] -> GSI 15 (level, low) -> IRQ
 15
ehci_hcd 0000:00:10.2: EHCI Host Controller
ehci_hcd 0000:00:10.2: new USB bus registered, assigned bus number 4
ehci_hcd 0000:00:10.2: irq 15, io mem 0xffafef00
ehci_hcd 0000:00:10.2: USB 2.0 started, EHCI 0.95, driver 10 Dec 2004
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 5 ports detected
usb 2-1: new full speed USB device using ohci_hcd and address 2
usb 3-2: new low speed USB device using uhci_hcd and address 2
usb 3-2: configuration #1 chosen from 1 choice
input: Microsoft Microsoft IntelliMouse� Explorer as /class/input/input1
input: USB HID v1.00 Mouse [Microsoft Microsoft IntelliMouse� Explorer] on
usb-0000:00:07.2-2
usb 4-2: new high speed USB device using ehci_hcd and address 2
usb 4-2: configuration #1 chosen from 1 choice
Initializing USB Mass Storage driver...
scsi1 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 2
usb-storage: waiting for device to settle before scanning
usbcore: registered new driver usb-storage
USB Mass Storage support registered.

sdc: Write Protect is off
sdc: Mode Sense: 53 00 00 08
sdc: assuming drive cache: write through
SCSI device sdc: 4063232 512-byte hdwr sectors (2080 MB)
sdc: Write Protect is off
sdc: Mode Sense: 53 00 00 08
sdc: assuming drive cache: write through
 sdc: sdc1
sd 1:0:0:0: Attached scsi removable disk sdc
sd 1:0:0:0: Attached scsi generic sg2 type 0
usb-storage: device scan complete

Comment 7 Kay Sievers 2006-02-15 17:50:59 EST
Ok, i've released udev 085, which does not longer print an error if the device
goes away while waiting for an attribute, which can also happens when is yanked
out before it is initialized.

The real problem we see here is likely a kernel bug:
  http://bugzilla.kernel.org/show_bug.cgi?id=6078
Comment 8 Jason 2006-03-06 10:47:24 EST
Starting with 2.6.15-1.2009.4.2_FC5 I nolonger see the wait_for_sysfs messages.
 I guess the kernel problem was fixed.
Comment 9 Jason 2006-03-08 08:58:53 EST
The problem is back starting as of yesterday.  I don't know why.
Comment 10 Harald Hoyer 2006-03-08 09:44:14 EST
assigning to kernel... it should really provide the bus
Comment 11 Dave Jones 2006-03-08 14:13:45 EST
Harald, what exactly is missing here ?
On the latest kernel, find /sys/devices shows up 'bus' entries for all my devices.
Comment 12 Harald Hoyer 2006-03-09 02:44:14 EST
> udevd_event [1133]: wait_for_sysfs: waiting for
> '/sys/devices/pci0000:00/0000:00:10:0/usb2/2-3/bus' failed
> udevd_event [1271]: wait_for_sysfs: waiting for 
> '/sys/devices/pci0000:00/0000:00:10:0/usb2/2-3/2-3:1.0/bus' failed

> These messages only occur when my kanaguru thumb drive is plugged in during 
> boot.  If I boot without the drive plugged in the messages go
> away.
Comment 13 Dave Jones 2006-03-09 18:06:26 EST
Jason, still a problem with latest kernel ?
I'm at a loss to explain why they'd be there for one system but not another.
Comment 14 Jason 2006-03-10 07:54:21 EST
I still get the following messages with  2.6.15-1.2032_FC5:
udevd_event [1092]: wait_for_sysfs: waiting for
'/sys/devices/pci0000:00/0000:00:10.0/usb1/1-3/bus' failed
udevd_event [1230]: wait_for_sysfs: waiting for
'/sys/devices/pci0000:00/0000:00:10.0/usb1/1-3/1-3:1.0/bus' failed
Comment 15 Jason 2006-03-10 09:16:47 EST
with  2.6.15-1.2038_FC5:
udevd_event [1105]: wait_for_sysfs: waiting for
'/sys/devices/pci0000:00/0000:00:10.0/usb1/1-3/bus' failed
udevd_event [1242]: wait_for_sysfs: waiting for
'/sys/devices/pci0000:00/0000:00:10.0/usb1/1-3/1-3:1.0/bus' failed

It is interesting to see that the event number changes, but nothing else does. 
I will attach the output of lspci -vvv and todays dmesg.
Comment 16 Jason 2006-03-10 09:17:55 EST
Created attachment 125944 [details]
lspci -vvv output
Comment 17 Jason 2006-03-10 09:19:18 EST
Created attachment 125945 [details]
dmesg output
Comment 18 Jason 2006-03-17 14:19:20 EST
wait_for_sys messages still happening with 2.6.15-1.2054_FC5
Comment 19 Jason 2006-08-28 12:38:43 EDT
I switched to rawhide and so far no messages.  I am closing this bug.

Note You need to log in before you can comment on or make changes to this bug.