linux-input.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* Slow boot due perhaps to locks in mouse and platform system
@ 2008-10-14 14:19 Phil Endecott
  2008-10-14 14:54 ` Dmitry Torokhov
  0 siblings, 1 reply; 13+ messages in thread
From: Phil Endecott @ 2008-10-14 14:19 UTC (permalink / raw)
  To: linux-input

Dear All,

I am seeing a 2-second pause while booting which I hypothesize is due 
to a locking interaction between the mouse system and the platform bus 
system.  Here's a fragment from dmesg:

[    2.202156] serio: i8042 KBD port at 0x60,0x64 irq 1
[    2.202170] serio: i8042 AUX port at 0x60,0x64 irq 12
[    2.202183] initcall i8042_init+0x0/0x32a returned 0 after 29 msecs
[    2.202191] calling  serio_raw_init+0x0/0x11 @ 1
[    2.202345] initcall serio_raw_init+0x0/0x11 returned 0 after 0 msecs
[    2.202356] calling  mousedev_init+0x0/0x72 @ 1
[    2.202638] mice: PS/2 mouse device common for all mice
[    2.202648] initcall mousedev_init+0x0/0x72 returned 0 after 0 msecs
[    2.202657] calling  evdev_init+0x0/0xa @ 1
[    2.208739] initcall evdev_init+0x0/0xa returned 0 after 5 msecs
[    2.208746] calling  atkbd_init+0x0/0x1b @ 1
[    2.208855] initcall atkbd_init+0x0/0x1b returned 0 after 0 msecs
[    2.208864] calling  psmouse_init+0x0/0x58 @ 1
[    2.232546] input: AT Translated Set 2 keyboard as /class/input/input5
[    2.247037] initcall psmouse_init+0x0/0x58 returned 0 after 36 msecs
[    2.247047] calling  pcspkr_init+0x0/0xa @ 1
[    2.247067] pcspkr_probe starting
[    2.249202] input: PC Speaker as /class/input/input6
[    2.259239] pcspkr_probe done
[    4.379527] input: ImPS/2 Logitech Wheel Mouse as /class/input/input7
[    4.387077] initcall pcspkr_init+0x0/0xa returned 0 after 2040 msecs

Note that the pause is between pcspkr_probe returning and pcspkr_init 
returning.  My guess is that during this time the platform bus is 
matching the pcspkr driver against all the other platform devices, and 
in order to do so it is taking various device locks; at the same time 
the kpsmoused workqueue is locking one of the same devices and spending 
a couple of seconds probing it.  But that's only a guess based on a 
couple of hours work; no doubt you experts will have a better idea of 
what's going on.

What can be done about this?  Is it unreasonable for the mouse probing 
to take 2 seconds?  Should it not be holding the conflicting lock while 
it is probing?  Does the platform matching code really need to hold the 
lock when it's just comparing the string names of the device and driver?

This is on an ASUS Eee 901, which is the same machine that Arjan van de 
Ven and Auke Kok have got to boot in 5 seconds (with only 1 second of 
that in the kernel).  As you can see I have some way to go still.  I 
would also be interested to hear if anyone knows what the touchpad in 
this machine really is - is "ImPS/2 Logitech Wheel Mouse" right?  I'd 
like to be able to tweak things like tap-to-click and two-finger scrolling.

Cheers,  Phil.




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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 14:19 Slow boot due perhaps to locks in mouse and platform system Phil Endecott
@ 2008-10-14 14:54 ` Dmitry Torokhov
  2008-10-14 15:12   ` Arjan van de Ven
  0 siblings, 1 reply; 13+ messages in thread
From: Dmitry Torokhov @ 2008-10-14 14:54 UTC (permalink / raw)
  To: Phil Endecott; +Cc: linux-input, Ingo Molnar

Hi Phil,

On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> Dear All,
>
> I am seeing a 2-second pause while booting which I hypothesize is due to a 
> locking interaction between the mouse system and the platform bus system.  
> Here's a fragment from dmesg:
>
> [    2.202156] serio: i8042 KBD port at 0x60,0x64 irq 1
> [    2.202170] serio: i8042 AUX port at 0x60,0x64 irq 12
> [    2.202183] initcall i8042_init+0x0/0x32a returned 0 after 29 msecs
> [    2.202191] calling  serio_raw_init+0x0/0x11 @ 1
> [    2.202345] initcall serio_raw_init+0x0/0x11 returned 0 after 0 msecs
> [    2.202356] calling  mousedev_init+0x0/0x72 @ 1
> [    2.202638] mice: PS/2 mouse device common for all mice
> [    2.202648] initcall mousedev_init+0x0/0x72 returned 0 after 0 msecs
> [    2.202657] calling  evdev_init+0x0/0xa @ 1
> [    2.208739] initcall evdev_init+0x0/0xa returned 0 after 5 msecs
> [    2.208746] calling  atkbd_init+0x0/0x1b @ 1
> [    2.208855] initcall atkbd_init+0x0/0x1b returned 0 after 0 msecs
> [    2.208864] calling  psmouse_init+0x0/0x58 @ 1
> [    2.232546] input: AT Translated Set 2 keyboard as /class/input/input5
> [    2.247037] initcall psmouse_init+0x0/0x58 returned 0 after 36 msecs
> [    2.247047] calling  pcspkr_init+0x0/0xa @ 1
> [    2.247067] pcspkr_probe starting
> [    2.249202] input: PC Speaker as /class/input/input6
> [    2.259239] pcspkr_probe done
> [    4.379527] input: ImPS/2 Logitech Wheel Mouse as /class/input/input7
> [    4.387077] initcall pcspkr_init+0x0/0xa returned 0 after 2040 msecs
>
> Note that the pause is between pcspkr_probe returning and pcspkr_init 
> returning.  My guess is that during this time the platform bus is matching 
> the pcspkr driver against all the other platform devices, and in order to 
> do so it is taking various device locks; at the same time the kpsmoused 
> workqueue is locking one of the same devices and spending a couple of 
> seconds probing it.  But that's only a guess based on a couple of hours 
> work; no doubt you experts will have a better idea of what's going on.
>

Hmm, I am not sure here. Psmouse module works on serio bus (with
devices registered by i8042). The real probing is offloaded to kseriod
as it may take a while (as in couple of seconds) to go through all
possible mice protocols - you can see it because psmouse_init returns
early, before the mouse is detected. Pcspkr works on platform bus. The
only thing they share is input device registration but I don't believe
we get stuck there. I wonder if this is a sign of scheduling problem
early in the boot, lets CC Ingo and see if he has any ideas.

> What can be done about this?  Is it unreasonable for the mouse probing to 
> take 2 seconds?  Should it not be holding the conflicting lock while it is 
> probing?  Does the platform matching code really need to hold the lock when 
> it's just comparing the string names of the device and driver?
>
> This is on an ASUS Eee 901, which is the same machine that Arjan van de Ven 
> and Auke Kok have got to boot in 5 seconds (with only 1 second of that in 
> the kernel).  As you can see I have some way to go still.  I would also be 
> interested to hear if anyone knows what the touchpad in this machine really 
> is - is "ImPS/2 Logitech Wheel Mouse" right?  I'd like to be able to tweak 
> things like tap-to-click and two-finger scrolling.
>

I believe Eee PCs use Elantech touchpad for which we have a driver from
Arjan Opmeer which should be merged real soon now.

-- 
Dmitry

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 14:54 ` Dmitry Torokhov
@ 2008-10-14 15:12   ` Arjan van de Ven
  2008-10-14 15:29     ` Dmitry Torokhov
  2008-10-14 16:18     ` Phil Endecott
  0 siblings, 2 replies; 13+ messages in thread
From: Arjan van de Ven @ 2008-10-14 15:12 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, 14 Oct 2008 10:54:36 -0400
Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:

> Hi Phil,
> 
> On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > Dear All,
> >
> > I am seeing a 2-second pause while booting which I hypothesize is
> > due to a locking interaction between the mouse system and the
> > platform bus system. Here's a fragment from dmesg:
> >
> > [    2.202156] serio: i8042 KBD port at 0x60,0x64 irq 1
> > [    2.202170] serio: i8042 AUX port at 0x60,0x64 irq 12
> > [    2.202183] initcall i8042_init+0x0/0x32a returned 0 after 29
> > msecs [    2.202191] calling  serio_raw_init+0x0/0x11 @ 1
> > [    2.202345] initcall serio_raw_init+0x0/0x11 returned 0 after 0
> > msecs [    2.202356] calling  mousedev_init+0x0/0x72 @ 1
> > [    2.202638] mice: PS/2 mouse device common for all mice
> > [    2.202648] initcall mousedev_init+0x0/0x72 returned 0 after 0
> > msecs [    2.202657] calling  evdev_init+0x0/0xa @ 1
> > [    2.208739] initcall evdev_init+0x0/0xa returned 0 after 5 msecs
> > [    2.208746] calling  atkbd_init+0x0/0x1b @ 1
> > [    2.208855] initcall atkbd_init+0x0/0x1b returned 0 after 0 msecs
> > [    2.208864] calling  psmouse_init+0x0/0x58 @ 1
> > [    2.232546] input: AT Translated Set 2 keyboard
> > as /class/input/input5 [    2.247037] initcall
> > psmouse_init+0x0/0x58 returned 0 after 36 msecs [    2.247047]
> > calling  pcspkr_init+0x0/0xa @ 1 [    2.247067] pcspkr_probe
> > starting [    2.249202] input: PC Speaker as /class/input/input6
> > [    2.259239] pcspkr_probe done
> > [    4.379527] input: ImPS/2 Logitech Wheel Mouse
> > as /class/input/input7 [    4.387077] initcall pcspkr_init+0x0/0xa
> > returned 0 after 2040 msecs
> >
> > Note that the pause is between pcspkr_probe returning and
> > pcspkr_init returning.  My guess is that during this time the
> > platform bus is matching the pcspkr driver against all the other
> > platform devices, and in order to do so it is taking various device
> > locks; at the same time the kpsmoused workqueue is locking one of
> > the same devices and spending a couple of seconds probing it.  But
> > that's only a guess based on a couple of hours work; no doubt you
> > experts will have a better idea of what's going on.
> >
> 
> Hmm, I am not sure here. Psmouse module works on serio bus (with
> devices registered by i8042). The real probing is offloaded to kseriod
> as it may take a while (as in couple of seconds) to go through all
> possible mice protocols - you can see it because psmouse_init returns
> early, before the mouse is detected. Pcspkr works on platform bus. The
> only thing they share is input device registration but I don't believe
> we get stuck there. I wonder if this is a sign of scheduling problem
> early in the boot, lets CC Ingo and see if he has any ideas.
> 
> > What can be done about this?  Is it unreasonable for the mouse
> > probing to take 2 seconds?  Should it not be holding the
> > conflicting lock while it is probing?  Does the platform matching
> > code really need to hold the lock when it's just comparing the
> > string names of the device and driver?
> >

the real thing is to not wait on this while booting;
my fastboot git tree has the patches to fix that part..


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:12   ` Arjan van de Ven
@ 2008-10-14 15:29     ` Dmitry Torokhov
  2008-10-14 15:37       ` Arjan van de Ven
  2008-10-14 15:37       ` Arjan van de Ven
  2008-10-14 16:18     ` Phil Endecott
  1 sibling, 2 replies; 13+ messages in thread
