linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm
@ 2011-04-12 19:14 Tim Shepard
  2011-04-12 23:22 ` Shaun Ruffell
  2011-04-17 17:12 ` Maciej Rutecki
  0 siblings, 2 replies; 5+ messages in thread
From: Tim Shepard @ 2011-04-12 19:14 UTC (permalink / raw)
  To: linux-kernel



2.6.38 is working fine on my PowerBook G4 (powerpc) and has none of
the issues described below.

Last week I tried 2.6.39-rc2 and it hung on reboot.
Same thing with 2.6.39-rc3 this week.

I've tracked this down to the "udevadm settle" in /etc/init.d/udev
(from Debian squeeze).

If I am patient it does timeout after 180 seconds and continues
booting.  But after booting finishes udev is still chewing CPU cycles
and load average is stuck at 1.

After the system is up:

# udevadm monitor
monitor will print the received events for:
UDEV - the event which udev sends out after rule processing
KERNEL - the kernel uevent

KERNEL[1302632376.412055] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.460742] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632376.501101] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.510745] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.560742] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632376.601155] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.610755] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.660744] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632376.701186] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.710751] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.760727] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632376.801135] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.810753] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.860748] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632376.901068] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.910748] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632376.960746] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632377.004023] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.010786] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.210681] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.260749] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632377.301096] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.310749] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.360749] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632377.401136] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.410753] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.460748] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632377.501264] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.510749] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.560730] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
UDEV  [1302632377.601147] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
KERNEL[1302632377.610793] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
^C# 
# 
# 
# dmesg | grep hdb
hdb: MATSHITADVD-R UJ-846, ATAPI CD/DVD-ROM drive
hdb: host max PIO4 wanted PIO255(auto-tune) selected PIO4
hdb: UDMA/66 mode selected
ide-cd: hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
# 
# dmesg | grep ide
radeonfb: Using Firmware dividers 0x00040089 from PPLL 0
ide-pmac 0002:24:0d.0: enabling device (0000 -> 0002)
ide-pmac: Found Apple UniNorth ATA-6 controller (PCI), bus ID 3, irq 39
Probing IDE interface ide0...
ide0 at 0xf106a000-0xf106a070,0xf106a160 on irq 39
ide-gd driver 1.18
ide-cd driver 5.00
ide-cd: hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
#


I am getting over 1300 interrupts per second for ide0:

# while grep ide /proc/interrupts && sleep 1 ; do : ; done
 39:     722724   MPIC 1     ide0
 39:     723042   MPIC 1     ide0
 39:     723364   MPIC 1     ide0
 39:     723685   MPIC 1     ide0
 39:     724012   MPIC 1     ide0
 39:     724334   MPIC 1     ide0
 39:     724656   MPIC 1     ide0
 39:     724978   MPIC 1     ide0
 39:     725296   MPIC 1     ide0
 39:     725615   MPIC 1     ide0
 39:     725936   MPIC 1     ide0
 39:     726257   MPIC 1     ide0
 39:     726577   MPIC 1     ide0
 39:     726901   MPIC 1     ide0
 39:     727226   MPIC 1     ide0
 39:     727549   MPIC 1     ide0
 39:     727868   MPIC 1     ide0
 39:     728190   MPIC 1     ide0
 39:     728512   MPIC 1     ide0
 39:     728833   MPIC 1     ide0
 39:     729152   MPIC 1     ide0
 39:     729473   MPIC 1     ide0
 39:     729800   MPIC 1     ide0
 39:     730111   MPIC 1     ide0
 39:     730435   MPIC 1     ide0
 39:     730755   MPIC 1     ide0
 39:     731083   MPIC 1     ide0
 39:     731402   MPIC 1     ide0
 39:     731720   MPIC 1     ide0
 39:     732052   MPIC 1     ide0
 39:     732368   MPIC 1     ide0
 39:     732689   MPIC 1     ide0
 39:     733010   MPIC 1     ide0
^C



I tried using the CDROM drive and it actually does work (as /dev/hdb).
So the only real problems are the 180 second hang while booting and
the interrupt storm and udev event storm that continues.

Any hints?


			-Tim Shepard
			 shep@alum.mit.edu

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm
  2011-04-12 19:14 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm Tim Shepard
@ 2011-04-12 23:22 ` Shaun Ruffell
  2011-04-17 17:12 ` Maciej Rutecki
  1 sibling, 0 replies; 5+ messages in thread
