Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Martin Knoblauch <knobi@knobisoft.de>
> To: Rafael J. Wysocki <rjw@sisk.pl>
> Cc: linux-kernel@vger.kernel.org; efault@gmx.de
> Sent: Wednesday, April 22, 2009 6:55:27 PM
> Subject: Re: Booting 2.6.30-rc2-git7 very slow
> 
> ----- Original Message ----
> 
> > From: Martin Knoblauch 
> > To: Rafael J. Wysocki 
> > Cc: linux-kernel@vger.kernel.org; efault@gmx.de
> > Sent: Wednesday, April 22, 2009 1:32:25 PM
> > Subject: Re: Booting 2.6.30-rc2-git7 very slow
> > 
> > ----- Original Message ----
> > 
> > > From: Martin Knoblauch 
> > > To: Rafael J. Wysocki 
> > > Cc: linux-kernel@vger.kernel.org
> > > Sent: Wednesday, April 22, 2009 11:56:27 AM
> > > Subject: Re: Booting 2.6.30-rc2-git7 very slow
> > > 
> > > > From: Rafael J. Wysocki 
> > > 
> > > > To: Martin Knoblauch 
> > > > Cc: linux-kernel@vger.kernel.org
> > > > Sent: Tuesday, April 21, 2009 9:12:20 PM
> > > > Subject: Re: Booting 2.6.30-rc2-git7 very slow
> > > > 
> > > > On Tuesday 21 April 2009, Martin Knoblauch wrote:
> > > > > 
> > > > > Hi, [please CC me on replies, as I am not subscribed]
> > > > > 
> > > > >  booting  2.6.30-rc2-git7 on a HP/DL380G3 (x86_64, RHEL4.3, 64 bit 
> > > userspace) 
> > > > is much slower that it used to be. It seems I run into timeouts when 
> [trying 
> > 
> > > to] 
> > > > load intel and tg3 microcodes:
> > > > > 
> > > > > [   14.478892] platform microcode: firmware: requesting 
> > intel-ucode/0f-04-0a
> > > > > [   74.476741] platform microcode: firmware: requesting 
> > intel-ucode/0f-04-0a
> > > > > [  134.476638] platform microcode: firmware: requesting 
> > intel-ucode/0f-04-0a
> > > > > [  194.476637] platform microcode: firmware: requesting 
> > intel-ucode/0f-04-0a
> > > > > [  254.476493] Microcode Update Driver: v2.00 , 
> > > > Peter Oruba
> > > > > [  254.718489] Microcode Update Driver: v2.00 removed.
> > > > > 
> > > > >  So, we see 60 seconds for eaoch of the CPUs
> > > > > 
> > > > > [  255.273426] tg3 0000:03:01.0: PME# disabled
> > > > > [  257.833769] tg3: eth0: Link is up at 1000 Mbps, full duplex.
> > > > > [  257.833775] tg3: eth0: Flow control is off for TX and off for RX.
> > > > > [  269.643973] tg3 0000:03:01.1: firmware: requesting tigon/tg3_tso.bin
> > > > > [  329.640456] eth1: Failed to load firmware "tigon/tg3_tso.bin"
> > > > > [  329.640463] eth1: TSO capability disabled.
> > > > > [  329.640487] tg3 0000:03:01.1: PME# disabled
> > > > > [  333.081753] tg3: eth1: Link is up at 1000 Mbps, full duplex.
> > > > > [  333.081759] tg3: eth1: Flow control is off for TX and off for RX.
> > > > > 
> > > > >  We see 60 seconds for eth1, complaining about a failed firmware load.
> > > > > /lib/firmware/tigon/tg3_tso.bin does exist and is from the current
> > > > > build.
> > > > 
> > > > Do I assume correctly that 2.6.29 did not have this problem?
> > > > 
> > > 
> > > Just checked. 2.6.29 has exactely the same problem. 2.6.28.2 was OK. This is 
> 
> > > from the 2.6.29 boot:
> > > 
> > > [   14.308340] platform microcode: firmware: requesting intel-ucode/0f-04-0a
> > > [   74.304612] platform microcode: firmware: requesting intel-ucode/0f-04-0a
> > > [  134.304651] platform microcode: firmware: requesting intel-ucode/0f-04-0a
> > > [  194.304638] platform microcode: firmware: requesting intel-ucode/0f-04-0a
> > > [  254.304597] Microcode Update Driver: v2.00 ,  Peter Oruba
> > > [  254.546200] Microcode Update Driver: v2.00 removed.
> > 
> > In case of the platform microcode, the delays happen when doing:
> > 
> > /sbin/modprobe microcode
> > 
> > from the init script. I have a "microcode.dat" File in both /etc/ and 
> > /etc/firmware.
> > 
> > > [  255.088405] tg3 0000:03:01.0: PME# disabled
> > > [  257.669617] tg3: eth0: Link is up at 1000 Mbps, full duplex.
> > > [  257.669622] tg3: eth0: Flow control is off for TX and off for RX.
> > > [  269.456132] tg3 0000:03:01.1: firmware: requesting tigon/tg3_tso.bin
> > > [  329.456495] eth1: Failed to load firmware "tigon/tg3_tso.bin"
> > > [  329.456500] eth1: TSO capability disabled.
> > > [  329.456524] tg3 0000:03:01.1: PME# disabled
> > > [  332.921832] tg3: eth1: Link is up at 1000 Mbps, full duplex.
> > > [  332.921837] tg3: eth1: Flow control is off for TX and off for RX.
> > > 
> > > 
> > 
> 
> OK, I was able to solve the tg3 failure by adding "tigon/tg3_tso.bin" to 
> CONFIG_EXTRA_FIRMWARE. I tried the same with the CPU microcode (after copying 
> /etc/firmware/microcode.dat to $BUILDDIR/firmware/), but no success.
> 
> Searching the archives also found some mentioning that I might need special 
> udev-rules to make firmware loading work again transparently. But no explicit 
> solution.
> 
> I find this new (since 2.6.29) behaviour:
> 
> - very unexpected
> - not well documented
> - the EXTRA_FIRMWARE solution very unscalable
> 

 OK, I just found the reason for both intel-ucode and tg3 failures. Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed from:

/sys /sys sysfs rw 0 0

to:

none /sys sysfs rw,relatime 0 0

 The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" when it tries to parse the mount point for "/sys". As a result, the firmware loading is never properly finished and the driver(s) just timeout on the value  in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool down Martin :-)

Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:

> 
> 
>  OK, I just found the reason for both intel-ucode and tg3 failures. Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed from:
> 
> /sys /sys sysfs rw 0 0
> 
> to:
> 
> none /sys sysfs rw,relatime 0 0

I assume that you're referring to the contents of /proc/mounts?

>  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" when it tries to parse the mount point for "/sys". As a result, the firmware loading is never properly finished and the driver(s) just timeout on the value  in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool down Martin :-)
> 
> Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?

afaik that was unintentional and was probably a mistake.

I wonder how we did that.

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Mike Galbraith]

On Tue, 2009-04-28 at 18:28 -0700, Andrew Morton wrote: 
> On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:
> 
> > 
> > 
> >  OK, I just found the reason for both intel-ucode and tg3 failures. Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed from:
> > 
> > /sys /sys sysfs rw 0 0
> > 
> > to:
> > 
> > none /sys sysfs rw,relatime 0 0
> 
> I assume that you're referring to the contents of /proc/mounts?
> 
> >  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" when it tries to parse the mount point for "/sys". As a result, the firmware loading is never properly finished and the driver(s) just timeout on the value  in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool down Martin :-)
> > 
> > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> 
> afaik that was unintentional and was probably a mistake.
> 
> I wonder how we did that.

<paste>
> [hotplug]# grep sysfs /proc/mounts
> none /sys sysfs rw,relatime 0 0
> /sys /sys sysfs rw,relatime 0 0

(I wonder how the heck that is accomplished)

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Wed, 29 Apr 2009 05:51:36 +0200 Mike Galbraith <efault@gmx.de> wrote:

> On Tue, 2009-04-28 at 18:28 -0700, Andrew Morton wrote: 
> > On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:
> > 
> > > 
> > > 
> > >  OK, I just found the reason for both intel-ucode and tg3 failures. Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed from:
> > > 
> > > /sys /sys sysfs rw 0 0
> > > 
> > > to:
> > > 
> > > none /sys sysfs rw,relatime 0 0
> > 
> > I assume that you're referring to the contents of /proc/mounts?
> > 
> > >  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" when it tries to parse the mount point for "/sys". As a result, the firmware loading is never properly finished and the driver(s) just timeout on the value  in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool down Martin :-)
> > > 
> > > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> > 
> > afaik that was unintentional and was probably a mistake.
> > 
> > I wonder how we did that.
> 
> <paste>
> > [hotplug]# grep sysfs /proc/mounts
> > none /sys sysfs rw,relatime 0 0
> > /sys /sys sysfs rw,relatime 0 0
> 
> ___(I wonder how the heck that is accomplished)
> 

Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
cc's viro).

Displaying relatime seems a bit pointless too.

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Andrew Morton <akpm@linux-foundation.org>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; efault@gmx.de; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 3:28:37 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch 
> wrote:
> 
> > 
> > 
> >  OK, I just found the reason for both intel-ucode and tg3 failures. Apparently 
> between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed from:
> > 
> > /sys /sys sysfs rw 0 0
> > 
> > to:
> > 
> > none /sys sysfs rw,relatime 0 0
> 
> I assume that you're referring to the contents of /proc/mounts?
> 
> >  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" when it 
> tries to parse the mount point for "/sys". As a result, the firmware loading is 
> never properly finished and the driver(s) just timeout on the value  in 
> /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool down 
> Martin :-)
> > 
> > Questions remains: was this intentional? It breaks existing userspace and 
> should therefore be considered a regression - right? On the other hand, it will 
> never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets 
> backported. Any ideas?
> 
> afaik that was unintentional and was probably a mistake.
> 
> I wonder how we did that.

 Actually, what breaks the RHEL-4.3 script is not the "none", but the duplicate lines in /proc/mounts that I reported earlier in the "regression" thread.

[root@lpsdm52]# grep sysfs /proc/mounts
none /sys sysfs rw,relatime 0 0
/sys /sys sysfs rw,relatime 0 0

 One of them likely comes from the respective line in /etc/fstab, but where does the second one come from?


Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

 ------------------------------------------------------
Martin Knoblauch
email: k n o b i AT knobisoft DOT de
www:   http://www.knobisoft.de



----- Original Message ----
> From: Andrew Morton <akpm@linux-foundation.org>
> To: Mike Galbraith <efault@gmx.de>
> Cc: Martin Knoblauch <knobi@knobisoft.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>; Al Viro <viro@zeniv.linux.org.uk>
> Sent: Wednesday, April 29, 2009 10:17:55 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 29 Apr 2009 05:51:36 +0200 Mike Galbraith wrote:
> 
> > On Tue, 2009-04-28 at 18:28 -0700, Andrew Morton wrote: 
> > > On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch 
> wrote:
> > > 
> > > > 
> > > > 
> > > >  OK, I just found the reason for both intel-ucode and tg3 failures. 
> Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed 
> from:
> > > > 
> > > > /sys /sys sysfs rw 0 0
> > > > 
> > > > to:
> > > > 
> > > > none /sys sysfs rw,relatime 0 0
> > > 
> > > I assume that you're referring to the contents of /proc/mounts?
> > > 
> > > >  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" 
> when it tries to parse the mount point for "/sys". As a result, the firmware 
> loading is never properly finished and the driver(s) just timeout on the value  
> in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool 
> down Martin :-)
> > > > 
> > > > Questions remains: was this intentional? It breaks existing userspace and 
> should therefore be considered a regression - right? On the other hand, it will 
> never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets 
> backported. Any ideas?
> > > 
> > > afaik that was unintentional and was probably a mistake.
> > > 
> > > I wonder how we did that.
> > 
> > 
> > > [hotplug]# grep sysfs /proc/mounts
> > > none /sys sysfs rw,relatime 0 0
> > > /sys /sys sysfs rw,relatime 0 0
> > 
> > ___(I wonder how the heck that is accomplished)
> > 
> 
> Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> cc's viro).
> 
> Displaying relatime seems a bit pointless too.

 Actually, relatime is added in 2.6.30. In 2.6.29 I only see the duplicate lines.

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Andrew Morton <akpm@linux-foundation.org>
> To: Mike Galbraith <efault@gmx.de>
> Cc: Martin Knoblauch <knobi@knobisoft.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>; Al Viro <viro@zeniv.linux.org.uk>
> Sent: Wednesday, April 29, 2009 10:17:55 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 29 Apr 2009 05:51:36 +0200 Mike Galbraith wrote:
> 
> > On Tue, 2009-04-28 at 18:28 -0700, Andrew Morton wrote: 
> > > On Fri, 24 Apr 2009 05:45:19 -0700 (PDT) Martin Knoblauch 
> wrote:
> > > 
> > > > 
> > > > 
> > > >  OK, I just found the reason for both intel-ucode and tg3 failures. 
> Apparently between 2.6.28 and 2.6.29 the mount of sysfs has subtely changed 
> from:
> > > > 
> > > > /sys /sys sysfs rw 0 0
> > > > 
> > > > to:
> > > > 
> > > > none /sys sysfs rw,relatime 0 0
> > > 
> > > I assume that you're referring to the contents of /proc/mounts?
> > > 
> > > >  The "none" breaks the RHEL-4 provided hotplug script "firmware.agent" 
> when it tries to parse the mount point for "/sys". As a result, the firmware 
> loading is never properly finished and the driver(s) just timeout on the value  
> in /sys/class/firmware/timeout. Bingo. Simple fix in user-pace possible - cool 
> down Martin :-)
> > > > 
> > > > Questions remains: was this intentional? It breaks existing userspace and 
> should therefore be considered a regression - right? On the other hand, it will 
> never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets 
> backported. Any ideas?
> > > 
> > > afaik that was unintentional and was probably a mistake.
> > > 
> > > I wonder how we did that.
> > 
> > 
> > > [hotplug]# grep sysfs /proc/mounts
> > > none /sys sysfs rw,relatime 0 0
> > > /sys /sys sysfs rw,relatime 0 0
> > 
> > ___(I wonder how the heck that is accomplished)
> > 
> 
> Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> cc's viro).
> 
> Displaying relatime seems a bit pointless too.

 Hmm. I actually believe the "none" line comes out of /etc/fstab, but was never before displayed in /proc/mount.

This is from 2.6.19:

[root@lpsdm60 ~]# grep sysfs /etc/fstab
none    /sys    sysfs   defaults        0       0
[root@lpsdm60 ~]# mount | grep sysfs
none on /sys type sysfs (rw)
[root@lpsdm60 ~]# grep sysfs /proc/mounts
/sys /sys sysfs rw 0 0


And this is from 2.6.30:

[root@lpsdm52 linux-2.6.30-rc3-git2]# grep sysfs /etc/fstab
none    /sys    sysfs   defaults        0       0
[root@lpsdm52 linux-2.6.30-rc3-git2]# mount | grep sysfs
none on /sys type sysfs (rw)
[root@lpsdm52 linux-2.6.30-rc3-git2]# grep sysfs /proc/mounts
none /sys sysfs rw,relatime 0 0
/sys /sys sysfs rw,relatime 0 0


 Any changes to mount-handling in 2.6.29?

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Al Viro]

On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:

> > > > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> > > 
> > > afaik that was unintentional and was probably a mistake.
> > > 
> > > I wonder how we did that.
> > 
> > <paste>
> > > [hotplug]# grep sysfs /proc/mounts
> > > none /sys sysfs rw,relatime 0 0
> > > /sys /sys sysfs rw,relatime 0 0
> > 
> > ___(I wonder how the heck that is accomplished)
> 
> Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> cc's viro).

Er...  Somebody mounting sysfs twice?  From some init script and from
/etc/fstab, perhaps?  That definitely looks like two mount(2) had to
have been done to cause that...

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Mike Galbraith]

On Wed, 2009-04-29 at 13:08 +0100, Al Viro wrote:
> On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:
> 
> > > > > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> > > > 
> > > > afaik that was unintentional and was probably a mistake.
> > > > 
> > > > I wonder how we did that.
> > > 
> > > <paste>
> > > > [hotplug]# grep sysfs /proc/mounts
> > > > none /sys sysfs rw,relatime 0 0
> > > > /sys /sys sysfs rw,relatime 0 0
> > > 
> > > ___(I wonder how the heck that is accomplished)
> > 
> > Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> > show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> > cc's viro).
> 
> Er...  Somebody mounting sysfs twice?  From some init script and from
> /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> have been done to cause that...

Yeah, but how does one go about doing that?

Using mount -f, I can convince mount to succeed, but I still have only
one entry in /proc/mounts, despite what my mount binary imagines.

marge:..sys/vm # grep sysfs /proc/mounts
sysfs /sys sysfs rw,relatime 0 0

marge:..sys/vm # mount|grep sysfs
sysfs on /sys type sysfs (rw)
sys on /sys type sysfs (rw)
/sys on /sys type sysfs (rw)

	-Mike

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Al Viro]

On Wed, Apr 29, 2009 at 04:18:45PM +0200, Mike Galbraith wrote:
> > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > have been done to cause that...
> 
> Yeah, but how does one go about doing that?
> 
> Using mount -f, I can convince mount to succeed, but I still have only
> one entry in /proc/mounts, despite what my mount binary imagines.

Huh?
       -f     Causes  everything to be done except for the actual system call;
              if it's not obvious, this ``fakes'' mounting  the  file  system.
              This  option is useful in conjunction with the -v flag to deter-
              mine what the mount command is trying to do. It can also be used
              to add entries for devices that were mounted earlier with the -n

What are you talking about?

The interesting part is why mount(2) doesn't fail with -EBUSY on that
overmounting.  Is there anything else mounted on /sys?  That, or any
interesting patches applied to the tree (fs/sysfs/mount.c, fs/namespace.c)

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Al Viro <viro@ZenIV.linux.org.uk>
> To: Andrew Morton <akpm@linux-foundation.org>
> Cc: Mike Galbraith <efault@gmx.de>; Martin Knoblauch <knobi@knobisoft.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 2:08:28 PM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:
> 
> > > > > Questions remains: was this intentional? It breaks existing userspace 
> and should therefore be considered a regression - right? On the other hand, it 
> will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets 
> backported. Any ideas?
> > > > 
> > > > afaik that was unintentional and was probably a mistake.
> > > > 
> > > > I wonder how we did that.
> > > 
> > > 
> > > > [hotplug]# grep sysfs /proc/mounts
> > > > none /sys sysfs rw,relatime 0 0
> > > > /sys /sys sysfs rw,relatime 0 0
> > > 
> > > ___(I wonder how the heck that is accomplished)
> > 
> > Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> > show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> > cc's viro).
> 
> Er...  Somebody mounting sysfs twice?  From some init script and from
> /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> have been done to cause that...

 One definitely comes from /etc/fstab, but I am not aware of any other script mounting sysfs in my userspace.

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Al Viro <viro@ZenIV.linux.org.uk>
> To: Mike Galbraith <efault@gmx.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; Martin Knoblauch <knobi@knobisoft.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 4:34:03 PM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, Apr 29, 2009 at 04:18:45PM +0200, Mike Galbraith wrote:
> > > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > > have been done to cause that...
> > 
> > Yeah, but how does one go about doing that?
> > 
> > Using mount -f, I can convince mount to succeed, but I still have only
> > one entry in /proc/mounts, despite what my mount binary imagines.
> 
> Huh?
>        -f     Causes  everything to be done except for the actual system call;
>               if it's not obvious, this ``fakes'' mounting  the  file  system.
>               This  option is useful in conjunction with the -v flag to deter-
>               mine what the mount command is trying to do. It can also be used
>               to add entries for devices that were mounted earlier with the -n
> 
> What are you talking about?
> 
> The interesting part is why mount(2) doesn't fail with -EBUSY on that
> overmounting.  Is there anything else mounted on /sys?  That, or any
> interesting patches applied to the tree (fs/sysfs/mount.c, fs/namespace.c)

 In my 2.6.30-rc3-git2 there is definitely nothing interesting, just my NFS readahead patch. But that touches nothing near sysfs.  And my 2.6.29 test-boot was from a plain build.

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Valdis.Kletnieks]

