Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.

Bug 532011

Summary: udevd eats 60% CPU cycles
Product: [Fedora] Fedora Reporter: Jochen Roth <jroth>
Component: halAssignee: Richard Hughes <richard>
Status: CLOSED WONTFIX QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 13CC: bobg+redhat, harald, james, mivainio, richard
Target Milestone: ---   
Target Release: ---   
Hardware: i386   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-06-27 14:28:59 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
result of fuser command none

Description Jochen Roth 2009-10-30 09:23:59 UTC
Description of problem:
After upgrading to the latest udev version on F11 my average CPU load moved to 60%. After downgrading from  141-7.fc11 to 141-3.fc11 everything seems to be back to normal.

udevadm monitor gives me tons of the following messages:

KERNEL[1256893586.555930] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1256893586.566538] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
KERNEL[1256893586.567861] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1256893586.567889] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)


The following forum post describes the same problem that I have:
http://forums.fedoraforum.org/showthread.php?t=232007

Version-Release number of selected component (if applicable):
141-7.fc11

How reproducible:
always

Steps to Reproduce:
1. Install udev-141-7.fc11
2. Watch the CPU load

Actual results:
60% CPU load

Expected results:
0% CPU load

Comment 1 Harald Hoyer 2009-10-30 09:27:01 UTC
It seems something is polling the disk and opens it with the writable flag set.

Can you identify what is polling the cd?

Be sure, to also update DeviceKit-disks. Maybe that will cure the symptom.

Comment 2 Jochen Roth 2009-10-30 10:53:20 UTC
(In reply to comment #1)
> It seems something is polling the disk and opens it with the writable flag set.
> 
> Can you identify what is polling the cd?

There is no CD in the drive and even when booting into single user mode the issue still happens. I can see 20% user and 20% system load after booting into single user mode.
As soon as I kill udevd my CPU load is back to 99% idle.
When I start the udevd again in single user mode the system is still 99% idle (no matter if with --debug or with -d).
But when I kill udevd and start it again in runlevel 5 udevd will be busy again.



> Be sure, to also update DeviceKit-disks. Maybe that will cure the symptom.  

[root@localhost ~]# rpm -qa udev DeviceKit-disks
udev-141-7.fc11.i586
DeviceKit-disks-004-5.fc11.i586


This issue does not happen when downgrading to 141-3. So one could think that it has something to do with the changes made in between -3 and -7, doesn't it?

Comment 3 Harald Hoyer 2009-10-30 11:00:14 UTC
(In reply to comment #2)
> > Be sure, to also update DeviceKit-disks. Maybe that will cure the symptom.  
> 
> [root@localhost ~]# rpm -qa udev DeviceKit-disks
> udev-141-7.fc11.i586
> DeviceKit-disks-004-5.fc11.i586

ok, as new as it can be.. :-(

> 
> 
> This issue does not happen when downgrading to 141-3. So one could think that
> it has something to do with the changes made in between -3 and -7, doesn't it?  

Correct. But it means another application is missbehaving. So please try to identify which application is opening the cdrom device on a change (besides of udev with cdrom_id and vol_id).

Comment 4 Jochen Roth 2009-10-30 11:14:40 UTC
> Correct. But it means another application is missbehaving. So please try to
> identify which application is opening the cdrom device on a change (besides of
> udev with cdrom_id and vol_id).  

OK, I'll do that if you tell me how. It also happens in single user mode. There shouldn't be a lot of applications out there polling the cd.

Thanks

Jochen

Comment 5 Harald Hoyer 2009-10-30 11:33:19 UTC
run this:

# while : ; do fuser -v /dev/sr0;done

Comment 6 Jochen Roth 2009-10-30 15:56:06 UTC
Created attachment 366819 [details]
result of fuser command

I ran this command for some minutes.

lots of scsi_id and cdrom_id

and 

hald_addon_stor 

root     29190  0.0  0.0   3516   904 ?        S    16:33   0:00 hald-addon-storage: polling /dev/sr0 (every 2 sec)

Comment 7 Harald Hoyer 2009-10-30 17:29:19 UTC
/dev/sr0:            root      29190 F.... hald-addon-stor...


Ok, seems like hald-addon-storage is opening /dev/sr0 with the write flage and so it will emit another change event...

Comment 8 Jochen Roth 2009-11-04 22:10:03 UTC
Any news regarding this issue?

Comment 9 James 2010-01-14 10:22:40 UTC
Seen here too on F11/x86-64. udevadm monitor spews lots of

KERNEL[1263464453.979413] change   /devices/pci0000:00/0000:00:02.0/drm/card0 (drm)
UDEV  [1263464453.983914] change   /devices/pci0000:00/0000:00:02.0/drm/card0 (drm)
KERNEL[1263464453.984891] change   /devices/pci0000:00/0000:00:02.0/drm/card0 (drm)
UDEV  [1263464453.989209] change   /devices/pci0000:00/0000:00:02.0/drm/card0 (drm)

udev-141-7.fc11.x86_64
kernel-2.6.30.10-105.fc11.x86_64

Comment 10 mivainio 2010-02-22 09:45:45 UTC
And seen here on F12/x86.

DeviceKit-disks-009-3.fc12.i686
kernel-2.6.31.12-174.2.22.fc12.i686
udev-145-15.fc12.i686

udevadm monitor repeats:
KERNEL[1266831770.900015] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1266831770.900046] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1266831770.918083] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1266831770.918114] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1266831770.935759] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1266831770.935790] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
...