From: Dmitry Torokhov @ 2008-10-14 15:29 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
> On Tue, 14 Oct 2008 10:54:36 -0400
> Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > > What can be done about this?  Is it unreasonable for the mouse
> > > probing to take 2 seconds?  Should it not be holding the
> > > conflicting lock while it is probing?  Does the platform matching
> > > code really need to hold the lock when it's just comparing the
> > > string names of the device and driver?
> > >
> 
> the real thing is to not wait on this while booting;
> my fastboot git tree has the patches to fix that part..
> 

Could you please be more specific?

-- 
Dmitry

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:29     ` Dmitry Torokhov
@ 2008-10-14 15:37       ` Arjan van de Ven
  2008-10-14 23:17         ` Phil Endecott
  2008-10-14 15:37       ` Arjan van de Ven
  1 sibling, 1 reply; 13+ messages in thread
From: Arjan van de Ven @ 2008-10-14 15:37 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, 14 Oct 2008 11:29:55 -0400
Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:

> On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
> > On Tue, 14 Oct 2008 10:54:36 -0400
> > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > > > What can be done about this?  Is it unreasonable for the mouse
> > > > probing to take 2 seconds?  Should it not be holding the
> > > > conflicting lock while it is probing?  Does the platform
> > > > matching code really need to hold the lock when it's just
> > > > comparing the string names of the device and driver?
> > > >
> > 
> > the real thing is to not wait on this while booting;
> > my fastboot git tree has the patches to fix that part..
> > 
> 
> Could you please be more specific?