[-- Attachment #1: Type: text/plain, Size: 384 bytes --]

On Wed, 29 Apr 2009 10:24:20 PDT, Martin Knoblauch said:

>  One definitely comes from /etc/fstab, but I am not aware of any other script
 mounting sysfs in my userspace.

You said it was a RedHat box?

Look in /etc/rc.sysinit:

        mount -n -t sysfs /sys /sys >/dev/null 2>&1

(Near line 28 for RHEL 4, line 23 for RHEL5, and line 21 for Fedora Rawhide)

Probably your culprit.


[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Al Viro]

On Wed, Apr 29, 2009 at 10:24:20AM -0700, Martin Knoblauch wrote:

> > Er...  Somebody mounting sysfs twice?  From some init script and from
> > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > have been done to cause that...
> 
>  One definitely comes from /etc/fstab, but I am not aware of any other script mounting sysfs in my userspace.

Check in /etc/init.d; e.g. on debian it's mountkernfs.  More interesting
question is what else is mounted on /sys; how about the entire /proc/mounts
contents?

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Al Viro]

On Wed, Apr 29, 2009 at 01:35:59PM -0400, Valdis.Kletnieks@vt.edu wrote:
> On Wed, 29 Apr 2009 10:24:20 PDT, Martin Knoblauch said:
> 
> >  One definitely comes from /etc/fstab, but I am not aware of any other script
>  mounting sysfs in my userspace.
> 
> You said it was a RedHat box?
> 
> Look in /etc/rc.sysinit:
> 
>         mount -n -t sysfs /sys /sys >/dev/null 2>&1
> 
> (Near line 28 for RHEL 4, line 23 for RHEL5, and line 21 for Fedora Rawhide)
> 
> Probably your culprit.

Again, the interesting question is WTF had mount(2) not failed with -EBUSY

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: "Valdis.Kletnieks@vt.edu" <Valdis.Kletnieks@vt.edu>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Al Viro <viro@ZenIV.linux.org.uk>; Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 7:35:59 PM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 29 Apr 2009 10:24:20 PDT, Martin Knoblauch said:
> 
> >  One definitely comes from /etc/fstab, but I am not aware of any other script
> mounting sysfs in my userspace.
> 
> You said it was a RedHat box?
> 
> Look in /etc/rc.sysinit:
> 
>         mount -n -t sysfs /sys /sys >/dev/null 2>&1
> 
> (Near line 28 for RHEL 4, line 23 for RHEL5, and line 21 for Fedora Rawhide)
> 
> Probably your culprit.

 OK, you got me. But still something changed with 2.6.29. Before, there was only one line in /proc/mounts

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

 ------------------------------------------------------
Martin Knoblauch
email: k n o b i AT knobisoft DOT de
www:   http://www.knobisoft.de



----- Original Message ----
> From: Al Viro <viro@ZenIV.linux.org.uk>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 7:41:54 PM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, Apr 29, 2009 at 10:24:20AM -0700, Martin Knoblauch wrote:
> 
> > > Er...  Somebody mounting sysfs twice?  From some init script and from
> > > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > > have been done to cause that...
> > 
> >  One definitely comes from /etc/fstab, but I am not aware of any other script 
> mounting sysfs in my userspace.
> 
> Check in /etc/init.d; e.g. on debian it's mountkernfs.  More interesting
> question is what else is mounted on /sys; how about the entire /proc/mounts
> contents?

2.6.30-rc3-git2:

rootfs / rootfs rw 0 0
/proc /proc proc rw,relatime 0 0
none /sys sysfs rw,relatime 0 0
none /dev tmpfs rw,relatime,mode=755 0 0
/dev/root / ext3 rw,relatime,errors=continue,data=writeback 0 0
none /dev tmpfs rw,relatime,mode=755 0 0
/proc /proc proc rw,relatime 0 0
/proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0
/sys /sys sysfs rw,relatime 0 0
none /dev/pts devpts rw,relatime,gid=5,mode=620 0 0
/dev/cciss/c0d0p1 /boot ext3 rw,relatime,errors=continue,data=writeback 0 0
none /dev/shm tmpfs rw,relatime 0 0
/dev/cciss/c0d0p4 /scratch ext2 rw,noatime,errors=continue 0 0
none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0


2.6.19.2

rootfs / rootfs rw 0 0
/proc /proc proc rw 0 0
none /dev tmpfs rw 0 0
/dev/root / ext3 rw,data=ordered 0 0
none /dev tmpfs rw 0 0
/proc /proc proc rw 0 0
/proc/bus/usb /proc/bus/usb usbfs rw 0 0
/sys /sys sysfs rw 0 0
none /dev/pts devpts rw 0 0
/dev/cciss/c0d0p1 /boot ext3 rw,data=ordered 0 0
none /dev/shm tmpfs rw 0 0
/dev/VolGroup00/LogVol02 /scratch ext2 rw,noatime 0 0
none /proc/sys/fs/binfmt_misc binfmt_misc rw 0 0
sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw 0 0


Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Al Viro]

On Wed, Apr 29, 2009 at 10:51:35AM -0700, Martin Knoblauch wrote:
> 2.6.30-rc3-git2:
> 
> rootfs / rootfs rw 0 0
> /proc /proc proc rw,relatime 0 0
> none /sys sysfs rw,relatime 0 0
> none /dev tmpfs rw,relatime,mode=755 0 0
> /dev/root / ext3 rw,relatime,errors=continue,data=writeback 0 0
> none /dev tmpfs rw,relatime,mode=755 0 0
> /proc /proc proc rw,relatime 0 0
> /proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0
> /sys /sys sysfs rw,relatime 0 0
> none /dev/pts devpts rw,relatime,gid=5,mode=620 0 0
> /dev/cciss/c0d0p1 /boot ext3 rw,relatime,errors=continue,data=writeback 0 0
> none /dev/shm tmpfs rw,relatime 0 0
> /dev/cciss/c0d0p4 /scratch ext2 rw,noatime,errors=continue 0 0
> none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
> sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0

Cute...  I wonder how that second mount(2) managed to succeed.  Could you
check what explicit mounting of sysfs on that point *again* does?

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Mike Galbraith]

On Wed, 2009-04-29 at 15:34 +0100, Al Viro wrote:
> On Wed, Apr 29, 2009 at 04:18:45PM +0200, Mike Galbraith wrote:
> > > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > > have been done to cause that...
> > 
> > Yeah, but how does one go about doing that?
> > 
> > Using mount -f, I can convince mount to succeed, but I still have only
> > one entry in /proc/mounts, despite what my mount binary imagines.
> 
> Huh?
>        -f     Causes  everything to be done except for the actual system call;
>               if it's not obvious, this ``fakes'' mounting  the  file  system.
>               This  option is useful in conjunction with the -v flag to deter-
>               mine what the mount command is trying to do. It can also be used
>               to add entries for devices that were mounted earlier with the -n
> 
> What are you talking about?

Me?  My binary lost touch with reality, but I couldn't induce it to
produce two /proc/mount entries.  I thought that's what I said.

	-Mike

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Al Viro <viro@ZenIV.linux.org.uk>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> Sent: Wednesday, April 29, 2009 8:10:41 PM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, Apr 29, 2009 at 10:51:35AM -0700, Martin Knoblauch wrote:
> > 2.6.30-rc3-git2:
> > 
> > rootfs / rootfs rw 0 0
> > /proc /proc proc rw,relatime 0 0
> > none /sys sysfs rw,relatime 0 0
> > none /dev tmpfs rw,relatime,mode=755 0 0
> > /dev/root / ext3 rw,relatime,errors=continue,data=writeback 0 0
> > none /dev tmpfs rw,relatime,mode=755 0 0
> > /proc /proc proc rw,relatime 0 0
> > /proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0
> > /sys /sys sysfs rw,relatime 0 0
> > none /dev/pts devpts rw,relatime,gid=5,mode=620 0 0
> > /dev/cciss/c0d0p1 /boot ext3 rw,relatime,errors=continue,data=writeback 0 0
> > none /dev/shm tmpfs rw,relatime 0 0
> > /dev/cciss/c0d0p4 /scratch ext2 rw,noatime,errors=continue 0 0
> > none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
> > sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0
> 
> Cute...  I wonder how that second mount(2) managed to succeed.  Could you
> check what explicit mounting of sysfs on that point *again* does?
Hi Al,

 by now I know a bit more. Starting with 2.6.29, the

none /sys sysfs rw 0 0

line is already in /proc/mounts when entering userspace. So I guess it comes out of my initrd. Again, what changed?

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Olivier Galibert]

On Wed, Apr 29, 2009 at 06:43:23PM +0100, Al Viro wrote:
> Again, the interesting question is WTF had mount(2) not failed with -EBUSY

A change of '/' between the two mounts maybe?  If one is done from
initrd and the other after / is mounted?

  OG.

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Wed, 29 Apr 2009 16:18:45 +0200
Mike Galbraith <efault@gmx.de> wrote:

> On Wed, 2009-04-29 at 13:08 +0100, Al Viro wrote:
> > On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:
> > 
> > > > > > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> > > > > 
> > > > > afaik that was unintentional and was probably a mistake.
> > > > > 
> > > > > I wonder how we did that.
> > > > 
> > > > <paste>
> > > > > [hotplug]# grep sysfs /proc/mounts
> > > > > none /sys sysfs rw,relatime 0 0
> > > > > /sys /sys sysfs rw,relatime 0 0
> > > > 
> > > > ___(I wonder how the heck that is accomplished)
> > > 
> > > Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> > > show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> > > cc's viro).
> > 
> > Er...  Somebody mounting sysfs twice?  From some init script and from
> > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > have been done to cause that...
> 
> Yeah, but how does one go about doing that?
> 
> Using mount -f, I can convince mount to succeed, but I still have only
> one entry in /proc/mounts, despite what my mount binary imagines.
> 
> marge:..sys/vm # grep sysfs /proc/mounts
> sysfs /sys sysfs rw,relatime 0 0
> 
> marge:..sys/vm # mount|grep sysfs
> sysfs on /sys type sysfs (rw)
> sys on /sys type sysfs (rw)
> /sys on /sys type sysfs (rw)
> 

So /proc/mounts is OK and /etc/mtab is wrong?

Obvious next step is to strace `mount -f', see what's happening around
sys_mount(), please.

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Mike Galbraith]

On Tue, 2009-05-05 at 15:49 -0700, Andrew Morton wrote:
> On Wed, 29 Apr 2009 16:18:45 +0200
> Mike Galbraith <efault@gmx.de> wrote:
> 
> > On Wed, 2009-04-29 at 13:08 +0100, Al Viro wrote:
> > > On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:
> > > 
> > > > > > > Questions remains: was this intentional? It breaks existing userspace and should therefore be considered a regression - right? On the other hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 2.6.29 gets backported. Any ideas?
> > > > > > 
> > > > > > afaik that was unintentional and was probably a mistake.
> > > > > > 
> > > > > > I wonder how we did that.
> > > > > 
> > > > > <paste>
> > > > > > [hotplug]# grep sysfs /proc/mounts
> > > > > > none /sys sysfs rw,relatime 0 0
> > > > > > /sys /sys sysfs rw,relatime 0 0
> > > > > 
> > > > > ___(I wonder how the heck that is accomplished)
> > > > 
> > > > Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> > > > show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> > > > cc's viro).
> > > 
> > > Er...  Somebody mounting sysfs twice?  From some init script and from
> > > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > > have been done to cause that...
> > 
> > Yeah, but how does one go about doing that?
> > 
> > Using mount -f, I can convince mount to succeed, but I still have only
> > one entry in /proc/mounts, despite what my mount binary imagines.
> > 
> > marge:..sys/vm # grep sysfs /proc/mounts
> > sysfs /sys sysfs rw,relatime 0 0
> > 
> > marge:..sys/vm # mount|grep sysfs
> > sysfs on /sys type sysfs (rw)
> > sys on /sys type sysfs (rw)
> > /sys on /sys type sysfs (rw)
> > 
> 
> So /proc/mounts is OK and /etc/mtab is wrong?
> 
> Obvious next step is to strace `mount -f', see what's happening around
> sys_mount(), please.

Well, there is no syscall with -f.

I was trying various mount options to see if I could find a way to
create bogons that could confuse scripts.  I could create bogons
in /etc/mtab with -f, or bogons in /proc/mounts by using --move.  I
could re-create the exact reported data with a combination of mount -n
and mount --move.  I could not get a double /proc/mounts entry without
--move, and that seems unlikely to appear in boot scripts.  So I still
wonder how the heck it was accomplished.

