strange keyboard lag after suspend testing

strange keyboard lag after suspend testing

[Pavel Machek]

Hi!

I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
like someone added 50..100msec delay somewhere in keyboard
handling. Mouse does not seem affected. /proc/interrupts seem to
increase as they should, for both keyboard and mouse. Can someone
reproduce it? Any ideas how to debug it?
								Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: strange keyboard lag after suspend testing

[Andreas Mohr]

Hi,

On Tue, Mar 20, 2007 at 04:33:32PM +0100, Pavel Machek wrote:
> Hi!
> 
> I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> like someone added 50..100msec delay somewhere in keyboard
> handling. Mouse does not seem affected. /proc/interrupts seem to
> increase as they should, for both keyboard and mouse. Can someone
> reproduce it? Any ideas how to debug it?

Probably just asking the obvious:
it's not a trivial "failed to re-configure repeat rate upon resume"
(which one could rule out by running "kbdrate" again)
but a lag in some interrupt handler or somewhere else deeper, right?

Andreas Mohr

Re: strange keyboard lag after suspend testing

[Pavel Machek]

Hi!

> > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> > like someone added 50..100msec delay somewhere in keyboard
> > handling. Mouse does not seem affected. /proc/interrupts seem to
> > increase as they should, for both keyboard and mouse. Can someone
> > reproduce it? Any ideas how to debug it?
> 
> Probably just asking the obvious:
> it's not a trivial "failed to re-configure repeat rate upon resume"
> (which one could rule out by running "kbdrate" again)
> but a lag in some interrupt handler or somewhere else deeper, right?

No, it is not keyboard rate. Keyboard lags during normal typing,
sometimes letters come in groups of two or so...
									Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: strange keyboard lag after suspend testing

[Dmitry Torokhov]

On 3/20/07, Pavel Machek <pavel@ucw.cz> wrote:
> Hi!
>
> > > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> > > like someone added 50..100msec delay somewhere in keyboard
> > > handling. Mouse does not seem affected. /proc/interrupts seem to
> > > increase as they should, for both keyboard and mouse. Can someone
> > > reproduce it? Any ideas how to debug it?
> >
> > Probably just asking the obvious:
> > it's not a trivial "failed to re-configure repeat rate upon resume"
> > (which one could rule out by running "kbdrate" again)
> > but a lag in some interrupt handler or somewhere else deeper, right?
>
> No, it is not keyboard rate. Keyboard lags during normal typing,
> sometimes letters come in groups of two or so...

I might start looking at embedded controller changes and switches. If
ACPI misbehaves that could starve keyboard controller... But you said
that mouse is OK... Hmm, what happens if you load evbug and type while
watching syslog. Do you observe the same delays?

-- 
Dmitry

Re: strange keyboard lag after suspend testing

[Pavel Machek]

Hi!

> >> > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> >> > like someone added 50..100msec delay somewhere in keyboard
> >> > handling. Mouse does not seem affected. /proc/interrupts seem to
> >> > increase as they should, for both keyboard and mouse. Can someone
> >> > reproduce it? Any ideas how to debug it?
> >>
> >> Probably just asking the obvious:
> >> it's not a trivial "failed to re-configure repeat rate upon resume"
> >> (which one could rule out by running "kbdrate" again)
> >> but a lag in some interrupt handler or somewhere else deeper, right?
> >
> >No, it is not keyboard rate. Keyboard lags during normal typing,
> >sometimes letters come in groups of two or so...
> 
> I might start looking at embedded controller changes and switches. If
> ACPI misbehaves that could starve keyboard controller... But you
> said

Mouse _seems_ okay, but I'm not sure if I'd notice lag there.

> that mouse is OK... Hmm, what happens if you load evbug and type while
> watching syslog. Do you observe the same delays?

Hmm, seems that it only happens in X... so maybe it is some strange
scheduling artefact?

Hmm, something is wrong here:

On console, I get expected 4-5 ticks a second. In x in gnome-terminal,
I get this:

