udevd takes 100% of cpu

Bug #780266 reported by picgla
76
This bug affects 14 people
Affects Status Importance Assigned to Milestone
udev (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

Binary package hint: udev

udevd is causing the machine to run very high cpu utilization rates; fan runs constantly. meerkat on the same machine caused no such problems.

ProblemType: Bug
DistroRelease: Ubuntu 11.04
Package: udev 167-0ubuntu3
ProcVersionSignature: Ubuntu 2.6.38-9.43-generic 2.6.38.4
Uname: Linux 2.6.38-9-generic i686
Architecture: i386
Date: Mon May 9 19:43:58 2011
InstallationMedia: Ubuntu 11.04 "Natty Narwhal" - Release i386 (20110427.1)
MachineType: Dell Inc. OptiPlex GX280
ProcEnviron:
 PATH=(custom, user)
 LANG=en_US.UTF-8
 SHELL=/usr/local/bin/zsh
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-2.6.38-9-generic root=UUID=da503c0c-0d80-4161-ad70-d5f050ed7527 ro
SourcePackage: udev
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 03/03/2006
dmi.bios.vendor: Dell Inc.
dmi.bios.version: A08
dmi.board.name: 0H8164
dmi.board.vendor: Dell Inc.
dmi.chassis.type: 15
dmi.chassis.vendor: Dell Inc.
dmi.modalias: dmi:bvnDellInc.:bvrA08:bd03/03/2006:svnDellInc.:pnOptiPlexGX280:pvr:rvnDellInc.:rn0H8164:rvr:cvnDellInc.:ct15:cvr:
dmi.product.name: OptiPlex GX280
dmi.sys.vendor: Dell Inc.

Revision history for this message
picgla (picgla) wrote :
Revision history for this message
Sam Liddicott (sam-liddicott) wrote :

Here is what strace shows:

recv(8, 0xbfced218, 8, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
sendmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=-4298, groups=00000000}, msg_iov(2)=[{"libudev\0\376\355\312\376(\0\0\0(\0\0\0\322\0\0\0\360\3\35\267{\313\305\356"..., 40}, {"UDEV_LOG=3\0ACTION=change\0DEVPATH"..., 210}], msg_controllen=0, msg_flags=0}, 0) = 250
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 5, -1) = 1 ([{fd=8, revents=POLLIN}])
recv(8, "\341\17\0\0\0\0\0\0", 8, MSG_DONTWAIT) = 8
_llseek(3, 0, [11513544], SEEK_CUR) = 0
write(3, "\351\260\0\0\0\0\0\0\0\0", 10) = 10
recv(8, 0xbfced218, 8, MSG_DONTWAIT) = -1 EAGAIN (Resource temporarily unavailable)
sendmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=-4298, groups=00000000}, msg_iov(2)=[{"libudev\0\376\355\312\376(\0\0\0(\0\0\0\322\0\0\0\360\3\35\267{\313\305\356"..., 40}, {"UDEV_LOG=3\0ACTION=change\0DEVPATH"..., 210}], msg_controllen=0, msg_flags=0}, 0) = 250
poll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}, {fd=6, events=POLLIN}, {fd=7, events=POLLIN}, {fd=8, events=POLLIN}], 5, -1) = 1 ([{fd=8, revents=POLLIN}])
recv(8, "\341\17\0\0\0\0\0\0", 8, MSG_DONTWAIT) = 8
_llseek(3, 0, [11513554], SEEK_CUR) = 0
write(3, "\352\260\0\0\0\0\0\0\0\0", 10) = 10

Revision history for this message
Sam Liddicott (sam-liddicott) wrote :

A trigger of this is inserting my Sandisk Cruzer USB memory stick with fake integrated CD-ROM.