right now, the linux kernel boot will wait for this probing to be done
before mounting the root fs and then exec()ing /sbin/init.
On my test laptop this takes 7 seconds of .. nothing ;-)

the patch I have makes the kernel NOT wait for this, but just it tries
to mount root right away (and if that fails, it THEN waits and retries)

> 


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:29     ` Dmitry Torokhov
  2008-10-14 15:37       ` Arjan van de Ven
@ 2008-10-14 15:37       ` Arjan van de Ven
  2008-10-14 15:48         ` Dmitry Torokhov
  1 sibling, 1 reply; 13+ messages in thread
From: Arjan van de Ven @ 2008-10-14 15:37 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, 14 Oct 2008 11:29:55 -0400
Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:

> On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
> > On Tue, 14 Oct 2008 10:54:36 -0400
> > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > > > What can be done about this?  Is it unreasonable for the mouse
> > > > probing to take 2 seconds?  Should it not be holding the
> > > > conflicting lock while it is probing?  Does the platform
> > > > matching code really need to hold the lock when it's just
> > > > comparing the string names of the device and driver?
> > > >
> > 
> > the real thing is to not wait on this while booting;
> > my fastboot git tree has the patches to fix that part..
> > 
> 
> Could you please be more specific?
\
oh btw you could make the mouse be exempt from this waiting that'd be a
much simpler/nicer solution ;-)