root@amd:~# while true ; do echo -n . ; sleep .2; date; done
.Tue Mar 20 17:28:34 CET 2007
.Tue Mar 20 17:28:35 CET 2007
.Tue Mar 20 17:28:35 CET 2007
.Tue Mar 20 17:28:35 CET 2007
.Tue Mar 20 17:28:36 CET 2007
.Tue Mar 20 17:28:36 CET 2007
.Tue Mar 20 17:28:36 CET 2007
.Tue Mar 20 17:28:36 CET 2007
.Tue Mar 20 17:28:37 CET 2007
.Tue Mar 20 17:28:37 CET 2007
.Tue Mar 20 17:28:37 CET 2007
.Tue Mar 20 17:28:37 CET 2007
.Tue Mar 20 17:28:38 CET 2007
.Tue Mar 20 17:28:38 CET 2007
.Tue Mar 20 17:28:38 CET 2007
.Tue Mar 20 17:28:39 CET 2007
.Tue Mar 20 17:28:39 CET 2007
.Tue Mar 20 17:28:39 CET 2007
.Tue Mar 20 17:28:39 CET 2007
.Tue Mar 20 17:28:39 CET 2007
.Tue Mar 20 17:28:40 CET 2007
.Tue Mar 20 17:28:40 CET 2007
.Tue Mar 20 17:28:40 CET 2007
.Tue Mar 20 17:28:40 CET 2007
.Tue Mar 20 17:28:41 CET 2007
.Tue Mar 20 17:28:41 CET 2007
.Tue Mar 20 17:28:41 CET 2007
.Tue Mar 20 17:28:42 CET 2007
.Tue Mar 20 17:28:42 CET 2007

So sorry for false alarm, it is not keyboard related, it is just very
very strange.
									Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: strange keyboard lag after suspend testing

[Pavel Machek]

Hi!

> > >> > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> > >> > like someone added 50..100msec delay somewhere in keyboard
> > >> > handling. Mouse does not seem affected. /proc/interrupts seem to
> > >> > increase as they should, for both keyboard and mouse. Can someone
> > >> > reproduce it? Any ideas how to debug it?
> > >>
> > >> Probably just asking the obvious:
> > >> it's not a trivial "failed to re-configure repeat rate upon resume"
> > >> (which one could rule out by running "kbdrate" again)
> > >> but a lag in some interrupt handler or somewhere else deeper, right?
> > >
> > >No, it is not keyboard rate. Keyboard lags during normal typing,
> > >sometimes letters come in groups of two or so...
> > 
> > I might start looking at embedded controller changes and switches. If
> > ACPI misbehaves that could starve keyboard controller... But you
> > said
> 
> Mouse _seems_ okay, but I'm not sure if I'd notice lag there.
> 
> > that mouse is OK... Hmm, what happens if you load evbug and type while
> > watching syslog. Do you observe the same delays?
> 
> Hmm, seems that it only happens in X... so maybe it is some strange
> scheduling artefact?
> 
> Hmm, something is wrong here:
> 
> On console, I get expected 4-5 ticks a second. In x in gnome-terminal,
> I get this:

It gets weirder: I killed some tasks and now: (on unloaded system
running X, notice that top latency was ~1sec at 33:09).

root@amd:~# while true ; do echo -n . ; sleep .2; date; done
.Tue Mar 20 17:33:07 CET 2007
.Tue Mar 20 17:33:07 CET 2007
.Tue Mar 20 17:33:08 CET 2007
.Tue Mar 20 17:33:08 CET 2007
.Tue Mar 20 17:33:08 CET 2007
.Tue Mar 20 17:33:08 CET 2007
.Tue Mar 20 17:33:09 CET 2007
.Tue Mar 20 17:33:10 CET 2007
.Tue Mar 20 17:33:10 CET 2007
.Tue Mar 20 17:33:10 CET 2007
.Tue Mar 20 17:33:10 CET 2007
.Tue Mar 20 17:33:10 CET 2007
.Tue Mar 20 17:33:11 CET 2007
.Tue Mar 20 17:33:11 CET 2007
.Tue Mar 20 17:33:11 CET 2007
.Tue Mar 20 17:33:12 CET 2007
.Tue Mar 20 17:33:12 CET 2007