From: Shaun Ruffell @ 2011-04-12 23:22 UTC (permalink / raw)
  To: Tim Shepard; +Cc: linux-kernel

Just adding my "me too" with some comments.

On 04/12/2011 02:14 PM, Tim Shepard wrote:
> 2.6.38 is working fine on my PowerBook G4 (powerpc) and has none of
> the issues described below.
> 
> Last week I tried 2.6.39-rc2 and it hung on reboot.
> Same thing with 2.6.39-rc3 this week.
> 
> I've tracked this down to the "udevadm settle" in /etc/init.d/udev
> (from Debian squeeze).

I noticed this hang on udevadm settle too. I'm temporarily working around
it by adding udevtimeout=5 to the command line. I haven't looked into it any further.

> # udevadm monitor
> monitor will print the received events for:
> UDEV - the event which udev sends out after rule processing
> KERNEL - the kernel uevent
> 
> KERNEL[1302632376.412055] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.460742] change   /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)

On my system I bisected these constant change notifications to 929e27252e
'ide: ide_requeue_and_plug() reinstate "always plug" behaviour' [1] but
haven't looked any past that.

[1] http://lkml.kernel.org/r/20110408201513.GA3040@digium.com

> I am getting over 1300 interrupts per second for ide0:

On my system, I'm not noticing anything strange here, but I'm not using the
CDROM drive:

]# cat /proc/interrupts  | grep ide && sleep 3 && cat /proc/interrupts | grep ide
 14:        100      43433        522          0   IO-APIC-edge      ide0
 15:          0          0          0          0   IO-APIC-edge      ide1
 14:        100      43469        522          0   IO-APIC-edge      ide0
 15:          0          0          0          0   IO-APIC-edge      ide1

Cheers,
Shaun

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm
  2011-04-12 19:14 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm Tim Shepard
  2011-04-12 23:22 ` Shaun Ruffell
@ 2011-04-17 17:12 ` Maciej Rutecki
  2011-04-19 18:01   ` Tim Shepard
  2011-04-27 21:28   ` Tim Shepard
  1 sibling, 2 replies; 5+ messages in thread
From: Maciej Rutecki @ 2011-04-17 17:12 UTC (permalink / raw)
  To: Tim Shepard; +Cc: linux-kernel

I created a Bugzilla entry at 
https://bugzilla.kernel.org/show_bug.cgi?id=33412
for your bug report, please add your address to the CC list in there, thanks!