> 


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:37       ` Arjan van de Ven
@ 2008-10-14 15:48         ` Dmitry Torokhov
  2008-10-14 15:58           ` Arjan van de Ven
  0 siblings, 1 reply; 13+ messages in thread
From: Dmitry Torokhov @ 2008-10-14 15:48 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, Oct 14, 2008 at 11:37:49AM -0400, Arjan van de Ven wrote:
> On Tue, 14 Oct 2008 11:29:55 -0400
> Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> 
> > On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
> > > On Tue, 14 Oct 2008 10:54:36 -0400
> > > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > > > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > > > > What can be done about this?  Is it unreasonable for the mouse
> > > > > probing to take 2 seconds?  Should it not be holding the
> > > > > conflicting lock while it is probing?  Does the platform
> > > > > matching code really need to hold the lock when it's just
> > > > > comparing the string names of the device and driver?
> > > > >
> > > 
> > > the real thing is to not wait on this while booting;
> > > my fastboot git tree has the patches to fix that part..
> > > 
> > 
> > Could you please be more specific?
> \
> oh btw you could make the mouse be exempt from this waiting that'd be a
> much simpler/nicer solution ;-)
> 

Like I said, mouse probing is done in kseriod which is a separate
thread. If you look at the trace psmouse_init returned way way before,
its pcspkr got stuck for some reason (after completing
pcspkr_probe)...

-- 
Dmitry

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:48         ` Dmitry Torokhov
@ 2008-10-14 15:58           ` Arjan van de Ven
  0 siblings, 0 replies; 13+ messages in thread
From: Arjan van de Ven @ 2008-10-14 15:58 UTC (permalink / raw)
  To: Dmitry Torokhov; +Cc: Phil Endecott, linux-input, Ingo Molnar

On Tue, 14 Oct 2008 11:48:37 -0400
Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:

> On Tue, Oct 14, 2008 at 11:37:49AM -0400, Arjan van de Ven wrote:
> > On Tue, 14 Oct 2008 11:29:55 -0400
> > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > 
> > > On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
> > > > On Tue, 14 Oct 2008 10:54:36 -0400
> > > > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
> > > > > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
> > > > > > What can be done about this?  Is it unreasonable for the
> > > > > > mouse probing to take 2 seconds?  Should it not be holding
> > > > > > the conflicting lock while it is probing?  Does the platform
> > > > > > matching code really need to hold the lock when it's just
> > > > > > comparing the string names of the device and driver?
> > > > > >
> > > > 
> > > > the real thing is to not wait on this while booting;
> > > > my fastboot git tree has the patches to fix that part..
> > > > 
> > > 
> > > Could you please be more specific?
> > \
> > oh btw you could make the mouse be exempt from this waiting that'd
> > be a much simpler/nicer solution ;-)
> > 
> 
> Like I said, mouse probing is done in kseriod which is a separate
> thread. If you look at the trace psmouse_init returned way way before,
> its pcspkr got stuck for some reason (after completing
> pcspkr_probe)...
but without that locking issue we still have the delay.
Because you run as a probe, and the kernel code waits until ALL probes
are done:
        /* wait for the known devices to complete their probing */
        while (driver_probe_done() != 0)
                msleep(100);


if the serio stuff wouldn't run as a "probe"... we wouldn't wait on it 
before mounting the root fs.

(and whoever comes up with "but I have my root fs on my mouse....
"LALALALALALA" <fingers in ears>)


> 


-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:12   ` Arjan van de Ven
  2008-10-14 15:29     ` Dmitry Torokhov
@ 2008-10-14 16:18     ` Phil Endecott
  1 sibling, 0 replies; 13+ messages in thread