Comment 11 Jochen Roth 2010-02-22 10:04:50 UTC
I'm also still seeing the same problem even though it is not 60% anymore. It reduced down to about 20% since F12.

I looks like the Problem doesn't happen as soon as there is a CD in the drive. 
Can someone please confirm this?

Comment 12 mivainio 2010-02-22 10:22:43 UTC
CPU usage drops from ~45% to ~12% when a CD is inserted.

Comment 13 Mace Moneta 2010-03-04 05:45:28 UTC
I'm seeing the same problem, about 70% of a quad-core.  udevadm monitor:

UDEV  [1267681377.659138] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.663257] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.714310] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.716608] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.767084] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.770620] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.818623] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.818657] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.870594] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.877968] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.924982] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.925209] change   /devices/virtual/block/md1 (block)
UDEV  [1267681377.974837] change   /devices/virtual/block/md0 (block)
UDEV  [1267681377.979478] change   /devices/virtual/block/md1 (block)
UDEV  [1267681378.031417] change   /devices/virtual/block/md0 (block)
UDEV  [1267681378.038039] change   /devices/virtual/block/md1 (block)
UDEV  [1267681378.082603] change   /devices/virtual/block/md0 (block)
UDEV  [1267681378.082637] change   /devices/virtual/block/md1 (block)

Smolt profile:  http://www.smolts.org/client/show/pub_d98859db-2a89-44d6-baec-284b6acac7f9

Comment 14 Bug Zapper 2010-04-28 11:01:20 UTC
This message is a reminder that Fedora 11 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 11.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '11'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 11's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 11 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 15 Jochen Roth 2010-04-28 11:07:05 UTC
I'm seeing the same behaviour with Fedora 12 + updates.

The only workaround so far is to kill udevd. 
Inserting a CD causes the CPU load to decrease but it is still higher than it should be.