As soon as I load the cpu up with while1, machine starts to behave.

When I turn on bluetooth (USB), ACPI can no longer use C3, and machine
starts to behave. Hmm?
								Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html

Re: strange keyboard lag after suspend testing

[Rafael J. Wysocki]

On Tuesday, 20 March 2007 17:38, Pavel Machek wrote:
> Hi!
> 
> > > >> > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
> > > >> > like someone added 50..100msec delay somewhere in keyboard
> > > >> > handling. Mouse does not seem affected. /proc/interrupts seem to
> > > >> > increase as they should, for both keyboard and mouse. Can someone
> > > >> > reproduce it? Any ideas how to debug it?
> > > >>
> > > >> Probably just asking the obvious:
> > > >> it's not a trivial "failed to re-configure repeat rate upon resume"
> > > >> (which one could rule out by running "kbdrate" again)
> > > >> but a lag in some interrupt handler or somewhere else deeper, right?
> > > >
> > > >No, it is not keyboard rate. Keyboard lags during normal typing,
> > > >sometimes letters come in groups of two or so...
> > > 
> > > I might start looking at embedded controller changes and switches. If
> > > ACPI misbehaves that could starve keyboard controller... But you
> > > said
> > 
> > Mouse _seems_ okay, but I'm not sure if I'd notice lag there.
> > 
> > > that mouse is OK... Hmm, what happens if you load evbug and type while
> > > watching syslog. Do you observe the same delays?
> > 
> > Hmm, seems that it only happens in X... so maybe it is some strange
> > scheduling artefact?
> > 
> > Hmm, something is wrong here:
> > 
> > On console, I get expected 4-5 ticks a second. In x in gnome-terminal,
> > I get this:
> 
> It gets weirder: I killed some tasks and now: (on unloaded system
> running X, notice that top latency was ~1sec at 33:09).
> 
> root@amd:~# while true ; do echo -n . ; sleep .2; date; done
> .Tue Mar 20 17:33:07 CET 2007
> .Tue Mar 20 17:33:07 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:09 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:12 CET 2007
> .Tue Mar 20 17:33:12 CET 2007
> 
> As soon as I load the cpu up with while1, machine starts to behave.
> 
> When I turn on bluetooth (USB), ACPI can no longer use C3, and machine
> starts to behave. Hmm?

Smells like a cpufreq problem or something related.

Greetings,
Rafael

Re: strange keyboard lag after suspend testing

[Luca Tettamanti]

Adding Thomas Gleixner to CC

Pavel Machek <pavel@ucw.cz> ha scritto:
> Hi!
> 
>> > >> > I was testing suspend in 2.6.21-rc4 a lot, and now... machine feels
>> > >> > like someone added 50..100msec delay somewhere in keyboard
>> > >> > handling. Mouse does not seem affected. /proc/interrupts seem to
>> > >> > increase as they should, for both keyboard and mouse. Can someone
>> > >> > reproduce it? Any ideas how to debug it?
>> > >>
>> > >> Probably just asking the obvious:
>> > >> it's not a trivial "failed to re-configure repeat rate upon resume"
>> > >> (which one could rule out by running "kbdrate" again)
>> > >> but a lag in some interrupt handler or somewhere else deeper, right?
>> > >
>> > >No, it is not keyboard rate. Keyboard lags during normal typing,
>> > >sometimes letters come in groups of two or so...
>> > 
>> > I might start looking at embedded controller changes and switches. If
>> > ACPI misbehaves that could starve keyboard controller... But you
>> > said
>> 
>> Mouse _seems_ okay, but I'm not sure if I'd notice lag there.
>> 
>> > that mouse is OK... Hmm, what happens if you load evbug and type while
>> > watching syslog. Do you observe the same delays?
>> 
>> Hmm, seems that it only happens in X... so maybe it is some strange
>> scheduling artefact?
>> 
>> Hmm, something is wrong here:
>> 
>> On console, I get expected 4-5 ticks a second. In x in gnome-terminal,
>> I get this:
> 
> It gets weirder: I killed some tasks and now: (on unloaded system
> running X, notice that top latency was ~1sec at 33:09).
> 
> root@amd:~# while true ; do echo -n . ; sleep .2; date; done
> .Tue Mar 20 17:33:07 CET 2007
> .Tue Mar 20 17:33:07 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:08 CET 2007
> .Tue Mar 20 17:33:09 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:10 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:11 CET 2007
> .Tue Mar 20 17:33:12 CET 2007
> .Tue Mar 20 17:33:12 CET 2007
> 
> As soon as I load the cpu up with while1, machine starts to behave.
> 
> When I turn on bluetooth (USB), ACPI can no longer use C3, and machine
> starts to behave. Hmm?