From: Phil Endecott @ 2008-10-14 16:18 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: linux-input

Arjan van de Ven wrote:
> the real thing is to not wait on this while booting;
> my fastboot git tree has the patches to fix that part..

Hi Arjan,

Actually I got your fastboot tree yesterday and have been using your 
bootgraph.pl script to track down things like this "pcspkr takes 2 
seconds" problem.  But I haven't yet got the async initcalls to work.  
I'll admit that I haven't really looked into it yet, but I'm guessing 
that either I have messed up with git and I don't really have your 
fastboot tree at all, or there is some config option that I need to 
toggle somewhere.  Can you give me a clue?  (And in general, where 
would you prefer to discuss fastboot-related things?  I have posted 
another message related to pcie hotplug, which I need because I have 
wireless networking enabled and which currently adds 4 seconds to the 
boot, here: http://thread.gmane.org/gmane.linux.kernel.pci/1311)

Cheers,  Phil.




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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 15:37       ` Arjan van de Ven
@ 2008-10-14 23:17         ` Phil Endecott
  2008-10-15  2:22           ` Arjan van de Ven
  0 siblings, 1 reply; 13+ messages in thread
From: Phil Endecott @ 2008-10-14 23:17 UTC (permalink / raw)
  To: linux-input; +Cc: Arjan van de Ven

Arjan van de Ven wrote:
> On Tue, 14 Oct 2008 11:29:55 -0400
> Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
>
>> On Tue, Oct 14, 2008 at 11:12:36AM -0400, Arjan van de Ven wrote:
>> > On Tue, 14 Oct 2008 10:54:36 -0400
>> > Dmitry Torokhov <dmitry.torokhov@gmail.com> wrote:
>> > > On Tue, Oct 14, 2008 at 03:19:28PM +0100, Phil Endecott wrote:
>> > > > What can be done about this?  Is it unreasonable for the mouse
>> > > > probing to take 2 seconds?  Should it not be holding the
>> > > > conflicting lock while it is probing?  Does the platform
>> > > > matching code really need to hold the lock when it's just
>> > > > comparing the string names of the device and driver?
>> > > >
>> > 
>> > the real thing is to not wait on this while booting;
>> > my fastboot git tree has the patches to fix that part..
>> > 
>> 
>> Could you please be more specific?
>
> right now, the linux kernel boot will wait for this probing to be done
> before mounting the root fs and then exec()ing /sbin/init.
> On my test laptop this takes 7 seconds of .. nothing ;-)
>
> the patch I have makes the kernel NOT wait for this, but just it tries
> to mount root right away (and if that fails, it THEN waits and retries)

So I worked out how to enable fastboot - the cunningly-named 
CONFIG_FASTBOOT option - and I now see initcalls running concurrently.  
I've saved a bootgraph at http://chezphil.org/tmp/bootgraph1.svg

The pcspkr delay symptom still exists, and as far as I can see the 
kernel doesn't try to mount root and start init until afterwards.  
Arjan, what do you mean by "right away" in the last line quoted above?  
Is there something that I have to do to get the pcspkr init off the 
path to mounting root?

Note also that in the graph serial8250_pci_init and uhci_hcd_init run 
concurrently and seem to terminate almost exactly simulataneously.  
Looking at the dmesg output, it's clear that serial8250_pci_init has 
been blocked waiting from uhci_hcd_init to terminate:

[    0.937759] calling  uhci_hcd_init+0x0/0x8e @ 14
[    0.937770] USB Universal Host Controller Interface driver v3.0
snip lots of sane UHCI messages
[    0.941187] calling  serial8250_pci_init+0x0/0x11 @ 1
snip lots more sane UHCI messages (root hub enumeration)
[    1.353134] initcall uhci_hcd_init+0x0/0x8e returned 0 after 396 msecs
[    1.353186] initcall serial8250_pci_init+0x0/0x11 returned 0 after 
392 msecs

It looks to me as if uhci holds some lock that 8250 needs before it can 
complete.  Now those are both PCI drivers in the same way that the last 
two that seemed to contend were both input drivers (touchpad and 
speaker) [hmm, except that as Dmitry pointed out there's a distinction 
between the platform bus and the serio bus].  Anyway, my ignorant 
suspicion is that there's some lock related to the bus or subsystem 
that they both need.  Maybe something in sysfs?

I tried running with CONFIG_LOCK_STAT set but I didn't see a huge 
amount of interest; but as I understand it, that only tracks locks not 
other locking things like semaphores and spinlocks.  The two 
conspicuous entries for my previous kernel build without 
CONFIG_FASTBOOT were

&type->i_mutex_dir_key#2  [<c017fb0c>] do_lookup+0x69/0x11d
  - looks like something fundamental in the filesystem

&battery->lock [<c022a524>] acpi_battery_get_state+0x50/0xc9
  - probably the reason for the acpi_battery_init which takes a few 
hundred miliseconds at the start of the boot; I think this is the first 
code to use ACPI, or something.

Any suggestions anyone?

Phil.





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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-14 23:17         ` Phil Endecott
@ 2008-10-15  2:22           ` Arjan van de Ven
  2008-10-15  9:19             ` Phil Endecott
  0 siblings, 1 reply; 13+ messages in thread
From: Arjan van de Ven @ 2008-10-15  2:22 UTC (permalink / raw)
  To: Phil Endecott; +Cc: linux-input

On Wed, 15 Oct 2008 00:17:29 +0100
"Phil Endecott" <phil_dubhl_endecott@chezphil.org> wrote:

> 
> It looks to me as if uhci holds some lock that 8250 needs before it
> can complete.  Now those are both PCI drivers in the same way that
> the last two that seemed to contend were both input drivers (touchpad
> and speaker) [hmm, except that as Dmitry pointed out there's a
> distinction between the platform bus and the serio bus].  Anyway, my
> ignorant suspicion is that there's some lock related to the bus or
> subsystem that they both need.  Maybe something in sysfs?

it does do this. And I know which lock... and I fixed it ;)
Just the patch for this is in Gregkh's tree since it's a change to the
device/sysfs layer and he wanted to carry it via that way.

