FS#16001 - [udev] udevd uses excessive cpu and spawns too many process on boot-up
Attached to Project:
Arch Linux
Opened by Jay Tanzman (jt512) - Saturday, 05 September 2009, 00:47 GMT
Last edited by Angel Velasquez (angvp) - Monday, 05 July 2010, 21:46 GMT
Opened by Jay Tanzman (jt512) - Saturday, 05 September 2009, 00:47 GMT
Last edited by Angel Velasquez (angvp) - Monday, 05 July 2010, 21:46 GMT
|
Details
Description:
Upon upgrading to 145-1, udevd spawns a second process and cpu usages goes up to around 25% (normal is about 1% on my laptop). After reboot, udevd spawns about 20 processes, and cpu usage is excessive. Additional info: * udev-145-1 Steps to reproduce: 1. Upgrade udev to 145-1 2. `ps -ef | grep udev` will show 2 udevd process, and cpu usage will be excessive 3. Reboot 4. `ps -ef | grep udev will show many udevd processes, and cpu usage will be excessive |
This task depends upon
Closed by Angel Velasquez (angvp)
Monday, 05 July 2010, 21:46 GMT
Reason for closing: Fixed
Additional comments about closing: re-open in case it happens again
Monday, 05 July 2010, 21:46 GMT
Reason for closing: Fixed
Additional comments about closing: re-open in case it happens again
Status with udev 146 from testing?
Could you please list the contents of /etc/udev/rules.d ?
Maybe this is caused by some broken rules processing :-/
ls /etc/udev/rules.d:
10-usb.rules
10-usb.rules~
53-sane.rules~
54-gphoto.rules
60-pcmcia.rules
75-cd-aliases-generator.rules.optional
75-persistent-net-generator.rules.optional
90-hal.rules
97-bluetooth-serial.rules
99-fuse.rules
device-mapper.rules
Do you want the contents of these files, too?
@Tobias: see http://nopaste.com/p/a9h826y0E - the logfile is flooded with this.
while on your system udev is flooded with events from sr0, don't know why
ls /etc/udev/rules.d/
10-vboxdrv.rules 54-gphoto.rules 75-cd-aliases-generator.rules.optional 90-hal.rules 99-fuse.rules
45-libnjb.rules 60-pcmcia.rules 75-persistent-net-generator.rules.optional 97-bluetooth-serial.rules device-mapper.rules
but at boot, I have to wait more than 3min to get uevent processed...
udevadm monitor is flooded with tons of :
KERNEL[1252250981.606281] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV [1252250981.606560] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
The problem still exactly the same with udev 146 from testing.
Everything else is up to date on my system.
KERNEL[1252263519.016398] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1252263519.017157] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV [1252263519.017403] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV [1252263519.119416] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
BUT one packet of this size by second, no more. With udev 145 and 146 I'm getting a lot of them by second.
In the version of udev-141 is no problem about this.
"udevadm monitor" gives the following:
KERNEL[1253500790.024037] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1253500790.025426] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV [1253500790.025977] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV [1253500790.220099] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1253500792.045671] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1253500792.046727] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV [1253500792.047275] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV [1253500792.203610] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
In version 141-1 aproximetlly 1-2 times per second and stops after "hal-disable-polling - device / dev / cdrom",
but versions of the 145-1 and 146-2 are not ceasing and "hal-disable-polling -- device / dev / cdrom "does not stop it.
The file output
udevadm monitor --property
What you need more?
thanks
I'm getting very similar msg with the working version of udev :
UDEV [1253572423.115047] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV_LOG=2
ACTION=change
DEVPATH=/devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0
SUBSYSTEM=block
DEVTYPE=disk
SEQNUM=96906
ID_CDROM=1
ID_CDROM_CD_R=1
ID_CDROM_CD_RW=1
ID_CDROM_DVD=1
ID_CDROM_DVD_R=1
ID_CDROM_DVD_RW=1
ID_CDROM_DVD_RAM=1
ID_CDROM_DVD_PLUS_R=1
ID_CDROM_DVD_PLUS_RW=1
ID_CDROM_DVD_PLUS_R_DL=1
ID_CDROM_MRW=1
ID_CDROM_MRW_W=1
ID_VENDOR=Optiarc
ID_VENDOR_ENC=Optiarc\x20
ID_MODEL=DVD_RW_AD-7560S
ID_MODEL_ENC=DVD\x20RW\x20AD-7560S\x20
ID_REVISION=S801
ID_TYPE=cd
ID_BUS=scsi
ID_PATH=pci-0000:00:1f.2-scsi-1:0:0:0
DEVNAME=/dev/sr0
MAJOR=11
MINOR=0
DEVLINKS=/dev/block/11:0 /dev/scd0 /dev/disk/by-path/pci-0000:00:1f.2-scsi-1:0:0:0 /dev/cd/cdrom-1:0:0:0 /dev/cd/cdrw-1:0:0:0 /dev/cd/dvd-1:0:0:0 /dev/cd/dvdrw-1:0:0:0
KERNEL[1253572425.014430] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV_LOG=2
ACTION=change
DEVPATH=/devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0
SUBSYSTEM=scsi
SDEV_MEDIA_CHANGE=1
DEVTYPE=scsi_device
DRIVER=sr
MODALIAS=scsi:t-0x05
SEQNUM=96907
KERNEL[1253572425.014861] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV_LOG=2
ACTION=change
DEVPATH=/devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0
SUBSYSTEM=block
DEVTYPE=disk
SEQNUM=96908
MAJOR=11
MINOR=0
UDEV [1253572425.015228] change /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV_LOG=2
ACTION=change
DEVPATH=/devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0
SUBSYSTEM=scsi
SDEV_MEDIA_CHANGE=1
DEVTYPE=scsi_device
DRIVER=sr
MODALIAS=scsi:t-0x05
SEQNUM=96907
udevadm monitor doesnt show anything at all.
udevadm-monitor (3.2 KiB)
I've found an entry on the kernel bug tracker about this issue:
http://bugzilla.kernel.org/show_bug.cgi?id=13783
1. "udevd uses excessive cpu and spawns too many process on boot-up"
I don't know, if is it a problem, but I have 116 udevd processes. They eat ~25% of my cpu in idle state.
workaround: add the --debug-trace option to udevd (in rc.sysinit for example); it will slow down the init procedure but you get only ~3 udevd instance
2. "udevd still uses (less) excessive cpu without spawning too many..."
After eliminating the first issue I have still ~6% cpu usage (by udevd) in idle state.
workaround: blacklist the module sr_mod (and forget using it :)
http://aur.archlinux.org/packages.php?ID=31373
udevadm control --max-childs=1
The events also stop appearing when using 'udevadm control --max-childs=1' ? When put in the udev hook of initcpio?
@brain0 thank you for pointing that out.
The underlying problem must still be in the kernel, not udev itself.
I agree with brain0, it's a kernel problem.
shouldn't 'udevadm monitor' show the events signalled by the kernel even if they are ignored by an udev rule?
Because when using udev-ubuntu 'udevadm' does not output any of those media change events here.
@craw: There is also a firmware for AD-7580S from dell: http://ftp.euro.dell.com/rmsd/AD-7580S%20FD06.zip
(Used unetbootin to create a bootable usbstick with freedos and unzipped the firmware package to it.)
Thank all of you for pointing this out
Device: Optiarc AD-7560S
Brand of notebook: Acer Extensa
Used firmware: http://ftp.euro.dell.com/rmsd/AD-7560S%20SD05.zip
The firmware I used is this one:
http://support.dell.com/support/downloads/download.aspx?c=ca&l=en&s=gen&releaseid=R225232&SystemID=STUDIO1737&servicetag=&os=WLH&osl=en&deviceid=16565&devlib=0&typecnt=0&vercnt=1&catid=-1&impid=-1&formatcnt=0&libid=32&typeid=-1&dateid=-1&formatid=-1&source=-1&fileid=323548
A DOS version is included in the zip file.