Ubuntu
linux-source-2.6.20 package

adds/removes same device many times a second causing high loads and extremally slow performance

Bug #81915 reported by Rimas Kudelis
26
Affects Status Importance Assigned to Milestone
hal (Ubuntu)
Invalid
Undecided
Unassigned
linux-source-2.6.20 (Ubuntu)
Fix Released
Undecided
Unassigned

Bug Description

Binary package hint: hal

I've dist-upgraded to feisty a few days ago, and since then my system is impossible to use. I suspect it's hald's fault, because it detects some device A LOT OF TIMES per second, adding and removing it each time. As a result of this, hald uses like 30% of my RAM (out of 512MB), causing extensive use of swap and really high latency. I also had to shut down ivman supposedly as a result of this problem (it demanded even more resources than hald).

Here's an excerpt from /var/log/daemon.log:

Jan 28 01:53:07 localhost NetworkManager: <debug info>^I[1169941987.972282] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.054945] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.055382] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.155758] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.156556] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.296920] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.297036] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.366818] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.367233] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.458259] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.458993] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.538494] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.538621] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.704625] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.704759] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.874736] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.875523] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.946867] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:08 localhost NetworkManager: <debug info>^I[1169941988.947673] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').
Jan 28 01:53:09 localhost NetworkManager: <debug info>^I[1169941989.023349] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/devices/platform_i82365_0').

Revision history for this message
rickmans (rickmans) wrote :

I have the same issue since I upgraded from edgy to feisty.

Revision history for this message
Rimas Kudelis (rq) wrote :

Oh, and here's a (most probably) related excerpt from kern.log:

Jan 28 20:05:49 localhost kernel: [28566.887995] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28566.944927] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.008010] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.079220] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.140799] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.198461] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.261892] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.317977] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.385285] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.438674] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.506369] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.558916] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.602245] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.668163] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.727009] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.791926] Intel ISA PCIC probe: not found.
Jan 28 20:05:50 localhost kernel: [28567.853064] Intel ISA PCIC probe: not found.
Jan 28 20:05:51 localhost kernel: [28567.919015] Intel ISA PCIC probe: not found.

Revision history for this message
D B (eburner) wrote :

I get the same thing! my dmesg is filled with the PCIC probe: not found. thing and killing udevd helps restore my cpu and stops filling dmesg with this.

Revision history for this message
Fastguy (erenoglu) wrote :