I can dig that patch out if you want

-- 
Arjan van de Ven 	Intel Open Source Technology Centre
For development, discussion and tips for power savings, 
visit http://www.lesswatts.org

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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-15  2:22           ` Arjan van de Ven
@ 2008-10-15  9:19             ` Phil Endecott
  2008-10-22 23:07               ` Phil Endecott
  0 siblings, 1 reply; 13+ messages in thread
From: Phil Endecott @ 2008-10-15  9:19 UTC (permalink / raw)
  To: Arjan van de Ven; +Cc: linux-input

Arjan van de Ven wrote:
> On Wed, 15 Oct 2008 00:17:29 +0100
> "Phil Endecott" <phil_dubhl_endecott@chezphil.org> wrote:
>
>> 
>> It looks to me as if uhci holds some lock that 8250 needs before it
>> can complete.  Now those are both PCI drivers in the same way that
>> the last two that seemed to contend were both input drivers (touchpad
>> and speaker) [hmm, except that as Dmitry pointed out there's a
>> distinction between the platform bus and the serio bus].  Anyway, my
>> ignorant suspicion is that there's some lock related to the bus or
>> subsystem that they both need.  Maybe something in sysfs?
>
> it does do this. And I know which lock... and I fixed it ;)
> Just the patch for this is in Gregkh's tree since it's a change to the
> device/sysfs layer and he wanted to carry it via that way.
>
> I can dig that patch out if you want

Yes please!


Phil.




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

* Re: Slow boot due perhaps to locks in mouse and platform system
  2008-10-15  9:19             ` Phil Endecott
