Re: Slow boot due perhaps to locks in mouse and platform system

[Dmitry Torokhov <dmitry.torokhov@gmail.com>]

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