When the CPU is in C3 the TSC and LAPIC (IIRC) are stopped, sounds like
the problem is here. Maybe after resume kernel fails to fall back to a
"safe" clocksource.

Luca
-- 
Inquietudine sintetica
Solo, davanti all'ignoto
Tienimi stretto a te

Re: strange keyboard lag after suspend testing

[Pavel Machek]

Hi!

> >> > >No, it is not keyboard rate. Keyboard lags during normal typing,
> >> > >sometimes letters come in groups of two or so...
> >> > 
> >> > I might start looking at embedded controller changes and switches. If
> >> > ACPI misbehaves that could starve keyboard controller... But you
> >> > said
> >> 
> >> Mouse _seems_ okay, but I'm not sure if I'd notice lag there.
> >> 
> >> > that mouse is OK... Hmm, what happens if you load evbug and type while
> >> > watching syslog. Do you observe the same delays?
> >> 
> >> Hmm, seems that it only happens in X... so maybe it is some strange
> >> scheduling artefact?
> >> 
> >> Hmm, something is wrong here:
> >> 
> >> On console, I get expected 4-5 ticks a second. In x in gnome-terminal,
> >> I get this:
> > 
> > It gets weirder: I killed some tasks and now: (on unloaded system
> > running X, notice that top latency was ~1sec at 33:09).
> > 
> > root@amd:~# while true ; do echo -n . ; sleep .2; date; done
> > .Tue Mar 20 17:33:07 CET 2007
> > .Tue Mar 20 17:33:07 CET 2007
> > .Tue Mar 20 17:33:08 CET 2007
> > .Tue Mar 20 17:33:08 CET 2007
> > .Tue Mar 20 17:33:08 CET 2007
> > .Tue Mar 20 17:33:08 CET 2007
> > .Tue Mar 20 17:33:09 CET 2007
> > .Tue Mar 20 17:33:10 CET 2007
> > .Tue Mar 20 17:33:10 CET 2007
> > .Tue Mar 20 17:33:10 CET 2007
> > .Tue Mar 20 17:33:10 CET 2007
> > .Tue Mar 20 17:33:10 CET 2007
> > .Tue Mar 20 17:33:11 CET 2007
> > .Tue Mar 20 17:33:11 CET 2007
> > .Tue Mar 20 17:33:11 CET 2007
> > .Tue Mar 20 17:33:12 CET 2007
> > .Tue Mar 20 17:33:12 CET 2007
> > 
> > As soon as I load the cpu up with while1, machine starts to behave.
> > 
> > When I turn on bluetooth (USB), ACPI can no longer use C3, and machine
> > starts to behave. Hmm?
> 
> When the CPU is in C3 the TSC and LAPIC (IIRC) are stopped, sounds like
> the problem is here. Maybe after resume kernel fails to fall back to a
> "safe" clocksource.

Notice that problem is _not_ easily reproducible :-(. One suspend is
not enough to trigger it.

									Pavel
-- 
(english) http://www.livejournal.com/~pavelmachek
(cesky, pictures) http://atrey.karlin.mff.cuni.cz/~pavel/picture/horses/blog.html