@ 2008-10-22 23:07               ` Phil Endecott
  0 siblings, 0 replies; 13+ messages in thread
From: Phil Endecott @ 2008-10-22 23:07 UTC (permalink / raw)
  To: linux-input

Phil Endecott wrote:
> Arjan van de Ven wrote:
>> On Wed, 15 Oct 2008 00:17:29 +0100
>> "Phil Endecott" <phil_dubhl_endecott@chezphil.org> wrote:
>>
>>> 
>>> It looks to me as if uhci holds some lock that 8250 needs before it
>>> can complete.  Now those are both PCI drivers in the same way that
>>> the last two that seemed to contend were both input drivers (touchpad
>>> and speaker) [hmm, except that as Dmitry pointed out there's a
>>> distinction between the platform bus and the serio bus].  Anyway, my
>>> ignorant suspicion is that there's some lock related to the bus or
>>> subsystem that they both need.  Maybe something in sysfs?
>>
>> it does do this. And I know which lock... and I fixed it ;)
>> Just the patch for this is in Gregkh's tree since it's a change to the
>> device/sysfs layer and he wanted to carry it via that way.
>>
>> I can dig that patch out if you want
>
> Yes please!

Google eventually found this for me:
   http://thread.gmane.org/gmane.linux.usb.general/9923

I presume that this is what Arjan was referring to.  It causes the 
device-to-driver matching loop to not take the device lock unless the 
match function succeeds.  In my case, the need to take this look was 
preventing the pcspkr initialisation from terminating until the mouse 
initialisation was done, even though the mouse initialisation is in a 
different thread, because the pcspkr init wanted to lock the mouse to 
check if it was actually a speaker.

Fixing it has halved my boot time.


Phil.




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

end of thread, other threads:[~2008-10-22 23:07 UTC | newest]

Thread overview: 13+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2008-10-14 14:19 Slow boot due perhaps to locks in mouse and platform system Phil Endecott
2008-10-14 14:54 ` Dmitry Torokhov
2008-10-14 15:12   ` Arjan van de Ven
2008-10-14 15:29     ` Dmitry Torokhov
2008-10-14 15:37       ` Arjan van de Ven
2008-10-14 23:17         ` Phil Endecott
2008-10-15  2:22           ` Arjan van de Ven
2008-10-15  9:19             ` Phil Endecott
2008-10-22 23:07               ` Phil Endecott
2008-10-14 15:37       ` Arjan van de Ven
2008-10-14 15:48         ` Dmitry Torokhov
2008-10-14 15:58           ` Arjan van de Ven
2008-10-14 16:18     ` Phil Endecott

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