I confirm this behaviour. I can see the same messages repeating on console (#4 i guess). The installation is stuck and does not go forward.

Config: Core2Duo E6300 2gig ram 2x250G sata disk, asus p5b-e board.

Regards

Fast

Revision history for this message
Stef Walter (stefw) wrote :

Same issue here. As indicated above after restarting udevd the problem seems to go away.

Revision history for this message
Daniel Holth (dholth) wrote :

I had the same problem. I am using Edgy Eft.

I got really annoyed because my disk was constantly filling up with these log messages, and having hald use 50% of my CPU all the time isn't too cool either. I don't think I was even able to log into KDE with a full disk. It's a good thing I'm a degree-bearing computer scientist and not my grandmother, or I would have had to seek professional help.

Thanks, original reporter, for this number: i82365. It was a PCMCIA driver. Since my desktop doesn't have any PCMCIA slots, it was safe to find i82356 and remove it here:

root@cardamom:/lib/modules/2.6.19.2-dwh/kernel/drivers# ls pcmcia/
i82092.ko i82365.ko pcmcia_core.ko pcmcia.ko pd6729.ko rsrc_nonstatic.ko tcic.ko yenta_socket.ko

rm -rf pcmcia/

The log messages stopped immediately.

To fix it for your machine:

cd /lib/modules/`uname -r`/kernel/drivers
rm -rf pcmcia

I will be sure not to compile PCMCIA support into my next kernel.

Revision history for this message
Fastguy (erenoglu) wrote :

Hi Again,

Unfortunately my problem occurs on the setup phase from the "alternate" installation CD (latest daily build of feisty). Whether I do a "command line installation" or a "text mode", the installation gets stuck after trying to recognize disk drives.

I then have this error message about PCIC Probe all over the place and cannot continue the installation.

The LiveCD boots and starts installation well.

Regards,

Fast

Revision history for this message
Martin Pool (mbp) wrote :

I have a similar problem while trying to install onto a Core 2 Duo machine with a Gigabyte 96SP-DS3 motherboard. Killing and restarting udevd, then waiting for a while lets the installation get a bit further. That's with the alternate install iso of 20070209.

Revision history for this message
Martin Pool (mbp) wrote :

Although I had these messages while trying to install, it's now ok running 2.6.20-6-generic

Revision history for this message
Rimas Kudelis (rq) wrote :

powersaved is another process that eats up RAM. Currently, to get my machine into usable state, I do the following:

$ sudo /etc/init.d/powersaved stop
$ sudo /etc/init.d/ivman stop

After this, hald still uses a lot of CPU cycles, but at least my RAM isn't consumed. Also, when memory usage rises, it's a signal that gnome-power-manager is misbehaving, so I run this command once in a while:

$ killall -9 gnome-power-manager

Hope this helps others for now.

Revision history for this message
Fastguy (erenoglu) wrote :

I am not able to continue the installation from the Alternate CD because of this bug. The live CD installs fine though.

When I kill udev, the errors vanish, but then the process cannot continue.

Revision history for this message
Martin Pool (mbp) wrote :

Fastguy, if you are patient then the installation may complete -- I had to leave it sit for a couple of minutes each time it went to look for hardware (ie after most interactions.) It's pretty annoying but the installation did complete. (May not work for you.)

Revision history for this message
Valentin Longchamp (longfield) wrote :
Download full text (16.4 KiB)

I have the same kind of problem. However I have been able to install Feisty rather cleanly and can use it in rather good conditions.

Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.079769] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_usbraw').
Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.082146] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_if0').
Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.082750] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial').
Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.391037] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial').
Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.475606] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_if0').
Feb 14 08:12:53 lsro1pc307 NetworkManager: <debug info>^I[1171437173.494472] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_usbraw').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.414194] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_usbraw').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.414788] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_if0').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.416037] nm_hal_device_removed (): Device removed (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.727227] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.809810] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_if0').
Feb 14 08:13:45 lsro1pc307 NetworkManager: <debug info>^I[1171437225.829630] nm_hal_device_added (): New device added (hal udi is '/org/freedesktop/Hal/d
evices/usb_device_483_2016_noserial_usbraw').

And this also seems to be related: when I plug in an USB device (FTDI-based USB-serial converter, using ftd_sio module), here are the various log files:

UDEVMONITOR:

UEVENT[1171437717.856855] add@/devices/pci0000:00/0000:00:1d.3/usb5/5-2
UEVENT[1171437717.856894] add@/class/usb_endpoint/usbdev5.7_ep00
UDEV [1171437717.857448] add@/devices/pci0000:00/0000:00:1d.3/usb5/5-2
UEVENT[1171437717.858739] add@/devices/pci0000:00/0000:00:1d.3/usb5/5-2/5-2:1.0
UEVENT[1171437717.860501] add@/class/usb_endpoint/usbdev5.7_ep81
UEVENT[1171437717.860527] add@/class/usb_endpoint/usbdev5.7_ep02
UEVENT[1171437717.860540] add@/class/usb_endpoint/usbdev5.7_ep83
UEVENT[1171437717.860552] add@/class/usb_device/usbde...

Revision history for this message
Martin Pitt (pitti) wrote :

hal just does what kernel/udev tell it, reassinging to the kernel. Can you please attach /var/log/kern.log?

Changed in hal:
status: Unconfirmed → Needs Info
Revision history for this message
Valentin Longchamp (longfield) wrote :
Download full text (7.1 KiB)

You're right Martin, the problem comes from the kernel, which goes on detecting USB connections although my USB device is disconnnected. (and furthermore, it cannot handle the USB device).

Here is /var/log/kernel.log:

 tail -f /var/log/kern.log
Feb 15 11:29:48 lsro1pc307 kernel: [79503.404000] usb 1-1: new full speed USB device using uhci_hcd and address 2
Feb 15 11:29:48 lsro1pc307 kernel: [79503.596000] usb 1-1: configuration #1 chosen from 1 choice
Feb 15 11:29:48 lsro1pc307 kernel: [79503.992000] usbcore: registered new interface driver usbserial
Feb 15 11:29:48 lsro1pc307 kernel: [79503.992000] drivers/usb/serial/usb-serial.c: USB Serial support registered for generic
Feb 15 11:29:49 lsro1pc307 kernel: [79504.084000] usbcore: registered new interface driver usbserial_generic
Feb 15 11:29:49 lsro1pc307 kernel: [79504.084000] drivers/usb/serial/usb-serial.c: USB Serial Driver core
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] drivers/usb/serial/usb-serial.c: USB Serial support registered for FTDI USB Serial Device
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] drivers/usb/serial/ftdi_sio.c: Detected FT232BM
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] usbcore: registered new interface driver ftdi_sio
Feb 15 11:29:49 lsro1pc307 kernel: [79504.096000] drivers/usb/serial/ftdi_sio.c: v1.4.3:USB FTDI Serial Converters Driver
Feb 15 11:29:49 lsro1pc307 kernel: [79504.300000] usb 1-1: usbfs: interface 0 claimed by ftdi_sio while 'brltty' sets config #1
Feb 15 11:29:49 lsro1pc307 kernel: [79504.304000] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Feb 15 11:29:49 lsro1pc307 kernel: [79504.304000] ftdi_sio 1-1:1.0: device disconnected
Feb 15 11:30:00 lsro1pc307 kernel: [79515.572000] usb 1-1: USB disconnect, address 2
Feb 15 11:30:00 lsro1pc307 kernel: [79515.684000] usb 1-1: new full speed USB device using uhci_hcd and address 3
Feb 15 11:30:00 lsro1pc307 kernel: [79515.876000] usb 1-1: configuration #1 chosen from 1 choice
Feb 15 11:30:00 lsro1pc307 kernel: [79515.880000] ftdi_sio 1-1:1.0: FTDI USB Serial Device converter detected
Feb 15 11:30:00 lsro1pc307 kernel: [79515.880000] drivers/usb/serial/ftdi_sio.c: Detected FT232BM
Feb 15 11:30:00 lsro1pc307 kernel: [79515.880000] usb 1-1: FTDI USB Serial Device converter now attached to ttyUSB0
Feb 15 11:30:06 lsro1pc307 kernel: [79521.032000] usb 1-1: usbfs: interface 0 claimed by ftdi_sio while 'brltty' sets config #1
Feb 15 11:30:06 lsro1pc307 kernel: [79521.036000] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
Feb 15 11:30:06 lsro1pc307 kernel: [79521.036000] ftdi_sio 1-1:1.0: device disconnected
Feb 15 11:30:11 lsro1pc307 kernel: [79526.516000] usb 4-2: USB disconnect, address 4
Feb 15 11:30:11 lsro1pc307 kernel: [79526.628000] usb 4-2: new full speed USB device using uhci_hcd and address 5
Feb 15 11:30:11 lsro1pc307 kernel: [79526.860000] usb 4-2: configuration #1 chosen from 1 choice
Feb 1...