On wtorek, 12 kwietnia 2011 o 21:14:35 Tim Shepard wrote:
> 2.6.38 is working fine on my PowerBook G4 (powerpc) and has none of
> the issues described below.
> 
> Last week I tried 2.6.39-rc2 and it hung on reboot.
> Same thing with 2.6.39-rc3 this week.
> 
> I've tracked this down to the "udevadm settle" in /etc/init.d/udev
> (from Debian squeeze).
> 
> If I am patient it does timeout after 180 seconds and continues
> booting.  But after booting finishes udev is still chewing CPU cycles
> and load average is stuck at 1.
> 
> After the system is up:
> 
> # udevadm monitor
> monitor will print the received events for:
> UDEV - the event which udev sends out after rule processing
> KERNEL - the kernel uevent
> 
> KERNEL[1302632376.412055] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.460742] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632376.501101] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.510745] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.560742] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632376.601155] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.610755] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.660744] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632376.701186] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.710751] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.760727] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632376.801135] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.810753] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.860748] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632376.901068] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.910748] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632376.960746] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632377.004023] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.010786] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.210681] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.260749] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632377.301096] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.310749] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.360749] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632377.401136] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.410753] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.460748] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632377.501264] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.510749] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.560730] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) UDEV 
> [1302632377.601147] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block)
> KERNEL[1302632377.610793] change  
> /devices/pci0002:24/0002:24:0d.0/ide0/0.1/block/hdb (block) ^C#
> #
> #
> # dmesg | grep hdb
> hdb: MATSHITADVD-R UJ-846, ATAPI CD/DVD-ROM drive
> hdb: host max PIO4 wanted PIO255(auto-tune) selected PIO4
> hdb: UDMA/66 mode selected
> ide-cd: hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
> #
> # dmesg | grep ide
> radeonfb: Using Firmware dividers 0x00040089 from PPLL 0
> ide-pmac 0002:24:0d.0: enabling device (0000 -> 0002)
> ide-pmac: Found Apple UniNorth ATA-6 controller (PCI), bus ID 3, irq 39
> Probing IDE interface ide0...
> ide0 at 0xf106a000-0xf106a070,0xf106a160 on irq 39
> ide-gd driver 1.18
> ide-cd driver 5.00
> ide-cd: hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
> #
> 
> 
> I am getting over 1300 interrupts per second for ide0:
> 
> # while grep ide /proc/interrupts && sleep 1 ; do : ; done
>  39:     722724   MPIC 1     ide0
>  39:     723042   MPIC 1     ide0
>  39:     723364   MPIC 1     ide0
>  39:     723685   MPIC 1     ide0
>  39:     724012   MPIC 1     ide0
>  39:     724334   MPIC 1     ide0
>  39:     724656   MPIC 1     ide0
>  39:     724978   MPIC 1     ide0
>  39:     725296   MPIC 1     ide0
>  39:     725615   MPIC 1     ide0
>  39:     725936   MPIC 1     ide0
>  39:     726257   MPIC 1     ide0
>  39:     726577   MPIC 1     ide0
>  39:     726901   MPIC 1     ide0
>  39:     727226   MPIC 1     ide0
>  39:     727549   MPIC 1     ide0
>  39:     727868   MPIC 1     ide0
>  39:     728190   MPIC 1     ide0
>  39:     728512   MPIC 1     ide0
>  39:     728833   MPIC 1     ide0
>  39:     729152   MPIC 1     ide0
>  39:     729473   MPIC 1     ide0
>  39:     729800   MPIC 1     ide0
>  39:     730111   MPIC 1     ide0
>  39:     730435   MPIC 1     ide0
>  39:     730755   MPIC 1     ide0
>  39:     731083   MPIC 1     ide0
>  39:     731402   MPIC 1     ide0
>  39:     731720   MPIC 1     ide0
>  39:     732052   MPIC 1     ide0
>  39:     732368   MPIC 1     ide0
>  39:     732689   MPIC 1     ide0
>  39:     733010   MPIC 1     ide0
> ^C
> 
> 
> 
> I tried using the CDROM drive and it actually does work (as /dev/hdb).
> So the only real problems are the 180 second hang while booting and
> the interrupt storm and udev event storm that continues.
> 
> Any hints?
> 
> 
> 			-Tim Shepard
> 			 shep@alum.mit.edu
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

-- 
Maciej Rutecki
http://www.maciek.unixy.pl

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm
  2011-04-17 17:12 ` Maciej Rutecki
@ 2011-04-19 18:01   ` Tim Shepard
  2011-04-27 21:28   ` Tim Shepard
  1 sibling, 0 replies; 5+ messages in thread
From: Tim Shepard @ 2011-04-19 18:01 UTC (permalink / raw)
  To: maciej.rutecki; +Cc: linux-kernel




I have tried 2.6.39-rc4 and the same problem still exists.


(And the rate of the interrupt storm is over 300 interrupts per
 second.  I misstated that as over 1300 interrupts per second in my
 initial report, but the while loop output that I included accurately
 shows the rate of the interrupt storm.)

			-Tim Shepard
			 shep@alum.mit.edu

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm
  2011-04-17 17:12 ` Maciej Rutecki
  2011-04-19 18:01   ` Tim Shepard
@ 2011-04-27 21:28   ` Tim Shepard
  1 sibling, 0 replies; 5+ messages in thread
From: Tim Shepard @ 2011-04-27 21:28 UTC (permalink / raw)
  To: maciej.rutecki, rjw; +Cc: linux-kernel



I tested 2.6.39-rc5 today and this bug appears to be fixed.... no
delay on bootup, "udevadm monitor" shows no spurious events, and
monitoring /proc/interrupts I see no ide-related interrupt storm.

I added a comment at https://bugzilla.kernel.org/show_bug.cgi?id=33412
but I could not figure out how to mark this bug closed/fixed, even
though I was logged in.

Please mark this bug closed and/or fixed (in 2.6.39-rc5).

			-Tim Shepard
			 shep@alum.mit.edu

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2011-04-27 21:28 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2011-04-12 19:14 2.6.39-rc3 udevadm settle timeout, many hdb events, interrupt storm Tim Shepard
2011-04-12 23:22 ` Shaun Ruffell
2011-04-17 17:12 ` Maciej Rutecki
2011-04-19 18:01   ` Tim Shepard
2011-04-27 21:28   ` Tim Shepard

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).