I also now wonder why you can --move mounts on top of one another, but
beck with it, ignorance conserves braincells I may some day need :)

	-Mike

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Mike Galbraith <efault@gmx.de>
> To: Andrew Morton <akpm@linux-foundation.org>
> Cc: viro@ZenIV.linux.org.uk; knobi@knobisoft.de; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> Sent: Wednesday, May 6, 2009 6:45:40 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Tue, 2009-05-05 at 15:49 -0700, Andrew Morton wrote:
> > On Wed, 29 Apr 2009 16:18:45 +0200
> > Mike Galbraith wrote:
> > 
> > > On Wed, 2009-04-29 at 13:08 +0100, Al Viro wrote:
> > > > On Wed, Apr 29, 2009 at 01:17:55AM -0700, Andrew Morton wrote:
> > > > 
> > > > > > > > Questions remains: was this intentional? It breaks existing 
> userspace and should therefore be considered a regression - right? On the other 
> hand, it will never be a problem for RHEL-4/5 kernels, unless the change in 
> 2.6.29 gets backported. Any ideas?
> > > > > > > 
> > > > > > > afaik that was unintentional and was probably a mistake.
> > > > > > > 
> > > > > > > I wonder how we did that.
> > > > > > 
> > > > > > 
> > > > > > > [hotplug]# grep sysfs /proc/mounts
> > > > > > > none /sys sysfs rw,relatime 0 0
> > > > > > > /sys /sys sysfs rw,relatime 0 0
> > > > > > 
> > > > > > ___(I wonder how the heck that is accomplished)
> > > > > 
> > > > > Beats me.  I'm not seeing likely changes in fs/proc/base.c or around
> > > > > show_mountinfo().  Maybe sysfs broke in an ingenious way.  (hopefully
> > > > > cc's viro).
> > > > 
> > > > Er...  Somebody mounting sysfs twice?  From some init script and from
> > > > /etc/fstab, perhaps?  That definitely looks like two mount(2) had to
> > > > have been done to cause that...
> > > 
> > > Yeah, but how does one go about doing that?
> > > 
> > > Using mount -f, I can convince mount to succeed, but I still have only
> > > one entry in /proc/mounts, despite what my mount binary imagines.
> > > 
> > > marge:..sys/vm # grep sysfs /proc/mounts
> > > sysfs /sys sysfs rw,relatime 0 0
> > > 
> > > marge:..sys/vm # mount|grep sysfs
> > > sysfs on /sys type sysfs (rw)
> > > sys on /sys type sysfs (rw)
> > > /sys on /sys type sysfs (rw)
> > > 
> > 
> > So /proc/mounts is OK and /etc/mtab is wrong?
> > 
> > Obvious next step is to strace `mount -f', see what's happening around
> > sys_mount(), please.
> 
> Well, there is no syscall with -f.
> 
> I was trying various mount options to see if I could find a way to
> create bogons that could confuse scripts.  I could create bogons
> in /etc/mtab with -f, or bogons in /proc/mounts by using --move.  I
> could re-create the exact reported data with a combination of mount -n
> and mount --move.  I could not get a double /proc/mounts entry without
> --move, and that seems unlikely to appear in boot scripts.  So I still
> wonder how the heck it was accomplished.
> 
> I also now wonder why you can --move mounts on top of one another, but
> beck with it, ignorance conserves braincells I may some day need :)
> 

 just to bring this back to my problem :-) Last week I reported that the "new" sysfs entry in /proc/mounts already comes out of initrd. Does this ring a bell?

http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Mike Galbraith]

On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:

>  just to bring this back to my problem :-)

Good idea :-)

>  Last week I reported that the "new" sysfs entry in /proc/mounts already comes out of initrd. Does this ring a bell?
> 
> http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html

Nope, no bells.

The only thing I can suggest is that you try a bisection.

	-Mike

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

 ------------------------------------------------------
Martin Knoblauch
email: k n o b i AT knobisoft DOT de
www:   http://www.knobisoft.de



----- Original Message ----
> From: Mike Galbraith <efault@gmx.de>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> Sent: Wednesday, May 6, 2009 10:37:45 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> 
> >  just to bring this back to my problem :-)
> 
> Good idea :-)
> 
> >  Last week I reported that the "new" sysfs entry in /proc/mounts already comes 
> out of initrd. Does this ring a bell?
> > 
> > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> 
> Nope, no bells.
> 
> The only thing I can suggest is that you try a bisection.
> 

 I was afraid that someone would bring up the bi-word :-) I am not using git so far, and my playground is behind a customers firewall.

 In a first attempt I tried to be "cheap" and look for the first rcX, but unfortunatelly the new behaviour already starts with 29-rc1 :-(

Cheers
Martin

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Mike Galbraith <efault@gmx.de>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> Sent: Wednesday, May 6, 2009 10:37:45 AM
> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> 
> >  just to bring this back to my problem :-)
> 
> Good idea :-)
> 
> >  Last week I reported that the "new" sysfs entry in /proc/mounts already comes 
> out of initrd. Does this ring a bell?
> > 
> > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> 
> Nope, no bells.
> 
> The only thing I can suggest is that you try a bisection.
> 
>     -Mike

 OK, so I finally managed to bisect the issue down to the following commit. Not much that I can say about it. Someone else suggested that it might all be a question of timing. Might very well be. I will try it out on a system with a different SCSI/RAID controller. The failing system has an "Smart Array 6i" (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.

|commit 1120f8b8169fb2cb51219d326892d963e762edb6
|Author: Stephen Hemminger <shemminger@vyatta.com>
|Date:   Thu Dec 18 09:17:16 2008 -0800
|
|    PCI: handle long delays in VPD access
|
|    Accessing the VPD area can take a long time.  The existing
|    VPD access code fails consistently on my hardware. There are comments
|
|    Change the access routines to:
|      * use a mutex rather than spinning with IRQ's disabled and lock held
|      * have a much longer timeout
|      * call cond_resched while spinning
|
|    Signed-off-by: Stephen Hemminger <shemminger@vyatta.com>
|    Reviewed-by: Matthew Wilcox <willy@linux.intel.com>
|    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>

Cheers
Martin

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Martin Knoblauch <knobi@knobisoft.de>
> To: Mike Galbraith <efault@gmx.de>
> Cc: Andrew Morton <akpm@linux-foundation.org>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers <kay.sievers@vrfy.org>; Rafael J. Wysocki <rjw@sisk.pl>; shemminger@vyatta.com
> Sent: Wednesday, May 20, 2009 12:22:28 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> ----- Original Message ----
> 
> > From: Mike Galbraith 
> > To: Martin Knoblauch 
> > Cc: Andrew Morton ; viro@ZenIV.linux.org.uk; 
> rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > 
> > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > 
> > >  just to bring this back to my problem :-)
> > 
> > Good idea :-)
> > 
> > >  Last week I reported that the "new" sysfs entry in /proc/mounts already 
> comes 
> > out of initrd. Does this ring a bell?
> > > 
> > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > 
> > Nope, no bells.
> > 
> > The only thing I can suggest is that you try a bisection.
> > 
> >     -Mike
> 
> OK, so I finally managed to bisect the issue down to the following commit. Not 
> much that I can say about it. Someone else suggested that it might all be a 
> question of timing. Might very well be. I will try it out on a system with a 
> different SCSI/RAID controller. The failing system has an "Smart Array 6i" 
> (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> 
> |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> |Author: Stephen Hemminger 
> |Date:   Thu Dec 18 09:17:16 2008 -0800
> |
> |    PCI: handle long delays in VPD access
> |
> |    Accessing the VPD area can take a long time.  The existing
> |    VPD access code fails consistently on my hardware. There are comments
> |
> |    Change the access routines to:
> |      * use a mutex rather than spinning with IRQ's disabled and lock held
> |      * have a much longer timeout
> |      * call cond_resched while spinning
> |
> |    Signed-off-by: Stephen Hemminger 
> |    Reviewed-by: Matthew Wilcox 
> |    Signed-off-by: Jesse Barnes 
> 


 yup. Different hardware (IBM x3650 with aacraid) does not show the problem. So it seems to be timing related. I more and more tend to view this as "so what" and go along.

Cheers
Martin

Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Thu, 30 Apr 2009 02:12:00 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:

> 
> ----- Original Message ----
> 
> > From: Al Viro <viro@ZenIV.linux.org.uk>
> > To: Martin Knoblauch <knobi@knobisoft.de>
> > Cc: Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; Rafael J. Wysocki <rjw@sisk.pl>; linux-kernel@vger.kernel.org; tigran aivazian <tigran@aivazian.fsnet.co.uk>
> > Sent: Wednesday, April 29, 2009 8:10:41 PM
> > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > 
> > On Wed, Apr 29, 2009 at 10:51:35AM -0700, Martin Knoblauch wrote:
> > > 2.6.30-rc3-git2:
> > > 
> > > rootfs / rootfs rw 0 0
> > > /proc /proc proc rw,relatime 0 0
> > > none /sys sysfs rw,relatime 0 0
> > > none /dev tmpfs rw,relatime,mode=755 0 0
> > > /dev/root / ext3 rw,relatime,errors=continue,data=writeback 0 0
> > > none /dev tmpfs rw,relatime,mode=755 0 0
> > > /proc /proc proc rw,relatime 0 0
> > > /proc/bus/usb /proc/bus/usb usbfs rw,relatime 0 0
> > > /sys /sys sysfs rw,relatime 0 0
> > > none /dev/pts devpts rw,relatime,gid=5,mode=620 0 0
> > > /dev/cciss/c0d0p1 /boot ext3 rw,relatime,errors=continue,data=writeback 0 0
> > > none /dev/shm tmpfs rw,relatime 0 0
> > > /dev/cciss/c0d0p4 /scratch ext2 rw,noatime,errors=continue 0 0
> > > none /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0
> > > sunrpc /var/lib/nfs/rpc_pipefs rpc_pipefs rw,relatime 0 0
> > 
> > Cute...  I wonder how that second mount(2) managed to succeed.  Could you
> > check what explicit mounting of sysfs on that point *again* does?
> Hi Al,
> 
>  by now I know a bit more. Starting with 2.6.29, the
> 
> none /sys sysfs rw 0 0
> 
> line is already in /proc/mounts when entering userspace. So I guess it comes out of my initrd. Again, what changed?
> 

afacit this didn't get understood, let alone fixed?

I see that you had a PCI-related issue which changed boot timing a lot,
but that isn't the bug - it simply exposed the bug by changing timing?

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:

> 
> ----- Original Message ----
> 
> > From: Mike Galbraith <efault@gmx.de>
> > To: Martin Knoblauch <knobi@knobisoft.de>
> > Cc: Andrew Morton <akpm@linux-foundation.org>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > 
> > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > 
> > >  just to bring this back to my problem :-)
> > 
> > Good idea :-)
> > 
> > >  Last week I reported that the "new" sysfs entry in /proc/mounts already comes 
> > out of initrd. Does this ring a bell?
> > > 
> > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > 
> > Nope, no bells.
> > 
> > The only thing I can suggest is that you try a bisection.
> > 
> >     -Mike
> 
>  OK, so I finally managed to bisect the issue down to the following commit. Not much that I can say about it. Someone else suggested that it might all be a question of timing. Might very well be. I will try it out on a system with a different SCSI/RAID controller. The failing system has an "Smart Array 6i" (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> 
> |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> |Author: Stephen Hemminger <shemminger@vyatta.com>
> |Date:   Thu Dec 18 09:17:16 2008 -0800
> |
> |    PCI: handle long delays in VPD access
> |
> |    Accessing the VPD area can take a long time.  The existing
> |    VPD access code fails consistently on my hardware. There are comments
> |
> |    Change the access routines to:
> |      * use a mutex rather than spinning with IRQ's disabled and lock held
> |      * have a much longer timeout
> |      * call cond_resched while spinning
> |
> |    Signed-off-by: Stephen Hemminger <shemminger@vyatta.com>
> |    Reviewed-by: Matthew Wilcox <willy@linux.intel.com>
> |    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>
> 

<hello, any maintainers out there?>

So afacit what's happening is that the above change caused one of your
PCI devices to take a very long time to initialise, yes?  Was it the
CCISS driver?

If you add "printk.time=y" to the kernel boot command line then you'll
get timestamped boot messages which will make it easier to determine
where the time was consumed.  Adding `initcall_debug' to the boot line
will help us delve further into the delay, assuming that the offending
driver is build into vmlinux (which it might not be).

Either way, it would be useful to know which driver the above change
broke.

Once we know that, the questions is: doe sthe driver still work?  If
so, then presumably the hardware if behaving unexpectedly, or in a way
which we're failing to cope with.

Or perhaps that patch was simply buggy.

btw, I don't agree that this report should be closed for "fuzziness"! 
AFACIT the regression clearly and reproducibly occurs on one of your
machines, yes?  That ain't fuzzy!

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

[-- Attachment #1: Type: text/plain, Size: 4330 bytes --]

----- Original Message ----

> From: Andrew Morton <akpm@linux-foundation.org>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Mike Galbraith <efault@gmx.de>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers <kay.sievers@vrfy.org>; shemminger@vyatta.com; Jesse Barnes <jbarnes@virtuousgeek.org>; Matthew Wilcox <matthew@wil.cx>
> Sent: Wednesday, May 27, 2009 8:31:02 AM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch 
> wrote:
> 
> > 
> > ----- Original Message ----
> > 
> > > From: Mike Galbraith 
> > > To: Martin Knoblauch 
> > > Cc: Andrew Morton ; viro@ZenIV.linux.org.uk; 
> rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > > 
> > > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > > 
> > > >  just to bring this back to my problem :-)
> > > 
> > > Good idea :-)
> > > 
> > > >  Last week I reported that the "new" sysfs entry in /proc/mounts already 
> comes 
> > > out of initrd. Does this ring a bell?
> > > > 
> > > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > > 
> > > Nope, no bells.
> > > 
> > > The only thing I can suggest is that you try a bisection.
> > > 
> > >     -Mike
> > 
> >  OK, so I finally managed to bisect the issue down to the following commit. 
> Not much that I can say about it. Someone else suggested that it might all be a 
> question of timing. Might very well be. I will try it out on a system with a 
> different SCSI/RAID controller. The failing system has an "Smart Array 6i" 
> (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> > 
> > |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> > |Author: Stephen Hemminger 
> > |Date:   Thu Dec 18 09:17:16 2008 -0800
> > |
> > |    PCI: handle long delays in VPD access
> > |
> > |    Accessing the VPD area can take a long time.  The existing
> > |    VPD access code fails consistently on my hardware. There are comments
> > |
> > |    Change the access routines to:
> > |      * use a mutex rather than spinning with IRQ's disabled and lock held
> > |      * have a much longer timeout
> > |      * call cond_resched while spinning
> > |
> > |    Signed-off-by: Stephen Hemminger 
> > |    Reviewed-by: Matthew Wilcox 
> > |    Signed-off-by: Jesse Barnes 
> > 
> 
> 
> 
> So afacit what's happening is that the above change caused one of your
> PCI devices to take a very long time to initialise, yes?  Was it the
> CCISS driver?
>

 the whole thing is not understood. I mentioned CCISS only because it is the most visible difference difference between my two test platforms.
 
> If you add "printk.time=y" to the kernel boot command line then you'll
> get timestamped boot messages which will make it easier to determine
> where the time was consumed.  Adding `initcall_debug' to the boot line
> will help us delve further into the delay, assuming that the offending
> driver is build into vmlinux (which it might not be).
>

 added both options. "dmesg" output from both is appended. The initcall timings vary in both directions. For CCISS, they are actually faster for the "bad" case.
 
> Either way, it would be useful to know which driver the above change
> broke.
>

 agreed.
 
> Once we know that, the questions is: doe sthe driver still work?  If
> so, then presumably the hardware if behaving unexpectedly, or in a way
> which we're failing to cope with.
>

 if it is CCISS, I can definitely say that it does work OK. As far as I can see, the whole system works OK, besides the duplicate sysfs line coming out of initrd.
 
> Or perhaps that patch was simply buggy.
> 
> btw, I don't agree that this report should be closed for "fuzziness"! 
> AFACIT the regression clearly and reproducibly occurs on one of your
> machines, yes?  That ain't fuzzy!

 frankly, I will stop caring about the DL380s before 2.6.31 gets released. My production kernels are not affected and the hotplug scripts can easily be fixed for testting. So, my interest is more curiosity. And the day-job does not really justify spending much more time on it. Aren't day-jobs annoying ...

Cheers
Martin

[-- Attachment #2: dmesg-g904d6a3-good --]
[-- Type: application/octet-stream, Size: 89766 bytes --]

[-- Attachment #3: dmesg-g1120f8b-bad --]
[-- Type: application/octet-stream, Size: 89617 bytes --]

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Matthew Wilcox]

On Tue, May 26, 2009 at 11:31:02PM -0700, Andrew Morton wrote:
> On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch <knobi@knobisoft.de> wrote:
> 
> > 
> > ----- Original Message ----
> > 
> > > From: Mike Galbraith <efault@gmx.de>
> > > To: Martin Knoblauch <knobi@knobisoft.de>
> > > Cc: Andrew Morton <akpm@linux-foundation.org>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > > 
> > > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > > 
> > > >  just to bring this back to my problem :-)
> > > 
> > > Good idea :-)
> > > 
> > > >  Last week I reported that the "new" sysfs entry in /proc/mounts already comes 
> > > out of initrd. Does this ring a bell?
> > > > 
> > > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > > 
> > > Nope, no bells.
> > > 
> > > The only thing I can suggest is that you try a bisection.
> > > 
> > >     -Mike
> > 
> >  OK, so I finally managed to bisect the issue down to the following commit. Not much that I can say about it. Someone else suggested that it might all be a question of timing. Might very well be. I will try it out on a system with a different SCSI/RAID controller. The failing system has an "Smart Array 6i" (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> > 
> > |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> > |Author: Stephen Hemminger <shemminger@vyatta.com>
> > |Date:   Thu Dec 18 09:17:16 2008 -0800
> > |
> > |    PCI: handle long delays in VPD access
> > |
> > |    Accessing the VPD area can take a long time.  The existing
> > |    VPD access code fails consistently on my hardware. There are comments
> > |
> > |    Change the access routines to:
> > |      * use a mutex rather than spinning with IRQ's disabled and lock held
> > |      * have a much longer timeout
> > |      * call cond_resched while spinning
> > |
> > |    Signed-off-by: Stephen Hemminger <shemminger@vyatta.com>
> > |    Reviewed-by: Matthew Wilcox <willy@linux.intel.com>
> > |    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>
> > 
> 
> <hello, any maintainers out there?>

This is the first I've seen of this report ...

> So afacit what's happening is that the above change caused one of your
> PCI devices to take a very long time to initialise, yes?  Was it the
> CCISS driver?
> 
> If you add "printk.time=y" to the kernel boot command line then you'll
> get timestamped boot messages which will make it easier to determine
> where the time was consumed.  Adding `initcall_debug' to the boot line
> will help us delve further into the delay, assuming that the offending
> driver is build into vmlinux (which it might not be).

The two message logs posted show NTP starting up within a second of
each other.  What was the problem again?

-- 
Matthew Wilcox				Intel Open Source Technology Centre
"Bill, look, we understand that you're interested in selling us this
operating system, but compare it to ours.  We can't possibly take such
a retrograde step."

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

[-- Attachment #1: Type: text/plain, Size: 5358 bytes --]

----- Original Message ----

> From: Martin Knoblauch <knobi@knobisoft.de>
> To: Andrew Morton <akpm@linux-foundation.org>
> Cc: Mike Galbraith <efault@gmx.de>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers <kay.sievers@vrfy.org>; shemminger@vyatta.com; Jesse Barnes <jbarnes@virtuousgeek.org>; Matthew Wilcox <matthew@wil.cx>
> Sent: Wednesday, May 27, 2009 11:14:06 AM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> ----- Original Message ----
> 
> > From: Andrew Morton 
> > To: Martin Knoblauch 
> > Cc: Mike Galbraith ; viro@ZenIV.linux.org.uk; rjw@sisk.pl; 
> linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers 
> ; shemminger@vyatta.com; Jesse Barnes 
> ; Matthew Wilcox 
> > Sent: Wednesday, May 27, 2009 8:31:02 AM
> > Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> > 
> > On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch 
> > wrote:
> > 
> > > 
> > > ----- Original Message ----
> > > 
> > > > From: Mike Galbraith 
> > > > To: Martin Knoblauch 
> > > > Cc: Andrew Morton ; viro@ZenIV.linux.org.uk; 
> > rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > > > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > > > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > > > 
> > > > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > > > 
> > > > >  just to bring this back to my problem :-)
> > > > 
> > > > Good idea :-)
> > > > 
> > > > >  Last week I reported that the "new" sysfs entry in /proc/mounts already 
> 
> > comes 
> > > > out of initrd. Does this ring a bell?
> > > > > 
> > > > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > > > 
> > > > Nope, no bells.
> > > > 
> > > > The only thing I can suggest is that you try a bisection.
> > > > 
> > > >     -Mike
> > > 
> > >  OK, so I finally managed to bisect the issue down to the following commit. 
> > Not much that I can say about it. Someone else suggested that it might all be 
> a 
> > question of timing. Might very well be. I will try it out on a system with a 
> > different SCSI/RAID controller. The failing system has an "Smart Array 6i" 
> > (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> > > 
> > > |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> > > |Author: Stephen Hemminger 
> > > |Date:   Thu Dec 18 09:17:16 2008 -0800
> > > |
> > > |    PCI: handle long delays in VPD access
> > > |
> > > |    Accessing the VPD area can take a long time.  The existing
> > > |    VPD access code fails consistently on my hardware. There are comments
> > > |
> > > |    Change the access routines to:
> > > |      * use a mutex rather than spinning with IRQ's disabled and lock held
> > > |      * have a much longer timeout
> > > |      * call cond_resched while spinning
> > > |
> > > |    Signed-off-by: Stephen Hemminger 
> > > |    Reviewed-by: Matthew Wilcox 
> > > |    Signed-off-by: Jesse Barnes 
> > > 
> > 
> > 
> > 
> > So afacit what's happening is that the above change caused one of your
> > PCI devices to take a very long time to initialise, yes?  Was it the
> > CCISS driver?
> >
> 
> the whole thing is not understood. I mentioned CCISS only because it is the most 
> visible difference difference between my two test platforms.
> 
> > If you add "printk.time=y" to the kernel boot command line then you'll
> > get timestamped boot messages which will make it easier to determine
> > where the time was consumed.  Adding `initcall_debug' to the boot line
> > will help us delve further into the delay, assuming that the offending
> > driver is build into vmlinux (which it might not be).
> >
> 
> added both options. "dmesg" output from both is appended. The initcall timings 
> vary in both directions. For CCISS, they are actually faster for the "bad" case.
> 
> > Either way, it would be useful to know which driver the above change
> > broke.
> >
> 
> agreed.
> 
> > Once we know that, the questions is: doe sthe driver still work?  If
> > so, then presumably the hardware if behaving unexpectedly, or in a way
> > which we're failing to cope with.
> >
> 
> if it is CCISS, I can definitely say that it does work OK. As far as I can see, 
> the whole system works OK, besides the duplicate sysfs line coming out of 
> initrd.
> 
> > Or perhaps that patch was simply buggy.
> > 
> > btw, I don't agree that this report should be closed for "fuzziness"! 
> > AFACIT the regression clearly and reproducibly occurs on one of your
> > machines, yes?  That ain't fuzzy!
> 
> frankly, I will stop caring about the DL380s before 2.6.31 gets released. My 
> production kernels are not affected and the hotplug scripts can easily be fixed 
> for testting. So, my interest is more curiosity. And the day-job does not really 
> justify spending much more time on it. Aren't day-jobs annoying ...
> 
> Cheers
> Martin

 FWIW, I compiled the CCISS driver into the kernel. This makes the second "/sys" line in /proc/mounts go away, dmesg attached. But does it prove anything? The initialization of the CCISS hardware now happens about 2 seconds earlier in the bootup sequence. Does this hint to a problem with CCISS, or just confirms that the whole issue is really timing dependent? Anyway, I add Mike to CC.

Cheers
Martin

[-- Attachment #2: dmesg-g904d6a3-dirty-modscsi-nomodcciss-good --]
[-- Type: application/octet-stream, Size: 89578 bytes --]

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Matthew Wilcox <matthew@wil.cx>
> To: Andrew Morton <akpm@linux-foundation.org>
> Cc: Martin Knoblauch <knobi@knobisoft.de>; Mike Galbraith <efault@gmx.de>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers <kay.sievers@vrfy.org>; shemminger@vyatta.com; Jesse Barnes <jbarnes@virtuousgeek.org>
> Sent: Wednesday, May 27, 2009 1:21:53 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> On Tue, May 26, 2009 at 11:31:02PM -0700, Andrew Morton wrote:
> > On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch 
> wrote:
> > 
> > > 
> > > ----- Original Message ----
> > > 
> > > > From: Mike Galbraith 
> > > > To: Martin Knoblauch 
> > > > Cc: Andrew Morton ; viro@ZenIV.linux.org.uk; 
> rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
> > > > Sent: Wednesday, May 6, 2009 10:37:45 AM
> > > > Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
> > > > 
> > > > On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
> > > > 
> > > > >  just to bring this back to my problem :-)
> > > > 
> > > > Good idea :-)
> > > > 
> > > > >  Last week I reported that the "new" sysfs entry in /proc/mounts already 
> comes 
> > > > out of initrd. Does this ring a bell?
> > > > > 
> > > > > http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
> > > > 
> > > > Nope, no bells.
> > > > 
> > > > The only thing I can suggest is that you try a bisection.
> > > > 
> > > >     -Mike
> > > 
> > >  OK, so I finally managed to bisect the issue down to the following commit. 
> Not much that I can say about it. Someone else suggested that it might all be a 
> question of timing. Might very well be. I will try it out on a system with a 
> different SCSI/RAID controller. The failing system has an "Smart Array 6i" 
> (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
> > > 
> > > |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> > > |Author: Stephen Hemminger 
> > > |Date:   Thu Dec 18 09:17:16 2008 -0800
> > > |
> > > |    PCI: handle long delays in VPD access
> > > |
> > > |    Accessing the VPD area can take a long time.  The existing
> > > |    VPD access code fails consistently on my hardware. There are comments
> > > |
> > > |    Change the access routines to:
> > > |      * use a mutex rather than spinning with IRQ's disabled and lock held
> > > |      * have a much longer timeout
> > > |      * call cond_resched while spinning
> > > |
> > > |    Signed-off-by: Stephen Hemminger 
> > > |    Reviewed-by: Matthew Wilcox 
> > > |    Signed-off-by: Jesse Barnes 
> > > 
> > 
> > 
> 
> This is the first I've seen of this report ...
> 
> > So afacit what's happening is that the above change caused one of your
> > PCI devices to take a very long time to initialise, yes?  Was it the
> > CCISS driver?
> > 
> > If you add "printk.time=y" to the kernel boot command line then you'll
> > get timestamped boot messages which will make it easier to determine
> > where the time was consumed.  Adding `initcall_debug' to the boot line
> > will help us delve further into the delay, assuming that the offending
> > driver is build into vmlinux (which it might not be).
> 
> The two message logs posted show NTP starting up within a second of
> each other.  What was the problem again?
> 

 Just to recap. Starting with 2.6.29-rc1, /proc/mounts has two "sysfs" lines:

|none /sys sysfs rw,relatime 0 0
| /sys /sys sysfs rw,relatime 0 0

 The first of them already comes out of initrd, which somehow means that the explicit umount in the initrd/init script seems to fail. This is observable on a HP/DL380G4 with a "SmartArray 6" controller (cciss driver).

 As a result of the two lines, the hotplug/firmware script in my RHEL4.3 userspace failed to determine the "/sys" mountpoint, which in turn resulted in a 60 second timeout for each firmware load attempt, adding 6 minutes to the boot sequence (4 CPUs, 2 tg3s). I have since then just fixed the hotplug script to do "the right thing". Therefore you are not seeing a big difference in the two posted dmesg logs. The underlying issue remains.

 In a next step I managed to bisect the appearance of the second "sysfs" line down to the following commit:

|commit 1120f8b8169fb2cb51219d326892d963e762edb6
|Author: Stephen Hemminger <shemminger@vyatta.com>
|Date:   Thu Dec 18 09:17:16 2008 -0800
|
|    PCI: handle long delays in VPD access
|
|    Accessing the VPD area can take a long time.  The existing
|    VPD access code fails consistently on my hardware. There are comments
|
|    Change the access routines to:
|      * use a mutex rather than spinning with IRQ's disabled and lock held
|      * have a much longer timeout
|      * call cond_resched while spinning
|
|    Signed-off-by: Stephen Hemminger <shemminger@vyatta.com>
|    Reviewed-by: Matthew Wilcox <willy@linux.intel.com>
|    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>

 The commit itself may just show a problem/bug elsewhere. It definitely changes locking and timing around PCI.

 Next, I tried to run an identically configured kernel on a different system (IBM/x3650 with aacraid). The problem was not observable. This now either points to CCISS, or leaves timing.

 Finally, today I built the ccsii driver into the kernel. It was previously modularized and loaded from initrd. The second "sysfs" line went away. But does this make cciss guilty? It is now loaded about 2 seconds earlier in the boot sequence, which is a big change in timing I guess.

 Enlighten me :-)