Comment 16 Harald Hoyer 2010-04-28 12:36:17 UTC
(In reply to comment #15)
> I'm seeing the same behaviour with Fedora 12 + updates.
> 
> The only workaround so far is to kill udevd. 
> Inserting a CD causes the CPU load to decrease but it is still higher than it
> should be.    

even with https://admin.fedoraproject.org/updates/udev-145-21.fc12 ?

Comment 17 Jochen Roth 2010-04-28 13:03:56 UTC
(In reply to comment #16)
> even with https://admin.fedoraproject.org/updates/udev-145-21.fc12 ?    

It seems to be better now as long as a CD is in the drive. The idle load in my case is 98%.

The combined user and system load is still ~20% in case there is no CD in the drive.

Comment 18 Jochen Roth 2010-05-27 10:33:53 UTC
It even got worse with F13. 

The load is at ~40% whilst udevd is running.
It is at ~1% after kill -9 udevd...

gvfs-gdu-volume seems to be the process with the highest load (according to top).

Comment 19 Harald Hoyer 2010-05-27 13:28:40 UTC
(In reply to comment #18)
> It even got worse with F13. 
> 
> The load is at ~40% whilst udevd is running.
> It is at ~1% after kill -9 udevd...
> 
> gvfs-gdu-volume seems to be the process with the highest load (according to
> top).    

and if you,

# mv /usr/libexec/gvfs-gdu-volume-monitor /usr/libexec/gvfs-gdu-volume-monitor.bak

does the problem persist after a reboot ?

Comment 20 Jochen Roth 2010-05-27 13:49:43 UTC
(In reply to comment #19)
> # mv /usr/libexec/gvfs-gdu-volume-monitor
> /usr/libexec/gvfs-gdu-volume-monitor.bak
> 
> does the problem persist after a reboot ?    

Thanks, that helped a lot.
The load reduced down to ~15% (5% udevd which causes 10% system load).

Comment 21 Harald Hoyer 2010-05-27 13:58:51 UTC
still... udevd should not be triggered by constant "change" events

Comment 22 Harald Hoyer 2010-05-27 13:59:56 UTC
(In reply to comment #20)
> (In reply to comment #19)
> > # mv /usr/libexec/gvfs-gdu-volume-monitor
> > /usr/libexec/gvfs-gdu-volume-monitor.bak
> > 
> > does the problem persist after a reboot ?    
> 
> Thanks, that helped a lot.
> The load reduced down to ~15% (5% udevd which causes 10% system load).    

what's your output of 

# udevadm monitor

?

Comment 23 Jochen Roth 2010-05-27 14:18:32 UTC
(In reply to comment #22)
> what's your output of 
> 
> # udevadm monitor

Loads of the following messages (repeats about every 40 ms).

It might have something to do with another problem I currently have. I'll open another bug for this one but the current kernel 2.6.33.4-95.fc13.i686 doesn't boot on my system. It loops forever when scsi_wait_scan is loaded by the initramfs.
Commenting the following line in the initramfs helped me to boot my system:

modprobe scsi_wait_scan && rmmod scsi_wait_scan

I'll post a bug report later but I'm pretty sure that this has something to do with buggy hardware I'm using.


#udevadm monitor

KERNEL[1274969517.470415] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
UDEV  [1274969517.470445] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0 (scsi)
KERNEL[1274969517.470466] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)
UDEV  [1274969517.511675] change   /devices/pci0000:00/0000:00:1f.2/host1/target1:0:0/1:0:0:0/block/sr0 (block)

#lspci -vv
00:1f.2 SATA controller: Intel Corporation ICH9M/M-E SATA AHCI Controller (rev 03) (prog-if 01 [AHCI 1.0])
	Subsystem: Acer Incorporated [ALI] Device 013c
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
	Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0
	Interrupt: pin B routed to IRQ 27
	Region 0: I/O ports at 1818 [size=8]
	Region 1: I/O ports at 180c [size=4]
	Region 2: I/O ports at 1810 [size=8]
	Region 3: I/O ports at 1808 [size=4]
	Region 4: I/O ports at 18e0 [size=32]
	Region 5: Memory at f4a04000 (32-bit, non-prefetchable) [size=2K]
	Capabilities: [80] MSI: Enable+ Count=1/16 Maskable- 64bit-
		Address: fee0100c  Data: 4181
	Capabilities: [70] Power Management version 3
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot+,D3cold-)
		Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [a8] SATA HBA v1.0 BAR4 Offset=00000004
	Capabilities: [b0] PCI Advanced Features
		AFCap: TP+ FLR+
		AFCtrl: FLR-
		AFStatus: TP-
	Kernel driver in use: ahci

Comment 24 Jochen Roth 2010-05-28 07:02:06 UTC
The kernel bug which might be related to this one (buggy hardware?)

https://bugzilla.redhat.com/show_bug.cgi?id=597110

Comment 25 Bob Glickstein 2010-06-06 16:10:41 UTC
I filed this bug: https://bugzilla.redhat.com/show_bug.cgi?id=600465

which may be the same issue but includes the observation that, when the CPU is pegged, it's possible to hotkey to the textual virtual terminal and system performance immediately returns to normal.  Switching back to the X session makes the load spike again.  So it seems like the X server is implicated somehow... maybe...

Comment 26 Bob Glickstein 2010-06-07 04:38:40 UTC
On further exploration, this looks a lot like https://bugzilla.redhat.com/show_bug.cgi?id=528312 to me.

Comment 27 Bug Zapper 2011-06-02 17:32:29 UTC
This message is a reminder that Fedora 13 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 13.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '13'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 13's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 13 is end of life.  If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 28 Bug Zapper 2011-06-27 14:28:59 UTC
Fedora 13 changed to end-of-life (EOL) status on 2011-06-25. Fedora 13 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.