This it dmesg when I insert the USB memory stick:
May 12 14:46:20 sojo kernel: [95455.488104] usb 1-3: new high speed USB device using ehci_hcd and address 12
May 12 14:46:20 sojo kernel: [95455.622507] scsi9 : usb-storage 1-3:1.0
May 12 14:46:21 sojo kernel: [95456.623418] scsi 9:0:0:0: Direct-Access SanDisk Cruzer 7.01 PQ: 0 ANSI: 0 CCS
May 12 14:46:21 sojo kernel: [95456.623973] scsi 9:0:0:1: CD-ROM SanDisk Cruzer 7.01 PQ: 0 ANSI: 0
May 12 14:46:21 sojo kernel: [95456.629231] sd 9:0:0:0: Attached scsi generic sg4 type 0
May 12 14:46:21 sojo kernel: [95456.635576] sd 9:0:0:0: [sdd] Attached SCSI removable disk
May 12 14:46:21 sojo kernel: [95456.645776] sr1: scsi3-mmc drive: 48x/48x tray
May 12 14:46:21 sojo kernel: [95456.645996] sr 9:0:0:1: Attached scsi CD-ROM sr1
May 12 14:46:21 sojo kernel: [95456.646558] sr 9:0:0:1: Attached scsi generic sg5 type 5
May 12 14:46:22 sojo kernel: [95457.352760] sd 9:0:0:0: [sdd] 31306239 512-byte logical blocks: (16.0 GB/14.9 GiB)
May 12 14:46:22 sojo kernel: [95457.354199] sd 9:0:0:0: [sdd] Asking for cache data failed
May 12 14:46:22 sojo kernel: [95457.354203] sd 9:0:0:0: [sdd] Assuming drive cache: write through
May 12 14:46:22 sojo kernel: [95457.358186] sd 9:0:0:0: [sdd] Asking for cache data failed
May 12 14:46:22 sojo kernel: [95457.358190] sd 9:0:0:0: [sdd] Assuming drive cache: write through
May 12 14:46:22 sojo kernel: [95457.358870] sdd: sdd1
May 12 14:46:23 sojo kernel: [95458.609921] ISO 9660 Extensions: Microsoft Joliet Level 3
May 12 14:46:24 sojo kernel: [95458.686421] ISOFS: changing to secondary root
May 12 14:46:24 sojo kernel: [95458.693931] VFS: busy inodes on changed media or resized disk sr1

Until I remove my SUB stick I get this in syslog repeatedly:
May 12 14:51:47 sojo kernel: [95782.079217] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.095640] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.112794] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.146326] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.162621] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.179708] VFS: busy inodes on changed media or resized disk sr1
May 12 14:51:47 sojo kernel: [95782.250378] VFS: busy inodes on changed media or resized disk sr1

But the CPU usage does not go away when I remove it, but udisks-daemon and dbys-daemon also take a lot of CPU.

Changed in udev (Ubuntu):
status: New → Confirmed
Revision history for this message
Sam Liddicott (sam-liddicott) wrote :

A while after I removed my usb stick, udisks-daemon and dbus-daemon quietened down. Maybe they were handling the backlog of inode changed messages?

Revision history for this message
Dmitry Savvateev (savvdm) wrote :

I have the same problem with USB stick with integrated CD (Transcend). I often keep it inserted all the time, so I have to disable udev with 'udevadm control --stop-exec-queue'. This is not a solution, of course, but so far I could not figure out how to block media change events from sr1.

Revision history for this message
Sam Liddicott (sam-liddicott) wrote : Re: [Bug 780266] Re: udevd takes 100% of cpu

thank-you for this solution.

I've been plugging my memory stick into my NAS and using NFS to mount
it, which is clearly stupid.

Your solution is much better.

Revision history for this message
Dmitry Savvateev (savvdm) wrote :

I have found a way to reduce CPU load without entirely stopping the udev queue.

Create /etc/udev/rules.d/my.rules file, and put the following line into it:
KERNEL=="sr1", ACTION=="change", WAIT_FOR="nothing"

This will introduce a 10 seconds delay when processing 'change' events from /dev/sr1. As a result, CPU load returns to normal. I did not notice any negative side effects so far. Other udev events seem to get processed normally.

This is still a work-around, not a solution. The solution would be to find out exactly what's wrong with the existing udev rules, and fix the problem there.

Revision history for this message
Dmitry Savvateev (savvdm) wrote :

Here's the answer from Kay Sievers (udev mailing list):

It's a broken device, that tells with every check that the media has
 changed. This patch needs to be tested:
  http://marc.info/?l=linux-hotplug&m=130843331916959&w=2

Revision history for this message
Alex (icidrop) wrote :

Where is the patch, and how to apply it? I couldn't find it in the link. Please direct me.

Revision history for this message
Dmitry Savvateev (savvdm) wrote :

There is a source code patch in the message - it should be applied to the original sources, and re-compiled.

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

Duplicates of this bug

Other bug subscribers

Remote bug watches

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