Cheers
Martin

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[jim owens]

Martin Knoblauch wrote:
> ----- Original Message ----
> 
>> From: Matthew Wilcox <matthew@wil.cx>
>> To: Andrew Morton <akpm@linux-foundation.org>
>> Cc: Martin Knoblauch <knobi@knobisoft.de>; Mike Galbraith <efault@gmx.de>; viro@ZenIV.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uks; Kay Sievers <kay.sievers@vrfy.org>; shemminger@vyatta.com; Jesse Barnes <jbarnes@virtuousgeek.org>
>> Sent: Wednesday, May 27, 2009 1:21:53 PM
>> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
>>
>> On Tue, May 26, 2009 at 11:31:02PM -0700, Andrew Morton wrote:
>>> On Wed, 20 May 2009 03:22:28 -0700 (PDT) Martin Knoblauch 
>> wrote:
>>>> ----- Original Message ----
>>>>
>>>>> From: Mike Galbraith 
>>>>> To: Martin Knoblauch 
>>>>> Cc: Andrew Morton ; viro@ZenIV.linux.org.uk; 
>> rjw@sisk.pl; linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk
>>>>> Sent: Wednesday, May 6, 2009 10:37:45 AM
>>>>> Subject: Re: Analyzed/Solved: Booting 2.6.30-rc2-git7 very slow
>>>>>
>>>>> On Wed, 2009-05-06 at 00:55 -0700, Martin Knoblauch wrote:
>>>>>
>>>>>>  just to bring this back to my problem :-)
>>>>> Good idea :-)
>>>>>
>>>>>>  Last week I reported that the "new" sysfs entry in /proc/mounts already 
>> comes 
>>>>> out of initrd. Does this ring a bell?
>>>>>> http://lkml.indiana.edu/hypermail/linux/kernel/0904.3/03048.html
>>>>> Nope, no bells.
>>>>>
>>>>> The only thing I can suggest is that you try a bisection.
>>>>>
>>>>>     -Mike
>>>>  OK, so I finally managed to bisect the issue down to the following commit. 
>> Not much that I can say about it. Someone else suggested that it might all be a 
>> question of timing. Might very well be. I will try it out on a system with a 
>> different SCSI/RAID controller. The failing system has an "Smart Array 6i" 
>> (cciss). "cciss", "ext3" and "jbd" are all modules coming from initrd.
>>>> |commit 1120f8b8169fb2cb51219d326892d963e762edb6
>>>> |Author: Stephen Hemminger 
>>>> |Date:   Thu Dec 18 09:17:16 2008 -0800
>>>> |
>>>> |    PCI: handle long delays in VPD access
>>>> |
>>>> |    Accessing the VPD area can take a long time.  The existing
>>>> |    VPD access code fails consistently on my hardware. There are comments
>>>> |
>>>> |    Change the access routines to:
>>>> |      * use a mutex rather than spinning with IRQ's disabled and lock held
>>>> |      * have a much longer timeout
>>>> |      * call cond_resched while spinning
>>>> |
>>>> |    Signed-off-by: Stephen Hemminger 
>>>> |    Reviewed-by: Matthew Wilcox 
>>>> |    Signed-off-by: Jesse Barnes 
>>>>
>>>
>> This is the first I've seen of this report ...
>>
>>> So afacit what's happening is that the above change caused one of your
>>> PCI devices to take a very long time to initialise, yes?  Was it the
>>> CCISS driver?
>>>
>>> If you add "printk.time=y" to the kernel boot command line then you'll
>>> get timestamped boot messages which will make it easier to determine
>>> where the time was consumed.  Adding `initcall_debug' to the boot line
>>> will help us delve further into the delay, assuming that the offending
>>> driver is build into vmlinux (which it might not be).
>> The two message logs posted show NTP starting up within a second of
>> each other.  What was the problem again?
>>
> 
>  Just to recap. Starting with 2.6.29-rc1, /proc/mounts has two "sysfs" lines:
> 
> |none /sys sysfs rw,relatime 0 0
> | /sys /sys sysfs rw,relatime 0 0
> 
>  The first of them already comes out of initrd, which somehow means that the explicit umount in the initrd/init script seems to fail. This is observable on a HP/DL380G4 with a "SmartArray 6" controller (cciss driver).
> 
>  As a result of the two lines, the hotplug/firmware script in my RHEL4.3 userspace failed to determine the "/sys" mountpoint, which in turn resulted in a 60 second timeout for each firmware load attempt, adding 6 minutes to the boot sequence (4 CPUs, 2 tg3s). I have since then just fixed the hotplug script to do "the right thing". Therefore you are not seeing a big difference in the two posted dmesg logs. The underlying issue remains.
> 
>  In a next step I managed to bisect the appearance of the second "sysfs" line down to the following commit:
> 
> |commit 1120f8b8169fb2cb51219d326892d963e762edb6
> |Author: Stephen Hemminger <shemminger@vyatta.com>
> |Date:   Thu Dec 18 09:17:16 2008 -0800
> |
> |    PCI: handle long delays in VPD access
> |
> |    Accessing the VPD area can take a long time.  The existing
> |    VPD access code fails consistently on my hardware. There are comments
> |
> |    Change the access routines to:
> |      * use a mutex rather than spinning with IRQ's disabled and lock held
> |      * have a much longer timeout
> |      * call cond_resched while spinning
> |
> |    Signed-off-by: Stephen Hemminger <shemminger@vyatta.com>
> |    Reviewed-by: Matthew Wilcox <willy@linux.intel.com>
> |    Signed-off-by: Jesse Barnes <jbarnes@virtuousgeek.org>
> 
>  The commit itself may just show a problem/bug elsewhere. It definitely changes locking and timing around PCI.
> 
>  Next, I tried to run an identically configured kernel on a different system (IBM/x3650 with aacraid). The problem was not observable. This now either points to CCISS, or leaves timing.
> 
>  Finally, today I built the ccsii driver into the kernel. It was previously modularized and loaded from initrd. The second "sysfs" line went away. But does this make cciss guilty? It is now loaded about 2 seconds earlier in the boot sequence, which is a big change in timing I guess.
> 
>  Enlighten me :-)

No idea what is going on, but since I saw your May 20 message,
I have been trying to wake up someone whose day job it should
be to care about dl380s and smartarrays. :)

If they don't react soon, I'll make this my own day job to
try to reproduce it.  We will need hardware config details and
firmware revs to start.

So I would not close the bug just yet.

jim

RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Miller, Mike (OS Dev)]

> > 
> >  Finally, today I built the ccsii driver into the kernel. 
> It was previously modularized and loaded from initrd. The 
> second "sysfs" line went away. But does this make cciss 
> guilty? It is now loaded about 2 seconds earlier in the boot 
> sequence, which is a big change in timing I guess.
> > 
> >  Enlighten me :-)
> 
> No idea what is going on, but since I saw your May 20 
> message, I have been trying to wake up someone whose day job 
> it should be to care about dl380s and smartarrays. :)

What? I know Martin has pinged me in the past, but I do not think it was about this issue. If there's multiple sysfs entries for cciss I can't explain that offhand. We do little to nothing for sysfs in the driver.
Had something similiar happen recently where "/" changed to "!". Had do to with our nested directory structure, /dev/cciss/name vs /dev/name. But we did not make that change, either.

-- mikem

> 
> If they don't react soon, I'll make this my own day job to 
> try to reproduce it.  We will need hardware config details 
> and firmware revs to start.
> 
> So I would not close the bug just yet.
> 
> jim
> 
> 

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[jim owens]

Miller, Mike (OS Dev) wrote:
>>>  Finally, today I built the ccsii driver into the kernel. 
>> It was previously modularized and loaded from initrd. The 
>> second "sysfs" line went away. But does this make cciss 
>> guilty? It is now loaded about 2 seconds earlier in the boot 
>> sequence, which is a big change in timing I guess.
>>>  Enlighten me :-)
>> No idea what is going on, but since I saw your May 20 
>> message, I have been trying to wake up someone whose day job 
>> it should be to care about dl380s and smartarrays. :)
> 
> What? I know Martin has pinged me in the past, but I do not think it was about this issue. If there's multiple sysfs entries for cciss I can't explain that offhand. We do little to nothing for sysfs in the driver.
> Had something similiar happen recently where "/" changed to "!". Had do to with our nested directory structure, /dev/cciss/name vs /dev/name. But we did not make that change, either.

It was not you that I was trying to get to look at this...
but now that I have your attention :)

I did not think it pointed at cciss or the sysfs entry as
being the problem.  I was wondering more about platform probe
timing, the bios, and how each card firmware reacts given
what I thought the patch did.  I could be totally wrong about
that as I work at the filesystem level.

We have not seen the problem yet but we have different
proliants/smartarrays.

If you can try it on matching hardware, great, if not
then someone will eventually find a system to test it.

jim

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Andrew Morton]

On Wed, 27 May 2009 04:25:57 -0700 (PDT)
Martin Knoblauch <knobi@knobisoft.de> wrote:

>  FWIW, I compiled the CCISS driver into the kernel. This makes the second "/sys" line in /proc/mounts go away, dmesg attached. But does it prove anything? The initialization of the CCISS hardware now happens about 2 seconds earlier in the bootup sequence. Does this hint to a problem with CCISS, or just confirms that the whole issue is really timing dependent? Anyway, I add Mike to CC.
> 

It seems that the PCI change caused timing changes which triggered a
udev/sysfs/whatever problem, which manifests as the duplicated
/proc/mounts entry to turn up.

What we don't know (afaik) is why the kernel permitted two entries in
/proc/mounts.  That might be a bug.

It could be that if dual /proc/mounts problem gets fixed, everything
works OK - by intent or by accident, the userspace startup scripts may
then work acceptably.

I think Al asked you a few questions around the behaviour of mount(8)
and the mount syscall, so we could delve further into why /proc/mounts
is getting mucked up.  Did you end up running those tests?

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Kay Sievers]

On Wed, May 27, 2009 at 22:31, Andrew Morton <akpm@linux-foundation.org> wrote:
> On Wed, 27 May 2009 04:25:57 -0700 (PDT)
> Martin Knoblauch <knobi@knobisoft.de> wrote:
>
>>  FWIW, I compiled the CCISS driver into the kernel. This makes the second "/sys" line in /proc/mounts go away, dmesg attached. But does it prove anything? The initialization of the CCISS hardware now happens about 2 seconds earlier in the bootup sequence. Does this hint to a problem with CCISS, or just confirms that the whole issue is really timing dependent? Anyway, I add Mike to CC.
>>
>
> It seems that the PCI change caused timing changes which triggered a
> udev/sysfs/whatever problem, which manifests as the duplicated
> /proc/mounts entry to turn up.
>
> What we don't know (afaik) is why the kernel permitted two entries in
> /proc/mounts.  That might be a bug.
>
> It could be that if dual /proc/mounts problem gets fixed, everything
> works OK - by intent or by accident, the userspace startup scripts may
> then work acceptably.
>
> I think Al asked you a few questions around the behaviour of mount(8)
> and the mount syscall, so we could delve further into why /proc/mounts
> is getting mucked up.  Did you end up running those tests?

I expect the duplicate comes from a left-over mount in initramfs which
isn't a duplicate in the sense of a bug in vfs or mount or anything. I
guess, it is just still mounted in the initial kernel rootfs, below
the root from the disk. It could be that a umount from initramfs did
go wrong because of a changed timing.

Thanks,
Kay

RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Miller, Mike (OS Dev)]

 

> -----Original Message-----
> From: Owens, James 
> Sent: Wednesday, May 27, 2009 3:13 PM
> To: Miller, Mike (OS Dev)
> Cc: Martin Knoblauch; Matthew Wilcox; Andrew Morton; Mike 
> Galbraith; viro@ZenIV.linux.org.uk; rjw@sisk.pl; 
> linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk; 
> Kay Sievers; shemminger@vyatta.com; Jesse Barnes
> Subject: Re: Analyzed/Solved/Bisected: Booting 
> 2.6.30-rc2-git7 very slow
> 
> Miller, Mike (OS Dev) wrote:
> >>>  Finally, today I built the ccsii driver into the kernel. 
> >> It was previously modularized and loaded from initrd. The second 
> >> "sysfs" line went away. But does this make cciss guilty? It is now 
> >> loaded about 2 seconds earlier in the boot sequence, which 
> is a big 
> >> change in timing I guess.
> >>>  Enlighten me :-)
> >> No idea what is going on, but since I saw your May 20 
> message, I have 
> >> been trying to wake up someone whose day job it should be to care 
> >> about dl380s and smartarrays. :)
> > 
> > What? I know Martin has pinged me in the past, but I do not 
> think it was about this issue. If there's multiple sysfs 
> entries for cciss I can't explain that offhand. We do little 
> to nothing for sysfs in the driver.
> > Had something similiar happen recently where "/" changed to 
> "!". Had do to with our nested directory structure, 
> /dev/cciss/name vs /dev/name. But we did not make that change, either.
> 
> It was not you that I was trying to get to look at this...
> but now that I have your attention :)
> 
> I did not think it pointed at cciss or the sysfs entry as 
> being the problem.  I was wondering more about platform probe 
> timing, the bios, and how each card firmware reacts given 
> what I thought the patch did.  I could be totally wrong about 
> that as I work at the filesystem level.
> 
> We have not seen the problem yet but we have different 
> proliants/smartarrays.
> 
> If you can try it on matching hardware, great, if not then 
> someone will eventually find a system to test it.
> 
Sorry, I don't have any hw that old. We're very limited on space these days.

-- mikem

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

[-- Attachment #1: Type: text/plain, Size: 2338 bytes --]

----- Original Message ----

> From: "Miller, Mike (OS Dev)" <Mike.Miller@hp.com>
> To: "Owens, James" <JOwens@hp.com>; Martin Knoblauch <knobi@knobisoft.de>
> Cc: Matthew Wilcox <matthew@wil.cx>; Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; "viro@ZenIV.linux.org.uk" <viro@ZenIV.linux.org.uk>; "rjw@sisk.pl" <rjw@sisk.pl>; "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>; "tigran@aivazian.fsnet.co.uk" <tigran@aivazian.fsnet.co.uk>; Kay Sievers <kay.sievers@vrfy.org>; "shemminger@vyatta.com" <shemminger@vyatta.com>; Jesse Barnes <jbarnes@virtuousgeek.org>
> Sent: Wednesday, May 27, 2009 8:18:46 PM
> Subject: RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> > > 
> > >  Finally, today I built the ccsii driver into the kernel. 
> > It was previously modularized and loaded from initrd. The 
> > second "sysfs" line went away. But does this make cciss 
> > guilty? It is now loaded about 2 seconds earlier in the boot 
> > sequence, which is a big change in timing I guess.
> > > 
> > >  Enlighten me :-)
> > 
> > No idea what is going on, but since I saw your May 20 
> > message, I have been trying to wake up someone whose day job 
> > it should be to care about dl380s and smartarrays. :)
> 
> What? I know Martin has pinged me in the past, but I do not think it was about 
> this issue. If there's multiple sysfs entries for cciss I can't explain that 
> offhand. We do little to nothing for sysfs in the driver.
> Had something similiar happen recently where "/" changed to "!". Had do to with 
> our nested directory structure, /dev/cciss/name vs /dev/name. But we did not 
> make that change, either.
> 
Hi Mike, Jim

 you are right. I never talked to you about this issue. Actually, I did not suspect CCISS or the DL380 in general to be involved before last week when I retested on the x3650 and the problem went away. Due to day-job and priorities I did not follow up.

> -- mikem
> 
> > 
> > If they don't react soon, I'll make this my own day job to 
> > try to reproduce it.  We will need hardware config details 
> > and firmware revs to start.
> > 

Dl380/G4
2x3.4 GHz CPUs
8 GB Memeory
4x72 GB as RAID5 on SA6i controller

BIOS: P51 (07(19/2007)
ILO FW: 1.91
SA6i FW: 2.84

lspci output (-vvv and -xxx) appendend to prevent line wrapping.


Cheers
Martin

[-- Attachment #2: lspci-bad --]
[-- Type: application/octet-stream, Size: 44310 bytes --]

00:00.0 Host bridge: Intel Corporation E7520 Memory Controller Hub (rev 0c)
	Subsystem: Compaq Computer Corporation: Unknown device 3200
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Capabilities: [40] Vendor Specific Information

00:02.0 PCI bridge: Intel Corporation E7525/E7520/E7320 PCI Express Port A (rev 0c) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=00, secondary=02, subordinate=04, sec-latency=0
	I/O behind bridge: 00004000-00004fff
	Memory behind bridge: fdc00000-fddfffff
	Prefetchable memory behind bridge: 00000000f0000000-00000000f0000000
	Secondary status: 66Mhz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [50] Power Management version 2
		Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [58] Message Signalled Interrupts: 64bit- Queue=0/1 Enable-
		Address: fee00000  Data: 0000
	Capabilities: [64] Express Root Port (Slot-) IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 128 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 2
		Link: Latency L0s <4us, L1 unlimited
		Link: ASPM Disabled RCB 64 bytes CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
		Root: Correctable- Non-Fatal- Fatal- PME-
	Capabilities: [100] Advanced Error Reporting

00:06.0 PCI bridge: Intel Corporation E7520 PCI Express Port C (rev 0c) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=00, secondary=05, subordinate=0c, sec-latency=0
	I/O behind bridge: 00005000-00005fff
	Memory behind bridge: fde00000-fdffffff
	Prefetchable memory behind bridge: 00000000f0100000-00000000f0200000
	Secondary status: 66Mhz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [50] Power Management version 2
		Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [58] Message Signalled Interrupts: 64bit- Queue=0/1 Enable-
		Address: fee00000  Data: 0000
	Capabilities: [64] Express Root Port (Slot+) IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 128 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 6
		Link: Latency L0s <4us, L1 unlimited
		Link: ASPM Disabled RCB 64 bytes CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
		Slot: AtnBtn- PwrCtrl- MRL- AtnInd- PwrInd- HotPlug- Surpise-
		Slot: Number 0, PowerLimit 0.000000
		Slot: Enabled AtnBtn- PwrFlt- MRL- PresDet- CmdCplt- HPIrq-
		Slot: AttnInd Off, PwrInd On, Power-
		Root: Correctable- Non-Fatal- Fatal- PME-
	Capabilities: [100] Advanced Error Reporting

00:1d.0 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #1 (rev 02) (prog-if 00 [UHCI])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin A routed to IRQ 16
	Region 4: I/O ports at 3000 [size=32]

00:1d.1 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #2 (rev 02) (prog-if 00 [UHCI])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin B routed to IRQ 19
	Region 4: I/O ports at 3020 [size=32]

00:1d.2 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #3 (rev 02) (prog-if 00 [UHCI])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin C routed to IRQ 18
	Region 4: I/O ports at 3040 [size=32]

00:1d.3 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #4 (rev 02) (prog-if 00 [UHCI])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O+ Mem- BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin A routed to IRQ 16
	Region 4: I/O ports at 3060 [size=32]

00:1d.7 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB2 EHCI Controller (rev 02) (prog-if 20 [EHCI])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin D routed to IRQ 23
	Region 0: Memory at fbef0000 (32-bit, non-prefetchable) [size=1K]
	Capabilities: [50] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [58] Debug port

00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev c2) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Bus: primary=00, secondary=01, subordinate=01, sec-latency=64
	I/O behind bridge: 00001000-00002fff
	Memory behind bridge: fbf00000-fcffffff
	Prefetchable memory behind bridge: f0300000-f03fffff
	Secondary status: 66Mhz- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-

00:1f.0 ISA bridge: Intel Corporation 82801EB/ER (ICH5/ICH5R) LPC Interface Bridge (rev 02)
	Control: I/O+ Mem+ BusMaster+ SpecCycle+ MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0

00:1f.1 IDE interface: Intel Corporation 82801EB/ER (ICH5/ICH5R) IDE Controller (rev 02) (prog-if 8a [Master SecP PriP])
	Subsystem: Compaq Computer Corporation: Unknown device 3201
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B-
	Status: Cap- 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0
	Interrupt: pin A routed to IRQ 255
	Region 0: I/O ports at 01f0 [size=8]
	Region 1: I/O ports at 03f4 [size=1]
	Region 2: I/O ports at 0170 [size=8]
	Region 3: I/O ports at 0374 [size=1]
	Region 4: I/O ports at 0500 [size=16]
	Region 5: Memory at f0400000 (32-bit, non-prefetchable) [size=1K]

01:03.0 VGA compatible controller: ATI Technologies Inc Rage XL (rev 27) (prog-if 00 [VGA])
	Subsystem: Compaq Computer Corporation: Unknown device 001e
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping+ SERR- FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64 (2000ns min), Cache Line Size 10
	Region 0: Memory at fc000000 (32-bit, non-prefetchable) [size=16M]
	Region 1: I/O ports at 2000 [size=256]
	Region 2: Memory at fbff0000 (32-bit, non-prefetchable) [size=4K]
	[virtual] Expansion ROM at f0300000 [disabled] [size=128K]
	Capabilities: [5c] Power Management version 2
		Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-

01:04.0 System peripheral: Compaq Computer Corporation Integrated Lights Out Controller (rev 01)
	Subsystem: Compaq Computer Corporation: Unknown device b206
	Control: I/O+ Mem+ BusMaster- SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Interrupt: pin A routed to IRQ 5
	Region 0: I/O ports at 1800 [size=256]
	Region 1: Memory at fbfe0000 (32-bit, non-prefetchable) [size=512]
	Capabilities: [f0] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-

01:04.2 System peripheral: Compaq Computer Corporation Integrated Lights Out  Processor (rev 01)
	Subsystem: Compaq Computer Corporation: Unknown device b206
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr- Stepping+ SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64, Cache Line Size 10
	Interrupt: pin B routed to IRQ 22
	Region 0: I/O ports at 2400 [size=256]
	Region 1: Memory at fbfd0000 (32-bit, non-prefetchable) [size=2K]
	Region 2: Memory at fbfc0000 (32-bit, non-prefetchable) [size=8K]
	Region 3: Memory at fbf00000 (32-bit, non-prefetchable) [size=512K]
	[virtual] Expansion ROM at f0320000 [disabled] [size=64K]
	Capabilities: [f0] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-

02:00.0 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge A (rev 09) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=02, secondary=03, subordinate=03, sec-latency=64
	I/O behind bridge: 0000f000-00000fff
	Memory behind bridge: fdc00000-fdcfffff
	Prefetchable memory behind bridge: 00000000fff00000-0000000000000000
	Secondary status: 66Mhz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [44] Express PCI/PCI-X Bridge IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: AtnBtn- AtnInd- PwrInd-
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 512 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 0
		Link: Latency L0s unlimited, L1 unlimited
		Link: ASPM Disabled CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
	Capabilities: [5c] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
		Address: 0000000000000000  Data: 0000
	Capabilities: [6c] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [d8] PCI-X bridge device.
		Secondary Status: 64bit+, 133MHz+, SCD-, USC-, SCO-, SRD- Freq=3
		Status: Bus=2 Dev=0 Func=0 64bit- 133MHz- SCD- USC-, SCO-, SRD-
		: Upstream: Capacity=65535, Commitment Limit=65535
		: Downstream: Capacity=65535, Commitment Limit=65535
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [300] Power Budgeting

02:00.2 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge B (rev 09) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=02, secondary=04, subordinate=04, sec-latency=64
	I/O behind bridge: 00004000-00004fff
	Memory behind bridge: fdd00000-fddfffff
	Prefetchable memory behind bridge: 00000000f0000000-00000000f0000000
	Secondary status: 66Mhz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [44] Express PCI/PCI-X Bridge IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: AtnBtn- AtnInd- PwrInd-
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 512 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 0
		Link: Latency L0s unlimited, L1 unlimited
		Link: ASPM Disabled CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
	Capabilities: [5c] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
		Address: 0000000000000000  Data: 0000
	Capabilities: [6c] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [d8] PCI-X bridge device.
		Secondary Status: 64bit+, 133MHz+, SCD-, USC-, SCO-, SRD- Freq=3
		Status: Bus=2 Dev=0 Func=2 64bit- 133MHz- SCD- USC-, SCO-, SRD-
		: Upstream: Capacity=65535, Commitment Limit=65535
		: Downstream: Capacity=65535, Commitment Limit=65535
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [300] Power Budgeting

03:01.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5704 Gigabit Ethernet (rev 10)
	Subsystem: Compaq Computer Corporation NC7782 Gigabit Server Adapter (PCI-X, 10,100,1000-T)
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64 (16000ns min), Cache Line Size 10
	Interrupt: pin A routed to IRQ 25
	Region 0: Memory at fdcf0000 (64-bit, non-prefetchable) [size=64K]
	Capabilities: [40] PCI-X non-bridge device.
		Command: DPERE- ERO- RBC=2 OST=0
		Status: Bus=3 Dev=1 Func=0 64bit+ 133MHz+ SCD- USC-, DC=simple, DMMRBC=2, DMOST=0, DMCRS=1, RSCEM-
	Capabilities: [48] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable+ DSel=0 DScale=1 PME-
	Capabilities: [50] Vital Product Data
	Capabilities: [58] Message Signalled Interrupts: 64bit+ Queue=0/3 Enable-
		Address: ebf7f7be0f3ffd08  Data: 85ed

03:01.1 Ethernet controller: Broadcom Corporation NetXtreme BCM5704 Gigabit Ethernet (rev 10)
	Subsystem: Compaq Computer Corporation NC7782 Gigabit Server Adapter (PCI-X, 10,100,1000-T)
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64 (16000ns min), Cache Line Size 10
	Interrupt: pin B routed to IRQ 26
	Region 0: Memory at fdce0000 (64-bit, non-prefetchable) [size=64K]
	Capabilities: [40] PCI-X non-bridge device.
		Command: DPERE- ERO- RBC=2 OST=0
		Status: Bus=3 Dev=1 Func=1 64bit+ 133MHz+ SCD- USC-, DC=simple, DMMRBC=2, DMOST=0, DMCRS=1, RSCEM-
	Capabilities: [48] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable+ DSel=0 DScale=1 PME-
	Capabilities: [50] Vital Product Data
	Capabilities: [58] Message Signalled Interrupts: 64bit+ Queue=0/3 Enable-
		Address: 3ab73a9f0d2a35f8  Data: e93c

04:03.0 RAID bus controller: Compaq Computer Corporation Smart Array 64xx (rev 01)
	Subsystem: Compaq Computer Corporation: Unknown device 4091
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64, Cache Line Size 10
	Interrupt: pin A routed to IRQ 51
	Region 0: Memory at fddf0000 (64-bit, non-prefetchable) [size=8K]
	Region 2: I/O ports at 4000 [size=256]
	Region 3: Memory at fdd80000 (64-bit, non-prefetchable) [size=256K]
	[virtual] Expansion ROM at f0000000 [disabled] [size=256K]
	Capabilities: [d0] Power Management version 2
		Flags: PMEClk- DSI- D1+ D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot-,D3cold-)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [dc] PCI-X non-bridge device.
		Command: DPERE- ERO+ RBC=0 OST=4
		Status: Bus=4 Dev=3 Func=0 64bit+ 133MHz+ SCD- USC-, DC=simple, DMMRBC=2, DMOST=4, DMCRS=2, RSCEM-
	Capabilities: [f0] Vital Product Data

05:00.0 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge A (rev 09) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=05, secondary=06, subordinate=09, sec-latency=48
	I/O behind bridge: 00005000-00005fff
	Memory behind bridge: fde00000-fdefffff
	Prefetchable memory behind bridge: 00000000f0100000-00000000f0100000
	Secondary status: 66Mhz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [44] Express PCI/PCI-X Bridge IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: AtnBtn- AtnInd- PwrInd-
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 512 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 0
		Link: Latency L0s unlimited, L1 unlimited
		Link: ASPM Disabled CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
	Capabilities: [5c] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
		Address: 0000000000000000  Data: 0000
	Capabilities: [6c] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [d8] PCI-X bridge device.
		Secondary Status: 64bit+, 133MHz+, SCD-, USC-, SCO-, SRD- Freq=0
		Status: Bus=5 Dev=0 Func=0 64bit- 133MHz- SCD- USC-, SCO-, SRD-
		: Upstream: Capacity=65535, Commitment Limit=65535
		: Downstream: Capacity=65535, Commitment Limit=65535
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [300] Power Budgeting

05:00.2 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge B (rev 09) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 0, Cache Line Size 10
	Bus: primary=05, secondary=0a, subordinate=0c, sec-latency=64
	I/O behind bridge: 0000f000-00000fff
	Memory behind bridge: fdf00000-fdffffff
	Prefetchable memory behind bridge: 00000000f0200000-00000000f0200000
	Secondary status: 66Mhz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
	BridgeCtl: Parity+ SERR+ NoISA- VGA- MAbort- >Reset- FastB2B-
	Capabilities: [44] Express PCI/PCI-X Bridge IRQ 0
		Device: Supported: MaxPayload 256 bytes, PhantFunc 0, ExtTag-
		Device: Latency L0s <64ns, L1 <1us
		Device: AtnBtn- AtnInd- PwrInd-
		Device: Errors: Correctable- Non-Fatal+ Fatal+ Unsupported-
		Device: RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
		Device: MaxPayload 256 bytes, MaxReadReq 512 bytes
		Link: Supported Speed 2.5Gb/s, Width x8, ASPM L0s, Port 0
		Link: Latency L0s unlimited, L1 unlimited
		Link: ASPM Disabled CommClk- ExtSynch-
		Link: Speed 2.5Gb/s, Width x8
	Capabilities: [5c] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
		Address: 0000000000000000  Data: 0000
	Capabilities: [6c] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=0 PME-
	Capabilities: [d8] PCI-X bridge device.
		Secondary Status: 64bit+, 133MHz+, SCD-, USC-, SCO-, SRD- Freq=3
		Status: Bus=5 Dev=0 Func=2 64bit- 133MHz- SCD- USC-, SCO-, SRD-
		: Upstream: Capacity=65535, Commitment Limit=65535
		: Downstream: Capacity=65535, Commitment Limit=65535
	Capabilities: [100] Advanced Error Reporting
	Capabilities: [300] Power Budgeting

06:01.0 Ethernet controller: Intel Corporation 82540EM Gigabit Ethernet Controller (rev 02)
	Subsystem: Intel Corporation PRO/1000 MT Desktop Adapter
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64 (63750ns min), Cache Line Size 10
	Interrupt: pin A routed to IRQ 74
	Region 0: Memory at fdee0000 (32-bit, non-prefetchable) [size=128K]
	Region 1: Memory at fdec0000 (32-bit, non-prefetchable) [size=128K]
	Region 2: I/O ports at 5000 [size=64]
	[virtual] Expansion ROM at f0100000 [disabled] [size=128K]
	Capabilities: [dc] Power Management version 2
		Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=1 PME-
	Capabilities: [e4] PCI-X non-bridge device.
		Command: DPERE- ERO+ RBC=0 OST=0
		Status: Bus=0 Dev=0 Func=0 64bit- 133MHz- SCD- USC-, DC=simple, DMMRBC=2, DMOST=0, DMCRS=1, RSCEM-
	Capabilities: [f0] Message Signalled Interrupts: 64bit+ Queue=0/0 Enable-
		Address: 0000000000000000  Data: 0000

0a:01.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5703 Gigabit Ethernet (rev 10)
	Subsystem: Compaq Computer Corporation NC7771 Gigabit Server Adapter (PCI-X, 10,100,1000-T)
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B-
	Status: Cap+ 66Mhz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR-
	Latency: 64 (16000ns min), Cache Line Size 10
	Interrupt: pin A routed to IRQ 97
	Region 0: Memory at fdff0000 (64-bit, non-prefetchable) [size=64K]
	[virtual] Expansion ROM at f0200000 [disabled] [size=64K]
	Capabilities: [40] PCI-X non-bridge device.
		Command: DPERE- ERO+ RBC=0 OST=0
		Status: Bus=10 Dev=1 Func=1 64bit+ 133MHz+ SCD- USC-, DC=simple, DMMRBC=2, DMOST=0, DMCRS=1, RSCEM-
	Capabilities: [48] Power Management version 2
		Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0-,D1-,D2-,D3hot+,D3cold+)
		Status: D0 PME-Enable- DSel=0 DScale=1 PME-
	Capabilities: [50] Vital Product Data
	Capabilities: [58] Message Signalled Interrupts: 64bit+ Queue=0/3 Enable-
		Address: fffef7feeffffffc  Data: fefe

00:00.0 Host bridge: Intel Corporation E7520 Memory Controller Hub (rev 0c)
00: 86 80 90 35 46 01 90 00 0c 00 00 06 00 00 80 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 00 32
30: 00 00 00 00 40 00 00 00 00 00 00 00 00 00 00 00
40: 09 00 05 41 10 00 00 00 00 00 00 00 00 00 00 00
50: 0c 60 0a 00 00 00 00 00 00 10 11 11 01 00 00 33
60: 20 20 30 30 40 40 40 40 00 00 00 00 00 00 00 00
70: 0b 0a 0a 00 00 00 00 00 44 11 9e 55 1e 02 20 2c
80: 48 12 41 00 00 00 00 00 80 01 00 f0 88 00 00 00
90: 00 04 01 00 00 aa 04 39 aa aa 0c 30 45 08 12 07
a0: 01 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00
b0: 76 75 33 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 44 c0 50 33 00 e0 80 00 87 00 48 00 40 00 00 e0
d0: 02 28 00 0e 03 00 00 00 00 00 93 b5 00 00 02 01
e0: 00 00 00 00 00 00 00 00 2e 46 00 00 00 00 00 00
f0: 00 00 00 00 10 01 02 00 80 0f 0c 00 00 00 00 00

00:02.0 PCI bridge: Intel Corporation E7525/E7520/E7320 PCI Express Port A (rev 0c)
00: 86 80 95 35 47 01 10 00 0c 00 04 06 10 00 01 00
10: 00 00 00 00 00 00 00 00 00 02 04 00 40 40 00 00
20: c0 fd d0 fd 01 f0 01 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 50 00 00 00 00 00 00 00 ff 01 03 00
40: 00 00 00 00 00 08 00 02 00 00 00 00 00 00 00 00
50: 01 58 22 c8 00 00 00 00 05 64 02 00 00 00 e0 fe
60: 00 00 00 00 10 00 41 00 01 00 00 00 26 00 00 00
70: 81 e4 03 02 00 00 81 10 00 00 00 00 c0 01 40 00
80: 0e 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 d6 0f 9a 00 01 00 32 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 30 09 00 00
f0: 82 20 05 00 00 00 00 00 00 00 00 00 00 00 00 00

00:06.0 PCI bridge: Intel Corporation E7520 PCI Express Port C (rev 0c)
00: 86 80 99 35 47 01 10 00 0c 00 04 06 10 00 01 00
10: 00 00 00 00 00 00 00 00 00 05 0c 00 50 50 00 00
20: e0 fd f0 fd 11 f0 21 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 50 00 00 00 00 00 00 00 ff 01 03 00
40: 00 00 00 00 00 08 00 02 00 00 00 00 00 00 00 00
50: 01 58 22 c8 00 00 00 00 05 64 02 00 00 00 e0 fe
60: 00 00 00 00 10 00 41 01 01 00 00 00 26 00 00 00
70: 81 e4 03 06 00 00 81 10 00 00 00 00 c0 01 40 00
80: 0e 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 30 00 0c 00 01 00 08 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 30 09 00 00
f0: 82 20 05 00 00 00 00 00 00 00 00 00 00 00 00 00

00:1d.0 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #1 (rev 02)
00: 86 80 d2 24 05 00 80 02 02 00 03 0c 00 00 80 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 01 30 00 00 00 00 00 00 00 00 00 00 11 0e 01 32
30: 00 00 00 00 00 00 00 00 00 00 00 00 05 01 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 00 00

00:1d.1 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #2 (rev 02)
00: 86 80 d4 24 05 00 80 02 02 00 03 0c 00 00 00 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 21 30 00 00 00 00 00 00 00 00 00 00 11 0e 01 32
30: 00 00 00 00 00 00 00 00 00 00 00 00 05 02 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 00 00

00:1d.2 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #3 (rev 02)
00: 86 80 d7 24 05 00 80 02 02 00 03 0c 00 00 00 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 41 30 00 00 00 00 00 00 00 00 00 00 11 0e 01 32
30: 00 00 00 00 00 00 00 00 00 00 00 00 05 03 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 00 00

00:1d.3 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB UHCI Controller #4 (rev 02)
00: 86 80 de 24 05 00 80 02 02 00 03 0c 00 00 00 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 61 30 00 00 00 00 00 00 00 00 00 00 11 0e 01 32
30: 00 00 00 00 00 00 00 00 00 00 00 00 05 01 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 10 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 00 00

00:1d.7 USB Controller: Intel Corporation 82801EB/ER (ICH5/ICH5R) USB2 EHCI Controller (rev 02)
00: 86 80 dd 24 06 01 90 02 02 20 03 0c 00 00 00 00
10: 00 00 ef fb 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 01 32
30: 00 00 00 00 50 00 00 00 00 00 00 00 05 04 00 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 01 58 c2 c9 00 00 00 00 0a 00 a0 20 00 00 00 00
60: 20 20 ff 01 00 00 00 00 01 00 00 00 00 00 08 c0
70: 00 00 c7 3f 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 55 55 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 80 00 00 88 83 40 00 66 0f 05 00 06 14 00 00

00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev c2)
00: 86 80 4e 24 47 01 80 00 c2 00 04 06 00 00 01 00
10: 00 00 00 00 00 00 00 00 00 01 01 40 10 20 80 02
20: f0 fb f0 fc 30 f0 30 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 03 00
40: 02 28 20 76 00 00 00 00 00 00 00 00 00 00 00 00
50: 02 64 40 00 00 00 00 00 50 01 34 00 00 00 00 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 82 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 01 00 02 00 00 00 c0 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 4b 3b

00:1f.0 ISA bridge: Intel Corporation 82801EB/ER (ICH5/ICH5R) LPC Interface Bridge (rev 02)
00: 86 80 d0 24 4f 01 80 02 02 00 01 06 00 00 80 00
10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
30: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
40: 01 09 00 00 10 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 01 08 00 00 10 00 00 00
60: 85 85 85 85 d0 00 00 00 80 85 85 85 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 06 00 00 00 00 00 00 00
90: ff fc 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 02 01 00 00 00 00 00 0d 00 00 00 00 00 c0 00
b0: 00 00 00 00 00 00 00 00 00 60 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 86 21 02 00 02 0f 00 00 00 00 00 00 00 00 00 00
e0: 10 00 00 ff 00 00 0c 14 00 00 00 00 00 00 67 45
f0: 0f 00 6d 00 04 00 00 00 66 0f 05 1e 00 00 00 00

00:1f.1 IDE interface: Intel Corporation 82801EB/ER (ICH5/ICH5R) IDE Controller (rev 02)
00: 86 80 db 24 07 00 88 02 02 8a 01 01 00 00 00 00
10: f1 01 00 00 f5 03 00 00 71 01 00 00 75 03 00 00
20: 01 05 00 00 00 00 40 f0 00 00 00 00 11 0e 01 32
30: 00 00 00 00 00 00 00 00 00 00 00 00 ff 01 00 00
40: 23 a3 22 80 00 00 00 00 01 00 02 00 00 00 00 00
50: 00 00 00 00 10 00 00 00 00 00 00 00 00 00 00 00
60: 08 00 00 00 00 00 00 00 08 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 66 0f 05 00 00 00 00 00

01:03.0 VGA compatible controller: ATI Technologies Inc Rage XL (rev 27)
00: 02 10 52 47 87 00 90 02 27 00 00 03 10 40 00 00
10: 00 00 00 fc 01 20 00 00 00 00 ff fb 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 1e 00
30: 00 00 00 00 5c 00 00 00 00 00 00 00 ff 00 08 00
40: 0c 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 02 5c 10 00 01 00 00 ff 00 00 00 00 01 00 02 06
60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

01:04.0 System peripheral: Compaq Computer Corporation Integrated Lights Out Controller (rev 01)
00: 11 0e 03 b2 03 01 90 02 01 00 80 08 00 00 80 00
10: 01 18 00 00 00 00 fe fb 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 06 b2
30: 00 00 00 00 f0 00 00 00 00 00 00 00 05 01 00 00
40: 67 00 80 3f 11 00 00 00 00 00 00 00 06 02 06 02
50: 32 81 f0 77 04 cb 00 00 fa 38 fd 77 01 00 00 00
60: ff ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 06 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 0c 00 88 03 43 50 51 00
90: 02 02 00 54 02 00 00 5f 00 00 00 01 00 00 00 15
a0: 00 00 00 00 00 00 02 00 00 00 00 00 04 04 c1 02
b0: 01 08 01 00 00 00 00 00 37 01 50 fe 84 00 03 09
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 01 00 00 00 00 00 00 00 01 00 00 00 00 1b 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 01 00 02 00 00 00 00 00 00 00 00 00 00 00 00 00

01:04.2 System peripheral: Compaq Computer Corporation Integrated Lights Out  Processor (rev 01)
00: 11 0e 04 b2 97 01 90 02 01 00 80 08 10 40 80 00
10: 01 24 00 00 00 00 fd fb 00 00 fc fb 00 00 f0 fb
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 06 b2
30: 00 00 00 00 f0 00 00 00 00 00 00 00 05 02 00 00
40: 04 0d 00 00 00 00 00 00 00 00 00 00 0a 01 15 12
50: 02 e0 7f 00 05 00 33 00 04 00 00 00 00 00 60 00
60: 00 00 10 00 00 00 00 00 85 60 56 05 59 28 82 00
70: 04 08 00 01 03 03 40 00 f8 01 00 80 00 00 00 00
80: c8 03 00 00 ec dc 04 00 fd 0c 77 63 f8 0b 0a 00
90: b8 0b 00 00 03 03 00 00 00 00 00 00 00 00 00 00
a0: 04 06 01 00 80 00 00 00 20 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 e7 81 ff e5 0e 00 00 00 00 00
c0: 01 00 00 00 00 00 02 00 01 00 00 00 00 00 02 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 0b 00 00 00 00 00 00 00 0b 00 00 00
f0: 01 00 02 c8 00 00 00 00 00 00 00 00 00 00 00 00

02:00.0 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge A (rev 09)
00: 86 80 29 03 47 01 10 00 09 00 04 06 10 00 81 00
10: 00 00 00 00 00 00 00 00 02 03 03 40 f0 00 a0 22
20: c0 fd c0 fd f1 ff 01 00 00 00 00 00 00 00 00 00
30: 00 00 00 00 44 00 00 00 00 00 00 00 00 00 03 00
40: 00 6e 08 c1 10 5c 71 00 01 00 00 00 26 20 0c 00
50: 81 f4 03 00 00 00 81 00 00 00 00 00 05 6c 80 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 01 d8 02 c8
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 07 00 c3 00 00 02 00 00
e0: ff ff ff ff ff ff ff ff 01 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00

02:00.2 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge B (rev 09)
00: 86 80 2a 03 47 01 10 00 09 00 04 06 10 00 81 00
10: 00 00 00 00 00 00 00 00 02 04 04 40 40 40 a0 02
20: d0 fd d0 fd 01 f0 01 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 44 00 00 00 00 00 00 00 00 00 03 00
40: 00 6e 08 c5 10 5c 71 00 01 00 00 00 26 20 0c 00
50: 81 f4 03 00 00 00 81 00 00 00 00 00 05 6c 80 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 01 d8 02 c8
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 07 00 c3 00 02 02 00 00
e0: ff ff ff ff ff ff ff ff 01 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00

03:01.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5704 Gigabit Ethernet (rev 10)
00: e4 14 48 16 46 01 b0 02 10 00 00 02 10 40 80 00
10: 04 00 cf fd 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e d0 00
30: 00 00 00 00 40 00 00 00 00 00 00 00 05 01 40 00
40: 07 48 08 00 08 03 43 04 01 50 02 c0 00 21 00 64
50: 03 58 fc 00 00 00 00 78 05 00 86 00 08 fd 3f 0f
60: be f7 f7 eb ed 85 00 00 98 02 00 21 00 40 9f 76
70: ea 30 00 00 c7 00 00 80 10 70 00 00 00 00 00 00
80: f0 66 ea 44 46 00 b3 be 34 00 13 04 82 90 68 00
90: 09 97 00 01 01 00 00 00 00 00 00 00 53 01 00 00
a0: 00 00 00 00 8b 02 00 00 00 00 00 00 e7 01 00 00
b0: 00 00 00 00 00 00 00 1a 04 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

03:01.1 Ethernet controller: Broadcom Corporation NetXtreme BCM5704 Gigabit Ethernet (rev 10)
00: e4 14 48 16 46 01 b0 02 10 00 00 02 10 40 80 00
10: 04 00 ce fd 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e d0 00
30: 00 00 00 00 40 00 00 00 00 00 00 00 05 02 40 00
40: 07 48 08 00 09 03 43 04 01 50 02 c0 00 21 00 64
50: 03 58 fc 00 00 00 00 78 05 00 86 00 f8 35 2a 0d
60: 9f 3a b7 3a 3c e9 00 00 98 02 00 21 00 40 9f 76
70: ea 30 00 00 c7 00 00 80 4c 5b 03 00 00 00 00 00
80: 00 00 00 00 a8 e1 e7 21 34 00 13 04 82 90 28 00
90: 09 97 00 01 01 00 00 00 00 00 00 00 59 01 00 00
a0: 00 00 00 00 91 00 00 00 00 00 00 00 02 00 00 00
b0: 00 00 00 00 00 00 00 94 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

04:03.0 RAID bus controller: Compaq Computer Corporation Smart Array 64xx (rev 01)
00: 11 0e 46 00 57 01 30 02 01 00 04 01 10 40 00 00
10: 04 00 df fd 00 00 00 00 01 40 00 00 04 00 d8 fd
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e 91 40
30: 00 00 00 00 d0 00 00 00 00 00 00 00 05 01 00 00
40: 60 00 a2 11 a1 60 00 00 00 00 00 00 00 00 00 00
50: bf 5f 07 00 00 00 00 00 42 00 00 00 31 10 2e 12
60: 5b 89 2e 64 00 00 00 00 00 00 00 c0 00 00 00 00
70: 01 00 00 e0 00 00 00 c0 00 00 00 00 00 00 00 04
80: 00 41 19 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 01 00 00 00 00 00 00 00 0d e0 ff ff 00 00 fc 40
a0: 00 00 00 00 01 ff ff ff 00 00 00 b0 00 00 00 00
b0: 01 00 fc ff 00 00 f8 ff 00 00 00 00 00 00 00 00
c0: 05 d0 82 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 01 dc 02 02 00 00 00 00 18 00 00 00 07 f0 42 00
e0: 18 04 43 0a 00 00 00 00 00 00 2b 03 00 12 00 07
f0: 03 00 00 00 00 00 00 00 ff ff ff ff ff ff ff ff

05:00.0 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge A (rev 09)
00: 86 80 29 03 47 01 10 00 09 00 04 06 10 00 81 00
10: 00 00 00 00 00 00 00 00 05 06 09 30 50 50 a0 02
20: e0 fd e0 fd 11 f0 11 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 44 00 00 00 00 00 00 00 00 00 03 00
40: 00 2a 08 c3 10 5c 71 00 01 00 00 00 26 20 0c 00
50: 81 f4 03 00 00 00 81 00 00 00 00 00 05 6c 80 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 01 d8 02 c8
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 07 00 03 00 00 05 00 00
e0: ff ff ff ff ff ff ff ff 01 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00

05:00.2 PCI bridge: Intel Corporation 6700PXH PCI Express-to-PCI Bridge B (rev 09)
00: 86 80 2a 03 47 01 10 00 09 00 04 06 10 00 81 00
10: 00 00 00 00 00 00 00 00 05 0a 0c 40 f0 00 a0 22
20: f0 fd f0 fd 21 f0 21 f0 00 00 00 00 00 00 00 00
30: 00 00 00 00 44 00 00 00 00 00 00 00 00 00 03 00
40: 00 6e 08 c1 10 5c 71 00 01 00 00 00 26 20 0c 00
50: 81 f4 03 00 00 00 81 00 00 00 00 00 05 6c 80 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 01 d8 02 c8
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 07 00 c3 00 02 05 00 00
e0: ff ff ff ff ff ff ff ff 01 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00

06:01.0 Ethernet controller: Intel Corporation 82540EM Gigabit Ethernet Controller (rev 02)
00: 86 80 0e 10 57 01 30 02 02 00 00 02 10 40 00 00
10: 00 00 ee fd 00 00 ec fd 01 50 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 86 80 2e 00
30: 00 00 00 00 dc 00 00 00 00 00 00 00 05 01 ff 00
40: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
60: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 01 e4 22 c8
e0: 00 20 00 28 07 f0 02 00 00 00 40 04 00 00 00 00
f0: 05 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00

0a:01.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5703 Gigabit Ethernet (rev 10)
00: e4 14 c7 16 46 01 b0 02 10 00 00 02 10 40 00 00
10: 04 00 ff fd 00 00 00 00 00 00 00 00 00 00 00 00
20: 00 00 00 00 00 00 00 00 00 00 00 00 11 0e ca 00
30: 00 00 00 00 40 00 00 00 00 00 00 00 05 01 40 00
40: 07 48 02 00 09 0a 43 04 01 50 02 c0 00 20 00 64
50: 03 58 fc 80 00 00 00 78 05 00 86 00 fc ff ff ef
60: fe f7 fe ff fe fe 00 00 9a 02 00 11 00 40 9c 76
70: aa 12 00 00 c7 00 00 00 20 70 00 00 00 00 00 00
80: 00 00 00 00 a7 83 7e 7e 34 00 00 00 fe d0 08 00
90: 09 07 00 01 00 00 00 00 00 00 00 00 00 00 00 00
a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

 ------------------------------------------------------
Martin Knoblauch
email: k n o b i AT knobisoft DOT de
www:   http://www.knobisoft.de



----- Original Message ----
> From: Kay Sievers <kay.sievers@vrfy.org>
> To: Andrew Morton <akpm@linux-foundation.org>
> Cc: Martin Knoblauch <knobi@knobisoft.de>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; jbarnes@virtuousgeek.org; matthew@wil.cx; mike.miller@hp.com
> Sent: Wednesday, May 27, 2009 10:56:45 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> On Wed, May 27, 2009 at 22:31, Andrew Morton wrote:
> > On Wed, 27 May 2009 04:25:57 -0700 (PDT)
> > Martin Knoblauch wrote:
> >
> >>  FWIW, I compiled the CCISS driver into the kernel. This makes the second 
> "/sys" line in /proc/mounts go away, dmesg attached. But does it prove anything? 
> The initialization of the CCISS hardware now happens about 2 seconds earlier in 
> the bootup sequence. Does this hint to a problem with CCISS, or just confirms 
> that the whole issue is really timing dependent? Anyway, I add Mike to CC.
> >>
> >
> > It seems that the PCI change caused timing changes which triggered a
> > udev/sysfs/whatever problem, which manifests as the duplicated
> > /proc/mounts entry to turn up.
> >
> > What we don't know (afaik) is why the kernel permitted two entries in
> > /proc/mounts.  That might be a bug.
> >
> > It could be that if dual /proc/mounts problem gets fixed, everything
> > works OK - by intent or by accident, the userspace startup scripts may
> > then work acceptably.
> >
> > I think Al asked you a few questions around the behaviour of mount(8)
> > and the mount syscall, so we could delve further into why /proc/mounts
> > is getting mucked up.  Did you end up running those tests?
> 

 I do not recall any questions from Al. If he asked, I am pretty sure I answered :-)

> I expect the duplicate comes from a left-over mount in initramfs which
> isn't a duplicate in the sense of a bug in vfs or mount or anything. I
> guess, it is just still mounted in the initial kernel rootfs, below
> the root from the disk. It could be that a umount from initramfs did
> go wrong because of a changed timing.
> 

 This is what I suspect as well. I know for sure that the first sysfs-line in /proc/mounts

| none /sys sysfs rw 0 0

is already there (2.6.29-rc1 and up) when entering startup-skripts. It is supposed to be unmounted before, but something seems to prevent it. I have idea how to capture debug output from the initrd/init script :-(

Cheers
Martin

RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Miller, Mike (OS Dev)]

 

> -----Original Message-----
> From: Martin Knoblauch [mailto:knobi@knobisoft.de] 
> Sent: Thursday, May 28, 2009 4:00 AM
> To: Miller, Mike (OS Dev); Owens, James
> Cc: Matthew Wilcox; Andrew Morton; Mike Galbraith; 
> viro@ZenIV.linux.org.uk; rjw@sisk.pl; 
> linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk; 
> Kay Sievers; shemminger@vyatta.com; Jesse Barnes
> Subject: Re: Analyzed/Solved/Bisected: Booting 
> 2.6.30-rc2-git7 very slow
> 
> ----- Original Message ----
> 
> > From: "Miller, Mike (OS Dev)" <Mike.Miller@hp.com>
> > To: "Owens, James" <JOwens@hp.com>; Martin Knoblauch 
> > <knobi@knobisoft.de>
> > Cc: Matthew Wilcox <matthew@wil.cx>; Andrew Morton 
> > <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; 
> > "viro@ZenIV.linux.org.uk" <viro@ZenIV.linux.org.uk>; "rjw@sisk.pl" 
> > <rjw@sisk.pl>; "linux-kernel@vger.kernel.org" 
> > <linux-kernel@vger.kernel.org>; "tigran@aivazian.fsnet.co.uk" 
> > <tigran@aivazian.fsnet.co.uk>; Kay Sievers <kay.sievers@vrfy.org>; 
> > "shemminger@vyatta.com" <shemminger@vyatta.com>; Jesse Barnes 
> > <jbarnes@virtuousgeek.org>
> > Sent: Wednesday, May 27, 2009 8:18:46 PM
> > Subject: RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very 
> > slow
> > 
> > > > 
> > > >  Finally, today I built the ccsii driver into the kernel. 
> > > It was previously modularized and loaded from initrd. The second 
> > > "sysfs" line went away. But does this make cciss guilty? 
> It is now 
> > > loaded about 2 seconds earlier in the boot sequence, 
> which is a big 
> > > change in timing I guess.
> > > > 
> > > >  Enlighten me :-)
> > > 
> > > No idea what is going on, but since I saw your May 20 message, I 
> > > have been trying to wake up someone whose day job it should be to 
> > > care about dl380s and smartarrays. :)
> > 
> > What? I know Martin has pinged me in the past, but I do not 
> think it 
> > was about this issue. If there's multiple sysfs entries for cciss I 
> > can't explain that offhand. We do little to nothing for 
> sysfs in the driver.
> > Had something similiar happen recently where "/" changed to 
> "!". Had 
> > do to with our nested directory structure, /dev/cciss/name vs 
> > /dev/name. But we did not make that change, either.
> > 
> Hi Mike, Jim
> 
>  you are right. I never talked to you about this issue. 
> Actually, I did not suspect CCISS or the DL380 in general to 
> be involved before last week when I retested on the x3650 and 
> the problem went away. Due to day-job and priorities I did 
> not follow up.

Martin,
Same exact OS install? Are you sure all the userspace stuff is the same?

-- mikem
> > 
> > > 
> > > If they don't react soon, I'll make this my own day job to try to 
> > > reproduce it.  We will need hardware config details and firmware 
> > > revs to start.
> > > 
> 
> Dl380/G4
> 2x3.4 GHz CPUs
> 8 GB Memeory
> 4x72 GB as RAID5 on SA6i controller
> 
> BIOS: P51 (07(19/2007)
> ILO FW: 1.91
> SA6i FW: 2.84
> 
> lspci output (-vvv and -xxx) appendend to prevent line wrapping.
> 
> 
> Cheers
> Martin
> 

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: "Miller, Mike (OS Dev)" <Mike.Miller@hp.com>
> To: Martin Knoblauch <knobi@knobisoft.de>; "Owens, James" <JOwens@hp.com>
> Cc: Matthew Wilcox <matthew@wil.cx>; Andrew Morton <akpm@linux-foundation.org>; Mike Galbraith <efault@gmx.de>; "viro@ZenIV.linux.org.uk" <viro@ZenIV.linux.org.uk>; "rjw@sisk.pl" <rjw@sisk.pl>; "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>; "tigran@aivazian.fsnet.co.uk" <tigran@aivazian.fsnet.co.uk>; Kay Sievers <kay.sievers@vrfy.org>; "shemminger@vyatta.com" <shemminger@vyatta.com>; Jesse Barnes <jbarnes@virtuousgeek.org>
> Sent: Thursday, May 28, 2009 9:01:15 PM
> Subject: RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> 
> 
> > -----Original Message-----
> > From: Martin Knoblauch [mailto:knobi@knobisoft.de] 
> > Sent: Thursday, May 28, 2009 4:00 AM
> > To: Miller, Mike (OS Dev); Owens, James
> > Cc: Matthew Wilcox; Andrew Morton; Mike Galbraith; 
> > viro@ZenIV.linux.org.uk; rjw@sisk.pl; 
> > linux-kernel@vger.kernel.org; tigran@aivazian.fsnet.co.uk; 
> > Kay Sievers; shemminger@vyatta.com; Jesse Barnes
> > Subject: Re: Analyzed/Solved/Bisected: Booting 
> > 2.6.30-rc2-git7 very slow
> > 
> > ----- Original Message ----
> > 
> > > From: "Miller, Mike (OS Dev)" 
> > > To: "Owens, James" ; Martin Knoblauch 
> > > 
> > > Cc: Matthew Wilcox ; Andrew Morton 
> > > ; Mike Galbraith ; 
> > > "viro@ZenIV.linux.org.uk" ; "rjw@sisk.pl" 
> > > ; "linux-kernel@vger.kernel.org" 
> > > ; "tigran@aivazian.fsnet.co.uk" 
> > > ; Kay Sievers ; 
> > > "shemminger@vyatta.com" ; Jesse Barnes 
> > > 
> > > Sent: Wednesday, May 27, 2009 8:18:46 PM
> > > Subject: RE: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very 
> > > slow
> > > 
> > > > > 
> > > > >  Finally, today I built the ccsii driver into the kernel. 
> > > > It was previously modularized and loaded from initrd. The second 
> > > > "sysfs" line went away. But does this make cciss guilty? 
> > It is now 
> > > > loaded about 2 seconds earlier in the boot sequence, 
> > which is a big 
> > > > change in timing I guess.
> > > > > 
> > > > >  Enlighten me :-)
> > > > 
> > > > No idea what is going on, but since I saw your May 20 message, I 
> > > > have been trying to wake up someone whose day job it should be to 
> > > > care about dl380s and smartarrays. :)
> > > 
> > > What? I know Martin has pinged me in the past, but I do not 
> > think it 
> > > was about this issue. If there's multiple sysfs entries for cciss I 
> > > can't explain that offhand. We do little to nothing for 
> > sysfs in the driver.
> > > Had something similiar happen recently where "/" changed to 
> > "!". Had 
> > > do to with our nested directory structure, /dev/cciss/name vs 
> > > /dev/name. But we did not make that change, either.
> > > 
> > Hi Mike, Jim
> > 
> >  you are right. I never talked to you about this issue. 
> > Actually, I did not suspect CCISS or the DL380 in general to 
> > be involved before last week when I retested on the x3650 and 
> > the problem went away. Due to day-job and priorities I did 
> > not follow up.
> 
> Martin,
> Same exact OS install? Are you sure all the userspace stuff is the same?
> 

 yup. Exactely same user-space. Same kernel config. Only difference is aacraid vs. cciss module in initrd

> -- mikem
> > > 
> > > > 
> > > > If they don't react soon, I'll make this my own day job to try to 
> > > > reproduce it.  We will need hardware config details and firmware 
> > > > revs to start.
> > > > 
> > 
> > Dl380/G4
> > 2x3.4 GHz CPUs
> > 8 GB Memeory
> > 4x72 GB as RAID5 on SA6i controller
> > 
> > BIOS: P51 (07(19/2007)
> > ILO FW: 1.91
> > SA6i FW: 2.84
> > 
> > lspci output (-vvv and -xxx) appendend to prevent line wrapping.
> > 
> > 
> > Cheers
> > Martin
> > 

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Jesse Barnes]

On Thu, 28 May 2009 02:14:46 -0700 (PDT)
Martin Knoblauch <knobi@knobisoft.de> wrote:
> > I expect the duplicate comes from a left-over mount in initramfs
> > which isn't a duplicate in the sense of a bug in vfs or mount or
> > anything. I guess, it is just still mounted in the initial kernel
> > rootfs, below the root from the disk. It could be that a umount
> > from initramfs did go wrong because of a changed timing.
> > 
> 
>  This is what I suspect as well. I know for sure that the first
> sysfs-line in /proc/mounts
> 
> | none /sys sysfs rw 0 0
> 
> is already there (2.6.29-rc1 and up) when entering startup-skripts.
> It is supposed to be unmounted before, but something seems to prevent
> it. I have idea how to capture debug output from the initrd/init
> script :-(

What's the latest here Martin?  It sounded like this was a userspace
issue, with something reading the VPD over and over?  Or was it just a
longer timeout that caused a specific driver to slow everything down?

-- 
Jesse Barnes, Intel Open Source Technology Center

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: Jesse Barnes <jbarnes@virtuousgeek.org>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Kay Sievers <kay.sievers@vrfy.org>; Andrew Morton <akpm@linux-foundation.org>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; matthew@wil.cx; mike.miller@hp.com
> Sent: Tuesday, June 16, 2009 9:25:47 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> On Thu, 28 May 2009 02:14:46 -0700 (PDT)
> Martin Knoblauch wrote:
> > > I expect the duplicate comes from a left-over mount in initramfs
> > > which isn't a duplicate in the sense of a bug in vfs or mount or
> > > anything. I guess, it is just still mounted in the initial kernel
> > > rootfs, below the root from the disk. It could be that a umount
> > > from initramfs did go wrong because of a changed timing.
> > > 
> > 
> >  This is what I suspect as well. I know for sure that the first
> > sysfs-line in /proc/mounts
> > 
> > | none /sys sysfs rw 0 0
> > 
> > is already there (2.6.29-rc1 and up) when entering startup-skripts.
> > It is supposed to be unmounted before, but something seems to prevent
> > it. I have idea how to capture debug output from the initrd/init
> > script :-(
> 
> What's the latest here Martin?  It sounded like this was a userspace
> issue, with something reading the VPD over and over?  Or was it just a
> longer timeout that caused a specific driver to slow everything down?
> 

 Not sure about the VPD thing. Anyway, no real news. Still happens in 2.6.30. But it only happens on a certain HW platform (HP/DL380G4). The folks at HP try to reproduce in their environment.

Cheers
Martin

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[jim owens]

Martin Knoblauch wrote:
> ----- Original Message ----
> 
>> From: Jesse Barnes <jbarnes@virtuousgeek.org>
>> To: Martin Knoblauch <knobi@knobisoft.de>
>> Cc: Kay Sievers <kay.sievers@vrfy.org>; Andrew Morton <akpm@linux-foundation.org>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; matthew@wil.cx; mike.miller@hp.com
>> Sent: Tuesday, June 16, 2009 9:25:47 PM
>> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
>>
>> On Thu, 28 May 2009 02:14:46 -0700 (PDT)
>> Martin Knoblauch wrote:
>>>> I expect the duplicate comes from a left-over mount in initramfs
>>>> which isn't a duplicate in the sense of a bug in vfs or mount or
>>>> anything. I guess, it is just still mounted in the initial kernel
>>>> rootfs, below the root from the disk. It could be that a umount
>>>> from initramfs did go wrong because of a changed timing.
>>>>
>>>  This is what I suspect as well. I know for sure that the first
>>> sysfs-line in /proc/mounts
>>>
>>> | none /sys sysfs rw 0 0
>>>
>>> is already there (2.6.29-rc1 and up) when entering startup-skripts.
>>> It is supposed to be unmounted before, but something seems to prevent
>>> it. I have idea how to capture debug output from the initrd/init
>>> script :-(
>> What's the latest here Martin?  It sounded like this was a userspace
>> issue, with something reading the VPD over and over?  Or was it just a
>> longer timeout that caused a specific driver to slow everything down?
>>
> 
>  Not sure about the VPD thing. Anyway, no real news. Still happens in 2.6.30. But it only happens on a certain HW platform (HP/DL380G4). The folks at HP try to reproduce in their environment.
> 
> Cheers
> Martin

I reproduced this and verified Martin's analysis.  Conclusions:

    - >>> | none /sys sysfs rw 0 0

is because the initrd "umount /sys" fails with EBUSY

    |commit 1120f8b8169fb2cb51219d326892d963e762edb6
    |Author: Stephen Hemminger <shemminger@vyatta.com>
    |Date:   Thu Dec 18 09:17:16 2008 -0800
    |
    |    PCI: handle long delays in VPD access

does not have a bug.  The longer timeout makes the problem visible.

/sys is busy because udev is trying to read the vpd and the
cciss pci device always fails the vpd with ETIMEOUT.  If all
timeouts are before or after the umount, no firmware load problem.

IMO there is either a vpd read bug on this platform or it is
unsupported and ETIMEOUT is the wrong error.

... now I punt this to the HP platform/driver people.

jim

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Matthew Wilcox]

On Sat, Jun 20, 2009 at 12:37:34PM -0400, jim owens wrote:
> Martin Knoblauch wrote:
>> ----- Original Message ----
>>
>>> From: Jesse Barnes <jbarnes@virtuousgeek.org>
>>> To: Martin Knoblauch <knobi@knobisoft.de>
>>> Cc: Kay Sievers <kay.sievers@vrfy.org>; Andrew Morton <akpm@linux-foundation.org>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; matthew@wil.cx; mike.miller@hp.com
>>> Sent: Tuesday, June 16, 2009 9:25:47 PM
>>> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
>>  Not sure about the VPD thing. Anyway, no real news. Still happens in 2.6.30. But it only happens on a certain HW platform (HP/DL380G4). The folks at HP try to reproduce in their environment.
>
> I reproduced this and verified Martin's analysis.  Conclusions:
>
>    - >>> | none /sys sysfs rw 0 0
>
> is because the initrd "umount /sys" fails with EBUSY
>
>    |commit 1120f8b8169fb2cb51219d326892d963e762edb6
>    |Author: Stephen Hemminger <shemminger@vyatta.com>
>    |Date:   Thu Dec 18 09:17:16 2008 -0800
>    |
>    |    PCI: handle long delays in VPD access
>
> does not have a bug.  The longer timeout makes the problem visible.
>
> /sys is busy because udev is trying to read the vpd and the
> cciss pci device always fails the vpd with ETIMEOUT.  If all
> timeouts are before or after the umount, no firmware load problem.
>
> IMO there is either a vpd read bug on this platform or it is
> unsupported and ETIMEOUT is the wrong error.
>
> ... now I punt this to the HP platform/driver people.

OK, let's add the PCI list in on this too ...

There are a bunch of PCI devices with buggy VPD.  I've got one (it's a prototype card, I think, so I shan't name the vendor).  lspci reports:

        Capabilities: [84] Vital Product Data
                Unknown small resource type 00
[last line repeated about 32768 times]

and it takes for-freaking-ever.  I posted a patch to pciutils on May
13th to fix this:

---

I have several cards which report more-or-less garbage in their VPD.
It can take an extraordinarily long time to read all their VPD and none
of it is of interest.  Instead, if we find an unknown resource type,
just stop trying to read any more.

Signed-off-by: Matthew Wilcox <willy@linux.intel.com>

diff --git a/ls-vpd.c b/ls-vpd.c
index f50d7a4..1ba917f 100644
--- a/ls-vpd.c
+++ b/ls-vpd.c
@@ -204,7 +204,7 @@ cap_vpd(struct device *d)
 	default:
 	  printf("\t\tUnknown %s resource type %02x\n",
 		 (tag & 0x80) ? "large" : "small", tag & ~0x80);
-	  break;
+	  return;
 	}
 
       res_addr += res_len;

-----

but I don't know what udev is doing.  The udev source doesn't seem to
read PCI vpd itself:

udev-0.141$ find -type f |xargs grep -il vpd
./extras/volume_id/lib/adaptec_raid.c
./extras/scsi_id/scsi_id.8
./extras/scsi_id/scsi.h
./extras/scsi_id/scsi_id.config
./extras/scsi_id/scsi_serial.c

so there must be some script that it's invoking which is doing that.
Anyone familiar with udev?

-- 
Matthew Wilcox				Intel Open Source Technology Centre
"Bill, look, we understand that you're interested in selling us this
operating system, but compare it to ours.  We can't possibly take such
a retrograde step."

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Kay Sievers]

On Sat, Jun 20, 2009 at 18:58, Matthew Wilcox<matthew@wil.cx> wrote:

> but I don't know what udev is doing.  The udev source doesn't seem to
> read PCI vpd itself:
>
> udev-0.141$ find -type f |xargs grep -il vpd
> ./extras/volume_id/lib/adaptec_raid.c
> ./extras/scsi_id/scsi_id.8
> ./extras/scsi_id/scsi.h
> ./extras/scsi_id/scsi_id.config
> ./extras/scsi_id/scsi_serial.c
>
> so there must be some script that it's invoking which is doing that.
> Anyone familiar with udev?

scsi_id is usually also called for cciss devices:
  KERNEL=="cciss*", ..., IMPORT{program}="scsi_id ...

Kay

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Matthew Wilcox]

On Sat, Jun 20, 2009 at 08:19:43PM +0200, Kay Sievers wrote:
> On Sat, Jun 20, 2009 at 18:58, Matthew Wilcox<matthew@wil.cx> wrote:
> 
> > but I don't know what udev is doing. ??The udev source doesn't seem to
> > read PCI vpd itself:
> >
> > udev-0.141$ find -type f |xargs grep -il vpd
> > ./extras/volume_id/lib/adaptec_raid.c
> > ./extras/scsi_id/scsi_id.8
> > ./extras/scsi_id/scsi.h
> > ./extras/scsi_id/scsi_id.config
> > ./extras/scsi_id/scsi_serial.c
> >
> > so there must be some script that it's invoking which is doing that.
> > Anyone familiar with udev?
> 
> scsi_id is usually also called for cciss devices:
>   KERNEL=="cciss*", ..., IMPORT{program}="scsi_id ...

yes, but it's getting SCSI VPD (by asking for mode pages from the SCSI
device).  This problem is with PCI VPD which is totally different.

-- 
Matthew Wilcox				Intel Open Source Technology Centre
"Bill, look, we understand that you're interested in selling us this
operating system, but compare it to ours.  We can't possibly take such
a retrograde step."

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Kay Sievers]

On Sat, Jun 20, 2009 at 20:26, Matthew Wilcox<matthew@wil.cx> wrote:
> On Sat, Jun 20, 2009 at 08:19:43PM +0200, Kay Sievers wrote:
>> On Sat, Jun 20, 2009 at 18:58, Matthew Wilcox<matthew@wil.cx> wrote:
>>
>> > but I don't know what udev is doing. ??The udev source doesn't seem to
>> > read PCI vpd itself:
>> >
>> > udev-0.141$ find -type f |xargs grep -il vpd
>> > ./extras/volume_id/lib/adaptec_raid.c
>> > ./extras/scsi_id/scsi_id.8
>> > ./extras/scsi_id/scsi.h
>> > ./extras/scsi_id/scsi_id.config
>> > ./extras/scsi_id/scsi_serial.c
>> >
>> > so there must be some script that it's invoking which is doing that.
>> > Anyone familiar with udev?
>>
>> scsi_id is usually also called for cciss devices:
>>   KERNEL=="cciss*", ..., IMPORT{program}="scsi_id ...
>
> yes, but it's getting SCSI VPD (by asking for mode pages from the SCSI
> device).  This problem is with PCI VPD which is totally different.

Ah, I see. There is no tool around udev, I know of, which does this.

Maybe someone is still using the broken-by-design libsysfs, which
opens _every_ file it can find in /sys, even when not asked for
anything specific.

Thanks,
Kay

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Matthew Wilcox]

On Sat, Jun 20, 2009 at 08:36:25PM +0200, Kay Sievers wrote:
> Ah, I see. There is no tool around udev, I know of, which does this.
> 
> Maybe someone is still using the broken-by-design libsysfs, which
> opens _every_ file it can find in /sys, even when not asked for
> anything specific.

I did consider that option, but dismissed it ... I didn't think anyone
was using something that old.  Martin, could you take a look at what
scripts you're running?

-- 
Matthew Wilcox				Intel Open Source Technology Centre
"Bill, look, we understand that you're interested in selling us this
operating system, but compare it to ours.  We can't possibly take such
a retrograde step."

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[jim owens]

Matthew Wilcox wrote:
> On Sat, Jun 20, 2009 at 08:36:25PM +0200, Kay Sievers wrote:
>> Ah, I see. There is no tool around udev, I know of, which does this.
>>
>> Maybe someone is still using the broken-by-design libsysfs, which
>> opens _every_ file it can find in /sys, even when not asked for
>> anything specific.
> 
> I did consider that option, but dismissed it ... I didn't think anyone
> was using something that old.

My test is a fresh RHEL 4.3 install with 2.6.30-rc8.  Whatever
scripts are running are stock redhat and I'm still in initrd
so what would I be looking for?

The initrd timeouts all seem to be triggered by the insmod and
only 1 more vpd read happens in init 3 at the end after HAL starts.

This is the BUG() I set to ID (maybe incorrectly)
that the vpd reads were comming from udev:

[    5.260664] ------------[ cut here ]------------
[    5.260667] kernel BUG at 
/root/linux-2.6.30-rc8/drivers/pci/access.c:207!
[    5.260671] invalid opcode: 0000 [#1] SMP
[    5.260675] last sysfs file: 
/sys/devices/pci0000:00/0000:00:02.0/0000:02:00.2/0000:04:03.0/msi_bus
[    5.260678] CPU 1
[    5.260681] Modules linked in: cciss(+) sd_mod scsi_mod
[    5.260689] Pid: 476, comm: udev Not tainted 2.6.30-rc8 #33 ProLiant 
DL380 G4
[    5.260692] RIP: 0010:[<ffffffff803b282f>]  [<ffffffff803b282f>] 
pci_vpd_pci22_wait+0xef/0x100
[    5.260703] RSP: 0018:ffff8801199e7dd8  EFLAGS: 00010246
[    5.260706] RAX: 0000000000000000 RBX: ffff88011ad60440 RCX: 
0000000000001001
[    5.260709] RDX: 0000000000007c7b RSI: 0000000000000001 RDI: 
ffffffff8072c160
[    5.260712] RBP: ffff8801199e7e08 R08: 0000000000000001 R09: 
0000000000000001
[    5.260715] R10: 0000000000000000 R11: 0000000000000006 R12: 
ffff88011ac8d800
[    5.260718] R13: 00000000fffee028 R14: ffff88011ac8d800 R15: 
ffff88011992e000
[    5.260722] FS:  0000000000000000(0000) GS:ffff88002edd9000(0000) 
knlGS:0000000000000000
[    5.260725] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[    5.260728] CR2: 00000000022562b8 CR3: 00000001198ef000 CR4: 
00000000000006e0
[    5.260731] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 
0000000000000000
[    5.260734] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 
0000000000000400
[    5.260738] Process udev (pid: 476, threadinfo ffff8801199e6000, task 
ffff88011b78c3c0)
[    5.260740] Stack:
[    5.260742]  ffff8801199e7e08 0000ffff803b268d 0000000000001000 
0000000000000000
[    5.260746]  0000000000000000 ffff88011ad60440 ffff8801199e7e68 
ffffffff803b292c
[    5.260752]  ffffffff803455f6 ffff88011ad60458 0000000000001000 
0000000000001000
[    5.260757] Call Trace:
[    5.260760]  [<ffffffff803b292c>] pci_vpd_pci22_read+0xec/0x170
[    5.260765]  [<ffffffff803455f6>] ? read+0x96/0x1b0
[    5.260771]  [<ffffffff803b22a9>] pci_read_vpd+0x29/0x40
[    5.260775]  [<ffffffff803bab06>] read_vpd_attr+0x46/0x50
[    5.260780]  [<ffffffff803456fb>] read+0x19b/0x1b0
[    5.260784]  [<ffffffff80363566>] ? security_file_permission+0x16/0x20
[    5.260790]  [<ffffffff802e3f5d>] vfs_read+0xbd/0x190
[    5.260797]  [<ffffffff802e4365>] sys_read+0x55/0x90
[    5.260801]  [<ffffffff8020b71b>] system_call_fastpath+0x16/0x1b
[    5.260807] Code: c9 c3 8b 35 74 33 fe 00 31 c0 4c 89 e2 48 c7 c7 ed 
89 6a 80 e8 b3 3d e9 ff 8b 05 5d 33 fe 00 ff c0 89 05 55 33 fe 00 ff c8 
75 04 <0f> 0b eb fe b8 92 ff ff ff e9 35 ff ff ff 66 66 90 55 48 89 e5
[    5.260845] RIP  [<ffffffff803b282f>] pci_vpd_pci22_wait+0xef/0x100
[    5.260849]  RSP <ffff8801199e7dd8>
[    5.260854] ---[ end trace 37f1683404a28980 ]---


here is a single user boot with a timeout printk() and a hack
in mkinitrd to sleep before and after the insmod cciss:

[    3.858278] NET: Registered protocol family 17
[    3.864293] Freeing unused kernel memory: 2416k freed
Red Hat nash version 4.2.1.6 starting
Mounted /proc filesystem
Mounting sysfs
Creating /dev
Starting udev
[    3.876470] udev used greatest stack depth: 5632 bytes left
Loading scsi_mod.ko module
[    3.977087] SCSI subsystem initialized
Loading sd_mod.ko module
[    3.987672] Driver 'sd' needs updating - please use bus_type methods
[    4.280095] input: AT Translated Set 2 keyboard as /class/input/input0
[    4.626432] input: PS/2 Generic Mouse as /class/input/input1
JIM sleep 1
Loading cciss.ko module
[    4.999782] HP CISS Driver (v 3.6.20)
[    5.003771] cciss 0000:04:03.0: PCI INT A -> GSI 51 (level, low) -> 
IRQ 51
[    5.052021] IRQ 51/cciss0: IRQF_DISABLED is not guaranteed on shared IRQs
[    5.059001] cciss0: <0x46> at PCI 0000:04:03.0 IRQ 51 using DAC
[    5.065800]       blocks= 71122560 block_size= 512
[    5.070602]       heads=255, sectors=32, cylinders=8716
[    5.070603]
[    5.077428]       blocks= 71122560 block_size= 512
[    5.082151]       heads=255, sectors=32, cylinders=8716
[    5.082153]
[    5.089413]  cciss/c0d0: p1
[    5.131820]       blocks= 71122560 block_size= 512
[    5.139627]       heads=255, sectors=32, cylinders=8716
[    5.139629]
[    5.146117]       blocks= 71122560 block_size= 512
[    5.150887]       heads=255, sectors=32, cylinders=8716
[    5.150889]
[    5.157577]  cciss/c0d1: p1
[    5.160261] TIMEOUT 1 ffff88011ad54800
[    5.164164]  p2 p3
[    5.208880]       blocks= 142253280 block_size= 512
[    5.215732]       heads=255, sectors=32, cylinders=17433
[    5.215734]
[    5.223191]       blocks= 142253280 block_size= 512
[    5.227965]
[    5.227966] TIMEOUT 2 ffff88011ad54800
[    5.232942]       heads=255, sectors=32, cylinders=17433
[    5.232944]
[    5.239516]  cciss/c0d2: p1 p2 p3
[    5.292263]
[    5.292265] TIMEOUT 3 ffff88011ad54800
[    5.356262]
[    5.356263] TIMEOUT 4 ffff88011ad54800
[    5.420266]
[    5.420267] TIMEOUT 5 ffff88011ad54800
[    5.484855]
[    5.484857] TIMEOUT 6 ffff88011ad54800
[    5.491980]       blocks= 71122560 block_size= 512
[    5.496991]       heads=255, sectors=32, cylinders=8716
[    5.496993]
[    5.503484]       blocks= 71122560 block_size= 512
[    5.508761]       heads=255, sectors=32, cylinders=8716
[    5.508763]
[    5.515729]  cciss/c0d3: p1
[    5.548263]
[    5.548264] TIMEOUT 7 ffff88011ad54800
[    5.610138] work_for_cpu used greatest stack depth: 4592 bytes left
[    5.612264]
[    5.612266] TIMEOUT 8 ffff88011ad54800
[    5.674223]
[    5.674224] TIMEOUT 9 ffff88011ad54800
[    5.736261]
[    5.736263] TIMEOUT 10 ffff88011ad54800
[    5.800261]
[    5.800263] TIMEOUT 11 ffff88011ad54800
[    5.864259]
[    5.864260] TIMEOUT 12 ffff88011ad54800
[    5.928259]
[    5.928260] TIMEOUT 13 ffff88011ad54800
[    5.992011]
[    5.992012] TIMEOUT 14 ffff88011ad54800
[    6.056011]
[    6.056012] TIMEOUT 15 ffff88011ad54800
[    6.120011]
[    6.120013] TIMEOUT 16 ffff88011ad54800
[    6.184011]
[    6.184012] TIMEOUT 17 ffff88011ad54800
[    6.248011]
[    6.248012] TIMEOUT 18 ffff88011ad54800
[    6.312011]
[    6.312012] TIMEOUT 19 ffff88011ad54800
[    6.376011]
[    6.376013] TIMEOUT 20 ffff88011ad54800
JIM sleep 1
Loading jbd.ko module
Loading ext3.ko module
Creating root device
Mounting root filesystem
[    6.760540] kjournald starting.  Commit interval 5 seconds
[    6.765559] EXT3-fs: mounted filesystem with writeback data mode.
Switching to new root
[    6.946395] SELinux:  Disabled at runtime.
[    6.950840] type=1404 audit(1245517131.950:2): selinux=0 
auid=4294967295 ses=4294967295
INIT: version 2.85 booting
[    7.235810] uname used greatest stack depth: 4296 bytes left
[    7.304350] awk used greatest stack depth: 3688 bytes left
		Welcome to Red Hat Enterprise Linux AS
		Press 'I' to enter interactive startup.
Starting udev:  [  OK  ]
Initializing hardware...  storage network audio done[  OK  ]
Configuring kernel parameters:  [  OK  ]
Setting clock  (utc): Sat Jun 20 12:59:02 EDT 2009 [  OK  ]
Setting hostname dl380.lnx.usa.hp.com:  [  OK  ]
Checking root filesystem
[/sbin/fsck.ext3 (1) -- /] fsck.ext3 -a /dev/cciss/c0d1p3
/1: clean, 348377/4177920 files, 2477319/8351791 blocks
[  OK  ]
Remounting root filesystem in read-write mode:  [  OK  ]
No devices found
no block devices found
Setting up Logical Volume Management: [  OK  ]
Checking filesystems
Checking all file systems.
[/sbin/fsck.ext3 (1) -- /boot] fsck.ext3 -a /dev/cciss/c0d1p1
/boot12: clean, 46/26104 files, 26042/104388 blocks
[  OK  ]
Mounting local filesystems:  [  OK  ]
Enabling local filesystem quotas:  [  OK  ]
Enabling swap space:  [  OK  ]
sh-3.00#

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: jim owens <jowens@hp.com>
> To: Martin Knoblauch <knobi@knobisoft.de>
> Cc: Jesse Barnes <jbarnes@virtuousgeek.org>; Kay Sievers <kay.sievers@vrfy.org>; Andrew Morton <akpm@linux-foundation.org>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; matthew@wil.cx; mike.miller@hp.com
> Sent: Saturday, June 20, 2009 6:37:34 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> Martin Knoblauch wrote:
> > ----- Original Message ----
> > 
> >> From: Jesse Barnes 
> >> To: Martin Knoblauch 
> >> Cc: Kay Sievers ; Andrew Morton 
> ; efault@gmx.de; viro@zeniv.linux.org.uk; 
> rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; 
> matthew@wil.cx; mike.miller@hp.com
> >> Sent: Tuesday, June 16, 2009 9:25:47 PM
> >> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> >> 
> >> On Thu, 28 May 2009 02:14:46 -0700 (PDT)
> >> Martin Knoblauch wrote:
> >>>> I expect the duplicate comes from a left-over mount in initramfs
> >>>> which isn't a duplicate in the sense of a bug in vfs or mount or
> >>>> anything. I guess, it is just still mounted in the initial kernel
> >>>> rootfs, below the root from the disk. It could be that a umount
> >>>> from initramfs did go wrong because of a changed timing.
> >>>> 
> >>>  This is what I suspect as well. I know for sure that the first
> >>> sysfs-line in /proc/mounts
> >>> 
> >>> | none /sys sysfs rw 0 0
> >>> 
> >>> is already there (2.6.29-rc1 and up) when entering startup-skripts.
> >>> It is supposed to be unmounted before, but something seems to prevent
> >>> it. I have idea how to capture debug output from the initrd/init
> >>> script :-(
> >> What's the latest here Martin?  It sounded like this was a userspace
> >> issue, with something reading the VPD over and over?  Or was it just a
> >> longer timeout that caused a specific driver to slow everything down?
> >> 
> > 
> >  Not sure about the VPD thing. Anyway, no real news. Still happens in 2.6.30. 
> But it only happens on a certain HW platform (HP/DL380G4). The folks at HP try 
> to reproduce in their environment.
> > 
> > Cheers
> > Martin
> 
> I reproduced this and verified Martin's analysis.  Conclusions:
>

 Cool, so I am not seeing gremlins :-)

Cheers
Martin 

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[Martin Knoblauch]

----- Original Message ----

> From: jim owens <jowens@hp.com>
> To: Matthew Wilcox <matthew@wil.cx>
> Cc: Kay Sievers <kay.sievers@vrfy.org>; Martin Knoblauch <knobi@knobisoft.de>; Jesse Barnes <jbarnes@virtuousgeek.org>; Andrew Morton <akpm@linux-foundation.org>; efault@gmx.de; viro@zeniv.linux.org.uk; rjw@sisk.pl; linux-kernel@vger.kernel.org; shemminger@vyatta.com; mike.miller@hp.com; linux-pci@vger.kernel.org
> Sent: Saturday, June 20, 2009 11:17:06 PM
> Subject: Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow
> 
> Matthew Wilcox wrote:
> > On Sat, Jun 20, 2009 at 08:36:25PM +0200, Kay Sievers wrote:
> >> Ah, I see. There is no tool around udev, I know of, which does this.
> >> 
> >> Maybe someone is still using the broken-by-design libsysfs, which
> >> opens _every_ file it can find in /sys, even when not asked for
> >> anything specific.
> > 
> > I did consider that option, but dismissed it ... I didn't think anyone
> > was using something that old.
> 
> My test is a fresh RHEL 4.3 install with 2.6.30-rc8.  Whatever
> scripts are running are stock redhat and I'm still in initrd
> so what would I be looking for?
> 

 same here. Anything in initrd is stock RedHat stuff, except the kernel modules

> The initrd timeouts all seem to be triggered by the insmod and
> only 1 more vpd read happens in init 3 at the end after HAL starts.
> 
> This is the BUG() I set to ID (maybe incorrectly)
> that the vpd reads were comming from udev:
> 
> [    5.260664] ------------[ cut here ]------------
> [    5.260667] kernel BUG at /root/linux-2.6.30-rc8/drivers/pci/access.c:207!
> [    5.260671] invalid opcode: 0000 [#1] SMP
> [    5.260675] last sysfs file: 
> /sys/devices/pci0000:00/0000:00:02.0/0000:02:00.2/0000:04:03.0/msi_bus
> [    5.260678] CPU 1
> [    5.260681] Modules linked in: cciss(+) sd_mod scsi_mod
> [    5.260689] Pid: 476, comm: udev Not tainted 2.6.30-rc8 #33 ProLiant DL380 G4
> [    5.260692] RIP: 0010:[]  [] 
> pci_vpd_pci22_wait+0xef/0x100
> [    5.260703] RSP: 0018:ffff8801199e7dd8  EFLAGS: 00010246
> [    5.260706] RAX: 0000000000000000 RBX: ffff88011ad60440 RCX: 0000000000001001
> [    5.260709] RDX: 0000000000007c7b RSI: 0000000000000001 RDI: ffffffff8072c160
> [    5.260712] RBP: ffff8801199e7e08 R08: 0000000000000001 R09: 0000000000000001
> [    5.260715] R10: 0000000000000000 R11: 0000000000000006 R12: ffff88011ac8d800
> [    5.260718] R13: 00000000fffee028 R14: ffff88011ac8d800 R15: ffff88011992e000
> [    5.260722] FS:  0000000000000000(0000) GS:ffff88002edd9000(0000) 
> knlGS:0000000000000000
> [    5.260725] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> [    5.260728] CR2: 00000000022562b8 CR3: 00000001198ef000 CR4: 00000000000006e0
> [    5.260731] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [    5.260734] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> [    5.260738] Process udev (pid: 476, threadinfo ffff8801199e6000, task 
> ffff88011b78c3c0)
> [    5.260740] Stack:
> [    5.260742]  ffff8801199e7e08 0000ffff803b268d 0000000000001000 
> 0000000000000000
> [    5.260746]  0000000000000000 ffff88011ad60440 ffff8801199e7e68 
> ffffffff803b292c
> [    5.260752]  ffffffff803455f6 ffff88011ad60458 0000000000001000 
> 0000000000001000
> [    5.260757] Call Trace:
> [    5.260760]  [] pci_vpd_pci22_read+0xec/0x170
> [    5.260765]  [] ? read+0x96/0x1b0
> [    5.260771]  [] pci_read_vpd+0x29/0x40
> [    5.260775]  [] read_vpd_attr+0x46/0x50
> [    5.260780]  [] read+0x19b/0x1b0
> [    5.260784]  [] ? security_file_permission+0x16/0x20
> [    5.260790]  [] vfs_read+0xbd/0x190
> [    5.260797]  [] sys_read+0x55/0x90
> [    5.260801]  [] system_call_fastpath+0x16/0x1b
> [    5.260807] Code: c9 c3 8b 35 74 33 fe 00 31 c0 4c 89 e2 48 c7 c7 ed 89 6a 80 
> e8 b3 3d e9 ff 8b 05 5d 33 fe 00 ff c0 89 05 55 33 fe 00 ff c8 75 04 <0f> 0b eb 
> fe b8 92 ff ff ff e9 35 ff ff ff 66 66 90 55 48 89 e5
> [    5.260845] RIP  [] pci_vpd_pci22_wait+0xef/0x100
> [    5.260849]  RSP 
> [    5.260854] ---[ end trace 37f1683404a28980 ]---
> 
> 
> here is a single user boot with a timeout printk() and a hack
> in mkinitrd to sleep before and after the insmod cciss:
>

 How do you get to see the debug-output from initrd? I never managed that.
 
> [    3.858278] NET: Registered protocol family 17
> [    3.864293] Freeing unused kernel memory: 2416k freed
> Red Hat nash version 4.2.1.6 starting
> Mounted /proc filesystem
> Mounting sysfs
> Creating /dev
> Starting udev
> [    3.876470] udev used greatest stack depth: 5632 bytes left
> Loading scsi_mod.ko module
> [    3.977087] SCSI subsystem initialized
> Loading sd_mod.ko module
> [    3.987672] Driver 'sd' needs updating - please use bus_type methods
> [    4.280095] input: AT Translated Set 2 keyboard as /class/input/input0
> [    4.626432] input: PS/2 Generic Mouse as /class/input/input1
> JIM sleep 1
> Loading cciss.ko module
> [    4.999782] HP CISS Driver (v 3.6.20)
> [    5.003771] cciss 0000:04:03.0: PCI INT A -> GSI 51 (level, low) -> IRQ 51
> [    5.052021] IRQ 51/cciss0: IRQF_DISABLED is not guaranteed on shared IRQs
> [    5.059001] cciss0: <0x46> at PCI 0000:04:03.0 IRQ 51 using DAC
> [    5.065800]       blocks= 71122560 block_size= 512
> [    5.070602]       heads=255, sectors=32, cylinders=8716
> [    5.070603]
> [    5.077428]       blocks= 71122560 block_size= 512
> [    5.082151]       heads=255, sectors=32, cylinders=8716
> [    5.082153]
> [    5.089413]  cciss/c0d0: p1
> [    5.131820]       blocks= 71122560 block_size= 512
> [    5.139627]       heads=255, sectors=32, cylinders=8716
> [    5.139629]
> [    5.146117]       blocks= 71122560 block_size= 512
> [    5.150887]       heads=255, sectors=32, cylinders=8716
> [    5.150889]
> [    5.157577]  cciss/c0d1: p1
> [    5.160261] TIMEOUT 1 ffff88011ad54800
> [    5.164164]  p2 p3
> [    5.208880]       blocks= 142253280 block_size= 512
> [    5.215732]       heads=255, sectors=32, cylinders=17433
> [    5.215734]
> [    5.223191]       blocks= 142253280 block_size= 512
> [    5.227965]
> [    5.227966] TIMEOUT 2 ffff88011ad54800
> [    5.232942]       heads=255, sectors=32, cylinders=17433
> [    5.232944]
> [    5.239516]  cciss/c0d2: p1 p2 p3
> [    5.292263]
> [    5.292265] TIMEOUT 3 ffff88011ad54800
> [    5.356262]
> [    5.356263] TIMEOUT 4 ffff88011ad54800
> [    5.420266]
> [    5.420267] TIMEOUT 5 ffff88011ad54800
> [    5.484855]
> [    5.484857] TIMEOUT 6 ffff88011ad54800
> [    5.491980]       blocks= 71122560 block_size= 512
> [    5.496991]       heads=255, sectors=32, cylinders=8716
> [    5.496993]
> [    5.503484]       blocks= 71122560 block_size= 512
> [    5.508761]       heads=255, sectors=32, cylinders=8716
> [    5.508763]
> [    5.515729]  cciss/c0d3: p1
> [    5.548263]
> [    5.548264] TIMEOUT 7 ffff88011ad54800
> [    5.610138] work_for_cpu used greatest stack depth: 4592 bytes left
> [    5.612264]
> [    5.612266] TIMEOUT 8 ffff88011ad54800
> [    5.674223]
> [    5.674224] TIMEOUT 9 ffff88011ad54800
> [    5.736261]
> [    5.736263] TIMEOUT 10 ffff88011ad54800
> [    5.800261]
> [    5.800263] TIMEOUT 11 ffff88011ad54800
> [    5.864259]
> [    5.864260] TIMEOUT 12 ffff88011ad54800
> [    5.928259]
> [    5.928260] TIMEOUT 13 ffff88011ad54800
> [    5.992011]
> [    5.992012] TIMEOUT 14 ffff88011ad54800
> [    6.056011]
> [    6.056012] TIMEOUT 15 ffff88011ad54800
> [    6.120011]
> [    6.120013] TIMEOUT 16 ffff88011ad54800
> [    6.184011]
> [    6.184012] TIMEOUT 17 ffff88011ad54800
> [    6.248011]
> [    6.248012] TIMEOUT 18 ffff88011ad54800
> [    6.312011]
> [    6.312012] TIMEOUT 19 ffff88011ad54800
> [    6.376011]
> [    6.376013] TIMEOUT 20 ffff88011ad54800
> JIM sleep 1
> Loading jbd.ko module
> Loading ext3.ko module
> Creating root device
> Mounting root filesystem
> [    6.760540] kjournald starting.  Commit interval 5 seconds
> [    6.765559] EXT3-fs: mounted filesystem with writeback data mode.
> Switching to new root
> [    6.946395] SELinux:  Disabled at runtime.
> [    6.950840] type=1404 audit(1245517131.950:2): selinux=0 auid=4294967295 
> ses=4294967295
> INIT: version 2.85 booting
> [    7.235810] uname used greatest stack depth: 4296 bytes left
> [    7.304350] awk used greatest stack depth: 3688 bytes left
>         Welcome to Red Hat Enterprise Linux AS
>         Press 'I' to enter interactive startup.
> Starting udev:  [  OK  ]
> Initializing hardware...  storage network audio done[  OK  ]
> Configuring kernel parameters:  [  OK  ]
> Setting clock  (utc): Sat Jun 20 12:59:02 EDT 2009 [  OK  ]
> Setting hostname dl380.lnx.usa.hp.com:  [  OK  ]
> Checking root filesystem
> [/sbin/fsck.ext3 (1) -- /] fsck.ext3 -a /dev/cciss/c0d1p3
> /1: clean, 348377/4177920 files, 2477319/8351791 blocks
> [  OK  ]
> Remounting root filesystem in read-write mode:  [  OK  ]
> No devices found
> no block devices found
> Setting up Logical Volume Management: [  OK  ]
> Checking filesystems
> Checking all file systems.
> [/sbin/fsck.ext3 (1) -- /boot] fsck.ext3 -a /dev/cciss/c0d1p1
> /boot12: clean, 46/26104 files, 26042/104388 blocks
> [  OK  ]
> Mounting local filesystems:  [  OK  ]
> Enabling local filesystem quotas:  [  OK  ]
> Enabling swap space:  [  OK  ]
> sh-3.00#

Re: Analyzed/Solved/Bisected: Booting 2.6.30-rc2-git7 very slow

[jim owens]

Martin Knoblauch wrote:
> 
>  How do you get to see the debug-output from initrd? I never managed that.

I did all my boot testing from ILO with VSP for a serial console.

jim