Read more...

Revision history for this message
Rimas Kudelis (rq) wrote :

Hmm...
The problem is gone for me. I think it may be related to the latest changes in linux-source-2.6.20, particularly this one:

  * i82365: Probe before adding platform dev.
    - GIT-SHA 06fd3fa13e3b336fcea01c326f3af314e5f37688

Not even adding kern.log, as it looks OK.

Revision history for this message
Rimas Kudelis (rq) wrote :

P.S. The version where the quoted change occured is 2.6.20-8.14.

I wonder if others are still having this problem.

Revision history for this message
D B (eburner) wrote :

Running 2.6.20-8.14, the issues seems to have disappeared for me.

It should also be noted that I switched to using KDE and KDM at the same time, but I'm unsure whether that had anything to do with it.

Revision history for this message
Valentin Longchamp (longfield) wrote :

No it has absolutely nothing to do with KDE or KDM because I'm using it too and the problem is also here. This is definitely kernel related. I'm currently running 2.6.20-8.4

Revision history for this message
Rimas Kudelis (rq) wrote :

Fixed in 2.6.20-8.14

Changed in linux-source-2.6.20:
status: Needs Info → Fix Released
Revision history for this message
D B (eburner) wrote :

Can someone close this bug? It's fixed!

Revision history for this message
Rimas Kudelis (rq) wrote :

I think it's closed now.

Changed in hal:
status: Unconfirmed → Rejected
Revision history for this message
Patrick Fischer (patrick-fischer) wrote :

maybe not.

Today I got this:
[ 2882.588453] usb 3-8.1: USB disconnect, address 6
[ 2884.830771] usb 3-8.1: new full speed USB device using ehci_hcd and address 7
[ 2884.932502] usb 3-8.1: configuration #1 chosen from 1 choice
[ 2884.932687] ftdi_sio 3-8.1:1.0: FTDI USB Serial Device converter detected
[ 2884.932696] drivers/usb/serial/ftdi_sio.c: Detected FT232BM
[ 2884.933050] usb 3-8.1: FTDI USB Serial Device converter now attached to ttyUSB0
[ 2886.538391] usb 3-8.1: usbfs: interface 0 claimed by ftdi_sio while 'brltty' sets config #1
[ 2886.539215] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[ 2886.539249] ftdi_sio 3-8.1:1.0: device disconnected
[ 2916.293150] usb 3-8.1: USB disconnect, address 7
[ 2919.615793] usb 3-8.1: new full speed USB device using ehci_hcd and address 8
[ 2919.713677] usb 3-8.1: configuration #1 chosen from 1 choice
[ 2919.713845] ftdi_sio 3-8.1:1.0: FTDI USB Serial Device converter detected
[ 2919.713856] drivers/usb/serial/ftdi_sio.c: Detected FT232BM
[ 2919.714252] usb 3-8.1: FTDI USB Serial Device converter now attached to ttyUSB0
[ 2919.839064] usb 3-8.1: usbfs: interface 0 claimed by ftdi_sio while 'brltty' sets config #1
[ 2919.839957] ftdi_sio ttyUSB0: FTDI USB Serial Device converter now disconnected from ttyUSB0
[ 2919.839989] ftdi_sio 3-8.1:1.0: device disconnected

Revision history for this message
Patrick Fischer (patrick-fischer) wrote :

pf@patrick-desktop:~$ uname -a
Linux patrick-desktop 2.6.20-15-generic #2 SMP Sun Apr 15 07:36:31 UTC 2007 i686 GNU/Linux

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.