[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (3 days old)

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Mon, 2009-01-19 at 22:45 +0100, Rafael J. Wysocki wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah@ucwb.org.au>
> Date		: 2009-01-17 03:37 (3 days old)

Yes, please keep this on the list.

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> On Mon, 2009-01-19 at 22:45 +0100, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> > Subject		: KVM guests stalling on 2.6.28 (bisected)
> > Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> > Date		: 2009-01-17 03:37 (3 days old)
> 
> Yes, please keep this on the list.

This only seems to occur under KVM, right? I.e. you tested it with -no-kvm 
and the problem went away, correct?

This suggests some sort of KVM-specific problem. Scheduler latencies in 
the seconds that occur under normal load situations are noticed and 
reported quickly - and there are no such open regressions currently.

Avi, can you reproduce these latencies? A possibly theory would be some 
sort of guest wakeup problem/race triggered by a shift in 
preemption/scheduling patterns. Or something related to preempt-notifiers 
(which KVM is using). A genuine scheduler bug is in the cards too, but the 
KVM-only angle of this bug gives it a low probability.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Ingo Molnar wrote:
> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
>
>   
>> On Mon, 2009-01-19 at 22:45 +0100, Rafael J. Wysocki wrote:
>>     
>>> This message has been generated automatically as a part of a report
>>> of regressions introduced between 2.6.27 and 2.6.28.
>>>
>>> The following bug entry is on the current list of known regressions
>>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>>> be listed and let me know (either way).
>>>
>>>
>>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>>> Date		: 2009-01-17 03:37 (3 days old)
>>>       
>> Yes, please keep this on the list.
>>     
>
> This only seems to occur under KVM, right? I.e. you tested it with -no-kvm 
> and the problem went away, correct?
>
> This suggests some sort of KVM-specific problem. Scheduler latencies in 
> the seconds that occur under normal load situations are noticed and 
> reported quickly - and there are no such open regressions currently.
>
>   

Not necessarily.  -no-kvm runs with only one thread, compared to kvm 
that runs with 1 + nr_cpus threads.

> Avi, can you reproduce these latencies? 

No.

> A possibly theory would be some 
> sort of guest wakeup problem/race triggered by a shift in 
> preemption/scheduling patterns. Or something related to preempt-notifiers 
> (which KVM is using). A genuine scheduler bug is in the cards too, but the 
> KVM-only angle of this bug gives it a low probability.
>   

Can we trace task wakeups somehow? (latency between wakeup and actually 
running).

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-01-20 at 12:35 +0100, Ingo Molnar wrote:
> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
> 
> > On Mon, 2009-01-19 at 22:45 +0100, Rafael J. Wysocki wrote:
> > > This message has been generated automatically as a part of a report
> > > of regressions introduced between 2.6.27 and 2.6.28.
> > > 
> > > The following bug entry is on the current list of known regressions
> > > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > > be listed and let me know (either way).
> > > 
> > > 
> > > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> > > Subject		: KVM guests stalling on 2.6.28 (bisected)
> > > Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> > > Date		: 2009-01-17 03:37 (3 days old)
> > 
> > Yes, please keep this on the list.
> 
> This only seems to occur under KVM, right? I.e. you tested it with -no-kvm 
> and the problem went away, correct?

Well, the I couldn't make the test conditions identical, but it the
problem didn't occur with the test I was able to do:

  http://marc.info/?l=linux-kernel&m=123228728416498&w=2

> This suggests some sort of KVM-specific problem. Scheduler latencies in 
> the seconds that occur under normal load situations are noticed and 
> reported quickly - and there are no such open regressions currently.

It at least suggests a problem with interaction between the scheduler
and kvm, otherwise reverting that scheduler patch wouldn't have made the
regression go away.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> > This suggests some sort of KVM-specific problem. Scheduler latencies 
> > in the seconds that occur under normal load situations are noticed and 
> > reported quickly - and there are no such open regressions currently.
> 
> It at least suggests a problem with interaction between the scheduler 
> and kvm, otherwise reverting that scheduler patch wouldn't have made the 
> regression go away.

the scheduler affects almost everything, so almost by definition a 
scheduler change can tickle a race or other timing bug in just about any 
code - and reverting that change in the scheduler can make the bug go 
away. But yes, it could also be a genuine scheduler bug - that is always a 
possibility.

Could you please run a cfs-debug-info.sh session on a CONFIG_SCHED_DEBUG=y 
and CONFIG_SCHEDSTATS=y kernel, while you are experiencing those 
latencies:

  http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh

and post that (relatively large) somewhere, or send it as a reply after 
bzip2 -9 compressing it? It will include a lot of information about the 
delays your tasks are experiencing.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Tue, 2009-01-20 at 12:35 +0100, Ingo Molnar wrote:
>   
>> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
>>
>>     
>>> On Mon, 2009-01-19 at 22:45 +0100, Rafael J. Wysocki wrote:
>>>       
>>>> This message has been generated automatically as a part of a report
>>>> of regressions introduced between 2.6.27 and 2.6.28.
>>>>
>>>> The following bug entry is on the current list of known regressions
>>>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>>>> be listed and let me know (either way).
>>>>
>>>>
>>>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>>>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>>>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>>>> Date		: 2009-01-17 03:37 (3 days old)
>>>>         
>>> Yes, please keep this on the list.
>>>       
>> This only seems to occur under KVM, right? I.e. you tested it with -no-kvm 
>> and the problem went away, correct?
>>     
>
> Well, the I couldn't make the test conditions identical, but it the
> problem didn't occur with the test I was able to do:
>
>   http://marc.info/?l=linux-kernel&m=123228728416498&w=2
>
>   

Can you also try with -no-kvm-irqchip?

You will need to comment out the lines

    /* ISA IRQs map to GSI 1-1 except for IRQ0 which maps
     * to GSI 2.  GSI maps to ioapic 1-1.  This is not
     * the cleanest way of doing it but it should work. */

    if (vector == 0)
        vector = 2;

in qemu/hw/apic.c (should also fix -no-kvm smp).  This will change kvm 
wakeups to use signals rather than the in-kernel code, which may be buggy.

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Ingo Molnar <mingo-X9Un+BFzKDI@public.gmane.org> wrote:

> 
> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
> 
> > > This suggests some sort of KVM-specific problem. Scheduler latencies 
> > > in the seconds that occur under normal load situations are noticed and 
> > > reported quickly - and there are no such open regressions currently.
> > 
> > It at least suggests a problem with interaction between the scheduler 
> > and kvm, otherwise reverting that scheduler patch wouldn't have made the 
> > regression go away.
> 
> the scheduler affects almost everything, so almost by definition a 
> scheduler change can tickle a race or other timing bug in just about any 
> code - and reverting that change in the scheduler can make the bug go 
> away. But yes, it could also be a genuine scheduler bug - that is always a 
> possibility.
> 
> Could you please run a cfs-debug-info.sh session on a CONFIG_SCHED_DEBUG=y 
> and CONFIG_SCHEDSTATS=y kernel, while you are experiencing those 
> latencies:
> 
>   http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh
> 
> and post that (relatively large) somewhere, or send it as a reply after 
> bzip2 -9 compressing it? It will include a lot of information about the 
> delays your tasks are experiencing.

Another test would be to build the scheduler latency tracer into your 
kernel:

    CONFIG_SCHED_TRACER=y

And enable it via:

    echo wakeup > /debug/tracing/current_tracer

and you should be seeing the worst-case scheduling latency traces in 
/debug/tracing/trace, and the largest observed latency will be in 
/debug/tracing/tracing_max_latency [in microseconds].

You can reset the max-latency (and thus restart tracing) via:

    echo 0 > /debug/tracing/tracing_max_latency

Latencies up to 100 microseconds are ok. If you see 10 seconds delays 
there (values of 10,000,000 or more) then it's probably a scheduler bug.

Please reproduce the latency under KVM and send us the trace. The trace 
file will be a lot more verbose and a lot more verbose if you also enable 
the function tracer (FUNCTION_TRACER, DYNAMIC_FTRACE and 
FUNCTION_GRAPH_TRACER).

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-01-20 at 13:56 +0100, Ingo Molnar wrote:
> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
> > > This suggests some sort of KVM-specific problem. Scheduler latencies 
> > > in the seconds that occur under normal load situations are noticed and 
> > > reported quickly - and there are no such open regressions currently.
> > 
> > It at least suggests a problem with interaction between the scheduler 
> > and kvm, otherwise reverting that scheduler patch wouldn't have made the 
> > regression go away.
> 
> the scheduler affects almost everything, so almost by definition a 
> scheduler change can tickle a race or other timing bug in just about any 
> code - and reverting that change in the scheduler can make the bug go 
> away. But yes, it could also be a genuine scheduler bug - that is always a 
> possibility.

Okay, I understand.

> Could you please run a cfs-debug-info.sh session on a CONFIG_SCHED_DEBUG=y 
> and CONFIG_SCHEDSTATS=y kernel, while you are experiencing those 
> latencies:
> 
>   http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh
> 
> and post that (relatively large) somewhere, or send it as a reply after 
> bzip2 -9 compressing it? It will include a lot of information about the 
> delays your tasks are experiencing.

Running it while the problem is occuring will be tricky, as it only
lasts for a few seconds at a time. Is it going to be useful at all to
just see those statistics if the system is running normally?

I might need to modify the script a little. Am I right that everything
above "gathering statistics..." is pretty much static information?

I could run top, vmstat and cat /proc/sched_debug in a loop until the
problem occurs and then trim it. Something like:

while true; do
  date                                >> $FILE
  echo "-- top: --"                   >> $FILE
  top -H -c -b -d 1 -n 0.5            >> $FILE 2>/dev/null
  echo "-- vmstat: --"                >> $FILE
  vmstat                              >> $FILE 2>/dev/null
  echo "-- sched_debug #$i: --"       >> $FILE
  cat /proc/sched_debug               >> $FILE 2>/dev/null
done

That should take a snapshot every half second or so.

Regards,
Kevin.

P.S. Please keep kmshanah-IiIpDuVlHfMLO379cgqW9odd74u8MsAO@public.gmane.org out of the CC list (it won't
     route properly anyway). I don't know how it got added - the only
     place it would have appeared was in the "revert" commit message
     when I was testing 2.6.28 with the commit I bisected down to
     removed.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> On Tue, 2009-01-20 at 13:56 +0100, Ingo Molnar wrote:
> > * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
> > > > This suggests some sort of KVM-specific problem. Scheduler latencies 
> > > > in the seconds that occur under normal load situations are noticed and 
> > > > reported quickly - and there are no such open regressions currently.
> > > 
> > > It at least suggests a problem with interaction between the scheduler 
> > > and kvm, otherwise reverting that scheduler patch wouldn't have made the 
> > > regression go away.
> > 
> > the scheduler affects almost everything, so almost by definition a 
> > scheduler change can tickle a race or other timing bug in just about any 
> > code - and reverting that change in the scheduler can make the bug go 
> > away. But yes, it could also be a genuine scheduler bug - that is always a 
> > possibility.
> 
> Okay, I understand.
> 
> > Could you please run a cfs-debug-info.sh session on a CONFIG_SCHED_DEBUG=y 
> > and CONFIG_SCHEDSTATS=y kernel, while you are experiencing those 
> > latencies:
> > 
> >   http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh
> > 
> > and post that (relatively large) somewhere, or send it as a reply after 
> > bzip2 -9 compressing it? It will include a lot of information about the 
> > delays your tasks are experiencing.
> 
> Running it while the problem is occuring will be tricky, as it only 
> lasts for a few seconds at a time. Is it going to be useful at all to 
> just see those statistics if the system is running normally?
> 
> I might need to modify the script a little. Am I right that everything 
> above "gathering statistics..." is pretty much static information?

Correct.

> I could run top, vmstat and cat /proc/sched_debug in a loop until the
> problem occurs and then trim it. Something like:
> 
> while true; do
>   date                                >> $FILE
>   echo "-- top: --"                   >> $FILE
>   top -H -c -b -d 1 -n 0.5            >> $FILE 2>/dev/null
>   echo "-- vmstat: --"                >> $FILE
>   vmstat                              >> $FILE 2>/dev/null
>   echo "-- sched_debug #$i: --"       >> $FILE
>   cat /proc/sched_debug               >> $FILE 2>/dev/null
> done
> 
> That should take a snapshot every half second or so.

Yeah, that would be lovely. You dont even have to trim it much - just give 
us a timestamp to look at for the delay incident. You might also want to 
start the kvm session while the script is already running - that way we'll 
get fresh statistics and see the whole thing.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frédéric Weisbecker]

2009/1/20 Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>:
> On Tue, 2009-01-20 at 13:56 +0100, Ingo Molnar wrote:
>> * Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:
>> > > This suggests some sort of KVM-specific problem. Scheduler latencies
>> > > in the seconds that occur under normal load situations are noticed and
>> > > reported quickly - and there are no such open regressions currently.
>> >
>> > It at least suggests a problem with interaction between the scheduler
>> > and kvm, otherwise reverting that scheduler patch wouldn't have made the
>> > regression go away.
>>
>> the scheduler affects almost everything, so almost by definition a
>> scheduler change can tickle a race or other timing bug in just about any
>> code - and reverting that change in the scheduler can make the bug go
>> away. But yes, it could also be a genuine scheduler bug - that is always a
>> possibility.
>
> Okay, I understand.
>
>> Could you please run a cfs-debug-info.sh session on a CONFIG_SCHED_DEBUG=y
>> and CONFIG_SCHEDSTATS=y kernel, while you are experiencing those
>> latencies:
>>
>>   http://people.redhat.com/mingo/cfs-scheduler/tools/cfs-debug-info.sh
>>
>> and post that (relatively large) somewhere, or send it as a reply after
>> bzip2 -9 compressing it? It will include a lot of information about the
>> delays your tasks are experiencing.
>
> Running it while the problem is occuring will be tricky, as it only
> lasts for a few seconds at a time. Is it going to be useful at all to
> just see those statistics if the system is running normally?
>
> I might need to modify the script a little. Am I right that everything
> above "gathering statistics..." is pretty much static information?
>
> I could run top, vmstat and cat /proc/sched_debug in a loop until the
> problem occurs and then trim it. Something like:
>
> while true; do
>  date                                >> $FILE
>  echo "-- top: --"                   >> $FILE
>  top -H -c -b -d 1 -n 0.5            >> $FILE 2>/dev/null
>  echo "-- vmstat: --"                >> $FILE
>  vmstat                              >> $FILE 2>/dev/null
>  echo "-- sched_debug #$i: --"       >> $FILE
>  cat /proc/sched_debug               >> $FILE 2>/dev/null
> done
>
> That should take a snapshot every half second or so.
>
> Regards,
> Kevin.
>
> P.S. Please keep kmshanah-IiIpDuVlHfMLO379cgqW9odd74u8MsAO@public.gmane.org out of the CC list (it won't
>     route properly anyway). I don't know how it got added - the only
>     place it would have appeared was in the "revert" commit message
>     when I was testing 2.6.28 with the commit I bisected down to
>     removed.
>


One other thing you can do is enabling CONFIG_FUNCTION_GRAPH_TRACER,
as Ingo suggested, and
trace the schedule() function.
This way you will see the time spent in (almost) each functions called
from schedule() and perhaps find
where is the contention (if it comes from the scheduler).

How to use it?

echo schedule > /debugfs/tracing/set_graph_function
echo function_graph > /debugfs/tracing/current_tracer
cat /debugfs/tracing/trace

Or even through a pipe:
cat /debugfs/tracing/trace_pipe > ~/func_graph.log

To end the tracing: echo nop > /debugfs/tracing/current_tracer
Or just make a pause: echo 0 > /debugfs/tracing/tracing_enabled

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Steven Rostedt]

On Tue, 20 Jan 2009, Ingo Molnar wrote:
> Another test would be to build the scheduler latency tracer into your 
> kernel:
> 
>     CONFIG_SCHED_TRACER=y
> 
> And enable it via:
> 
>     echo wakeup > /debug/tracing/current_tracer
> 
> and you should be seeing the worst-case scheduling latency traces in 
> /debug/tracing/trace, and the largest observed latency will be in 
> /debug/tracing/tracing_max_latency [in microseconds].

Note, the wakeup latency only tests realtime threads, since other threads
can have other issues for wakeup. I could change the wakeup tracer as
wakeup_rt, and make a new "wakeup" that tests all threads, but it may
be difficult to get something accurate.

-- Steve

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Steven Rostedt <rostedt-nx8X9YLhiw1AfugRpC6u6w@public.gmane.org> wrote:

> On Tue, 20 Jan 2009, Ingo Molnar wrote:
> > Another test would be to build the scheduler latency tracer into your 
> > kernel:
> > 
> >     CONFIG_SCHED_TRACER=y
> > 
> > And enable it via:
> > 
> >     echo wakeup > /debug/tracing/current_tracer
> > 
> > and you should be seeing the worst-case scheduling latency traces in 
> > /debug/tracing/trace, and the largest observed latency will be in 
> > /debug/tracing/tracing_max_latency [in microseconds].
> 
> Note, the wakeup latency only tests realtime threads, since other 
> threads can have other issues for wakeup. I could change the wakeup 
> tracer as wakeup_rt, and make a new "wakeup" that tests all threads, but 
> it may be difficult to get something accurate.

hm, that's a significant regression then. The latency tracer used to 
measure the highest-prio task in the system - be that RT or non-rt.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-01-20 at 15:25 +0100, Ingo Molnar wrote:
> > I could run top, vmstat and cat /proc/sched_debug in a loop until the
> > problem occurs and then trim it. Something like:
> > 
> > while true; do
> >   date                                >> $FILE
> >   echo "-- top: --"                   >> $FILE
> >   top -H -c -b -d 1 -n 0.5            >> $FILE 2>/dev/null
> >   echo "-- vmstat: --"                >> $FILE
> >   vmstat                              >> $FILE 2>/dev/null
> >   echo "-- sched_debug #$i: --"       >> $FILE
> >   cat /proc/sched_debug               >> $FILE 2>/dev/null
> > done
> > 
> > That should take a snapshot every half second or so.
> 
> Yeah, that would be lovely. You dont even have to trim it much - just give 
> us a timestamp to look at for the delay incident. You might also want to 
> start the kvm session while the script is already running - that way we'll 
> get fresh statistics and see the whole thing.

I've uploaded the debug info here:
  http://disenchant.net/tmp/bug-12465/

Some interesting sections should be around these times:

  01:36:04 -> 01:36:27
  01:37:30 -> 01:37:42
  01:37:52 -> 01:37:56
  01:39:37 -> 01:39:40
  01:40:01 -> 01:40:14

The output from ping is there too so you can see how the delays usually
show up (e.g. in clusters). The large debug file runs from before I
launched the VMs, right through the ping test. The trimmed file just
cuts out everything before I started ping.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> I've uploaded the debug info here:
>   http://disenchant.net/tmp/bug-12465/

one interesting number to watch for is the KVM thread's wait_max in 
/proc/*/sched. The largest one seems to be 11 milliseconds:

se.wait_max                        :             3.175034
se.wait_max                        :             4.029938
se.wait_max                        :             4.217674
se.wait_max                        :             4.957836
se.wait_max                        :            10.339471
se.wait_max                        :            11.603943

which would be about right given your latency settings:

 /proc/sys/kernel/sched_latency_ns:
 60000000

[ 60 msecs ]

but ... i dont specifically see the kvm threads there. Are they not in 
/proc/*? Maybe it's in threads and it needs to be accessed via 
/proc/*/task/*/sched, as via:

$ grep -h wait_max /proc/*/task/*/sched | sort -t: -n -k 2 | tail -10
se.wait_max                        :            77.858092
se.wait_max                        :            78.778409
se.wait_max                        :            79.379026
se.wait_max                        :            85.930963
se.wait_max                        :            87.671842
se.wait_max                        :            88.008602
se.wait_max                        :            95.095744
se.wait_max                        :           157.882573
se.wait_max                        :           268.714775
se.wait_max                        :           393.085252

so the worst-case latency

Btw., there's a few weird stats in your logs:

se.wait_max                        :          -284.864857
se.wait_max                        :          -284.843431
se.wait_max                        :          -284.820204
se.wait_max                        :          -284.345294
se.wait_max                        :          -284.298462
se.wait_max                        :          -284.018644
se.wait_max                        :          -284.018070
se.wait_max                        :          -188.022417
se.wait_max                        :          -188.021659
se.wait_max                        :           -92.030204
se.wait_max                        :           -92.027877

that field is not supposed to be negative. Mike, Peter, any ideas?

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Peter Zijlstra]

On Tue, 2009-01-20 at 17:06 +0100, Ingo Molnar wrote:
> se.wait_max                        :           -92.027877
> 
> that field is not supposed to be negative. Mike, Peter, any ideas?

Possibly unrelated, but whilst I was poking at try_to_wake_up yesterday,
I thought I spotted a site where we fail to update rq clock.

Since we just moved the task to a new cpu (and thus rq) we need to
update_rq_clock() again.

diff --git a/kernel/sched.c b/kernel/sched.c
index d7ae5f4..6cd5e52 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -2398,6 +2398,7 @@ static int try_to_wake_up(struct task_struct *p, unsigned int state, int sync)
 	if (cpu != orig_cpu) {
 		set_task_cpu(p, cpu);
 		task_rq_unlock(rq, &flags);
+		update_rq_clock(rq);
 		/* might preempt at this point */
 		rq = task_rq_lock(p, &flags);
 		old_state = p->state;

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Steven Rostedt wrote:
> Note, the wakeup latency only tests realtime threads, since other threads
> can have other issues for wakeup. I could change the wakeup tracer as
> wakeup_rt, and make a new "wakeup" that tests all threads, but it may
> be difficult to get something accurate.
>   

Kevin, can you retest with kvm at realtime priority?

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Steven Rostedt]

On Tue, 20 Jan 2009, Ingo Molnar wrote:

> 
> * Steven Rostedt <rostedt-nx8X9YLhiw1AfugRpC6u6w@public.gmane.org> wrote:
> 
> > On Tue, 20 Jan 2009, Ingo Molnar wrote:
> > > Another test would be to build the scheduler latency tracer into your 
> > > kernel:
> > > 
> > >     CONFIG_SCHED_TRACER=y
> > > 
> > > And enable it via:
> > > 
> > >     echo wakeup > /debug/tracing/current_tracer
> > > 
> > > and you should be seeing the worst-case scheduling latency traces in 
> > > /debug/tracing/trace, and the largest observed latency will be in 
> > > /debug/tracing/tracing_max_latency [in microseconds].
> > 
> > Note, the wakeup latency only tests realtime threads, since other 
> > threads can have other issues for wakeup. I could change the wakeup 
> > tracer as wakeup_rt, and make a new "wakeup" that tests all threads, but 
> > it may be difficult to get something accurate.
> 
> hm, that's a significant regression then. The latency tracer used to 
> measure the highest-prio task in the system - be that RT or non-rt.

Well, it is a regression from what was in -rt yes. But not from what ever 
was in mainline.

But I needed to change this to detect the problem that we 
solved with push and pull of rt tasks. The wake up of a non-rt tasks 
always took longer than an -rt task, and by tracing all tasks, I never got 
the wake up latency of an rt task.

As I mentioned earlier, I can make a wakeup-rt to do the rt tracing, and 
make wakeup do all tasks.

-- Steve

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-01-20 at 15:04 +0200, Avi Kivity wrote:
> Kevin Shanahan wrote:
> > On Tue, 2009-01-20 at 12:35 +0100, Ingo Molnar wrote:
> >> This only seems to occur under KVM, right? I.e. you tested it with -no-kvm 
> >> and the problem went away, correct?
> >>     
> >
> > Well, the I couldn't make the test conditions identical, but it the
> > problem didn't occur with the test I was able to do:
> >
> >   http://marc.info/?l=linux-kernel&m=123228728416498&w=2
> >
> >   
> 
> Can you also try with -no-kvm-irqchip?
> 
> You will need to comment out the lines
> 
>     /* ISA IRQs map to GSI 1-1 except for IRQ0 which maps
>      * to GSI 2.  GSI maps to ioapic 1-1.  This is not
>      * the cleanest way of doing it but it should work. */
> 
>     if (vector == 0)
>         vector = 2;
> 
> in qemu/hw/apic.c (should also fix -no-kvm smp).  This will change kvm 
> wakeups to use signals rather than the in-kernel code, which may be buggy.

Okay, I commented out those lines and compiled a new kvm-82 userspace
and kernel modules. Using those on a vanilla 2.6.28 kernel, with all
guests run with -no-kvm-irqchip added.

As before a number of the XP guests wanted to chug away at 100% CPU
usage for a long time. Three of the guests clocked up ~40 minutes CPU
time before I decided to just shut them down. Perhaps coincidentally,
these three guests are the only ones with Office 2003 installed on them.
That could be the difference between those guests and the other XP
guests, but that's probably not important for now.

The two Linux SMP guests booted okay this time, though they seem to only
use one CPU on the host (I guess kvm is not multi-threaded in this
mode?). "hermes-old", the guest I am pinging in all my tests, had a lot
of trouble running the apache2 setup - it was so slow it was difficult
to load a complete page from our RT system. The kvm process for this
guest was taking up 100% cpu on the host constantly and all sorts of
wierd stuff could be seen by watching top in the guest:

top - 03:44:17 up 43 min,  1 user,  load average: 3.95, 1.55, 0.80
Tasks: 101 total,   4 running,  97 sleeping,   0 stopped,   0 zombie
Cpu(s): 79.7%us, 10.4%sy,  0.0%ni,  0.0%id,  0.0%wa,  0.0%hi,  9.9%si,
0.0%st
Mem:   2075428k total,   391128k used,  1684300k free,    13044k buffers
Swap:  3502160k total,        0k used,  3502160k free,   118488k cached
  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND             
 2956 postgres  20   0 19704  11m  10m S 1658  0.6   2:55.99 postmaster          
 2934 www-data  20   0 60392  40m 5132 R   31  2.0   0:17.28 apache2             
 2958 postgres  20   0 19700  11m 9.8m R   28  0.6   0:20.41 postmaster          
 2940 www-data  20   0 58652  38m 5016 S   27  1.9   0:04.87 apache2             
 2937 www-data  20   0 60124  40m 5112 S   18  2.0   0:11.00 apache2             
 2959 postgres  20   0 19132 5424 4132 S   10  0.3   0:01.50 postmaster          
 2072 postgres  20   0  8064 1416  548 S    7  0.1   0:23.71 postmaster          
 2960 postgres  20   0 19132 5368 4060 R    6  0.3   0:01.55 postmaster          
 2071 postgres  20   0  8560 1972  488 S    5  0.1   0:08.33 postmaster    

Running the ping test with without apache2 running in the guest:

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 902740ms
rtt min/avg/max/mdev = 0.568/3.745/272.558/16.990 ms

And with apache2 running:

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 902758ms
rtt min/avg/max/mdev = 0.625/25.634/852.739/76.586 ms

In both cases it's quite variable, but the max latency is still not as
bad as when running with the irq chip enabled.

Anyway, the test is again not ideal, but I hope we're proving something.
That's all I can do for tonight - should be ready for more again
tomorrow night.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Steven Rostedt <rostedt-nx8X9YLhiw1AfugRpC6u6w@public.gmane.org> wrote:

> > hm, that's a significant regression then. The latency tracer used to 
> > measure the highest-prio task in the system - be that RT or non-rt.
> 
> Well, it is a regression from what was in -rt yes. But not from what 
> ever was in mainline.

indeed, it is not a regression, it is worse: it makes the mainline version 
utterly useless in 99% of the cases ... This really needs to be fixed.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> Running the ping test with without apache2 running in the guest:
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 902740ms
> rtt min/avg/max/mdev = 0.568/3.745/272.558/16.990 ms
> 
> And with apache2 running:
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 902758ms
> rtt min/avg/max/mdev = 0.625/25.634/852.739/76.586 ms
> 
> In both cases it's quite variable, but the max latency is still not as 
> bad as when running with the irq chip enabled.

So the worst-case ping latency is more than 10 times lower?

I'd say this points in the direction of some sort of KVM-internal 
wakeup/signalling latency that happens if KVM does not deschedule. For 
example it could be a bug like this: if a guest image runs at 100% CPU 
time for a long time, IRQ injections might not propagate up until the 
preemption callbacks run. (but i'm just speculating here)

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-01-20 at 19:47 +0200, Avi Kivity wrote:
> Steven Rostedt wrote:
> > Note, the wakeup latency only tests realtime threads, since other threads
> > can have other issues for wakeup. I could change the wakeup tracer as
> > wakeup_rt, and make a new "wakeup" that tests all threads, but it may
> > be difficult to get something accurate.
> 
> Kevin, can you retest with kvm at realtime priority?

Running vanilla Linux 2.6.28, kvm-82. First a control test to check that
the problem is still there when running at normal priority:

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 899283ms
rtt min/avg/max/mdev = 0.119/269.773/13739.426/1230.836 ms, pipe 14

Yeah, sure is.

Okay, so now I set the realtime attributes of the processes for the VM
instance being pinged:

flexo:~# ps ax | grep 6284
 6284 ?        Sl     6:11 /usr/local/kvm/bin/qemu-system-x86_64 -smp 2
-m 2048 -hda kvm-17-1.img -hdb kvm-17-tmp.img -net
nic,vlan=0,macaddr=52:54:00:12:34:67,model=rtl8139 -net
tap,vlan=0,ifname=tap17,script=no -vnc 127.0.0.1:17 -usbdevice tablet
-daemonize
flexo:~# pstree -p 6284
qemu-system-x86(6284)─┬─{qemu-system-x86}(6285)
                      ├─{qemu-system-x86}(6286)
                      └─{qemu-system-x86}(6540)

(info cpus on the QEMU console shows 6285 and 6286 being the VCPU
processes. Not sure what the third child is for, maybe vnc?.)

flexo:~# chrt -r -p 3 6284
flexo:~# chrt -r -p 3 6285
flexo:~# chrt -r -p 3 6286
flexo:~# chrt -p 6284
pid 6284's current scheduling policy: SCHED_RR
pid 6284's current scheduling priority: 3
flexo:~# chrt -p 6285
pid 6285's current scheduling policy: SCHED_RR
pid 6285's current scheduling priority: 3
flexo:~# chrt -p 6286
pid 6286's current scheduling policy: SCHED_RR
pid 6286's current scheduling priority: 3

And the result of the ping test now:

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 899326ms
rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms

So, a _huge_ difference. But what does it mean?

Regards,
Kevin.

P.S. Can someone tell me if I'm doing the CC: to bugme-daemon wrong? I
     thought that was supposed to add the emails as comments to the
     bugzilla report?

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Tue, 2009-01-20 at 19:47 +0200, Avi Kivity wrote:
>   
>> Steven Rostedt wrote:
>>     
>>> Note, the wakeup latency only tests realtime threads, since other threads
>>> can have other issues for wakeup. I could change the wakeup tracer as
>>> wakeup_rt, and make a new "wakeup" that tests all threads, but it may
>>> be difficult to get something accurate.
>>>       
>> Kevin, can you retest with kvm at realtime priority?
>>     
>
> Running vanilla Linux 2.6.28, kvm-82. First a control test to check that
> the problem is still there when running at normal priority:
>
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 899283ms
> rtt min/avg/max/mdev = 0.119/269.773/13739.426/1230.836 ms, pipe 14
>
> Yeah, sure is.
>
> Okay, so now I set the realtime attributes of the processes for the VM
> instance being pinged:
>
> flexo:~# ps ax | grep 6284
>  6284 ?        Sl     6:11 /usr/local/kvm/bin/qemu-system-x86_64 -smp 2
> -m 2048 -hda kvm-17-1.img -hdb kvm-17-tmp.img -net
> nic,vlan=0,macaddr=52:54:00:12:34:67,model=rtl8139 -net
> tap,vlan=0,ifname=tap17,script=no -vnc 127.0.0.1:17 -usbdevice tablet
> -daemonize
> flexo:~# pstree -p 6284
> qemu-system-x86(6284)─┬─{qemu-system-x86}(6285)
>                       ├─{qemu-system-x86}(6286)
>                       └─{qemu-system-x86}(6540)
>
> (info cpus on the QEMU console shows 6285 and 6286 being the VCPU
> processes. Not sure what the third child is for, maybe vnc?.)
>
> flexo:~# chrt -r -p 3 6284
> flexo:~# chrt -r -p 3 6285
> flexo:~# chrt -r -p 3 6286
> flexo:~# chrt -p 6284
> pid 6284's current scheduling policy: SCHED_RR
> pid 6284's current scheduling priority: 3
> flexo:~# chrt -p 6285
> pid 6285's current scheduling policy: SCHED_RR
> pid 6285's current scheduling priority: 3
> flexo:~# chrt -p 6286
> pid 6286's current scheduling policy: SCHED_RR
> pid 6286's current scheduling priority: 3
>
> And the result of the ping test now:
>
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
> rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
>
> So, a _huge_ difference. But what does it mean?

It means, a scheduling problem.  Can you run the latency tracer (which 
only works with realtime priority), so we can tell if it is (a) kvm 
failing to wake up the vcpu properly or (b) the scheduler delaying the 
vcpu from running.

> P.S. Can someone tell me if I'm doing the CC: to bugme-daemon wrong? I
>      thought that was supposed to add the emails as comments to the
>      bugzilla report?
>   

So long as it isn't complaining, you can continue.

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-01-21 at 16:34 +0200, Avi Kivity wrote:
> Kevin Shanahan wrote:
> > On Tue, 2009-01-20 at 19:47 +0200, Avi Kivity wrote:
> >> Kevin, can you retest with kvm at realtime priority?
...

> > --- hermes-old.wumi.org.au ping statistics ---
> > 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
> > rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
> >
> > So, a _huge_ difference. But what does it mean?
> 
> It means, a scheduling problem.  Can you run the latency tracer (which 
> only works with realtime priority), so we can tell if it is (a) kvm 
> failing to wake up the vcpu properly or (b) the scheduler delaying the 
> vcpu from running.

Sorry, but are you sure that's going to be useful?

If it only works on realtime threads and I'm not seeing the problem when
running kvm with realtime priority, is this going to tell you what you
want to know?

Not trying to be difficult, but that just didn't make sense to me.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
>>> --- hermes-old.wumi.org.au ping statistics ---
>>> 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
>>> rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
>>>
>>> So, a _huge_ difference. But what does it mean?
>>>       
>> It means, a scheduling problem.  Can you run the latency tracer (which 
>> only works with realtime priority), so we can tell if it is (a) kvm 
>> failing to wake up the vcpu properly or (b) the scheduler delaying the 
>> vcpu from running.
>>     
>
> Sorry, but are you sure that's going to be useful?
>
> If it only works on realtime threads and I'm not seeing the problem when
> running kvm with realtime priority, is this going to tell you what you
> want to know?
>
> Not trying to be difficult, but that just didn't make sense to me.
>   

You're right, wasn't thinking properly.

This is a tough one.  I'll see if I can think of something.  Ingo, any 
ideas?

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Steven Rostedt]

On Wed, 21 Jan 2009, Avi Kivity wrote:

> Kevin Shanahan wrote:
> > On Tue, 2009-01-20 at 19:47 +0200, Avi Kivity wrote:
> >   
> > > Steven Rostedt wrote:
> > >     
> > > > Note, the wakeup latency only tests realtime threads, since other
> > > > threads
> > > > can have other issues for wakeup. I could change the wakeup tracer as
> > > > wakeup_rt, and make a new "wakeup" that tests all threads, but it may
> > > > be difficult to get something accurate.
> > > >       
> > > Kevin, can you retest with kvm at realtime priority?
> > >     
> > 
> > Running vanilla Linux 2.6.28, kvm-82. First a control test to check that
> > the problem is still there when running at normal priority:
> > 
> > --- hermes-old.wumi.org.au ping statistics ---
> > 900 packets transmitted, 900 received, 0% packet loss, time 899283ms
> > rtt min/avg/max/mdev = 0.119/269.773/13739.426/1230.836 ms, pipe 14
> > 
> > Yeah, sure is.
> > 
> > Okay, so now I set the realtime attributes of the processes for the VM
> > instance being pinged:
> > 
> > flexo:~# ps ax | grep 6284
> >  6284 ?        Sl     6:11 /usr/local/kvm/bin/qemu-system-x86_64 -smp 2
> > -m 2048 -hda kvm-17-1.img -hdb kvm-17-tmp.img -net
> > nic,vlan=0,macaddr=52:54:00:12:34:67,model=rtl8139 -net
> > tap,vlan=0,ifname=tap17,script=no -vnc 127.0.0.1:17 -usbdevice tablet
> > -daemonize
> > flexo:~# pstree -p 6284
> > qemu-system-x86(6284)???{qemu-system-x86}(6285)
> >                       ??{qemu-system-x86}(6286)
> >                       ??{qemu-system-x86}(6540)
> > 
> > (info cpus on the QEMU console shows 6285 and 6286 being the VCPU
> > processes. Not sure what the third child is for, maybe vnc?.)
> > 
> > flexo:~# chrt -r -p 3 6284
> > flexo:~# chrt -r -p 3 6285
> > flexo:~# chrt -r -p 3 6286
> > flexo:~# chrt -p 6284
> > pid 6284's current scheduling policy: SCHED_RR
> > pid 6284's current scheduling priority: 3
> > flexo:~# chrt -p 6285
> > pid 6285's current scheduling policy: SCHED_RR
> > pid 6285's current scheduling priority: 3
> > flexo:~# chrt -p 6286
> > pid 6286's current scheduling policy: SCHED_RR
> > pid 6286's current scheduling priority: 3
> > 
> > And the result of the ping test now:
> > 
> > --- hermes-old.wumi.org.au ping statistics ---
> > 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
> > rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
> > 
> > So, a _huge_ difference. But what does it mean?
> 
> It means, a scheduling problem.  Can you run the latency tracer (which only
> works with realtime priority), so we can tell if it is (a) kvm failing to wake
> up the vcpu properly or (b) the scheduler delaying the vcpu from running.
> 

Note, I'm working on a tracer that will also measure non RT task wake up 
times.

-- Steve

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Steven Rostedt]

On Wed, 21 Jan 2009, Avi Kivity wrote:

> Kevin Shanahan wrote:
> > > > --- hermes-old.wumi.org.au ping statistics ---
> > > > 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
> > > > rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
> > > > 
> > > > So, a _huge_ difference. But what does it mean?
> > > >       
> > > It means, a scheduling problem.  Can you run the latency tracer (which
> > > only works with realtime priority), so we can tell if it is (a) kvm
> > > failing to wake up the vcpu properly or (b) the scheduler delaying the
> > > vcpu from running.
> > >     
> > 
> > Sorry, but are you sure that's going to be useful?
> > 
> > If it only works on realtime threads and I'm not seeing the problem when
> > running kvm with realtime priority, is this going to tell you what you
> > want to know?
> > 
> > Not trying to be difficult, but that just didn't make sense to me.
> >   
> 
> You're right, wasn't thinking properly.
> 
> This is a tough one.  I'll see if I can think of something.  Ingo, any ideas?
> 

I should have replied to this email :-)

Yeah, I'm working on making wakeup latency tracer work with non rt tasks.

The "wakeup" tracer will now trace all tasks where as a new "wakeup_rt" 
tracer will only trace rt tasks. I did it for rt tasks only because it 
only records the highest latency wake ups and the non rt tasks were always 
bigger than the rt tasks which made what I was tracing useless (the rt 
scheduling).

But by not having an option for all tasks, it makes the wakeup tracer 
useless for everyone else ;-)

-- Steve

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:

> Kevin Shanahan wrote:
>> On Tue, 2009-01-20 at 19:47 +0200, Avi Kivity wrote:
>>   
>>> Steven Rostedt wrote:
>>>     
>>>> Note, the wakeup latency only tests realtime threads, since other threads
>>>> can have other issues for wakeup. I could change the wakeup tracer as
>>>> wakeup_rt, and make a new "wakeup" that tests all threads, but it may
>>>> be difficult to get something accurate.
>>>>       
>>> Kevin, can you retest with kvm at realtime priority?
>>>     
>>
>> Running vanilla Linux 2.6.28, kvm-82. First a control test to check that
>> the problem is still there when running at normal priority:
>>
>> --- hermes-old.wumi.org.au ping statistics ---
>> 900 packets transmitted, 900 received, 0% packet loss, time 899283ms
>> rtt min/avg/max/mdev = 0.119/269.773/13739.426/1230.836 ms, pipe 14
>>
>> Yeah, sure is.
>>
>> Okay, so now I set the realtime attributes of the processes for the VM
>> instance being pinged:
>>
>> flexo:~# ps ax | grep 6284
>>  6284 ?        Sl     6:11 /usr/local/kvm/bin/qemu-system-x86_64 -smp 2
>> -m 2048 -hda kvm-17-1.img -hdb kvm-17-tmp.img -net
>> nic,vlan=0,macaddr=52:54:00:12:34:67,model=rtl8139 -net
>> tap,vlan=0,ifname=tap17,script=no -vnc 127.0.0.1:17 -usbdevice tablet
>> -daemonize
>> flexo:~# pstree -p 6284
>> qemu-system-x86(6284)─┬─{qemu-system-x86}(6285)
>>                       ├─{qemu-system-x86}(6286)
>>                       └─{qemu-system-x86}(6540)
>>
>> (info cpus on the QEMU console shows 6285 and 6286 being the VCPU
>> processes. Not sure what the third child is for, maybe vnc?.)
>>
>> flexo:~# chrt -r -p 3 6284
>> flexo:~# chrt -r -p 3 6285
>> flexo:~# chrt -r -p 3 6286
>> flexo:~# chrt -p 6284
>> pid 6284's current scheduling policy: SCHED_RR
>> pid 6284's current scheduling priority: 3
>> flexo:~# chrt -p 6285
>> pid 6285's current scheduling policy: SCHED_RR
>> pid 6285's current scheduling priority: 3
>> flexo:~# chrt -p 6286
>> pid 6286's current scheduling policy: SCHED_RR
>> pid 6286's current scheduling priority: 3
>>
>> And the result of the ping test now:
>>
>> --- hermes-old.wumi.org.au ping statistics ---
>> 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
>> rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
>>
>> So, a _huge_ difference. But what does it mean?
>
> It means, a scheduling problem.  Can you run the latency tracer (which 
> only works with realtime priority), so we can tell if it is (a) kvm 
> failing to wake up the vcpu properly or (b) the scheduler delaying the 
> vcpu from running.

Could we please get an ftrace capture of the incident?

Firstly, it makes sense to simplify the tracing environment as much as 
possible: for example single-CPU traces are much easier to interpret.

Can you reproduce it with just one CPU online? I.e. if you offline all the 
other cores via:

  echo 0 > /sys/devices/system/cpu/cpu1/online

  [etc.]

and keep CPU#0 only, do the latencies still occur?

If they do still occur, then please do the traces that way.

[ If they do not occur then switch back on all CPUs - we'll sort out the
  traces ;-) ]

Then please build a function tracer kernel, by enabling:

  CONFIG_FUNCTION_TRACER=y
  CONFIG_FUNCTION_GRAPH_TRACER=y
  CONFIG_DYNAMIC_FTRACE=y

Once you boot into such a kernel, you can switch on function tracing via:

  cd /debug/tracing/

  echo 0 > tracing_enabled
  echo function_graph > current_tracer
  echo funcgraph-proc > trace_options 

It does not run yet, first find a suitable set of functions to trace. For 
example this will be a pretty good starting point for scheduler+KVM 
problems:

  echo ''         > set_ftrace_filter  # clear filter functions
  echo '*sched*' >> set_ftrace_filter 
  echo '*wake*'  >> set_ftrace_filter
  echo '*kvm*'   >> set_ftrace_filter
  echo 1 > tracing_enabled             # let the tracer go

You can see your current selection of functions to trace via 'cat 
set_ftrace_filter', and you can see all functions via 'cat 
available_filter_functions'.

You can also trace all functions via:

  echo '*' > set_ftrace_filter

Tracer output can be captured from the 'trace' file. It should look like 
this:

 15)   cc1-28106    |   0.263 us    |    page_evictable();
 15)   cc1-28106    |               |    lru_cache_add_lru() {
 15)   cc1-28106    |   0.252 us    |      __lru_cache_add();
 15)   cc1-28106    |   0.738 us    |    }
 15)   cc1-28106    | + 74.026 us   |  }
 15)   cc1-28106    |               |  up_read() {
 15)   cc1-28106    |   0.257 us    |    _spin_lock_irqsave();
 15)   cc1-28106    |   0.253 us    |    _spin_unlock_irqrestore();
 15)   cc1-28106    |   1.329 us    |  }

To capture a continuous stream of all trace data you can do:

  cat trace_pipe > /tmp/trace.txt

(this will also drain the trace ringbuffers.)

Note that this can be quite expensive if there are a lot of functions that 
are traced - so it makes sense to trim down the set of traced functions to 
only the interesting ones. Which are the interesting ones can be 
determined from looking at the traces. You should see your KVM threads 
getting active every second as the ping happens.

If you get lost events you can increase the trace buffer size via the 
buffer_size_kb control - the default is around 1.4 MB.

Let me know if any of these steps is causing problems or if interpreting 
the traces is difficult.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Steven Rostedt]

On Wed, 21 Jan 2009, Avi Kivity wrote:

> Kevin Shanahan wrote:
> > > > --- hermes-old.wumi.org.au ping statistics ---
> > > > 900 packets transmitted, 900 received, 0% packet loss, time 899326ms
> > > > rtt min/avg/max/mdev = 0.093/0.157/3.611/0.117 ms
> > > > 
> > > > So, a _huge_ difference. But what does it mean?
> > > >       
> > > It means, a scheduling problem.  Can you run the latency tracer (which
> > > only works with realtime priority), so we can tell if it is (a) kvm
> > > failing to wake up the vcpu properly or (b) the scheduler delaying the
> > > vcpu from running.
> > >     
> > 
> > Sorry, but are you sure that's going to be useful?
> > 
> > If it only works on realtime threads and I'm not seeing the problem when
> > running kvm with realtime priority, is this going to tell you what you
> > want to know?
> > 
> > Not trying to be difficult, but that just didn't make sense to me.
> >   
> 
> You're right, wasn't thinking properly.
> 
> This is a tough one.  I'll see if I can think of something.  Ingo, any ideas?

I fixed up the wakeup latency tracer to work with all tasks (as well as 
other fixes). You can checkout the following:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git

  branch: tip/devel

compile with CONFIG_FUNCTION_TRACER and CONFIG_SCHED_TRACER and just

echo 0 > /debug/tracing/tracing_enabled
echo wakeup > /debug/tracing/current_tracer

echo 1 > /debug/tracing/tracing_enabled
run your test
echo 0 > /debug/tracing/tracing_enabled

and then look at /debug/tracing/latency_trace

-- Steve

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-01-21 at 16:18 +0100, Ingo Molnar wrote:
> * Avi Kivity <avi@redhat.com> wrote:
> > It means, a scheduling problem.  Can you run the latency tracer (which 
> > only works with realtime priority), so we can tell if it is (a) kvm 
> > failing to wake up the vcpu properly or (b) the scheduler delaying the 
> > vcpu from running.
> 
> Could we please get an ftrace capture of the incident?
> 
> Firstly, it makes sense to simplify the tracing environment as much as 
> possible: for example single-CPU traces are much easier to interpret.
> 
> Can you reproduce it with just one CPU online? I.e. if you offline all the 
> other cores via:
> 
>   echo 0 > /sys/devices/system/cpu/cpu1/online
> 
>   [etc.]
> 
> and keep CPU#0 only, do the latencies still occur?
> 
> If they do still occur, then please do the traces that way.
> 
> [ If they do not occur then switch back on all CPUs - we'll sort out the
>   traces ;-) ]
> 
> Then please build a function tracer kernel, by enabling:
> 
>   CONFIG_FUNCTION_TRACER=y
>   CONFIG_FUNCTION_GRAPH_TRACER=y
>   CONFIG_DYNAMIC_FTRACE=y

Looks like the function graph tracer is only in 2.6.29, so I've updated
now to 2.6.29-rc2-00013-gf3b8436.

Again, a control test to make sure the problem still occurs:

--- hermes-old.wumi.org.au ping statistics ---
64 packets transmitted, 64 received, 0% packet loss, time 63080ms
rtt min/avg/max/mdev = 0.168/479.893/4015.950/894.721 ms, pipe 5

Yes, plenty of delays there. Next, checking if I can reproduce with only
one core online:

echo 0 > /sys/devices/system/cpu/cpu1/online
echo 0 > /sys/devices/system/cpu/cpu2/online
echo 0 > /sys/devices/system/cpu/cpu3/online
...

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 900253ms
rtt min/avg/max/mdev = 0.127/38.937/2082.347/170.348 ms, pipe 3

--- hermes-old.wumi.org.au ping statistics ---
900 packets transmitted, 900 received, 0% packet loss, time 900995ms
rtt min/avg/max/mdev = 0.127/428.398/17126.227/1634.980 ms, pipe 18

So it looks like I can do the simplified trace. I've run out of time for
that this morning, but I'll spend some time on it over the weekend.
Thanks for the detailed instructions - it doesn't look like it will be
too hard.

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org> wrote:

> On Wed, 2009-01-21 at 16:18 +0100, Ingo Molnar wrote:
> > * Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:
> > > It means, a scheduling problem.  Can you run the latency tracer (which 
> > > only works with realtime priority), so we can tell if it is (a) kvm 
> > > failing to wake up the vcpu properly or (b) the scheduler delaying the 
> > > vcpu from running.
> > 
> > Could we please get an ftrace capture of the incident?
> > 
> > Firstly, it makes sense to simplify the tracing environment as much as 
> > possible: for example single-CPU traces are much easier to interpret.
> > 
> > Can you reproduce it with just one CPU online? I.e. if you offline all the 
> > other cores via:
> > 
> >   echo 0 > /sys/devices/system/cpu/cpu1/online
> > 
> >   [etc.]
> > 
> > and keep CPU#0 only, do the latencies still occur?
> > 
> > If they do still occur, then please do the traces that way.
> > 
> > [ If they do not occur then switch back on all CPUs - we'll sort out the
> >   traces ;-) ]
> > 
> > Then please build a function tracer kernel, by enabling:
> > 
> >   CONFIG_FUNCTION_TRACER=y
> >   CONFIG_FUNCTION_GRAPH_TRACER=y
> >   CONFIG_DYNAMIC_FTRACE=y
> 
> Looks like the function graph tracer is only in 2.6.29, so I've updated
> now to 2.6.29-rc2-00013-gf3b8436.
> 
> Again, a control test to make sure the problem still occurs:
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 64 packets transmitted, 64 received, 0% packet loss, time 63080ms
> rtt min/avg/max/mdev = 0.168/479.893/4015.950/894.721 ms, pipe 5
> 
> Yes, plenty of delays there. Next, checking if I can reproduce with only
> one core online:
> 
> echo 0 > /sys/devices/system/cpu/cpu1/online
> echo 0 > /sys/devices/system/cpu/cpu2/online
> echo 0 > /sys/devices/system/cpu/cpu3/online
> ...
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 900253ms
> rtt min/avg/max/mdev = 0.127/38.937/2082.347/170.348 ms, pipe 3
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 900 packets transmitted, 900 received, 0% packet loss, time 900995ms
> rtt min/avg/max/mdev = 0.127/428.398/17126.227/1634.980 ms, pipe 18
> 
> So it looks like I can do the simplified trace. [...]

That's good news! Another thing is that happens sometimes is that narrow 
races go away if tracing is turned on - the dreaded Heisenbugs. Hopefully 
this wont happen, but if it does, tracing is the cheapest when only a few 
specific functions are traced.

There are two main types of delays that can occur:

 - the delay is CPU time - i.e. anomalously large amount of CPU time spent 
   somewhere in the kernel. Getting a trace of exactly what that 
   processing is would be nice.

 - the delay is some sort of missed wakeup or other logic error in the 
   flow of execution. These are harder to trace - you might want to take a 
   look at trace_options to extend the trace format with various details, 
   if the need arises.

> [...] I've run out of time for that this morning, but I'll spend some 
> time on it over the weekend. Thanks for the detailed instructions - it 
> doesn't look like it will be too hard.

ok, looking forward to your traces. Also, let us know if you run into 
anything unintuitive / complicated in the ftrace usage side.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-01-21 at 16:18 +0100, Ingo Molnar wrote:
> * Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:
> > It means, a scheduling problem.  Can you run the latency tracer (which 
> > only works with realtime priority), so we can tell if it is (a) kvm 
> > failing to wake up the vcpu properly or (b) the scheduler delaying the 
> > vcpu from running.
> 
> Could we please get an ftrace capture of the incident?
> 
> Firstly, it makes sense to simplify the tracing environment as much as 
> possible: for example single-CPU traces are much easier to interpret.
> 
> Can you reproduce it with just one CPU online? I.e. if you offline all the 
> other cores via:
> 
>   echo 0 > /sys/devices/system/cpu/cpu1/online
> 
>   [etc.]
> 
> and keep CPU#0 only, do the latencies still occur?
> 
> If they do still occur, then please do the traces that way.
> 
> [ If they do not occur then switch back on all CPUs - we'll sort out the
>   traces ;-) ]
> 
> Then please build a function tracer kernel, by enabling:
> 
>   CONFIG_FUNCTION_TRACER=y
>   CONFIG_FUNCTION_GRAPH_TRACER=y
>   CONFIG_DYNAMIC_FTRACE=y
> 
> Once you boot into such a kernel, you can switch on function tracing via:
> 
>   cd /debug/tracing/
> 
>   echo 0 > tracing_enabled
>   echo function_graph > current_tracer
>   echo funcgraph-proc > trace_options 
> 
> It does not run yet, first find a suitable set of functions to trace. For 
> example this will be a pretty good starting point for scheduler+KVM 
> problems:
> 
>   echo ''         > set_ftrace_filter  # clear filter functions
>   echo '*sched*' >> set_ftrace_filter 
>   echo '*wake*'  >> set_ftrace_filter
>   echo '*kvm*'   >> set_ftrace_filter
>   echo 1 > tracing_enabled             # let the tracer go
> 
> You can see your current selection of functions to trace via 'cat 
> set_ftrace_filter', and you can see all functions via 'cat 
> available_filter_functions'.
> 
> You can also trace all functions via:
> 
>   echo '*' > set_ftrace_filter
> 
> Tracer output can be captured from the 'trace' file. It should look like 
> this:
> 
>  15)   cc1-28106    |   0.263 us    |    page_evictable();
>  15)   cc1-28106    |               |    lru_cache_add_lru() {
>  15)   cc1-28106    |   0.252 us    |      __lru_cache_add();
>  15)   cc1-28106    |   0.738 us    |    }
>  15)   cc1-28106    | + 74.026 us   |  }
>  15)   cc1-28106    |               |  up_read() {
>  15)   cc1-28106    |   0.257 us    |    _spin_lock_irqsave();
>  15)   cc1-28106    |   0.253 us    |    _spin_unlock_irqrestore();
>  15)   cc1-28106    |   1.329 us    |  }
> 
> To capture a continuous stream of all trace data you can do:
> 
>   cat trace_pipe > /tmp/trace.txt
> 
> (this will also drain the trace ringbuffers.)
> 
> Note that this can be quite expensive if there are a lot of functions that 
> are traced - so it makes sense to trim down the set of traced functions to 
> only the interesting ones. Which are the interesting ones can be 
> determined from looking at the traces. You should see your KVM threads 
> getting active every second as the ping happens.
> 
> If you get lost events you can increase the trace buffer size via the 
> buffer_size_kb control - the default is around 1.4 MB.
> 
> Let me know if any of these steps is causing problems or if interpreting 
> the traces is difficult.

Just carrying out the steps was okay, but I don't really know what I'm
looking at. I've uploaded the trace here (about 10 seconds worth, I
think):

  http://disenchant.net/tmp/bug-12465/trace-1/

The guest being pinged is process 4353:

kmshanah@flexo:~$ pstree -p 4353
qemu-system-x86(4353)─┬─{qemu-system-x86}(4354)
                      ├─{qemu-system-x86}(4355)
                      └─{qemu-system-x86}(4772)

I guess the larger overhead/duration values are what we are looking for,
e.g.:

kmshanah@flexo:~$ bzgrep -E '[[:digit:]]{6,}' trace.txt.bz2 
 0)   ksoftir-4    | ! 3010470 us |  }
 0)  qemu-sy-4354  | ! 250406.2 us |    }
 0)  qemu-sy-4354  | ! 250407.0 us |  }
 0)  qemu-sy-4354  | ! 362946.3 us |    }
 0)  qemu-sy-4354  | ! 362947.0 us |  }
 0)  qemu-sy-4177  | ! 780480.3 us |  }
 0)  qemu-sy-4354  | ! 117685.7 us |    }
 0)  qemu-sy-4354  | ! 117686.5 us |  }

That ksoftirqd value is a bit strange (> 3 seconds, or is the formatting
wrong?). I guess I still need some guidance to know what I'm looking at
with this trace and/or what to do next.

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Peter Zijlstra]

On Mon, 2009-01-26 at 20:25 +1030, Kevin Shanahan wrote:

> Just carrying out the steps was okay, but I don't really know what I'm
> looking at. I've uploaded the trace here (about 10 seconds worth, I
> think):
> 
>   http://disenchant.net/tmp/bug-12465/trace-1/
> 
> The guest being pinged is process 4353:
> 
> kmshanah@flexo:~$ pstree -p 4353
> qemu-system-x86(4353)─┬─{qemu-system-x86}(4354)
>                       ├─{qemu-system-x86}(4355)
>                       └─{qemu-system-x86}(4772)
> 
> I guess the larger overhead/duration values are what we are looking for,
> e.g.:
> 
> kmshanah@flexo:~$ bzgrep -E '[[:digit:]]{6,}' trace.txt.bz2 
>  0)   ksoftir-4    | ! 3010470 us |  }
>  0)  qemu-sy-4354  | ! 250406.2 us |    }
>  0)  qemu-sy-4354  | ! 250407.0 us |  }
>  0)  qemu-sy-4354  | ! 362946.3 us |    }
>  0)  qemu-sy-4354  | ! 362947.0 us |  }
>  0)  qemu-sy-4177  | ! 780480.3 us |  }
>  0)  qemu-sy-4354  | ! 117685.7 us |    }
>  0)  qemu-sy-4354  | ! 117686.5 us |  }
> 
> That ksoftirqd value is a bit strange (> 3 seconds, or is the formatting
> wrong?). I guess I still need some guidance to know what I'm looking at
> with this trace and/or what to do next.

What happens is that it gets preempted a few times while running a
particular function, say do_softirqd(), or kvm_arch_vcpu_ioctl_run().

Now, when this function ends, it prints the wall-time delay between
start and end of that function, instead of the task-time delay.

So by having been preempted several times, that gets inflated.

That said, the output is slightly 'buggy' in that is seems to miss
context switches at times:

 0)  qemu-sy-4339  |               |        schedule() {
 0)  qemu-sy-4131  | ! 6750.369 us |        }

I also find it very hard to attribute all time:

 0)  qemu-sy-4354  |               |  kvm_vcpu_ioctl() {
 0)  qemu-sy-4354  |               |    kvm_arch_vcpu_ioctl_run() {
 0)  qemu-sy-4354  |               |      kvm_arch_vcpu_load() {
 0)  qemu-sy-4354  |               |        kvm_write_guest_time() {
 0)  qemu-sy-4354  |   0.289 us    |        }
 0)  qemu-sy-4354  |   0.956 us    |      }
 0)  qemu-sy-4354  |               |      kvm_inject_pending_timer_irqs() {
 0)  qemu-sy-4354  |               |        kvm_inject_apic_timer_irqs() {
 0)  qemu-sy-4354  |   0.295 us    |        }
 0)  qemu-sy-4354  |               |        kvm_inject_pit_timer_irqs() {
 0)  qemu-sy-4354  |   0.304 us    |        }
 0)  qemu-sy-4354  |   1.488 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_enabled() {
 0)  qemu-sy-4354  |   0.294 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_find_highest_irr() {
 0)  qemu-sy-4354  |   0.307 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_has_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.325 us    |        }
 0)  qemu-sy-4354  |               |        kvm_apic_accept_pic_intr() {
 0)  qemu-sy-4354  |   0.298 us    |        }
 0)  qemu-sy-4354  |   1.521 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_to_vapic() {
 0)  qemu-sy-4354  |   0.295 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |               |                  wakeup_preempt_entity() {
 0)  qemu-sy-4354  |   0.309 us    |                  }
 0)  qemu-sy-4354  |               |                  resched_task() {
 0)  qemu-sy-4354  |   0.324 us    |                  }
 0)  qemu-sy-4354  |   1.614 us    |                }
 0)  qemu-sy-4354  |   2.934 us    |              }
 0)  qemu-sy-4354  |   3.529 us    |            }
 0)  qemu-sy-4354  |   4.118 us    |          }
 0)  qemu-sy-4354  |   4.743 us    |        }
 0)  qemu-sy-4354  |   5.432 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  =>  qemu-sy-4294
 0)  qemu-sy-4237  =>  qemu-sy-4354
 0)  qemu-sy-4354  |   5.500 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.316 us    |                }
 0)  qemu-sy-4354  |   1.250 us    |              }
 0)  qemu-sy-4354  |   1.834 us    |            }
 0)  qemu-sy-4354  |   2.434 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.418 us    |              }
 0)  qemu-sy-4354  |   1.001 us    |            }
 0)  qemu-sy-4354  |   1.608 us    |          }
 0)  qemu-sy-4354  |   4.987 us    |        }
 0)  qemu-sy-4354  |   5.597 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.325 us    |                }
 0)  qemu-sy-4354  |   1.247 us    |              }
 0)  qemu-sy-4354  |   1.831 us    |            }
 0)  qemu-sy-4354  |   2.435 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.415 us    |              }
 0)  qemu-sy-4354  |   0.995 us    |            }
 0)  qemu-sy-4354  |   1.587 us    |          }
 0)  qemu-sy-4354  |   5.026 us    |        }
 0)  qemu-sy-4354  |   5.639 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.313 us    |                }
 0)  qemu-sy-4354  |   1.331 us    |              }
 0)  qemu-sy-4354  |   1.903 us    |            }
 0)  qemu-sy-4354  |   2.507 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.415 us    |              }
 0)  qemu-sy-4354  |   0.998 us    |            }
 0)  qemu-sy-4354  |   1.596 us    |          }
 0)  qemu-sy-4354  |   5.017 us    |        }
 0)  qemu-sy-4354  |   5.630 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.318 us    |                }
 0)  qemu-sy-4354  |   1.275 us    |              }
 0)  qemu-sy-4354  |   1.860 us    |            }
 0)  qemu-sy-4354  |   2.474 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.406 us    |              }
 0)  qemu-sy-4354  |   0.989 us    |            }
 0)  qemu-sy-4354  |   1.581 us    |          }
 0)  qemu-sy-4354  |   4.953 us    |        }
 0)  qemu-sy-4354  |   5.567 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.313 us    |                }
 0)  qemu-sy-4354  |   2.645 us    |              }
 0)  qemu-sy-4354  |   3.219 us    |            }
 0)  qemu-sy-4354  |   3.824 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.396 us    |              }
 0)  qemu-sy-4354  |   0.968 us    |            }
 0)  qemu-sy-4354  |   1.557 us    |          }
 0)  qemu-sy-4354  |   6.390 us    |        }
 0)  qemu-sy-4354  |   7.004 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.310 us    |                }
 0)  qemu-sy-4354  |   1.160 us    |              }
 0)  qemu-sy-4354  |   1.731 us    |            }
 0)  qemu-sy-4354  |   2.330 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.397 us    |              }
 0)  qemu-sy-4354  |   0.965 us    |            }
 0)  qemu-sy-4354  |   1.554 us    |          }
 0)  qemu-sy-4354  |   4.768 us    |        }
 0)  qemu-sy-4354  |   5.383 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.307 us    |                }
 0)  qemu-sy-4354  |   1.208 us    |              }
 0)  qemu-sy-4354  |   1.777 us    |            }
 0)  qemu-sy-4354  |   2.377 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.394 us    |              }
 0)  qemu-sy-4354  |   0.964 us    |            }
 0)  qemu-sy-4354  |   1.554 us    |          }
 0)  qemu-sy-4354  |   4.855 us    |        }
 0)  qemu-sy-4354  |   5.482 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.307 us    |                }
 0)  qemu-sy-4354  |   1.193 us    |              }
 0)  qemu-sy-4354  |   1.765 us    |            }
 0)  qemu-sy-4354  |   2.368 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.394 us    |              }
 0)  qemu-sy-4354  |   0.974 us    |            }
 0)  qemu-sy-4354  |   1.560 us    |          }
 0)  qemu-sy-4354  |   4.831 us    |        }
 0)  qemu-sy-4354  |   5.461 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.318 us    |                }
 0)  qemu-sy-4354  |   1.175 us    |              }
 0)  qemu-sy-4354  |   1.747 us    |            }
 0)  qemu-sy-4354  |   2.344 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   2.029 us    |              }
 0)  qemu-sy-4354  |   2.597 us    |            }
 0)  qemu-sy-4354  |   3.186 us    |          }
 0)  qemu-sy-4354  |   6.430 us    |        }
 0)  qemu-sy-4354  |   7.046 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.310 us    |                }
 0)  qemu-sy-4354  |   1.199 us    |              }
 0)  qemu-sy-4354  |   1.780 us    |            }
 0)  qemu-sy-4354  |   2.378 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.397 us    |              }
 0)  qemu-sy-4354  |   0.968 us    |            }
 0)  qemu-sy-4354  |   1.560 us    |          }
 0)  qemu-sy-4354  |   4.933 us    |        }
 0)  qemu-sy-4354  |   5.549 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.316 us    |                }
 0)  qemu-sy-4354  |   1.202 us    |              }
 0)  qemu-sy-4354  |   1.792 us    |            }
 0)  qemu-sy-4354  |   2.357 us    |          }
 0)  qemu-sy-4354  |   2.973 us    |        }
 0)  qemu-sy-4354  |   3.607 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.304 us    |                }
 0)  qemu-sy-4354  |   1.149 us    |              }
 0)  qemu-sy-4354  |   1.713 us    |            }
 0)  qemu-sy-4354  |   2.309 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.405 us    |              }
 0)  qemu-sy-4354  |   0.971 us    |            }
 0)  qemu-sy-4354  |   1.569 us    |          }
 0)  qemu-sy-4354  |   4.800 us    |        }
 0)  qemu-sy-4354  |   5.408 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.298 us    |                }
 0)  qemu-sy-4354  |   1.127 us    |              }
 0)  qemu-sy-4354  |   1.695 us    |            }
 0)  qemu-sy-4354  |   2.291 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.403 us    |              }
 0)  qemu-sy-4354  |   0.974 us    |            }
 0)  qemu-sy-4354  |   1.575 us    |          }
 0)  qemu-sy-4354  |   4.888 us    |        }
 0)  qemu-sy-4354  |   5.482 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.303 us    |                }
 0)  qemu-sy-4354  |   2.428 us    |              }
 0)  qemu-sy-4354  |   2.991 us    |            }
 0)  qemu-sy-4354  |   3.559 us    |          }
 0)  qemu-sy-4354  |   4.157 us    |        }
 0)  qemu-sy-4354  |   4.752 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.313 us    |                }
 0)  qemu-sy-4354  |   1.437 us    |              }
 0)  qemu-sy-4354  |   2.002 us    |            }
 0)  qemu-sy-4354  |   2.594 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.418 us    |              }
 0)  qemu-sy-4354  |   1.016 us    |            }
 0)  qemu-sy-4354  |   1.587 us    |          }
 0)  qemu-sy-4354  |   5.077 us    |        }
 0)  qemu-sy-4354  |   5.699 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.309 us    |                }
 0)  qemu-sy-4354  |   1.314 us    |              }
 0)  qemu-sy-4354  |   1.884 us    |            }
 0)  qemu-sy-4354  |   2.480 us    |          }
 0)  qemu-sy-4354  |               |          pollwake() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |   0.405 us    |              }
 0)  qemu-sy-4354  |   0.977 us    |            }
 0)  qemu-sy-4354  |   1.560 us    |          }
 0)  qemu-sy-4354  |   4.962 us    |        }
 0)  qemu-sy-4354  |   5.591 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.304 us    |                }
 0)  qemu-sy-4354  |   1.199 us    |              }
 0)  qemu-sy-4354  |   1.765 us    |            }
 0)  qemu-sy-4354  |   2.330 us    |          }
 0)  qemu-sy-4354  |   2.952 us    |        }
 0)  qemu-sy-4354  |   3.547 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.322 us    |                }
 0)  qemu-sy-4354  |   1.278 us    |              }
 0)  qemu-sy-4354  |   1.839 us    |            }
 0)  qemu-sy-4354  |   2.402 us    |          }
 0)  qemu-sy-4354  |   3.032 us    |        }
 0)  qemu-sy-4354  |   3.658 us    |      }
 0)  qemu-sy-4354  |               |      __wake_up() {
 0)  qemu-sy-4354  |               |        __wake_up_common() {
 0)  qemu-sy-4354  |               |          autoremove_wake_function() {
 0)  qemu-sy-4354  |               |            default_wake_function() {
 0)  qemu-sy-4354  |               |              try_to_wake_up() {
 0)  qemu-sy-4354  |               |                check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.303 us    |                }
 0)  qemu-sy-4354  |   1.208 us    |              }
 0)  qemu-sy-4354  |   1.759 us    |            }
 0)  qemu-sy-4354  |   2.341 us    |          }
 0)  qemu-sy-4354  |   2.949 us    |        }
 0)  qemu-sy-4354  |   3.556 us    |      }
 0)  qemu-sy-4354  |               |      scheduler_tick() {
 0)  qemu-sy-4354  |               |        sched_slice() {
 0)  qemu-sy-4354  |   0.342 us    |        }
 0)  qemu-sy-4354  |   3.222 us    |      }
 0)  qemu-sy-4354  |               |      wake_up_process() {
 0)  qemu-sy-4354  |               |        try_to_wake_up() {
 0)  qemu-sy-4354  |               |          check_preempt_wakeup() {
 0)  qemu-sy-4354  |   0.343 us    |          }
 0)  qemu-sy-4354  |   1.331 us    |        }
 0)  qemu-sy-4354  |   1.915 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_from_vapic() {
 0)  qemu-sy-4354  |   0.294 us    |      }
 0)  qemu-sy-4354  |               |      kvm_handle_exit() {
 0)  qemu-sy-4354  |   0.457 us    |      }
 0)  qemu-sy-4354  |               |      kvm_resched() {
 0)  qemu-sy-4354  |               |        _cond_resched() {
 0)  qemu-sy-4354  |               |          __cond_resched() {
 0)  qemu-sy-4354  |               |            schedule() {
 0)  qemu-sy-4354  |               |              wakeup_preempt_entity() {
 0)  qemu-sy-4354  |   0.294 us    |              }
 0)  qemu-sy-4354  |               |              kvm_sched_out() {
 0)  qemu-sy-4354  |               |                kvm_arch_vcpu_put() {
 0)  qemu-sy-4354  |   0.592 us    |                }
 0)  qemu-sy-4354  |   1.218 us    |              }
 0)  qemu-sy-4354  =>   kipmi0-496
 0)  qemu-sy-4213  =>  qemu-sy-4354
 0)  qemu-sy-4354  |               |              kvm_sched_in() {
 0)  qemu-sy-4354  |               |                kvm_arch_vcpu_load() {
 0)  qemu-sy-4354  |               |                  kvm_write_guest_time() {
 0)  qemu-sy-4354  |   0.298 us    |                  }
 0)  qemu-sy-4354  |   1.070 us    |                }
 0)  qemu-sy-4354  |   1.665 us    |              }
 0)  qemu-sy-4354  | ! 9172.159 us |            }
 0)  qemu-sy-4354  | ! 9172.793 us |          }
 0)  qemu-sy-4354  | ! 9173.422 us |        }
 0)  qemu-sy-4354  | ! 9174.032 us |      }
 0)  qemu-sy-4354  |               |      kvm_inject_pending_timer_irqs() {
 0)  qemu-sy-4354  |               |        kvm_inject_apic_timer_irqs() {
 0)  qemu-sy-4354  |               |          kvm_vcpu_kick() {
 0)  qemu-sy-4354  |   0.291 us    |          }
 0)  qemu-sy-4354  |   1.151 us    |        }
 0)  qemu-sy-4354  |               |        kvm_inject_pit_timer_irqs() {
 0)  qemu-sy-4354  |   0.352 us    |        }
 0)  qemu-sy-4354  |   2.429 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_enabled() {
 0)  qemu-sy-4354  |   0.291 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_find_highest_irr() {
 0)  qemu-sy-4354  |   0.312 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_get_cr8() {
 0)  qemu-sy-4354  |   0.298 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_has_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.385 us    |        }
 0)  qemu-sy-4354  |   0.980 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_to_vapic() {
 0)  qemu-sy-4354  |   0.295 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_from_vapic() {
 0)  qemu-sy-4354  |   0.331 us    |      }
 0)  qemu-sy-4354  |               |      kvm_handle_exit() {
 0)  qemu-sy-4354  |   0.568 us    |      }
 0)  qemu-sy-4354  |               |      kvm_inject_pending_timer_irqs() {
 0)  qemu-sy-4354  |               |        kvm_inject_apic_timer_irqs() {
 0)  qemu-sy-4354  |               |          kvm_vcpu_kick() {
 0)  qemu-sy-4354  |   0.295 us    |          }
 0)  qemu-sy-4354  |   0.959 us    |        }
 0)  qemu-sy-4354  |               |        kvm_inject_pit_timer_irqs() {
 0)  qemu-sy-4354  |   0.313 us    |        }
 0)  qemu-sy-4354  |   2.170 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_enabled() {
 0)  qemu-sy-4354  |   0.310 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_find_highest_irr() {
 0)  qemu-sy-4354  |   0.295 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_get_cr8() {
 0)  qemu-sy-4354  |   0.295 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_has_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.325 us    |        }
 0)  qemu-sy-4354  |   0.938 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_get_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_get_apic_interrupt() {
 0)  qemu-sy-4354  |               |          kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.322 us    |          }
 0)  qemu-sy-4354  |   0.944 us    |        }
 0)  qemu-sy-4354  |   1.542 us    |      }
 0)  qemu-sy-4354  |               |      kvm_timer_intr_post() {
 0)  qemu-sy-4354  |               |        kvm_apic_timer_intr_post() {
 0)  qemu-sy-4354  |   0.309 us    |        }
 0)  qemu-sy-4354  |   2.059 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_has_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.340 us    |        }
 0)  qemu-sy-4354  |               |        kvm_apic_accept_pic_intr() {
 0)  qemu-sy-4354  |   0.313 us    |        }
 0)  qemu-sy-4354  |   1.560 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_to_vapic() {
 0)  qemu-sy-4354  |   0.298 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_from_vapic() {
 0)  qemu-sy-4354  |   0.319 us    |      }
 0)  qemu-sy-4354  |               |      kvm_handle_exit() {
 0)  qemu-sy-4354  |               |        kvm_mmu_page_fault() {
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.764 us    |            }
 0)  qemu-sy-4354  |   1.377 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.499 us    |            }
 0)  qemu-sy-4354  |   1.088 us    |          }
 0)  qemu-sy-4354  |               |          kvm_release_pfn_clean() {
 0)  qemu-sy-4354  |   0.349 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.451 us    |            }
 0)  qemu-sy-4354  |   1.046 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.361 us    |            }
 0)  qemu-sy-4354  |   0.956 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.381 us    |            }
 0)  qemu-sy-4354  |   0.974 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.345 us    |            }
 0)  qemu-sy-4354  |   0.959 us    |          }
 0)  qemu-sy-4354  |               |          kvm_read_guest() {
 0)  qemu-sy-4354  |               |            kvm_read_guest_page() {
 0)  qemu-sy-4354  |   0.364 us    |            }
 0)  qemu-sy-4354  |   0.965 us    |          }
 0)  qemu-sy-4354  |               |          kvm_ioapic_update_eoi() {
 0)  qemu-sy-4354  |   0.358 us    |          }
 0)  qemu-sy-4354  | + 13.782 us   |        }
 0)  qemu-sy-4354  | + 14.681 us   |      }
 0)  qemu-sy-4354  |               |      kvm_inject_pending_timer_irqs() {
 0)  qemu-sy-4354  |               |        kvm_inject_apic_timer_irqs() {
 0)  qemu-sy-4354  |               |          kvm_vcpu_kick() {
 0)  qemu-sy-4354  |   0.291 us    |          }
 0)  qemu-sy-4354  |   0.953 us    |        }
 0)  qemu-sy-4354  |               |        kvm_inject_pit_timer_irqs() {
 0)  qemu-sy-4354  |   0.304 us    |        }
 0)  qemu-sy-4354  |   2.150 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_enabled() {
 0)  qemu-sy-4354  |   0.304 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_find_highest_irr() {
 0)  qemu-sy-4354  |   0.295 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_get_cr8() {
 0)  qemu-sy-4354  |   0.309 us    |      }
 0)  qemu-sy-4354  |               |      kvm_cpu_has_interrupt() {
 0)  qemu-sy-4354  |               |        kvm_apic_has_interrupt() {
 0)  qemu-sy-4354  |   0.315 us    |        }
 0)  qemu-sy-4354  |   0.914 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_to_vapic() {
 0)  qemu-sy-4354  |   0.297 us    |      }
 0)  qemu-sy-4354  |               |      kvm_lapic_sync_from_vapic() {
 0)  qemu-sy-4354  |   0.318 us    |      }
 0)  qemu-sy-4354  |               |      kvm_handle_exit() {
 0)  qemu-sy-4354  |               |        kvm_emulate_pio() {
 0)  qemu-sy-4354  |               |          kvm_io_bus_find_dev() {
 0)  qemu-sy-4354  |   0.406 us    |          }
 0)  qemu-sy-4354  |   1.115 us    |        }
 0)  qemu-sy-4354  |   2.026 us    |      }
 0)  qemu-sy-4354  |               |      kvm_get_cr8() {
 0)  qemu-sy-4354  |               |        kvm_lapic_get_cr8() {
 0)  qemu-sy-4354  |   0.292 us    |        }
 0)  qemu-sy-4354  |   2.257 us    |      }
 0)  qemu-sy-4354  |               |      kvm_arch_vcpu_put() {
 0)  qemu-sy-4354  |   0.574 us    |      }
 0)  qemu-sy-4354  | ! 250406.2 us |    }
 0)  qemu-sy-4354  | ! 250407.0 us |  }


There's 2 preemptions in there, accounting for perhaps 15ms
Then there's about 20 __wake_up()s in there (wth do those come from?)
accounting for 5ms each, totaling 100ms.

There's a scheduler_tick() in there but no IRQ entry ?!

All in all its very hard to get to the total of 250ms.

I suspect __vcpu_run() and vcpu_enter_guest() get inlined, and we might
just be looking at time spend in the guest... bit hard to tell for me,
as this is the first time ever I looked at all this kvm code.


Is there a way to add a wall-time column to this output so that we can
see where the time goes?

Another something nice would be to have ctx switches like:

foo-1 => bar-2 ran: ${time foo spend on the cpu} since: ${time bar spend away from the cpu}

I'll poke me a little at this function graph tracer thingy to see if I
can do that.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Peter Zijlstra <a.p.zijlstra-/NLkJaSkS4VmR6Xm/wNWPw@public.gmane.org> wrote:

> Is there a way to add a wall-time column to this output so that we can 
> see where the time goes?

yes, on tip/master:

  http://people.redhat.com/mingo/tip.git/README

do something like this:

 echo funcgraph-abstime > /debug/tracing/trace_options

when the function-graph plugin is active. This will activate the absolute 
timestamps column in the trace output.

> Another something nice would be to have ctx switches like:
> 
> foo-1 => bar-2 ran: ${time foo spend on the cpu} since: ${time bar spend away from the cpu}
> 
> I'll poke me a little at this function graph tracer thingy to see if I 
> can do that.

indeed, tracking the 'scheduling atom duration' would be very nice.

	Ingo

2.6.29-rc3-git6: Reported regressions 2.6.27 -> 2.6.28

[Rafael J. Wysocki]

This message contains a list of some regressions introduced between 2.6.27 and
2.6.28, for which there are no fixes in the mainline I know of.  If any of them
have been fixed already, please let me know.

If you know of any other unresolved regressions introduced between 2.6.27
and 2.6.28, please let me know either and I'll add them to the list.
Also, please let me know if any of the entries below are invalid.

Each entry from the list will be sent additionally in an automatic reply to
this message with CCs to the people involved in reporting and handling the
issue.


Listed regressions statistics:

  Date          Total  Pending  Unresolved
  ----------------------------------------
  2009-02-04      149       33          30
  2009-01-20      144       30          27
  2009-01-11      139       33          30
  2008-12-21      120       19          17
  2008-12-13      111       14          13
  2008-12-07      106       20          17
  2008-12-04      106       29          21
  2008-11-22       93       25          15
  2008-11-16       89       32          18
  2008-11-09       73       40          27
  2008-11-02       55       41          29
  2008-10-25       26       25          20



Unresolved regressions
----------------------

Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12619
Subject		: Regression 2.6.28 and last - boot failed
Submitter	: jan sonnek <ha2nny@gmail.com>
Date		: 2009-02-01 19:59 (4 days old)
References	: http://marc.info/?l=linux-kernel&m=123351836213969&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12612
Subject		: hard lockup when interrupting cdda2wav
Submitter	: Matthias Reichl <hias@horus.com>
Date		: 2009-01-28 16:41 (8 days old)
References	: http://marc.info/?l=linux-kernel&m=123316111415677&w=4
Handled-By	: FUJITA Tomonori <fujita.tomonori@lab.ntt.co.jp>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12559
Subject		: Huawei E169 doesn't work as mass storage anymore
Submitter	: kpalberg <kpalberg@gmail.com>
Date		: 2009-01-28 02:34 (8 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12520
Subject		: Cannot boot 2.6.28 under Dell OptiPlex 960
Submitter	: Denis Scherbakov <denis_scherbakov@yahoo.com>
Date		: 2009-01-22 04:37 (14 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12500
Subject		: r8169: NETDEV WATCHDOG: eth0 (r8169): transmit timed out
Submitter	: Justin Piszcz <jpiszcz@lucidpixels.com>
Date		: 2009-01-13 21:19 (23 days old)
References	: http://marc.info/?l=linux-kernel&m=123188160811322&w=4
Handled-By	: Francois Romieu <romieu@fr.zoreil.com>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah@ucwb.org.au>
Date		: 2009-01-17 03:37 (19 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
Subject		: TMDC Joystick no longer works in kernel 2.6.28
Submitter	: Andrew S. Johnson <andy@asjohnson.com>
Date		: 2009-01-10 21:53 (26 days old)
References	: http://marc.info/?l=linux-kernel&m=123162486415366&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12421
Subject		: GPF on 2.6.28 &amp; 2.6.28-rc9-git3    e1000e / e1000 issues
Submitter	: Doug Bazarnic <doug@bazarnic.net>
Date		: 2009-01-09 21:26 (27 days old)
References	: http://marc.info/?l=linux-kernel&m=123153653120204&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12411
Subject		: 2.6.28: BUG in r8169
Submitter	: Andrey Vul <andrey.vul@gmail.com>
Date		: 2008-12-31 18:37 (36 days old)
References	: http://marc.info/?l=linux-kernel&m=123074869611409&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12409
Subject		: NULL pointer dereference at get_stats()
Submitter	: Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
Date		: 2008-12-30 12:53 (37 days old)
References	: http://marc.info/?l=linux-kernel&m=123064167008695&w=4
Handled-By	: Frederik Deweerdt <frederik.deweerdt@xprog.eu>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12408
Subject		: Funny problem with 2.6.28: Kernel stalls
Submitter	: Michael Roth <mroth@nessie.de>
Date		: 2008-12-25 15:14 (42 days old)
References	: http://marc.info/?l=linux-kernel&m=123021931714282&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12407
Subject		: Kernel 2.6.28 regression: Hang after hibernate
Submitter	: Frank Groeneveld <frankgroeneveld@gmail.com>
Date		: 2008-12-28 20:34 (39 days old)
References	: http://marc.info/?l=linux-kernel&m=123049651906081&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12405
Subject		: oops in __bounce_end_io_read under kvm
Submitter	: Christoph Hellwig <hch@lst.de>
Date		: 2008-12-26 17:36 (41 days old)
References	: http://marc.info/?l=linux-kernel&m=123031303400676&w=4
Handled-By	: Jens Axboe <jens.axboe@oracle.com>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12404
Subject		: Oops in 2.6.28-rc9 and -rc8 -- mtrr issues / e1000e
Submitter	: Kernel <kernel@bazarnic.net>
Date		: 2008-12-22 9:37 (45 days old)
References	: http://marc.info/?l=linux-kernel&m=122993873320150&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12403
Subject		: TTY problem on linux-2.6.28-rc7
Submitter	: sasa sasa <sasak.1983@gmail.com>
Date		: 2008-12-22 4:23 (45 days old)
References	: http://marc.info/?l=linux-kernel&m=122991914600390&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12401
Subject		: 2.6.28 regression: xbacklight broken on ThinkPad X61s
Submitter	: Tino Keitel <tino.keitel@gmx.de>
Date		: 2009-01-05 8:39 (31 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=22c13f9d8179f4c9caecfcb60a95214562b9addc
References	: http://marc.info/?l=linux-kernel&m=123114479110314&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12395
Subject		: 2.6.28-rc9: oprofile regression
Submitter	: Tim Blechmann <tim@klingt.org>
Date		: 2008-12-21 14:23 (46 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=b99170288421c79f0c2efa8b33e26e65f4bb7fb8
References	: http://marc.info/?l=linux-kernel&m=122986946614791&w=4
Handled-By	: Andi Kleen <ak@linux.intel.com>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12393
Subject		: debugging in dosemu causes lots of 'scheduling while atomic'
Submitter	: Michal Suchanek <hramrach@centrum.cz>
Date		: 2009-01-09 07:28 (27 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12391
Subject		: Processor does not go below C2 state until usb.autosuspend is enabled
Submitter	: Gergely Imreh <imrehg@gmail.com>
Date		: 2009-01-09 02:35 (27 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12337
Subject		: ~100 extra wakeups reported by powertop
Submitter	: Alberto Gonzalez <luis6674@yahoo.com>
Date		: 2008-12-31 12:25 (36 days old)


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12265
Subject		: FPU emulation broken in 2.6.28-rc8 ?
Submitter	: Rogier Wolff <R.E.Wolff@bitwizard.nl>
Date		: 2008-12-17 8:56 (50 days old)
References	: http://marc.info/?l=linux-kernel&m=122950463030747&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12264
Subject		: i915: switching from kwin in opengl mode to a VT then back to x11, x11 freezes
Submitter	: Caleb Cushing <xenoterracide@gmail.com>
Date		: 2008-12-16 11:40 (51 days old)
References	: http://marc.info/?l=linux-kernel&m=122942777030666&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12263
Subject		: Sata soft reset filling log
Submitter	: Justin Madru <bevicm@dslextreme.com>
Date		: 2008-12-13 2:07 (54 days old)
References	: http://marc.info/?l=linux-kernel&m=122913412608533&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12224
Subject		: journal activity on inactive partition causes inactive harddrive spinup
Submitter	: C Sights <csights@fastmail.fm>
Date		: 2008-12-14 11:39 (53 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=c87591b719737b4e91eb1a9fa8fd55a4ff1886d6
Handled-By	: Eric Sandeen <sandeen@redhat.com>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12209
Subject		: oldish top core dumps (in its meminfo() function)
Submitter	: Andreas Mohr <andi@lisas.de>
Date		: 2008-12-12 18:49 (55 days old)
References	: http://marc.info/?l=linux-kernel&m=122910784006472&w=4
		  http://marc.info/?l=linux-kernel&m=122907511319288&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12208
Subject		: uml is very slow on 2.6.28 host
Submitter	: Miklos Szeredi <miklos@szeredi.hu>
Date		: 2008-12-12 9:35 (55 days old)
References	: http://marc.info/?l=linux-kernel&m=122907463518593&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12160
Subject		: networking oops after resume from s2ram (2.6.28-rc6)
Submitter	: Marcin Slusarz <marcin.slusarz@gmail.com>
Date		: 2008-11-28 21:15 (69 days old)
References	: http://marc.info/?l=linux-kernel&m=122790701615723&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12159
Subject		: 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver
Submitter	: Miles Lane <miles.lane@gmail.com>
Date		: 2008-11-27 20:33 (70 days old)
References	: http://marc.info/?l=linux-kernel&m=122781805620212&w=4
Handled-By	: Takashi Iwai <tiwai@suse.de>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12061
Subject		: snd_hda_intel: power_save: sound cracks on powerdown
Submitter	: Jens Weibler <bugzilla-kernel@jensthebrain.de>
Date		: 2008-11-18 12:07 (79 days old)
Handled-By	: Takashi Iwai <tiwai@suse.de>


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=11849
Subject		: default IRQ affinity change in v2.6.27 (breaking several SMP PPC based systems)
Submitter	: Kumar Gala <galak@kernel.crashing.org>
Date		: 2008-10-24 12:45 (104 days old)
References	: http://marc.info/?l=linux-kernel&m=122485245924125&w=4


Regressions with patches
------------------------

Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12614
Subject		: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
Submitter	: Philipp Matthias Hahn <pmhahn@titan.lahn.de>
Date		: 2009-01-29 6:31 (7 days old)
References	: http://marc.info/?l=linux-kernel&m=123321232825316&w=4
Handled-By	: Yinghai Lu <yinghai@kernel.org>
Patch		: http://marc.info/?l=linux-kernel&m=123330459229248&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12406
Subject		: 2.6.28 thinks that my PS/2 mouse is a touchpad
Submitter	: Alexander E. Patrakov <patrakov@gmail.com>
Date		: 2008-12-27 9:06 (40 days old)
References	: http://marc.info/?l=linux-kernel&m=123036893817280&w=4
Handled-By	: Arjan Opmeer <arjan@opmeer.net>
Patch		: http://marc.info/?l=linux-kernel&m=123092147703236&w=4


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12396
Subject		: hwinfo problem since 2.6.28
Submitter	: Beschorner Daniel <Daniel.Beschorner@facton.com>
Date		: 2009-01-06 8:53 (30 days old)
References	: http://marc.info/?l=linux-kernel&m=123123277800835&w=4
Handled-By	: Suresh Siddha <suresh.b.siddha@intel.com>
Patch		: http://marc.info/?l=linux-kernel&m=123154005127497&w=4


For details, please visit the bug entries and follow the links given in
references.

As you can see, there is a Bugzilla entry for each of the listed regressions.
There also is a Bugzilla entry used for tracking the regressions introduced
between 2.6.27 and 2.6.28, unresolved as well as resolved, at:

http://bugzilla.kernel.org/show_bug.cgi?id=11808

Please let me know if there are any Bugzilla entries that should be added to
the list in there.

Thanks,
Rafael

--
To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

[Bug #11849] default IRQ affinity change in v2.6.27 (breaking several SMP PPC based systems)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=11849
Subject		: default IRQ affinity change in v2.6.27 (breaking several SMP PPC based systems)
Submitter	: Kumar Gala <galak-XVmvHMARGAS8U2dJNN8I7kB+6BGkLq7r@public.gmane.org>
Date		: 2008-10-24 12:45 (104 days old)
References	: http://marc.info/?l=linux-kernel&m=122485245924125&w=4

[Bug #12061] snd_hda_intel: power_save: sound cracks on powerdown

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12061
Subject		: snd_hda_intel: power_save: sound cracks on powerdown
Submitter	: Jens Weibler <bugzilla-kernel-6hJTtV8wudIr9FUcG+3rRQ@public.gmane.org>
Date		: 2008-11-18 12:07 (79 days old)
Handled-By	: Takashi Iwai <tiwai-l3A5Bk7waGM@public.gmane.org>

[Bug #12159] 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12159
Subject		: 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver
Submitter	: Miles Lane <miles.lane-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-11-27 20:33 (70 days old)
References	: http://marc.info/?l=linux-kernel&m=122781805620212&w=4
Handled-By	: Takashi Iwai <tiwai-l3A5Bk7waGM@public.gmane.org>

[Bug #12160] networking oops after resume from s2ram (2.6.28-rc6)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12160
Subject		: networking oops after resume from s2ram (2.6.28-rc6)
Submitter	: Marcin Slusarz <marcin.slusarz@gmail.com>
Date		: 2008-11-28 21:15 (69 days old)
References	: http://marc.info/?l=linux-kernel&m=122790701615723&w=4

[Bug #12208] uml is very slow on 2.6.28 host

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12208
Subject		: uml is very slow on 2.6.28 host
Submitter	: Miklos Szeredi <miklos-sUDqSbJrdHQHWmgEVkV9KA@public.gmane.org>
Date		: 2008-12-12 9:35 (55 days old)
References	: http://marc.info/?l=linux-kernel&m=122907463518593&w=4

[Bug #12209] oldish top core dumps (in its meminfo() function)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12209
Subject		: oldish top core dumps (in its meminfo() function)
Submitter	: Andreas Mohr <andi-5+Cda9B46AM@public.gmane.org>
Date		: 2008-12-12 18:49 (55 days old)
References	: http://marc.info/?l=linux-kernel&m=122910784006472&w=4
		  http://marc.info/?l=linux-kernel&m=122907511319288&w=4

[Bug #12224] journal activity on inactive partition causes inactive harddrive spinup

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12224
Subject		: journal activity on inactive partition causes inactive harddrive spinup
Submitter	: C Sights <csights-97jfqw80gc6171pxa8y+qA@public.gmane.org>
Date		: 2008-12-14 11:39 (53 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=c87591b719737b4e91eb1a9fa8fd55a4ff1886d6
Handled-By	: Eric Sandeen <sandeen-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

[Bug #12265] FPU emulation broken in 2.6.28-rc8 ?

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12265
Subject		: FPU emulation broken in 2.6.28-rc8 ?
Submitter	: Rogier Wolff <R.E.Wolff-bu/CaDbLbdHGjfRZg6uqBA@public.gmane.org>
Date		: 2008-12-17 8:56 (50 days old)
References	: http://marc.info/?l=linux-kernel&m=122950463030747&w=4

[Bug #12264] i915: switching from kwin in opengl mode to a VT then back to x11, x11 freezes

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12264
Subject		: i915: switching from kwin in opengl mode to a VT then back to x11, x11 freezes
Submitter	: Caleb Cushing <xenoterracide-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-16 11:40 (51 days old)
References	: http://marc.info/?l=linux-kernel&m=122942777030666&w=4

[Bug #12263] Sata soft reset filling log

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12263
Subject		: Sata soft reset filling log
Submitter	: Justin Madru <bevicm-QP1aEjBt37AFQeE35raUng@public.gmane.org>
Date		: 2008-12-13 2:07 (54 days old)
References	: http://marc.info/?l=linux-kernel&m=122913412608533&w=4

[Bug #12337] ~100 extra wakeups reported by powertop

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12337
Subject		: ~100 extra wakeups reported by powertop
Submitter	: Alberto Gonzalez <luis6674-/E1597aS9LQAvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-31 12:25 (36 days old)

[Bug #12391] Processor does not go below C2 state until usb.autosuspend is enabled

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12391
Subject		: Processor does not go below C2 state until usb.autosuspend is enabled
Submitter	: Gergely Imreh <imrehg-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2009-01-09 02:35 (27 days old)

[Bug #12395] 2.6.28-rc9: oprofile regression

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12395
Subject		: 2.6.28-rc9: oprofile regression
Submitter	: Tim Blechmann <tim-xpEK/MU0Hawdnm+yROfE0A@public.gmane.org>
Date		: 2008-12-21 14:23 (46 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=b99170288421c79f0c2efa8b33e26e65f4bb7fb8
References	: http://marc.info/?l=linux-kernel&m=122986946614791&w=4
Handled-By	: Andi Kleen <ak-VuQAYsv1563Yd54FQh9/CA@public.gmane.org>

[Bug #12393] debugging in dosemu causes lots of 'scheduling while atomic'

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12393
Subject		: debugging in dosemu causes lots of 'scheduling while atomic'
Submitter	: Michal Suchanek <hramrach-aRb0bU7PRFPrBKCeMvbIDA@public.gmane.org>
Date		: 2009-01-09 07:28 (27 days old)

[Bug #12396] hwinfo problem since 2.6.28

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12396
Subject		: hwinfo problem since 2.6.28
Submitter	: Beschorner Daniel <Daniel.Beschorner-cdG02ZADnvLQT0dZR+AlfA@public.gmane.org>
Date		: 2009-01-06 8:53 (30 days old)
References	: http://marc.info/?l=linux-kernel&m=123123277800835&w=4
Handled-By	: Suresh Siddha <suresh.b.siddha-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
Patch		: http://marc.info/?l=linux-kernel&m=123154005127497&w=4

[Bug #12401] 2.6.28 regression: xbacklight broken on ThinkPad X61s

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12401
Subject		: 2.6.28 regression: xbacklight broken on ThinkPad X61s
Submitter	: Tino Keitel <tino.keitel-Mmb7MZpHnFY@public.gmane.org>
Date		: 2009-01-05 8:39 (31 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=22c13f9d8179f4c9caecfcb60a95214562b9addc
References	: http://marc.info/?l=linux-kernel&m=123114479110314&w=4

[Bug #12406] 2.6.28 thinks that my PS/2 mouse is a touchpad

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12406
Subject		: 2.6.28 thinks that my PS/2 mouse is a touchpad
Submitter	: Alexander E. Patrakov <patrakov-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-27 9:06 (40 days old)
References	: http://marc.info/?l=linux-kernel&m=123036893817280&w=4
Handled-By	: Arjan Opmeer <arjan-OssVvNj1wBysTnJN9+BGXg@public.gmane.org>
Patch		: http://marc.info/?l=linux-kernel&m=123092147703236&w=4

[Bug #12403] TTY problem on linux-2.6.28-rc7

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12403
Subject		: TTY problem on linux-2.6.28-rc7
Submitter	: sasa sasa <sasak.1983-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-22 4:23 (45 days old)
References	: http://marc.info/?l=linux-kernel&m=122991914600390&w=4

[Bug #12405] oops in __bounce_end_io_read under kvm

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12405
Subject		: oops in __bounce_end_io_read under kvm
Submitter	: Christoph Hellwig <hch-jcswGhMUV9g@public.gmane.org>
Date		: 2008-12-26 17:36 (41 days old)
References	: http://marc.info/?l=linux-kernel&m=123031303400676&w=4
Handled-By	: Jens Axboe <jens.axboe-QHcLZuEGTsvQT0dZR+AlfA@public.gmane.org>

[Bug #12404] Oops in 2.6.28-rc9 and -rc8 -- mtrr issues / e1000e

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12404
Subject		: Oops in 2.6.28-rc9 and -rc8 -- mtrr issues / e1000e
Submitter	: Kernel <kernel-nOyj/A09A+/k1uMJSBkQmQ@public.gmane.org>
Date		: 2008-12-22 9:37 (45 days old)
References	: http://marc.info/?l=linux-kernel&m=122993873320150&w=4

[Bug #12408] Funny problem with 2.6.28: Kernel stalls

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12408
Subject		: Funny problem with 2.6.28: Kernel stalls
Submitter	: Michael Roth <mroth-+8Z3Oe2AQjqzQB+pC5nmwQ@public.gmane.org>
Date		: 2008-12-25 15:14 (42 days old)
References	: http://marc.info/?l=linux-kernel&m=123021931714282&w=4

[Bug #12407] Kernel 2.6.28 regression: Hang after hibernate

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12407
Subject		: Kernel 2.6.28 regression: Hang after hibernate
Submitter	: Frank Groeneveld <frankgroeneveld-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-28 20:34 (39 days old)
References	: http://marc.info/?l=linux-kernel&m=123049651906081&w=4

[Bug #12409] NULL pointer dereference at get_stats()

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12409
Subject		: NULL pointer dereference at get_stats()
Submitter	: Tetsuo Handa <penguin-kernel-1yMVhJb1mP/7nzcFbJAaVXf5DAMn2ifp@public.gmane.org>
Date		: 2008-12-30 12:53 (37 days old)
References	: http://marc.info/?l=linux-kernel&m=123064167008695&w=4
Handled-By	: Frederik Deweerdt <frederik.deweerdt-kjvbsxwSFqI@public.gmane.org>

[Bug #12411] 2.6.28: BUG in r8169

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12411
Subject		: 2.6.28: BUG in r8169
Submitter	: Andrey Vul <andrey.vul-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2008-12-31 18:37 (36 days old)
References	: http://marc.info/?l=linux-kernel&m=123074869611409&w=4

[Bug #12426] TMDC Joystick no longer works in kernel 2.6.28

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
Subject		: TMDC Joystick no longer works in kernel 2.6.28
Submitter	: Andrew S. Johnson <andy-9eXmkf4BiQ2aMJb+Lgu22Q@public.gmane.org>
Date		: 2009-01-10 21:53 (26 days old)
References	: http://marc.info/?l=linux-kernel&m=123162486415366&w=4

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (19 days old)

[Bug #12500] r8169: NETDEV WATCHDOG: eth0 (r8169): transmit timed out

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12500
Subject		: r8169: NETDEV WATCHDOG: eth0 (r8169): transmit timed out
Submitter	: Justin Piszcz <jpiszcz-BP4nVm5VUdNhbmWW9KSYcQ@public.gmane.org>
Date		: 2009-01-13 21:19 (23 days old)
References	: http://marc.info/?l=linux-kernel&m=123188160811322&w=4
Handled-By	: Francois Romieu <romieu-W8zweXLXuWQS+FvcfC7Uqw@public.gmane.org>

[Bug #12520] Cannot boot 2.6.28 under Dell OptiPlex 960

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12520
Subject		: Cannot boot 2.6.28 under Dell OptiPlex 960
Submitter	: Denis Scherbakov <denis_scherbakov-/E1597aS9LQAvxtiuMwx3w@public.gmane.org>
Date		: 2009-01-22 04:37 (14 days old)

[Bug #12559] Huawei E169 doesn't work as mass storage anymore

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12559
Subject		: Huawei E169 doesn't work as mass storage anymore
Submitter	: kpalberg <kpalberg-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2009-01-28 02:34 (8 days old)

[Bug #12612] hard lockup when interrupting cdda2wav

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12612
Subject		: hard lockup when interrupting cdda2wav
Submitter	: Matthias Reichl <hias-vtPv7MOkFPkAvxtiuMwx3w@public.gmane.org>
Date		: 2009-01-28 16:41 (8 days old)
References	: http://marc.info/?l=linux-kernel&m=123316111415677&w=4
Handled-By	: FUJITA Tomonori <fujita.tomonori-Zyj7fXuS5i5L9jVzuh4AOg@public.gmane.org>

[Bug #12614] WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12614
Subject		: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
Submitter	: Philipp Matthias Hahn <pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org>
Date		: 2009-01-29 6:31 (7 days old)
References	: http://marc.info/?l=linux-kernel&m=123321232825316&w=4
Handled-By	: Yinghai Lu <yinghai-DgEjT+Ai2ygdnm+yROfE0A@public.gmane.org>
Patch		: http://marc.info/?l=linux-kernel&m=123330459229248&w=4

[Bug #12619] Regression 2.6.28 and last - boot failed

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12619
Subject		: Regression 2.6.28 and last - boot failed
Submitter	: jan sonnek <ha2nny-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
Date		: 2009-02-01 19:59 (4 days old)
References	: http://marc.info/?l=linux-kernel&m=123351836213969&w=4

Re: [Bug #12159] 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver

[Miles Lane]

This bug is fixed in Linus' tree, afaict.

On Wed, Feb 4, 2009 at 5:58 AM, Rafael J. Wysocki <rjw-KKrjLPT3xs0@public.gmane.org> wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
>
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
>
>
> Bug-Entry       : http://bugzilla.kernel.org/show_bug.cgi?id=12159
> Subject         : 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver
> Submitter       : Miles Lane <miles.lane-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
> Date            : 2008-11-27 20:33 (70 days old)
> References      : http://marc.info/?l=linux-kernel&m=122781805620212&w=4
> Handled-By      : Takashi Iwai <tiwai-l3A5Bk7waGM@public.gmane.org>
>
>
>

Re: [Bug #12426] TMDC Joystick no longer works in kernel 2.6.28

[Jiri Kosina]

On Wed, 4 Feb 2009, Rafael J. Wysocki wrote:

> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
> Subject		: TMDC Joystick no longer works in kernel 2.6.28
> Submitter	: Andrew S. Johnson <andy-9eXmkf4BiQ2aMJb+Lgu22Q@public.gmane.org>
> Date		: 2009-01-10 21:53 (26 days old)
> References	: http://marc.info/?l=linux-kernel&m=123162486415366&w=4

I asked [1] the Submitter some time ago to check whether reverting a 
particular commit fixes the issue, but never heard back.

[1] http://lkml.org/lkml/2009/1/26/70

-- 
Jiri Kosina
SUSE Labs

Re: [Bug #12396] hwinfo problem since 2.6.28

[Beschorner Daniel]

> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it 
> still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12396
> Subject		: hwinfo problem since 2.6.28
> Submitter	: Beschorner Daniel <Daniel.Beschorner-cdG02ZADnvLQT0dZR+AlfA@public.gmane.org>
> Date		: 2009-01-06 8:53 (30 days old)
> References	: http://marc.info/?l=linux-kernel&m=123123277800835&w=4
> Handled-By	: Suresh Siddha <suresh.b.siddha-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
> Patch		: http://marc.info/?l=linux-kernel&m=123154005127497&w=4

Fixed with 2.6.28.3.

Daniel

Re: [Bug #12159] 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver

[Rafael J. Wysocki]

On Wednesday 04 February 2009, Miles Lane wrote:
> This bug is fixed in Linus' tree, afaict.

Closed already.

Thanks,
Rafael


> On Wed, Feb 4, 2009 at 5:58 AM, Rafael J. Wysocki <rjw-KKrjLPT3xs0@public.gmane.org> wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> >
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> >
> >
> > Bug-Entry       : http://bugzilla.kernel.org/show_bug.cgi?id=12159
> > Subject         : 2.6.28-rc6-git1 -- No sound produced from Intel HDA ALSA driver
> > Submitter       : Miles Lane <miles.lane-Re5JQEeQqe8AvxtiuMwx3w@public.gmane.org>
> > Date            : 2008-11-27 20:33 (70 days old)
> > References      : http://marc.info/?l=linux-kernel&m=122781805620212&w=4
> > Handled-By      : Takashi Iwai <tiwai-l3A5Bk7waGM@public.gmane.org>

Re: [Bug #12396] hwinfo problem since 2.6.28

[Rafael J. Wysocki]

On Wednesday 04 February 2009, Beschorner Daniel wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it 
> > still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12396
> > Subject		: hwinfo problem since 2.6.28
> > Submitter	: Beschorner Daniel <Daniel.Beschorner-cdG02ZADnvLQT0dZR+AlfA@public.gmane.org>
> > Date		: 2009-01-06 8:53 (30 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123123277800835&w=4
> > Handled-By	: Suresh Siddha <suresh.b.siddha-ral2JQCrhuEAvxtiuMwx3w@public.gmane.org>
> > Patch		: http://marc.info/?l=linux-kernel&m=123154005127497&w=4
> 
> Fixed with 2.6.28.3.

Thanks, closed.

Rafael

Re: [Bug #12426] TMDC Joystick no longer works in kernel 2.6.28

[Rafael J. Wysocki]

On Wednesday 04 February 2009, Jiri Kosina wrote:
> On Wed, 4 Feb 2009, Rafael J. Wysocki wrote:
> 
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
> > Subject		: TMDC Joystick no longer works in kernel 2.6.28
> > Submitter	: Andrew S. Johnson <andy-9eXmkf4BiQ2aMJb+Lgu22Q@public.gmane.org>
> > Date		: 2009-01-10 21:53 (26 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123162486415366&w=4
> 
> I asked [1] the Submitter some time ago to check whether reverting a 
> particular commit fixes the issue, but never heard back.
> 
> [1] http://lkml.org/lkml/2009/1/26/70

Rejected as "insufficient data" and closed.

Thanks,
Rafael

Re: [Bug #12224] journal activity on inactive partition causes inactive harddrive spinup

[Theodore Tso]

On Wed, Feb 04, 2009 at 11:58:33AM +0100, Rafael J. Wysocki wrote:
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12224
> Subject		: journal activity on inactive partition causes inactive harddrive spinup
> Submitter	: C Sights <csights-97jfqw80gc6171pxa8y+qA@public.gmane.org>
> Date		: 2008-12-14 11:39 (53 days old)
> First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=c87591b719737b4e91eb1a9fa8fd55a4ff1886d6
> Handled-By	: Eric Sandeen <sandeen-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

Patches against ext3 have been posted by Jan Kara and have been sucked
into the mm tree.  I don't know if Andrew is planning on waiting until
the next merge window, or is planning on pushing it sooner given that
it is a regression.  (These supercede the ones currently posted by
Eric in the BZ entry.)

Similar patches have been posted against ext4, and I will be handling
them in the ext4 tree.

						- Ted

Re: [Bug #12224] journal activity on inactive partition causes inactive harddrive spinup

[Andrew Morton]

On Wed, 4 Feb 2009 21:00:13 -0500 Theodore Tso <tytso-3s7WtUTddSA@public.gmane.org> wrote:

> On Wed, Feb 04, 2009 at 11:58:33AM +0100, Rafael J. Wysocki wrote:
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12224
> > Subject		: journal activity on inactive partition causes inactive harddrive spinup
> > Submitter	: C Sights <csights-97jfqw80gc6171pxa8y+qA@public.gmane.org>
> > Date		: 2008-12-14 11:39 (53 days old)
> > First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=c87591b719737b4e91eb1a9fa8fd55a4ff1886d6
> > Handled-By	: Eric Sandeen <sandeen-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
> 
> Patches against ext3 have been posted by Jan Kara and have been sucked
> into the mm tree.  I don't know if Andrew is planning on waiting until
> the next merge window, or is planning on pushing it sooner given that
> it is a regression.

Yes, I have jbd-fix-return-value-of-journal_start_commit.patch and
revert-ext3-wait-on-all-pending-commits-in-ext3_sync_fs.patch queued
for 2.6.29.

The secret algorithm for determining this is to peek in the series file
(http://userweb.kernel.org/~akpm/mmotm/series) and see where I positioned the
patch:

   #
-> # more 2.6.29 queue:
   #
   # me:
   #
   migration-migrate_vmas-should-check-vma.patch
   rtc-update-maintainership-of-pxa-rtc-driver.patch
   lxfb-properly-alloc-cmap-in-all-cases-and-dont-leak-the-memory.patch
   gxfb-properly-alloc-cmap-and-plug-cmap-leak.patch
   gx1fb-properly-alloc-cmap-and-plug-cmap-leak.patch
   mm-fix-dirty_bytes-dirty_background_bytes-sysctls-on-64bit-arches.patch
   mm-fix-dirty_bytes-dirty_background_bytes-sysctls-on-64bit-arches-fix.patch
-> jbd-fix-return-value-of-journal_start_commit.patch
-> revert-ext3-wait-on-all-pending-commits-in-ext3_sync_fs.patch
   writeback-fix-nr_to_write-counter.patch
   
   

Re: [Bug #12393] debugging in dosemu causes lots of 'scheduling while atomic'

[Michal Suchanek]

As I said earlier I have received a patch that I applied locally and
that fixes the problem.

As to if and when the patch actually appears in the kernel is out of
my control, and nobody told me that it was applied.

If you believe it was applied to a kernel version that is readily
available for download I am wiling to test such version.

Thanks

Michal

2009/2/4 Rafael J. Wysocki <rjw-KKrjLPT3xs0@public.gmane.org>:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
>
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
>
>
> Bug-Entry       : http://bugzilla.kernel.org/show_bug.cgi?id=12393
> Subject         : debugging in dosemu causes lots of 'scheduling while atomic'
> Submitter       : Michal Suchanek <hramrach-aRb0bU7PRFPrBKCeMvbIDA@public.gmane.org>
> Date            : 2009-01-09 07:28 (27 days old)
>
>
>

Re: [Bug #12612] hard lockup when interrupting cdda2wav

[Matthias Reichl]

On Wed, Feb 04, 2009 at 11:58:51AM +0100, Rafael J. Wysocki wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12612
> Subject		: hard lockup when interrupting cdda2wav
> Submitter	: Matthias Reichl <hias-vtPv7MOkFPkAvxtiuMwx3w@public.gmane.org>
> Date		: 2009-01-28 16:41 (8 days old)
> References	: http://marc.info/?l=linux-kernel&m=123316111415677&w=4
> Handled-By	: FUJITA Tomonori <fujita.tomonori-Zyj7fXuS5i5L9jVzuh4AOg@public.gmane.org>

This bug is still present in 2.6.28.3.

so long,

Hias

=============================================
[ INFO: possible recursive locking detected ]
2.6.28.3-dbg #1
---------------------------------------------
swapper/0 is trying to acquire lock:
 (&q->__queue_lock){.+..}, at: [<ffffffff8040e5f5>] blk_put_request+0x25/0x60

but task is already holding lock:
 (&q->__queue_lock){.+..}, at: [<ffffffff8040e4da>] blk_end_io+0x5a/0xa0

other info that might help us debug this:
1 lock held by swapper/0:
 #0:  (&q->__queue_lock){.+..}, at: [<ffffffff8040e4da>] blk_end_io+0x5a/0xa0

stack backtrace:
Pid: 0, comm: swapper Not tainted 2.6.28.3-dbg #1
Call Trace:
 <IRQ>  [<ffffffff8026cc87>] __lock_acquire+0x1797/0x1930
 [<ffffffff806abd7b>] error_exit+0x29/0xa9
 [<ffffffff80521e20>] sg_rq_end_io+0x0/0x2e0
 [<ffffffff8026ceba>] lock_acquire+0x9a/0xe0
 [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
 [<ffffffff806ab763>] _spin_lock_irqsave+0x43/0x90
 [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
 [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
 [<ffffffff80520974>] sg_finish_rem_req+0xa4/0x100
 [<ffffffff80522098>] sg_rq_end_io+0x278/0x2e0
 [<ffffffff8040e281>] end_that_request_last+0x61/0x260
 [<ffffffff8040e4e8>] blk_end_io+0x68/0xa0
 [<ffffffff80508061>] scsi_end_request+0x41/0xd0
 [<ffffffff80508750>] scsi_io_completion+0x130/0x470
 [<ffffffff804133e5>] blk_done_softirq+0x75/0x90
 [<ffffffff802488ab>] __do_softirq+0x9b/0x180
 [<ffffffff80213df3>] native_sched_clock+0x13/0x70
 [<ffffffff8020d6ec>] call_softirq+0x1c/0x30
 [<ffffffff8020f175>] do_softirq+0x65/0xa0
 [<ffffffff80248345>] irq_exit+0xa5/0xb0
 [<ffffffff8020f467>] do_IRQ+0x107/0x1d0
 [<ffffffff8020c7fb>] ret_from_intr+0x0/0xf
 <EOI>  [<ffffffff80214ba6>] mwait_idle+0x56/0x60
 [<ffffffff80214b9d>] mwait_idle+0x4d/0x60
 [<ffffffff8020b353>] cpu_idle+0x63/0xc0

Re: [Bug #12393] debugging in dosemu causes lots of 'scheduling while atomic'

[Rafael J. Wysocki]

On Thursday 05 February 2009, Michal Suchanek wrote:
> As I said earlier I have received a patch that I applied locally and
> that fixes the problem.
> 
> As to if and when the patch actually appears in the kernel is out of
> my control, and nobody told me that it was applied.
> 
> If you believe it was applied to a kernel version that is readily
> available for download I am wiling to test such version.

I don't at the moment.

Can you send me a URL to the patch, please?

Rafael

Re: [Bug #12612] hard lockup when interrupting cdda2wav

[Rafael J. Wysocki]

On Thursday 05 February 2009, Matthias Reichl wrote:
> On Wed, Feb 04, 2009 at 11:58:51AM +0100, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12612
> > Subject		: hard lockup when interrupting cdda2wav
> > Submitter	: Matthias Reichl <hias@horus.com>
> > Date		: 2009-01-28 16:41 (8 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123316111415677&w=4
> > Handled-By	: FUJITA Tomonori <fujita.tomonori@lab.ntt.co.jp>
> 
> This bug is still present in 2.6.28.3.
> 
> =============================================
> [ INFO: possible recursive locking detected ]
> 2.6.28.3-dbg #1
> ---------------------------------------------
> swapper/0 is trying to acquire lock:
>  (&q->__queue_lock){.+..}, at: [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
> 
> but task is already holding lock:
>  (&q->__queue_lock){.+..}, at: [<ffffffff8040e4da>] blk_end_io+0x5a/0xa0
> 
> other info that might help us debug this:
> 1 lock held by swapper/0:
>  #0:  (&q->__queue_lock){.+..}, at: [<ffffffff8040e4da>] blk_end_io+0x5a/0xa0
> 
> stack backtrace:
> Pid: 0, comm: swapper Not tainted 2.6.28.3-dbg #1
> Call Trace:
>  <IRQ>  [<ffffffff8026cc87>] __lock_acquire+0x1797/0x1930
>  [<ffffffff806abd7b>] error_exit+0x29/0xa9
>  [<ffffffff80521e20>] sg_rq_end_io+0x0/0x2e0
>  [<ffffffff8026ceba>] lock_acquire+0x9a/0xe0
>  [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
>  [<ffffffff806ab763>] _spin_lock_irqsave+0x43/0x90
>  [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
>  [<ffffffff8040e5f5>] blk_put_request+0x25/0x60
>  [<ffffffff80520974>] sg_finish_rem_req+0xa4/0x100
>  [<ffffffff80522098>] sg_rq_end_io+0x278/0x2e0
>  [<ffffffff8040e281>] end_that_request_last+0x61/0x260
>  [<ffffffff8040e4e8>] blk_end_io+0x68/0xa0
>  [<ffffffff80508061>] scsi_end_request+0x41/0xd0
>  [<ffffffff80508750>] scsi_io_completion+0x130/0x470
>  [<ffffffff804133e5>] blk_done_softirq+0x75/0x90
>  [<ffffffff802488ab>] __do_softirq+0x9b/0x180
>  [<ffffffff80213df3>] native_sched_clock+0x13/0x70
>  [<ffffffff8020d6ec>] call_softirq+0x1c/0x30
>  [<ffffffff8020f175>] do_softirq+0x65/0xa0
>  [<ffffffff80248345>] irq_exit+0xa5/0xb0
>  [<ffffffff8020f467>] do_IRQ+0x107/0x1d0
>  [<ffffffff8020c7fb>] ret_from_intr+0x0/0xf
>  <EOI>  [<ffffffff80214ba6>] mwait_idle+0x56/0x60
>  [<ffffffff80214b9d>] mwait_idle+0x4d/0x60
>  [<ffffffff8020b353>] cpu_idle+0x63/0xc0

Thanks for the update.

Rafael

Re: [Bug #12393] debugging in dosemu causes lots of 'scheduling while atomic'

[Ray Lee]

On Thu, Feb 5, 2009 at 8:09 AM, Rafael J. Wysocki <rjw-KKrjLPT3xs0@public.gmane.org> wrote:
> On Thursday 05 February 2009, Michal Suchanek wrote:
>> As I said earlier I have received a patch that I applied locally and
>> that fixes the problem.
>>
>> As to if and when the patch actually appears in the kernel is out of
>> my control, and nobody told me that it was applied.
>>
>> If you believe it was applied to a kernel version that is readily
>> available for download I am wiling to test such version.
>
> I don't at the moment.
>
> Can you send me a URL to the patch, please?

http://lkml.org/lkml/2009/1/13/445

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-02-04 at 11:58 +0100, Rafael J. Wysocki wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> Date		: 2009-01-17 03:37 (19 days old)

Yes, this should still be listed.

Please remove kmshanah-IiIpDuVlHfMLO379cgqW9odd74u8MsAO@public.gmane.org from the CC list.

Thanks,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

On Thursday 05 February 2009, Kevin Shanahan wrote:
> On Wed, 2009-02-04 at 11:58 +0100, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> > Subject		: KVM guests stalling on 2.6.28 (bisected)
> > Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> > Date		: 2009-01-17 03:37 (19 days old)
> 
> Yes, this should still be listed.

Thanks for the update.
 
> Please remove kmshanah-IiIpDuVlHfMLO379cgqW9odd74u8MsAO@public.gmane.org from the CC list.

It gets added because it is present in the Author: field in
http://bugzilla.kernel.org/show_bug.cgi?id=12465#c5

This is how the script works, sorry for the inconvenience.

Rafael


> 
> Thanks,
> Kevin.
> 
> 
> 
> 


-- 
Everyone knows that debugging is twice as hard as writing a program
in the first place.  So if you're as clever as you can be when you write it,
how will you ever debug it? --- Brian Kernighan

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Philipp Matthias Hahn]

Hello!

On Thu, Jan 29, 2009 at 10:53:40PM -0800, Yinghai Lu wrote:
> can not find the reason why the WOL doesn't work...
> 
> please post
> 1. boot log for just after AC is pluged-in... ===> you should have
> "nv_probe: set workaround bit for reversed mac addr"
> 2. and boot log after boot from WOL...==> you have have "nv_probe: set
> workaround bit for reversed mac addr" too.

On Wed, Feb 04, 2009 at 11:58:53AM +0100, Rafael J. Wysocki wrote:
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12614
> Subject		: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
> Submitter	: Philipp Matthias Hahn <pmhahn@titan.lahn.de>
> Date		: 2009-01-29 6:31 (7 days old)
> References	: http://marc.info/?l=linux-kernel&m=123321232825316&w=4
> Handled-By	: Yinghai Lu <yinghai@kernel.org>
> Patch		: http://marc.info/?l=linux-kernel&m=123330459229248&w=4

Strage, at the moment I can't seem to reproduce the problem. I've
switched back to the version of 2.6.28.3 and now it seems to work.
I'll continue with tesing.

Some additional data:
The BIOS-upgrade tool (Afud408.exe) resets the MAC address. I had to run
the tool a second time to re-programm the MAC-address using its /M
option. I useed the unreversed MAC-address back than.
I also tried the reversed address once, but after that forcedeth.c
complained about a wrong MAC-address.

If I completely turn off the power (pull the plug), WOL doesn't work,
even when it's enabled in the BIOS.

Only after I'v started Linux, do "echo NMAC > /proc/acpi/wakeup" and
"ethtool -s eth0 wol g" does it work again.

Nether the less here's the output of dmesg:
        forcedeth: Reverse Engineered nFoce ethernet driver. Version 0.61.
        ACPI: PCI Interrupt Link [LMAC] enables at IRQ 23
        forcedeth: 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
        forcedeth: 0000:00:14.0: setting latency timer to 64
*       nv_probe: MAC_ADDR_REV ELSE
        nv_probe: set workaround bit for reversed mac addr
        forcedeth: 0000:00:14.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:19:db:f2:e1:35
        forcedeth: 0000:00:14.0: highdma pwrctl timirq gbit lnktim desc-v3
The line maked * was inserted by me in the source file for my debugging.

BYtE
Philipp Hahn
-- 
  / /  (_)__  __ ____  __ Philipp Hahn
 / /__/ / _ \/ // /\ \/ /
/____/_/_//_/\_,_/ /_/\_\ pmhahn@titan.lahn.de

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Yinghai Lu]

On Thu, Feb 5, 2009 at 3:23 PM, Philipp Matthias Hahn
<pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org> wrote:
> Hello!
>
> On Thu, Jan 29, 2009 at 10:53:40PM -0800, Yinghai Lu wrote:
>> can not find the reason why the WOL doesn't work...
>>
>> please post
>> 1. boot log for just after AC is pluged-in... ===> you should have
>> "nv_probe: set workaround bit for reversed mac addr"
>> 2. and boot log after boot from WOL...==> you have have "nv_probe: set
>> workaround bit for reversed mac addr" too.
>
> On Wed, Feb 04, 2009 at 11:58:53AM +0100, Rafael J. Wysocki wrote:
>> Bug-Entry     : http://bugzilla.kernel.org/show_bug.cgi?id=12614
>> Subject               : WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
>> Submitter     : Philipp Matthias Hahn <pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org>
>> Date          : 2009-01-29 6:31 (7 days old)
>> References    : http://marc.info/?l=linux-kernel&m=123321232825316&w=4
>> Handled-By    : Yinghai Lu <yinghai-DgEjT+Ai2ygdnm+yROfE0A@public.gmane.org>
>> Patch         : http://marc.info/?l=linux-kernel&m=123330459229248&w=4
>
> Strage, at the moment I can't seem to reproduce the problem. I've
> switched back to the version of 2.6.28.3 and now it seems to work.
> I'll continue with tesing.
>
> Some additional data:
> The BIOS-upgrade tool (Afud408.exe) resets the MAC address. I had to run
> the tool a second time to re-programm the MAC-address using its /M
> option. I useed the unreversed MAC-address back than.
> I also tried the reversed address once, but after that forcedeth.c
> complained about a wrong MAC-address.
>
> If I completely turn off the power (pull the plug), WOL doesn't work,
> even when it's enabled in the BIOS.
>
> Only after I'v started Linux, do "echo NMAC > /proc/acpi/wakeup" and
> "ethtool -s eth0 wol g" does it work again.
>
> Nether the less here's the output of dmesg:
>        forcedeth: Reverse Engineered nFoce ethernet driver. Version 0.61.
>        ACPI: PCI Interrupt Link [LMAC] enables at IRQ 23
>        forcedeth: 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
>        forcedeth: 0000:00:14.0: setting latency timer to 64
> *       nv_probe: MAC_ADDR_REV ELSE
>        nv_probe: set workaround bit for reversed mac addr

that means your BIOS doesn't reverse mac addr.
this is the one for new BIOS or old BIOS?

YH

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Rafael J. Wysocki]

On Friday 06 February 2009, Philipp Matthias Hahn wrote:
> Hello!
> 
> On Thu, Jan 29, 2009 at 10:53:40PM -0800, Yinghai Lu wrote:
> > can not find the reason why the WOL doesn't work...
> > 
> > please post
> > 1. boot log for just after AC is pluged-in... ===> you should have
> > "nv_probe: set workaround bit for reversed mac addr"
> > 2. and boot log after boot from WOL...==> you have have "nv_probe: set
> > workaround bit for reversed mac addr" too.
> 
> On Wed, Feb 04, 2009 at 11:58:53AM +0100, Rafael J. Wysocki wrote:
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12614
> > Subject		: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
> > Submitter	: Philipp Matthias Hahn <pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org>
> > Date		: 2009-01-29 6:31 (7 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123321232825316&w=4
> > Handled-By	: Yinghai Lu <yinghai-DgEjT+Ai2ygdnm+yROfE0A@public.gmane.org>
> > Patch		: http://marc.info/?l=linux-kernel&m=123330459229248&w=4
> 
> Strage, at the moment I can't seem to reproduce the problem. I've
> switched back to the version of 2.6.28.3 and now it seems to work.
> I'll continue with tesing.

OK, but for now I'll close the bug as unreproducible.

> Some additional data:
> The BIOS-upgrade tool (Afud408.exe) resets the MAC address. I had to run
> the tool a second time to re-programm the MAC-address using its /M
> option. I useed the unreversed MAC-address back than.
> I also tried the reversed address once, but after that forcedeth.c
> complained about a wrong MAC-address.
> 
> If I completely turn off the power (pull the plug), WOL doesn't work,
> even when it's enabled in the BIOS.
> 
> Only after I'v started Linux, do "echo NMAC > /proc/acpi/wakeup" and
> "ethtool -s eth0 wol g" does it work again.

The "echo NMAC > /proc/acpi/wakeup" thing shouldn't be necessary if you do
"ethtool -s eth0 wol g".

Thanks,
Rafael

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Philipp Matthias Hahn]

Hello!

On Fri, Feb 06, 2009 at 01:13:30AM +0100, Rafael J. Wysocki wrote:
...
> > > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12614
> > > Subject		: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e
...
> > Strage, at the moment I can't seem to reproduce the problem. I've
> > switched back to the version of 2.6.28.3 and now it seems to work.
> > I'll continue with tesing.
> 
> OK, but for now I'll close the bug as unreproducible.

Just this morning I had to use the reverted address to wake up my
desktop PC after 6 hours of poweroff.

Yesterdays tests were domething like the following:
	Grub: Linux "loglevel=9 ignore_loglevel break=modules"
	dmesg -c > /dev/null
	modprobe forcedeth
	dmesg
	ethtool -s eth0 wol g
	echo NMAC > /proc/acpi/wakeup
	reboot to Grub using Alt-SysRq-B
	Grub: "halt"
I have to reboot back to Grub, since doing a "poweroff" from initrd or
pressing Alt-SysRq-O seems to turn of WOL.

...
> The "echo NMAC > /proc/acpi/wakeup" thing shouldn't be necessary if you do
> "ethtool -s eth0 wol g".

Will try.

On Thu, Feb 05, 2009 at 03:35:25PM -0800, Yinghai Lu wrote:
> > Nether the less here's the output of dmesg:
> >        forcedeth: Reverse Engineered nFoce ethernet driver. Version 0.61.
> >        ACPI: PCI Interrupt Link [LMAC] enables at IRQ 23
> >        forcedeth: 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
> >        forcedeth: 0000:00:14.0: setting latency timer to 64
> > *       nv_probe: MAC_ADDR_REV ELSE
> >        nv_probe: set workaround bit for reversed mac addr
> 
> that means your BIOS doesn't reverse mac addr.
> this is the one for new BIOS or old BIOS?

This is the new BIOS.

BYtE
Philipp Hahn
-- 
  / /  (_)__  __ ____  __ Philipp Hahn
 / /__/ / _ \/ // /\ \/ /
/____/_/_//_/\_,_/ /_/\_\ pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Philipp Matthias Hahn]

Hello again!

On Fri, Feb 06, 2009 at 06:33:20AM +0100, Philipp Matthias Hahn wrote:
> Just this morning I had to use the reverted address to wake up my
> desktop PC after 6 hours of poweroff.

I did some structured tesing:

1. WOL does _not_ work at all when I do:
	(grub) boot into initrd
	(initrd) modprobe forcedeth
	(initrd) ethtool -s eth0 wol g
*	(initrd) poweroff

2. WOL does _not_ work at all when I do:
	(grub) boot into initrd
	(initrd) modprobe forcedeth
	(initrd) ethtool -s eth0 wol g
*	(initrd) Alt-SysRq-O

3. WOL works using the _un-reversed_ MAC when I do:
	(grub) boot into initrd
	(initrd) modprobe forcedeth
	(initrd) ethtool -s eth0 wol g
*	(initrd) Alt-SysRq-B
*	(grub) halt

4. WOL works using the _reversed_ MAC when I do:
	(grub) boot into initrd
	(initrd) modprobe forcedeth
	(initrd) ethtool -s eth0 wol g
	(initrd) exit
*	(Debian) poweroff

If I do the poweroff from linux (either initrd or Debian), forcedeth
seems to display some messages just before poweroff. I'll try to get
hands on a Serial-USB-Converter and a NULL-modem-cable to capture it,
since my laptop is legacy-free :-(

BYtE
Philipp Hahn

PS: initrd is actually initramfs, before somebody wonders.
-- 
  / /  (_)__  __ ____  __ Philipp Hahn
 / /__/ / _ \/ // /\ \/ /
/____/_/_//_/\_,_/ /_/\_\ pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org

Re: [Bug #12612] hard lockup when interrupting cdda2wav

[FUJITA Tomonori]

On Thu, 5 Feb 2009 14:16:44 +0100
Matthias Reichl <hias-vtPv7MOkFPkAvxtiuMwx3w@public.gmane.org> wrote:

> On Wed, Feb 04, 2009 at 11:58:51AM +0100, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> > 
> > 
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12612
> > Subject		: hard lockup when interrupting cdda2wav
> > Submitter	: Matthias Reichl <hias-vtPv7MOkFPkAvxtiuMwx3w@public.gmane.org>
> > Date		: 2009-01-28 16:41 (8 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123316111415677&w=4
> > Handled-By	: FUJITA Tomonori <fujita.tomonori-Zyj7fXuS5i5L9jVzuh4AOg@public.gmane.org>
> 
> This bug is still present in 2.6.28.3.

There is a fix against scsi-misc:

http://marc.info/?l=linux-scsi&m=123371501613019&w=2

I might need to fix it in a different way though.

There are other pending patches to fix other sg oops in scsi-misc so
the above fix can't be cleanly applied to 2.6.28.X. I'll send a patch
for 2.6.28.X once I get SCSI maintainer's ACK on it.

Sorry for the inconvenience,

Re: [Bug #12405] oops in __bounce_end_io_read under kvm

[Christoph Hellwig]

On Wed, Feb 04, 2009 at 11:58:40AM +0100, Rafael J. Wysocki wrote:
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12405
> Subject		: oops in __bounce_end_io_read under kvm
> Submitter	: Christoph Hellwig <hch-jcswGhMUV9g@public.gmane.org>
> Date		: 2008-12-26 17:36 (41 days old)
> References	: http://marc.info/?l=linux-kernel&m=123031303400676&w=4
> Handled-By	: Jens Axboe <jens.axboe-QHcLZuEGTsvQT0dZR+AlfA@public.gmane.org>

Still around.  Btw, I'm not sure it's a regression as I only started
using virtio_blk heavily during the 2.6.28 cycle.

Re: [Bug #12426] TMDC Joystick no longer works in kernel 2.6.28

[Andrew S. Johnson]

On Wednesday 04 February 2009 07:34:55 pm Rafael J. Wysocki wrote:
> On Wednesday 04 February 2009, Jiri Kosina wrote:
> > On Wed, 4 Feb 2009, Rafael J. Wysocki wrote:
> > > This message has been generated automatically as a part of a
> > > report of regressions introduced between 2.6.27 and 2.6.28.
> > >
> > > The following bug entry is on the current list of known
> > > regressions introduced between 2.6.27 and 2.6.28.  Please
> > > verify if it still should be listed and let me know (either
> > > way).
> > >
> > >
> > > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
> > > Subject		: TMDC Joystick no longer works in kernel 2.6.28
> > > Submitter	: Andrew S. Johnson <andy-9eXmkf4BiQ2aMJb+Lgu22Q@public.gmane.org>
> > > Date		: 2009-01-10 21:53 (26 days old)
> > > References	:
> > > http://marc.info/?l=linux-kernel&m=123162486415366&w=4
> >
> > I asked [1] the Submitter some time ago to check whether
> > reverting a particular commit fixes the issue, but never heard
> > back.
> >
> > [1] http://lkml.org/lkml/2009/1/26/70
>
> Rejected as "insufficient data" and closed.

I never received the email referring to a particular commit because
I am not subscribed to LKML.  The commit revert seemed to work OK on 
gameport.c, but I get an error that gameport.h requires merge 
resolution.

Can you send the gameport.c and gameport.h files to me with the
reverted commit, or tell me how to get this resolved?

Please CC me directly.

Thanks,

Andy Johnson

>
> Thanks,
> Rafael

Re: [Bug #12426] TMDC Joystick no longer works in kernel 2.6.28

[Jiri Kosina]

On Fri, 6 Feb 2009, Andrew S. Johnson wrote:

> > > > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12426
> > > > Subject		: TMDC Joystick no longer works in kernel 2.6.28
> > > > Submitter	: Andrew S. Johnson <andy-9eXmkf4BiQ2aMJb+Lgu22Q@public.gmane.org>
> > > > Date		: 2009-01-10 21:53 (26 days old)
> > > > References	:
> > > > http://marc.info/?l=linux-kernel&m=123162486415366&w=4
> > > I asked [1] the Submitter some time ago to check whether
> > > reverting a particular commit fixes the issue, but never heard
> > > back.
> > > [1] http://lkml.org/lkml/2009/1/26/70
> > Rejected as "insufficient data" and closed.
> I never received the email referring to a particular commit because I am 
> not subscribed to LKML.  

I CCed you, but your ISP blacklisted both of my SMTP servers I have tried 
for no apparent reason.

> The commit revert seemed to work OK on gameport.c, but I get an error 
> that gameport.h requires merge resolution.

Please try the patch below. It's not a simple revert of 6902c0be, needed 
some manual tweaking.

diff --git a/drivers/input/gameport/gameport.c b/drivers/input/gameport/gameport.c
index ebf4be5..5f2e729 100644
--- a/drivers/input/gameport/gameport.c
+++ b/drivers/input/gameport/gameport.c
@@ -231,7 +231,6 @@ static void gameport_find_driver(struct gameport *gameport)
 enum gameport_event_type {
 	GAMEPORT_REGISTER_PORT,
 	GAMEPORT_REGISTER_DRIVER,
-	GAMEPORT_ATTACH_DRIVER,
 };
 
 struct gameport_event {
@@ -246,12 +245,11 @@ static LIST_HEAD(gameport_event_list);
 static DECLARE_WAIT_QUEUE_HEAD(gameport_wait);
 static struct task_struct *gameport_task;
 
-static int gameport_queue_event(void *object, struct module *owner,
-				enum gameport_event_type event_type)
+static void gameport_queue_event(void *object, struct module *owner,
+			      enum gameport_event_type event_type)
 {
 	unsigned long flags;
 	struct gameport_event *event;
-	int retval = 0;
 
 	spin_lock_irqsave(&gameport_event_lock, flags);
 
@@ -270,34 +268,24 @@ static int gameport_queue_event(void *object, struct module *owner,
 		}
 	}
 
-	event = kmalloc(sizeof(struct gameport_event), GFP_ATOMIC);
-	if (!event) {
-		printk(KERN_ERR
-			"gameport: Not enough memory to queue event %d\n",
-			event_type);
-		retval = -ENOMEM;
-		goto out;
-	}
-
-	if (!try_module_get(owner)) {
-		printk(KERN_WARNING
-			"gameport: Can't get module reference, dropping event %d\n",
-			event_type);
-		kfree(event);
-		retval = -EINVAL;
-		goto out;
-	}
-
-	event->type = event_type;
-	event->object = object;
-	event->owner = owner;
+	if ((event = kmalloc(sizeof(struct gameport_event), GFP_ATOMIC))) {
+		if (!try_module_get(owner)) {
+			printk(KERN_WARNING "gameport: Can't get module reference, dropping event %d\n", event_type);
+			kfree(event);
+			goto out;
+		}
 
-	list_add_tail(&event->node, &gameport_event_list);
-	wake_up(&gameport_wait);
+		event->type = event_type;
+		event->object = object;
+		event->owner = owner;
 
+		list_add_tail(&event->node, &gameport_event_list);
+		wake_up(&gameport_wait);
+	} else {
+		printk(KERN_ERR "gameport: Not enough memory to queue event %d\n", event_type);
+	}
 out:
 	spin_unlock_irqrestore(&gameport_event_lock, flags);
-	return retval;
 }
 
 static void gameport_free_event(struct gameport_event *event)
@@ -390,10 +378,9 @@ static void gameport_handle_event(void)
 }
 
 /*
- * Remove all events that have been submitted for a given object,
- * be it a gameport port or a driver.
+ * Remove all events that have been submitted for a given gameport port.
  */
-static void gameport_remove_pending_events(void *object)
+static void gameport_remove_pending_events(struct gameport *gameport)
 {
 	struct list_head *node, *next;
 	struct gameport_event *event;
@@ -403,7 +390,7 @@ static void gameport_remove_pending_events(void *object)
 
 	list_for_each_safe(node, next, &gameport_event_list) {
 		event = list_entry(node, struct gameport_event, node);
-		if (event->object == object) {
+		if (event->object == gameport) {
 			list_del_init(node);
 			gameport_free_event(event);
 		}
@@ -717,40 +704,10 @@ static void gameport_add_driver(struct gameport_driver *drv)
 			drv->driver.name, error);
 }
 
-int __gameport_register_driver(struct gameport_driver *drv, struct module *owner,
-				const char *mod_name)
+void __gameport_register_driver(struct gameport_driver *drv, struct module *owner)
 {
-	int error;
-
 	drv->driver.bus = &gameport_bus;
-	drv->driver.owner = owner;
-	drv->driver.mod_name = mod_name;
-
-	/*
-	 * Temporarily disable automatic binding because probing
-	 * takes long time and we are better off doing it in kgameportd
-	 */
-	drv->ignore = 1;
-
-	error = driver_register(&drv->driver);
-	if (error) {
-		printk(KERN_ERR
-			"gameport: driver_register() failed for %s, error: %d\n",
-			drv->driver.name, error);
-		return error;
-	}
-
-	/*
-	 * Reset ignore flag and let kgameportd bind the driver to free ports
-	 */
-	drv->ignore = 0;
-	error = gameport_queue_event(drv, NULL, GAMEPORT_ATTACH_DRIVER);
-	if (error) {
-		driver_unregister(&drv->driver);
-		return error;
-	}
-
-	return 0;
+	gameport_queue_event(drv, owner, GAMEPORT_REGISTER_DRIVER);
 }
 
 void gameport_unregister_driver(struct gameport_driver *drv)
@@ -758,9 +715,7 @@ void gameport_unregister_driver(struct gameport_driver *drv)
 	struct gameport *gameport;
 
 	mutex_lock(&gameport_mutex);
-
 	drv->ignore = 1;	/* so gameport_find_driver ignores it */
-	gameport_remove_pending_events(drv);
 
 start_over:
 	list_for_each_entry(gameport, &gameport_list, node) {
@@ -773,7 +728,6 @@ start_over:
 	}
 
 	driver_unregister(&drv->driver);
-
 	mutex_unlock(&gameport_mutex);
 }
 
diff --git a/drivers/input/joystick/a3d.c b/drivers/input/joystick/a3d.c
index 6489f40..92498d4 100644
--- a/drivers/input/joystick/a3d.c
+++ b/drivers/input/joystick/a3d.c
@@ -414,7 +414,8 @@ static struct gameport_driver a3d_drv = {
 
 static int __init a3d_init(void)
 {
-	return gameport_register_driver(&a3d_drv);
+	gameport_register_driver(&a3d_drv);
+	return 0;
 }
 
 static void __exit a3d_exit(void)
diff --git a/drivers/input/joystick/adi.c b/drivers/input/joystick/adi.c
index 89c4c08..d1ca8a1 100644
--- a/drivers/input/joystick/adi.c
+++ b/drivers/input/joystick/adi.c
@@ -572,7 +572,8 @@ static struct gameport_driver adi_drv = {
 
 static int __init adi_init(void)
 {
-	return gameport_register_driver(&adi_drv);
+	gameport_register_driver(&adi_drv);
+	return 0;
 }
 
 static void __exit adi_exit(void)
diff --git a/drivers/input/joystick/analog.c b/drivers/input/joystick/analog.c
index 356b3a2..708c5ae 100644
--- a/drivers/input/joystick/analog.c
+++ b/drivers/input/joystick/analog.c
@@ -761,7 +761,9 @@ static struct gameport_driver analog_drv = {
 static int __init analog_init(void)
 {
 	analog_parse_options();
-	return gameport_register_driver(&analog_drv);
+	gameport_register_driver(&analog_drv);
+
+	return 0;
 }
 
 static void __exit analog_exit(void)
diff --git a/drivers/input/joystick/cobra.c b/drivers/input/joystick/cobra.c
index 3497b87..639b975 100644
--- a/drivers/input/joystick/cobra.c
+++ b/drivers/input/joystick/cobra.c
@@ -263,7 +263,8 @@ static struct gameport_driver cobra_drv = {
 
 static int __init cobra_init(void)
 {
-	return gameport_register_driver(&cobra_drv);
+	gameport_register_driver(&cobra_drv);
+	return 0;
 }
 
 static void __exit cobra_exit(void)
diff --git a/drivers/input/joystick/gf2k.c b/drivers/input/joystick/gf2k.c
index 67c207f..cb6eef1 100644
--- a/drivers/input/joystick/gf2k.c
+++ b/drivers/input/joystick/gf2k.c
@@ -375,7 +375,8 @@ static struct gameport_driver gf2k_drv = {
 
 static int __init gf2k_init(void)
 {
-	return gameport_register_driver(&gf2k_drv);
+	gameport_register_driver(&gf2k_drv);
+	return 0;
 }
 
 static void __exit gf2k_exit(void)
diff --git a/drivers/input/joystick/grip.c b/drivers/input/joystick/grip.c
index fc55899..684e07c 100644
--- a/drivers/input/joystick/grip.c
+++ b/drivers/input/joystick/grip.c
@@ -426,7 +426,8 @@ static struct gameport_driver grip_drv = {
 
 static int __init grip_init(void)
 {
-	return gameport_register_driver(&grip_drv);
+	gameport_register_driver(&grip_drv);
+	return 0;
 }
 
 static void __exit grip_exit(void)
diff --git a/drivers/input/joystick/grip_mp.c b/drivers/input/joystick/grip_mp.c
index 2d47baf..8279481 100644
--- a/drivers/input/joystick/grip_mp.c
+++ b/drivers/input/joystick/grip_mp.c
@@ -689,7 +689,8 @@ static struct gameport_driver grip_drv = {
 
 static int __init grip_init(void)
 {
-	return gameport_register_driver(&grip_drv);
+	gameport_register_driver(&grip_drv);
+	return 0;
 }
 
 static void __exit grip_exit(void)
diff --git a/drivers/input/joystick/guillemot.c b/drivers/input/joystick/guillemot.c
index 4058d4b..25ec3fa 100644
--- a/drivers/input/joystick/guillemot.c
+++ b/drivers/input/joystick/guillemot.c
@@ -283,7 +283,8 @@ static struct gameport_driver guillemot_drv = {
 
 static int __init guillemot_init(void)
 {
-	return gameport_register_driver(&guillemot_drv);
+	gameport_register_driver(&guillemot_drv);
+	return 0;
 }
 
 static void __exit guillemot_exit(void)
diff --git a/drivers/input/joystick/interact.c b/drivers/input/joystick/interact.c
index 2478289..8c3290b 100644
--- a/drivers/input/joystick/interact.c
+++ b/drivers/input/joystick/interact.c
@@ -317,7 +317,8 @@ static struct gameport_driver interact_drv = {
 
 static int __init interact_init(void)
 {
-	return gameport_register_driver(&interact_drv);
+	gameport_register_driver(&interact_drv);
+	return 0;
 }
 
 static void __exit interact_exit(void)
diff --git a/drivers/input/joystick/joydump.c b/drivers/input/joystick/joydump.c
index cd894a0..2a1b82c 100644
--- a/drivers/input/joystick/joydump.c
+++ b/drivers/input/joystick/joydump.c
@@ -161,7 +161,8 @@ static struct gameport_driver joydump_drv = {
 
 static int __init joydump_init(void)
 {
-	return gameport_register_driver(&joydump_drv);
+	gameport_register_driver(&joydump_drv);
+	return 0;
 }
 
 static void __exit joydump_exit(void)
diff --git a/drivers/input/joystick/sidewinder.c b/drivers/input/joystick/sidewinder.c
index ca13a6b..7b4865f 100644
--- a/drivers/input/joystick/sidewinder.c
+++ b/drivers/input/joystick/sidewinder.c
@@ -818,7 +818,8 @@ static struct gameport_driver sw_drv = {
 
 static int __init sw_init(void)
 {
-	return gameport_register_driver(&sw_drv);
+	gameport_register_driver(&sw_drv);
+	return 0;
 }
 
 static void __exit sw_exit(void)
diff --git a/drivers/input/joystick/tmdc.c b/drivers/input/joystick/tmdc.c
index d6c6098..60c37bc 100644
--- a/drivers/input/joystick/tmdc.c
+++ b/drivers/input/joystick/tmdc.c
@@ -438,7 +438,8 @@ static struct gameport_driver tmdc_drv = {
 
 static int __init tmdc_init(void)
 {
-	return gameport_register_driver(&tmdc_drv);
+	gameport_register_driver(&tmdc_drv);
+	return 0;
 }
 
 static void __exit tmdc_exit(void)
diff --git a/include/linux/gameport.h b/include/linux/gameport.h
index 0cd825f..f64e29c 100644
--- a/include/linux/gameport.h
+++ b/include/linux/gameport.h
@@ -146,11 +146,10 @@ static inline void gameport_unpin_driver(struct gameport *gameport)
 	mutex_unlock(&gameport->drv_mutex);
 }
 
-int __gameport_register_driver(struct gameport_driver *drv,
-				struct module *owner, const char *mod_name);
-static inline int __must_check gameport_register_driver(struct gameport_driver *drv)
+void __gameport_register_driver(struct gameport_driver *drv, struct module *owner);
+static inline void gameport_register_driver(struct gameport_driver *drv)
 {
-	return __gameport_register_driver(drv, THIS_MODULE, KBUILD_MODNAME);
+	__gameport_register_driver(drv, THIS_MODULE);
 }
 
 void gameport_unregister_driver(struct gameport_driver *drv);

Re: [Bug #12405] oops in __bounce_end_io_read under kvm

[Rafael J. Wysocki]

On Friday 06 February 2009, Christoph Hellwig wrote:
> On Wed, Feb 04, 2009 at 11:58:40AM +0100, Rafael J. Wysocki wrote:
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12405
> > Subject		: oops in __bounce_end_io_read under kvm
> > Submitter	: Christoph Hellwig <hch-jcswGhMUV9g@public.gmane.org>
> > Date		: 2008-12-26 17:36 (41 days old)
> > References	: http://marc.info/?l=linux-kernel&m=123031303400676&w=4
> > Handled-By	: Jens Axboe <jens.axboe-QHcLZuEGTsvQT0dZR+AlfA@public.gmane.org>
> 
> Still around.  Btw, I'm not sure it's a regression as I only started
> using virtio_blk heavily during the 2.6.28 cycle.

Well, assuming that it is a regression raises its chances to be fixed faster. ;-)

Re: WOL with forcedeth broken since f55c21fd9a92a444e55ad1ca4e4732d56661bf2e

[Philipp Matthias Hahn]

HellO!

On Fri, Feb 06, 2009 at 07:59:12AM +0100, Philipp Matthias Hahn wrote:
> I did some structured tesing:

Here are my captured console logs:
scout=Desktop with nVidia Corporation MCP51 Ethernet Controller (rev a3)
euro=Laptop used for capturing and wakeup

(initramfs) modprobe forcedeth
forcedeth: Reverse Engineered nForce ethernet driver. Version 0.61.
ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 23
forcedeth 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
forcedeth 0000:00:14.0: setting latency timer to 64
nv_probe: MAC_ADDR_REV ELSE
nv_probe: set workaround bit for reversed mac addr
forcedeth 0000:00:14.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:19:db:f2:e1:35
forcedeth 0000:00:14.0: highdma pwrctl timirq gbit lnktim desc-v3
(initramfs) ethtool -s eth0 wol g
(initramfs) poweroff
...
forcedeth 0000:00:14.0: PCI INT A disabled
forcedeth 0000:00:14.0: PME# enabled
forcedeth 0000:00:14.0: wake-up capability enabled by ACPI
ACPI: Preparing to enter system sleep state S5
...
Power down.
acpi_power_off called

euro:~# etherwake -i eth0 00:19:db:f2:e1:35 # FAIL
euro:~# etherwake -i eth0 35:e1:f2:db:19:00 # FAIL


(initramfs) modprobe forcedeth
forcedeth: Reverse Engineered nForce ethernet driver. Version 0.61.
ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 23
forcedeth 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
forcedeth 0000:00:14.0: setting latency timer to 64
nv_probe: MAC_ADDR_REV ELSE
nv_probe: set workaround bit for reversed mac addr
forcedeth 0000:00:14.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:19:db:f2:e1:35
forcedeth 0000:00:14.0: highdma pwrctl timirq gbit lnktim desc-v3
(initramfs) ethtool -s eth0 wol g
(initramfs) echo o > /proc/sysrq-trigger
SysRq : Power Off
...
forcedeth 0000:00:14.0: PCI INT A disabled
forcedeth 0000:00:14.0: PME# enabled
forcedeth 0000:00:14.0: wake-up capability enabled by ACPI
ACPI: Preparing to enter system sleep state S5
...
Power down.
acpi_power_off called

euro:~# etherwake -i eth0 00:19:db:f2:e1:35 # FAIL
euro:~# etherwake -i eth0 35:e1:f2:db:19:00 # FAIL


(initramfs) modprobe forcedeth
forcedeth: Reverse Engineered nForce ethernet driver. Version 0.61.
ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 23
forcedeth 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
forcedeth 0000:00:14.0: setting latency timer to 64
nv_probe: MAC_ADDR_REV ELSE
nv_probe: set workaround bit for reversed mac addr
forcedeth 0000:00:14.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:19:db:f2:e1:35
forcedeth 0000:00:14.0: highdma pwrctl timirq gbit lnktim desc-v3
(initramfs) ethtool -s eth0 wol g
(initramfs) echo b > /proc/sysrq-trigger
SysRq : Resetting
(grub) halt

euro:~# etherwake -i eth0 35:e1:f2:db:19:00 # FAIL
euro:~# etherwake -i eth0 00:19:db:f2:e1:35 # SUCCESS


(initramfs) modprobe forcedeth
forcedeth: Reverse Engineered nForce ethernet driver. Version 0.61.
ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 23
forcedeth 0000:00:14.0: PCI INT A -> Link[LMAC] -> GSI 23 (level, low) -> IRQ 23
forcedeth 0000:00:14.0: setting latency timer to 64
nv_probe: MAC_ADDR_REV ELSE
nv_probe: set workaround bit for reversed mac addr
forcedeth 0000:00:14.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:19:db:f2:e1:35
forcedeth 0000:00:14.0: highdma pwrctl timirq gbit lnktim desc-v3
(initramfs) ethtool -s eth0 wol g
(initramfs) exit
...
scout:~# poweroff
...
forcedeth 0000:00:14.0: PCI INT A disabled
forcedeth 0000:00:14.0: PME# enabled
forcedeth 0000:00:14.0: wake-up capability enabled by ACPI
ACPI: Preparing to enter system sleep state S5
...
Power down.
acpi_power_off called

euro:~# etherwake -i eth0 00:19:db:f2:e1:35 # FAIL
euro:~# etherwake -i eth0 35:e1:f2:db:19:00 # SUCCESS

BYtE
Philipp Hahn
-- 
  / /  (_)__  __ ____  __ Philipp Hahn
 / /__/ / _ \/ // /\ \/ /
/____/_/_//_/\_,_/ /_/\_\ pmhahn-u4khhh1J0LzF41mA0N3lWw@public.gmane.org

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (29 days old)

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (38 days old)

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Mon, 2009-02-23 at 23:03 +0100, Rafael J. Wysocki wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).

Yes, the problem should still be listed.
The bug is still present as recently as 2.6.29-rc5-00299-gadfafef.

Regards,
Kevin.

> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> Date		: 2009-01-17 03:37 (38 days old)

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

On Tuesday 24 February 2009, Kevin Shanahan wrote:
> On Mon, 2009-02-23 at 23:03 +0100, Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of regressions introduced between 2.6.27 and 2.6.28.
> > 
> > The following bug entry is on the current list of known regressions
> > introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > be listed and let me know (either way).
> 
> Yes, the problem should still be listed.
> The bug is still present as recently as 2.6.29-rc5-00299-gadfafef.

Thanks for the update.

Rafael

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Mon, 2009-02-23 at 23:03 +0100, Rafael J. Wysocki wrote:
>   
>> This message has been generated automatically as a part of a report
>> of regressions introduced between 2.6.27 and 2.6.28.
>>
>> The following bug entry is on the current list of known regressions
>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>> be listed and let me know (either way).
>>     
>
> Yes, the problem should still be listed.
> The bug is still present as recently as 2.6.29-rc5-00299-gadfafef.
>   

Did tracing turn anything up?

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-02-24 at 14:09 +0200, Avi Kivity wrote:
> Kevin Shanahan wrote:
> > On Mon, 2009-02-23 at 23:03 +0100, Rafael J. Wysocki wrote:
> >   
> >> This message has been generated automatically as a part of a report
> >> of regressions introduced between 2.6.27 and 2.6.28.
> >>
> >> The following bug entry is on the current list of known regressions
> >> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> >> be listed and let me know (either way).
> >>     
> >
> > Yes, the problem should still be listed.
> > The bug is still present as recently as 2.6.29-rc5-00299-gadfafef.
> >   
> 
> Did tracing turn anything up?

I provided some more traces using Ingo's "tip" branch, but I don't think
anyone has looked at them yet.

  http://bugzilla.kernel.org/show_bug.cgi?id=12465#c11

I can provide more traces if e.g. a different set of functions is
required, but I'm not going to be able to analyse them properly myself.

I should have a bit more time for testing next week and I plan to try
setting up the guest with the different virtual network adapters models
to see if that helps.

Cheers,
Kevin.

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (46 days old)
Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-03-03 at 20:41 +0100, Rafael J. Wysocki wrote:
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> Date		: 2009-01-17 03:37 (46 days old)
> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

Yes this should still be listed.

The traces are there waiting to be looked at. If there's anything else I
can do to help things along, please let me know.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Tue, 2009-03-03 at 20:41 +0100, Rafael J. Wysocki wrote:
>   
>> The following bug entry is on the current list of known regressions
>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>> be listed and let me know (either way).
>>
>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>> Date		: 2009-01-17 03:37 (46 days old)
>> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
>>     
>
> Yes this should still be listed.
>
> The traces are there waiting to be looked at. If there's anything else I
> can do to help things along, please let me know.
>
>   

I was away on vacation, I'll try to look at the traces soon.  Help from 
the sched developers would be appreciated, though, as I doubt I have the 
skills to decypher them.


-- 
error compiling committee.c: too many arguments to function

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (57 days old)
Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> Date		: 2009-01-17 03:37 (57 days old)
> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

No further updates since the last reminder.
The bug should still be listed.

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
>   
>> This message has been generated automatically as a part of a report
>> of regressions introduced between 2.6.27 and 2.6.28.
>>
>> The following bug entry is on the current list of known regressions
>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>> be listed and let me know (either way).
>>
>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>> Date		: 2009-01-17 03:37 (57 days old)
>> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
>>     
>
> No further updates since the last reminder.
> The bug should still be listed.
>   

I've looked at the traces but lack the skill to make any sense out of them.


-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org> wrote:

> Kevin Shanahan wrote:
>> On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
>>   
>>> This message has been generated automatically as a part of a report
>>> of regressions introduced between 2.6.27 and 2.6.28.
>>>
>>> The following bug entry is on the current list of known regressions
>>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>>> be listed and let me know (either way).
>>>
>>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>>> Date		: 2009-01-17 03:37 (57 days old)
>>> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
>>>     
>>
>> No further updates since the last reminder.
>> The bug should still be listed.
>>   
>
> I've looked at the traces but lack the skill to make any sense 
> out of them.

Do you have specific questions about them that we could answer?

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Ingo Molnar wrote:
>> I've looked at the traces but lack the skill to make any sense 
>> out of them.
>>     
>
> Do you have specific questions about them that we could answer?
>   

A general question: what's going on?  I guess this will only be answered 
by me getting my hands dirty and understanding how ftrace works and how 
the output maps to what's happening.  I'll look at the docs for a while.

A specific question for now is how can I identify long latency within 
qemu here?  As far as I can tell all qemu latencies in trace6.txt are 
sub 100ms, which, while long, don't explain the guest stalling for many 
seconds.

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Avi Kivity <avi@redhat.com> wrote:

> Ingo Molnar wrote:
>>> I've looked at the traces but lack the skill to make any sense out of 
>>> them.
>>>     
>>
>> Do you have specific questions about them that we could answer?
>>   
>
> A general question: what's going on?  I guess this will only 
> be answered by me getting my hands dirty and understanding how 
> ftrace works and how the output maps to what's happening.  
> I'll look at the docs for a while.
>
> A specific question for now is how can I identify long latency 
> within qemu here?  As far as I can tell all qemu latencies in 
> trace6.txt are sub 100ms, which, while long, don't explain the 
> guest stalling for many seconds.

Exactly - that in turn means that there's no scheduler latency 
on the host/native kernel side - in turn it must be a KVM 
related latency. (If there was any host side scheduler wakeup or 
other type of latency we'd see it in the trace.)

The most useful trace would be a specific set of trace_printk() 
calls (available on the latest tracing tree), coupled with a 
hyper_trace_printk() which injects a trace entry from the guest 
side into the host kernel trace buffer. (== that would mean a 
hypercall that does a trace_printk().)

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Ingo Molnar wrote:
>> A specific question for now is how can I identify long latency 
>> within qemu here?  As far as I can tell all qemu latencies in 
>> trace6.txt are sub 100ms, which, while long, don't explain the 
>> guest stalling for many seconds.
>>     
>
> Exactly - that in turn means that there's no scheduler latency 
> on the host/native kernel side - in turn it must be a KVM 
> related latency. (If there was any host side scheduler wakeup or 
> other type of latency we'd see it in the trace.)
>   

But if there's a missing wakeup (which is the likeliest candidate for 
the bug) then we would have seen high latencies, no?

Can you explain what the patch in question (14800984706) does?  Maybe 
that will give us a clue.

> The most useful trace would be a specific set of trace_printk() 
> calls (available on the latest tracing tree), coupled with a 
> hyper_trace_printk() which injects a trace entry from the guest 
> side into the host kernel trace buffer. (== that would mean a 
> hypercall that does a trace_printk().)

Yes, that would provide all the information.  Not sure if I would be up 
to decoding it, though.

-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Avi Kivity]

Kevin Shanahan wrote:
> On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
>   
>> This message has been generated automatically as a part of a report
>> of regressions introduced between 2.6.27 and 2.6.28.
>>
>> The following bug entry is on the current list of known regressions
>> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
>> be listed and let me know (either way).
>>
>> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
>> Subject		: KVM guests stalling on 2.6.28 (bisected)
>> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
>> Date		: 2009-01-17 03:37 (57 days old)
>> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
>>     
>
> No further updates since the last reminder.
> The bug should still be listed.
>
>   

Does the bug reproduce if you use the acpi_pm clocksource in the guests?


-- 
error compiling committee.c: too many arguments to function

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Mon, 2009-03-16 at 11:49 +0200, Avi Kivity wrote:
> Kevin Shanahan wrote:
> > On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
> >   
> >> This message has been generated automatically as a part of a report
> >> of regressions introduced between 2.6.27 and 2.6.28.
> >>
> >> The following bug entry is on the current list of known regressions
> >> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> >> be listed and let me know (either way).
> >>
> >> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> >> Subject		: KVM guests stalling on 2.6.28 (bisected)
> >> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> >> Date		: 2009-01-17 03:37 (57 days old)
> >> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
> >>     
> >
> > No further updates since the last reminder.
> > The bug should still be listed.   
> 
> Does the bug reproduce if you use the acpi_pm clocksource in the guests?

In the guest being pinged? Yes, it still happens.

hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/available_clocksource 
kvm-clock acpi_pm jiffies tsc 
hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource 
acpi_pm

kmshanah@flexo:~$ ping -c 600 hermes-old

--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599439ms
rtt min/avg/max/mdev = 0.131/723.197/9941.884/1569.918 ms, pipe 10

I had to reconfigure the guest kernel to make that clocksource
available. The way I had the guest kernel configured before, it only had
tsc and jiffies clocksources available. Unstable TSC was detected, so it
has been using jiffies until now.

Here's another test, using kvm-clock as the guest's clocksource:

hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource 
kvm-clock

kmshanah@flexo:~$ ping -c 600 hermes-old

--- hermes-old.wumi.org.au ping statistics ---
600 packets transmitted, 600 received, 0% packet loss, time 599295ms
rtt min/avg/max/mdev = 0.131/1116.170/30840.411/4171.905 ms, pipe 31

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Mon, Mar 16, 2009 at 11:16:35PM +1030, Kevin Shanahan wrote:
> On Mon, 2009-03-16 at 11:49 +0200, Avi Kivity wrote:
> > Kevin Shanahan wrote:
> > > On Sat, 2009-03-14 at 20:20 +0100, Rafael J. Wysocki wrote:
> > >   
> > >> This message has been generated automatically as a part of a report
> > >> of regressions introduced between 2.6.27 and 2.6.28.
> > >>
> > >> The following bug entry is on the current list of known regressions
> > >> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> > >> be listed and let me know (either way).
> > >>
> > >> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> > >> Subject		: KVM guests stalling on 2.6.28 (bisected)
> > >> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> > >> Date		: 2009-01-17 03:37 (57 days old)
> > >> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>
> > >>     
> > >
> > > No further updates since the last reminder.
> > > The bug should still be listed.   
> > 
> > Does the bug reproduce if you use the acpi_pm clocksource in the guests?
> 
> In the guest being pinged? Yes, it still happens.


Hi Kevin,

I've looked a bit at your traces.
I think it's probably too wide to find something inside.
Latest -tip is provided with a new set of events tracing, meaning
that you will be able to produce function graph traces with various
sched events included.

Another thing, is it possible to reproduce it with only one ping?
Or testing perioding pings and keep only one that raised a relevant
threshold of latency? I think we could do a script that can do that.
It would make the trace much clearer.

Just wait a bit, I'm looking at which event could be relevant to enable
and I come back to you with a set of commands to test.

Frederic.
 
> hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/available_clocksource 
> kvm-clock acpi_pm jiffies tsc 
> hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource 
> acpi_pm
> 
> kmshanah@flexo:~$ ping -c 600 hermes-old
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 600 packets transmitted, 600 received, 0% packet loss, time 599439ms
> rtt min/avg/max/mdev = 0.131/723.197/9941.884/1569.918 ms, pipe 10
> 
> I had to reconfigure the guest kernel to make that clocksource
> available. The way I had the guest kernel configured before, it only had
> tsc and jiffies clocksources available. Unstable TSC was detected, so it
> has been using jiffies until now.
> 
> Here's another test, using kvm-clock as the guest's clocksource:
> 
> hermes-old:~# cat /sys/devices/system/clocksource/clocksource0/current_clocksource 
> kvm-clock
> 
> kmshanah@flexo:~$ ping -c 600 hermes-old
> 
> --- hermes-old.wumi.org.au ping statistics ---
> 600 packets transmitted, 600 received, 0% packet loss, time 599295ms
> rtt min/avg/max/mdev = 0.131/1116.170/30840.411/4171.905 ms, pipe 31
> 
> Regards,
> Kevin.
> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Mon, 2009-03-16 at 21:07 +0100, Frederic Weisbecker wrote:
> I've looked a bit at your traces.
> I think it's probably too wide to find something inside.
> Latest -tip is provided with a new set of events tracing, meaning
> that you will be able to produce function graph traces with various
> sched events included.
> 
> Another thing, is it possible to reproduce it with only one ping?
> Or testing perioding pings and keep only one that raised a relevant
> threshold of latency? I think we could do a script that can do that.
> It would make the trace much clearer.

Yeah, I think that should be possible. If you can come up with such a
script, that would be great.

> Just wait a bit, I'm looking at which event could be relevant to enable
> and I come back to you with a set of commands to test.

Excellent! Thanks for looking into this.

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Tue, Mar 17, 2009 at 09:25:37AM +1030, Kevin Shanahan wrote:
> On Mon, 2009-03-16 at 21:07 +0100, Frederic Weisbecker wrote:
> > I've looked a bit at your traces.
> > I think it's probably too wide to find something inside.
> > Latest -tip is provided with a new set of events tracing, meaning
> > that you will be able to produce function graph traces with various
> > sched events included.
> > 
> > Another thing, is it possible to reproduce it with only one ping?
> > Or testing perioding pings and keep only one that raised a relevant
> > threshold of latency? I think we could do a script that can do that.
> > It would make the trace much clearer.
> 
> Yeah, I think that should be possible. If you can come up with such a
> script, that would be great.

Ok, I've made a small script based on yours which could do this job.
You will just have to set yourself a threshold of latency
that you consider as buggy. I don't remember the latency you observed.
About 5 secs right?

It's the "thres" variable in the script.

The resulting trace should be a mixup of the function graph traces
and scheduler events which look like this:

 gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
  xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
  xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
            Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>

+ is a wakeup and ==> is a context switch.


The script will loop trying some pings and will only keep the trace that matches
the latency threshold you defined.

Tell if the following script work for you.

You will need to pull the latest -tip tree and enable the following:

CONFIG_FUNCTION_TRACER=y
CONFIG_FUNCTION_GRAPH_TRACER=y
CONFIG_DYNAMIC_FTRACE=y
CONFIG_SCHED_TRACER=y
CONFIG_CONTEXT_SWITCH_TRACER=y
CONFIG_EVENT_TRACER=y

Thanks!

Ah and you will need python too (since bash can't do floating point
operation, it uses python here).

#!/bin/bash

# Switch off all CPUs except for one to simplify the trace
echo 0 > /sys/devices/system/cpu/cpu1/online
echo 0 > /sys/devices/system/cpu/cpu2/online
echo 0 > /sys/devices/system/cpu/cpu3/online


# Make sure debugfs has been mounted
if [ ! -d /sys/kernel/debug/tracing ]; then
    mount -t debugfs debugfs /sys/kernel/debug
fi

# Set up the trace parameters
pushd /sys/kernel/debug/tracing || exit 1
echo 0 > tracing_enabled
echo function_graph > current_tracer
echo funcgraph-abstime > trace_options
echo funcgraph-proc    > trace_options

# Set here the kvm IP addr
addr=""

# Set here a threshold of latency in sec
thres="5"
found="False"
lat=0
prefix=/sys/kernel/debug/tracing

echo 1 > $prefix/events/sched/sched_wakeup/enable
echo 1 > $prefix/events/sched/sched_switch/enable

while [ "$found" != "True" ]
do
	# Flush the previous buffer
	echo nop > $prefix/current_tracer

	# Reset the function_graph tracer
	echo function_graph > $prefix/current_tracer

	echo 1 > $prefix/tracing_enabled
	lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
	echo 0 > $prefix/tracing_enabled

	found=$(python -c "print float(str($lat).strip()) > $thres")
	sleep 0.01
done

echo 0 > $prefix/events/sched/sched_wakeup/enable
echo 0 > $prefix/events/sched/sched_switch/enable


echo "Found buggy latency: $lat"
echo "Please send the trace you will find on $prefix/trace"



> 
> > Just wait a bit, I'm looking at which event could be relevant to enable
> > and I come back to you with a set of commands to test.
> 
> Excellent! Thanks for looking into this.
> 
> Cheers,
> Kevin.
> 
> 

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> On Tue, Mar 17, 2009 at 09:25:37AM +1030, Kevin Shanahan wrote:
> > On Mon, 2009-03-16 at 21:07 +0100, Frederic Weisbecker wrote:
> > > I've looked a bit at your traces.
> > > I think it's probably too wide to find something inside.
> > > Latest -tip is provided with a new set of events tracing, meaning
> > > that you will be able to produce function graph traces with various
> > > sched events included.
> > > 
> > > Another thing, is it possible to reproduce it with only one ping?
> > > Or testing perioding pings and keep only one that raised a relevant
> > > threshold of latency? I think we could do a script that can do that.
> > > It would make the trace much clearer.
> > 
> > Yeah, I think that should be possible. If you can come up with such a
> > script, that would be great.
> 
> Ok, I've made a small script based on yours which could do this job.
> You will just have to set yourself a threshold of latency
> that you consider as buggy. I don't remember the latency you observed.
> About 5 secs right?
> 
> It's the "thres" variable in the script.
> 
> The resulting trace should be a mixup of the function graph traces
> and scheduler events which look like this:
> 
>  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
>   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
>   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
>             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> 
> + is a wakeup and ==> is a context switch.
> 
> 
> The script will loop trying some pings and will only keep the trace that matches
> the latency threshold you defined.
> 
> Tell if the following script work for you.

Yes, this looks like it will work as intended.

One thing I was thinking about though - would we need to look for a
trace that consists of a fast ping followed by a slow ping? If we only
keep the trace data from when we experience the slow ping, the guest
will have already "stalled" before the trace started, so the trace won't
indicate any of the information about how we got into that state. Is
that information going to be important, or is it enough to just see what
it does to get out of the stalled state?

Either way, I'll try to get some results in my maintenance window
tonight.

Cheers,
Kevin.

> You will need to pull the latest -tip tree and enable the following:
> 
> CONFIG_FUNCTION_TRACER=y
> CONFIG_FUNCTION_GRAPH_TRACER=y
> CONFIG_DYNAMIC_FTRACE=y
> CONFIG_SCHED_TRACER=y
> CONFIG_CONTEXT_SWITCH_TRACER=y
> CONFIG_EVENT_TRACER=y
> 
> Thanks!
> 
> Ah and you will need python too (since bash can't do floating point
> operation, it uses python here).
> 
> #!/bin/bash
> 
> # Switch off all CPUs except for one to simplify the trace
> echo 0 > /sys/devices/system/cpu/cpu1/online
> echo 0 > /sys/devices/system/cpu/cpu2/online
> echo 0 > /sys/devices/system/cpu/cpu3/online
> 
> 
> # Make sure debugfs has been mounted
> if [ ! -d /sys/kernel/debug/tracing ]; then
>     mount -t debugfs debugfs /sys/kernel/debug
> fi
> 
> # Set up the trace parameters
> pushd /sys/kernel/debug/tracing || exit 1
> echo 0 > tracing_enabled
> echo function_graph > current_tracer
> echo funcgraph-abstime > trace_options
> echo funcgraph-proc    > trace_options
> 
> # Set here the kvm IP addr
> addr=""
> 
> # Set here a threshold of latency in sec
> thres="5"
> found="False"
> lat=0
> prefix=/sys/kernel/debug/tracing
> 
> echo 1 > $prefix/events/sched/sched_wakeup/enable
> echo 1 > $prefix/events/sched/sched_switch/enable
> 
> while [ "$found" != "True" ]
> do
> 	# Flush the previous buffer
> 	echo nop > $prefix/current_tracer
> 
> 	# Reset the function_graph tracer
> 	echo function_graph > $prefix/current_tracer
> 
> 	echo 1 > $prefix/tracing_enabled
> 	lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
> 	echo 0 > $prefix/tracing_enabled
> 
> 	found=$(python -c "print float(str($lat).strip()) > $thres")
> 	sleep 0.01
> done
> 
> echo 0 > $prefix/events/sched/sched_wakeup/enable
> echo 0 > $prefix/events/sched/sched_switch/enable
> 
> 
> echo "Found buggy latency: $lat"
> echo "Please send the trace you will find on $prefix/trace"

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Wed, Mar 18, 2009 at 11:46:26AM +1030, Kevin Shanahan wrote:
> On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > On Tue, Mar 17, 2009 at 09:25:37AM +1030, Kevin Shanahan wrote:
> > > On Mon, 2009-03-16 at 21:07 +0100, Frederic Weisbecker wrote:
> > > > I've looked a bit at your traces.
> > > > I think it's probably too wide to find something inside.
> > > > Latest -tip is provided with a new set of events tracing, meaning
> > > > that you will be able to produce function graph traces with various
> > > > sched events included.
> > > > 
> > > > Another thing, is it possible to reproduce it with only one ping?
> > > > Or testing perioding pings and keep only one that raised a relevant
> > > > threshold of latency? I think we could do a script that can do that.
> > > > It would make the trace much clearer.
> > > 
> > > Yeah, I think that should be possible. If you can come up with such a
> > > script, that would be great.
> > 
> > Ok, I've made a small script based on yours which could do this job.
> > You will just have to set yourself a threshold of latency
> > that you consider as buggy. I don't remember the latency you observed.
> > About 5 secs right?
> > 
> > It's the "thres" variable in the script.
> > 
> > The resulting trace should be a mixup of the function graph traces
> > and scheduler events which look like this:
> > 
> >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > 
> > + is a wakeup and ==> is a context switch.
> > 
> > 
> > The script will loop trying some pings and will only keep the trace that matches
> > the latency threshold you defined.
> > 
> > Tell if the following script work for you.
> 
> Yes, this looks like it will work as intended.
> 
> One thing I was thinking about though - would we need to look for a
> trace that consists of a fast ping followed by a slow ping? If we only
> keep the trace data from when we experience the slow ping, the guest
> will have already "stalled" before the trace started, so the trace won't
> indicate any of the information about how we got into that state. Is
> that information going to be important, or is it enough to just see what
> it does to get out of the stalled state?


I don't know :-)
I fear the only thing we would see by looking at a fast ping trace
is the kvm going to sleep at the end. I guess the hot black box
here is likely: what happens when we try to wake up kvm and why it is
taking so long.

May be by looking at a slow ping trace, we could follow the flow once
the kvm is supposed to be awaken. At this stage, we can perhaps
follow both the scheduler and kvm activities. Hopefully after that
we can reduce more the trace, by filtering some specific areas.

It will likely end up with some ftrace_printk() (putting specific
trace messages in defined locations)...


 
> Either way, I'll try to get some results in my maintenance window
> tonight.
>
> Cheers,
> Kevin.
> 
> > You will need to pull the latest -tip tree and enable the following:
> > 
> > CONFIG_FUNCTION_TRACER=y
> > CONFIG_FUNCTION_GRAPH_TRACER=y
> > CONFIG_DYNAMIC_FTRACE=y
> > CONFIG_SCHED_TRACER=y
> > CONFIG_CONTEXT_SWITCH_TRACER=y
> > CONFIG_EVENT_TRACER=y
> > 
> > Thanks!
> > 
> > Ah and you will need python too (since bash can't do floating point
> > operation, it uses python here).
> > 
> > #!/bin/bash
> > 
> > # Switch off all CPUs except for one to simplify the trace
> > echo 0 > /sys/devices/system/cpu/cpu1/online
> > echo 0 > /sys/devices/system/cpu/cpu2/online
> > echo 0 > /sys/devices/system/cpu/cpu3/online
> > 
> > 
> > # Make sure debugfs has been mounted
> > if [ ! -d /sys/kernel/debug/tracing ]; then
> >     mount -t debugfs debugfs /sys/kernel/debug
> > fi
> > 
> > # Set up the trace parameters
> > pushd /sys/kernel/debug/tracing || exit 1
> > echo 0 > tracing_enabled
> > echo function_graph > current_tracer
> > echo funcgraph-abstime > trace_options
> > echo funcgraph-proc    > trace_options
> > 
> > # Set here the kvm IP addr
> > addr=""
> > 
> > # Set here a threshold of latency in sec
> > thres="5"
> > found="False"
> > lat=0
> > prefix=/sys/kernel/debug/tracing
> > 
> > echo 1 > $prefix/events/sched/sched_wakeup/enable
> > echo 1 > $prefix/events/sched/sched_switch/enable
> > 
> > while [ "$found" != "True" ]
> > do
> > 	# Flush the previous buffer
> > 	echo nop > $prefix/current_tracer
> > 
> > 	# Reset the function_graph tracer
> > 	echo function_graph > $prefix/current_tracer
> > 
> > 	echo 1 > $prefix/tracing_enabled
> > 	lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
> > 	echo 0 > $prefix/tracing_enabled
> > 
> > 	found=$(python -c "print float(str($lat).strip()) > $thres")
> > 	sleep 0.01
> > done
> > 
> > echo 0 > $prefix/events/sched/sched_wakeup/enable
> > echo 0 > $prefix/events/sched/sched_switch/enable
> > 
> > 
> > echo "Found buggy latency: $lat"
> > echo "Please send the trace you will find on $prefix/trace"
> 
> 

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Wed, 2009-03-18 at 11:46 +1030, Kevin Shanahan wrote:
> On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > Ok, I've made a small script based on yours which could do this job.
> > You will just have to set yourself a threshold of latency
> > that you consider as buggy. I don't remember the latency you observed.
> > About 5 secs right?
> > 
> > It's the "thres" variable in the script.
> > 
> > The resulting trace should be a mixup of the function graph traces
> > and scheduler events which look like this:
> > 
> >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > 
> > + is a wakeup and ==> is a context switch.
> > 
> > The script will loop trying some pings and will only keep the trace that matches
> > the latency threshold you defined.
> > 
> > Tell if the following script work for you.

...

> Either way, I'll try to get some results in my maintenance window
> tonight.

Testing did not go so well. I compiled and booted
2.6.29-rc8-tip-02630-g93c4989, but had some problems with the system
load when I tried to start tracing - it shot up to around 16-20 or so. I
started shutting down VMs to try and get it under control, but before I
got back to tracing again the machine disappeared off the network -
unresponsive to ping.

When I got in this morning, there was nothing on the console, nothing in
the logs to show what went wrong. I will try again, but my next chance
will probably be Saturday. Stay tuned.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Thu, 2009-03-19 at 07:54 +1030, Kevin Shanahan wrote:
> On Wed, 2009-03-18 at 11:46 +1030, Kevin Shanahan wrote:
> > On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > > Ok, I've made a small script based on yours which could do this job.
> > > You will just have to set yourself a threshold of latency
> > > that you consider as buggy. I don't remember the latency you observed.
> > > About 5 secs right?
> > > 
> > > It's the "thres" variable in the script.
> > > 
> > > The resulting trace should be a mixup of the function graph traces
> > > and scheduler events which look like this:
> > > 
> > >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> > >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> > >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> > >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > > 
> > > + is a wakeup and ==> is a context switch.
> > > 
> > > The script will loop trying some pings and will only keep the trace that matches
> > > the latency threshold you defined.
> > > 
> > > Tell if the following script work for you.
> 
> ...
> 
> > Either way, I'll try to get some results in my maintenance window
> > tonight.
> 
> Testing did not go so well. I compiled and booted
> 2.6.29-rc8-tip-02630-g93c4989, but had some problems with the system
> load when I tried to start tracing - it shot up to around 16-20 or so. I
> started shutting down VMs to try and get it under control, but before I
> got back to tracing again the machine disappeared off the network -
> unresponsive to ping.
> 
> When I got in this morning, there was nothing on the console, nothing in
> the logs to show what went wrong. I will try again, but my next chance
> will probably be Saturday. Stay tuned.

Okay, new set of traces have been uploaded to:

  http://disenchant.net/tmp/bug-12465/trace-3/

These were done on the latest tip, which I pulled down this morning:
2.6.29-rc8-tip-02744-gd9937cb.

The system load was very high again when I first tried to trace with
sevarl guests running, so I ended up only having the one guest running
and thankfully the bug was still reproducable that way.

Fingers crossed this set of traces is able to tell us something.

Regards,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Sat, Mar 21, 2009 at 03:30:39PM +1030, Kevin Shanahan wrote:
> On Thu, 2009-03-19 at 07:54 +1030, Kevin Shanahan wrote:
> > On Wed, 2009-03-18 at 11:46 +1030, Kevin Shanahan wrote:
> > > On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > > > Ok, I've made a small script based on yours which could do this job.
> > > > You will just have to set yourself a threshold of latency
> > > > that you consider as buggy. I don't remember the latency you observed.
> > > > About 5 secs right?
> > > > 
> > > > It's the "thres" variable in the script.
> > > > 
> > > > The resulting trace should be a mixup of the function graph traces
> > > > and scheduler events which look like this:
> > > > 
> > > >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> > > >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> > > >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> > > >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > > > 
> > > > + is a wakeup and ==> is a context switch.
> > > > 
> > > > The script will loop trying some pings and will only keep the trace that matches
> > > > the latency threshold you defined.
> > > > 
> > > > Tell if the following script work for you.
> > 
> > ...
> > 
> > > Either way, I'll try to get some results in my maintenance window
> > > tonight.
> > 
> > Testing did not go so well. I compiled and booted
> > 2.6.29-rc8-tip-02630-g93c4989, but had some problems with the system
> > load when I tried to start tracing - it shot up to around 16-20 or so. I
> > started shutting down VMs to try and get it under control, but before I
> > got back to tracing again the machine disappeared off the network -
> > unresponsive to ping.
> > 
> > When I got in this morning, there was nothing on the console, nothing in
> > the logs to show what went wrong. I will try again, but my next chance
> > will probably be Saturday. Stay tuned.
> 
> Okay, new set of traces have been uploaded to:
> 
>   http://disenchant.net/tmp/bug-12465/trace-3/
> 
> These were done on the latest tip, which I pulled down this morning:
> 2.6.29-rc8-tip-02744-gd9937cb.
> 
> The system load was very high again when I first tried to trace with
> sevarl guests running, so I ended up only having the one guest running
> and thankfully the bug was still reproducable that way.
> 
> Fingers crossed this set of traces is able to tell us something.


Thanks a lot Kevin!

The traces seem indeed much more clearer now.
Looking at the first trace, we begin with qemu which answers to the ping.
By roughly simplying the trace, we have that:


Found buggy latency:  9297.585
Please send the trace you will find on /sys/kernel/debug/tracing/trace
# tracer: function_graph
#
#      TIME       CPU  TASK/PID        DURATION                  FUNCTION CALLS
#       |         |    |    |           |   |                     |   |   |   |

							/* answer the ping (socket write) */
 2668.130735 |   0)  qemu-sy-4048  |               |  sys_writev() {
 2668.130735 |   0)  qemu-sy-4048  |   0.361 us    |    fget_light();
 2668.130744 |   0)  qemu-sy-4048  |               |       netif_rx_ni() {
 2668.130744 |   0)  qemu-sy-4048  |               |         netif_rx() {
 2668.130763 |   0)  qemu-sy-4048  |               |           ipv4_conntrack_in() {
 2668.130764 |   0)  qemu-sy-4048  |               |             nf_conntrack_in() {
 2668.130764 |   0)  qemu-sy-4048  |   0.328 us    |               ipv4_get_l4proto();
 2668.130765 |   0)  qemu-sy-4048  |   0.310 us    |               __nf_ct_l4proto_find();
 2668.130776 |   0)  qemu-sy-4048  |               |                 icmp_packet() {
 2668.130804 |   0)  qemu-sy-4048  |               |                   netif_receive_skb() {
 2668.130804 |   0)  qemu-sy-4048  |               |                     ip_rcv() {
 2668.130824 |   0)  qemu-sy-4048  |               |                       raw_rcv() {
 2668.130824 |   0)  qemu-sy-4048  |   0.307 us    |                         skb_push();
 2668.130825 |   0)  qemu-sy-4048  |               |                           raw_rcv_skb() {
 2668.130832 |   0)  qemu-sy-4048  |               |                             __wake_up_common() {
 2668.130838 |   0)  qemu-sy-4048  |               |                               /* sched_wakeup: task ping:7420 [120] success=1 */
 2668.130839 |   0)  qemu-sy-4048  |   0.312 us    |                           }
                                                                              }
                                                                             }
                                                      [...]

							/* ping was waaiting for this response and is now awaken */
 2668.130876 |   0)  qemu-sy-4048  |               |  schedule() {
 2668.130885 |   0)  qemu-sy-4048  |               |  /* sched_switch: task qemu-system-x86:4048 [120] ==> ping:7420 [120] */
 2668.130885 |   0)  qemu-sy-4048  |               |    runqueue_is_locked() {
 2668.130886 |   0)  qemu-sy-4048  |   0.399 us    |    __phys_addr();
 ------------------------------------------
 0)  qemu-sy-4048  =>   ping-7420   
 ------------------------------------------

 2668.130887 |   0)   ping-7420    |               |                  finish_task_switch() {
 2668.130887 |   0)   ping-7420    |               |                    perf_counter_task_sched_in() {
 2668.130888 |   0)   ping-7420    |   0.319 us    |                      _spin_lock();
 2668.130888 |   0)   ping-7420    |   0.959 us    |                    }
 2668.130889 |   0)   ping-7420    |   1.644 us    |                  }
 2668.130889 |   0)   ping-7420    | ! 298102.3 us |                }
 2668.130890 |   0)   ping-7420    |               |                del_timer_sync() {
 2668.130890 |   0)   ping-7420    |               |                  try_to_del_timer_sync() {
 2668.130890 |   0)   ping-7420    |               |                    lock_timer_base() {
 2668.130890 |   0)   ping-7420    |   0.328 us    |                      _spin_lock_irqsave();
 2668.130891 |   0)   ping-7420    |   0.946 us    |                    }
 2668.130891 |   0)   ping-7420    |   0.328 us    |                    _spin_unlock_irqrestore();
 2668.130892 |   0)   ping-7420    |   2.218 us    |                  }
 2668.130892 |   0)   ping-7420    |   2.847 us    |                }
 2668.130893 |   0)   ping-7420    | ! 298108.7 us |              }
 2668.130893 |   0)   ping-7420    |   0.340 us    |              finish_wait();
 2668.130894 |   0)   ping-7420    |   0.328 us    |              _spin_lock_irqsave();
 2668.130894 |   0)   ping-7420    |   0.324 us    |              _spin_unlock_irqrestore();



As you can see we are in the middle of the dialog between ping and the kvm.
It means that we have lost many traces. I thing that the ring buffer does not have
enough space allocated for these 9 seconds of processing.

Just wait a bit while I'm cooking a better script, or at least trying to get a
better number of entries to allocate to the ring buffer and I come back to you.

But anyway, the scheduler switch and wake up events help a lot.

 
> Regards,
> Kevin.
> 
> 

[Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Rafael J. Wysocki]

This message has been generated automatically as a part of a report
of regressions introduced between 2.6.27 and 2.6.28.

The following bug entry is on the current list of known regressions
introduced between 2.6.27 and 2.6.28.  Please verify if it still should
be listed and let me know (either way).


Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
Subject		: KVM guests stalling on 2.6.28 (bisected)
Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
Date		: 2009-01-17 03:37 (64 days old)
References	: http://lkml.org/lkml/2009/3/15/51
Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Ingo Molnar]

* Rafael J. Wysocki <rjw-KKrjLPT3xs0@public.gmane.org> wrote:

> This message has been generated automatically as a part of a report
> of regressions introduced between 2.6.27 and 2.6.28.
> 
> The following bug entry is on the current list of known regressions
> introduced between 2.6.27 and 2.6.28.  Please verify if it still should
> be listed and let me know (either way).
> 
> 
> Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=12465
> Subject		: KVM guests stalling on 2.6.28 (bisected)
> Submitter	: Kevin Shanahan <kmshanah-biM/RbsGxha6c6uEtOJ/EA@public.gmane.org>
> Date		: 2009-01-17 03:37 (64 days old)
> References	: http://lkml.org/lkml/2009/3/15/51
> Handled-By	: Avi Kivity <avi-H+wXaHxf7aLQT0dZR+AlfA@public.gmane.org>

It's still being investigated.

	Ingo

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Sat, Mar 21, 2009 at 03:30:39PM +1030, Kevin Shanahan wrote:
> On Thu, 2009-03-19 at 07:54 +1030, Kevin Shanahan wrote:
> > On Wed, 2009-03-18 at 11:46 +1030, Kevin Shanahan wrote:
> > > On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > > > Ok, I've made a small script based on yours which could do this job.
> > > > You will just have to set yourself a threshold of latency
> > > > that you consider as buggy. I don't remember the latency you observed.
> > > > About 5 secs right?
> > > > 
> > > > It's the "thres" variable in the script.
> > > > 
> > > > The resulting trace should be a mixup of the function graph traces
> > > > and scheduler events which look like this:
> > > > 
> > > >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> > > >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> > > >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> > > >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > > > 
> > > > + is a wakeup and ==> is a context switch.
> > > > 
> > > > The script will loop trying some pings and will only keep the trace that matches
> > > > the latency threshold you defined.
> > > > 
> > > > Tell if the following script work for you.
> > 
> > ...
> > 
> > > Either way, I'll try to get some results in my maintenance window
> > > tonight.
> > 
> > Testing did not go so well. I compiled and booted
> > 2.6.29-rc8-tip-02630-g93c4989, but had some problems with the system
> > load when I tried to start tracing - it shot up to around 16-20 or so. I
> > started shutting down VMs to try and get it under control, but before I
> > got back to tracing again the machine disappeared off the network -
> > unresponsive to ping.
> > 
> > When I got in this morning, there was nothing on the console, nothing in
> > the logs to show what went wrong. I will try again, but my next chance
> > will probably be Saturday. Stay tuned.
> 
> Okay, new set of traces have been uploaded to:
> 
>   http://disenchant.net/tmp/bug-12465/trace-3/
> 
> These were done on the latest tip, which I pulled down this morning:
> 2.6.29-rc8-tip-02744-gd9937cb.
> 
> The system load was very high again when I first tried to trace with
> sevarl guests running, so I ended up only having the one guest running
> and thankfully the bug was still reproducable that way.
> 
> Fingers crossed this set of traces is able to tell us something.
> 
> Regards,
> Kevin.
> 
> 

Sorry, I've been late to answer.
As I explained in my previous mail, you trace is only
a snapshot that happened in 10 msec.

I experimented different sizes for the ring buffer but even
a 1 second trace require 20 Mo of memory. And a so huge trace
would be impractical.

I think we should keep the trace filters we had previously.
If you don't minde, could you please retest against latest -tip
the following updated patch? Iadded the filters, fixed the python
subshell and also flushed the buffer more nicely according to
a recent feature in -tip:

echo > trace 

instead of switching to nop.
You will need to pull latest -tip again.

Thanks a lot Kevin!


#!/bin/bash

# Switch off all CPUs except for one to simplify the trace
echo 0 > /sys/devices/system/cpu/cpu1/online
echo 0 > /sys/devices/system/cpu/cpu2/online
echo 0 > /sys/devices/system/cpu/cpu3/online


# Make sure debugfs has been mounted
if [ ! -d /sys/kernel/debug/tracing ]; then
    mount -t debugfs debugfs /sys/kernel/debug
fi

# Set up the trace parameters
pushd /sys/kernel/debug/tracing || exit 1
echo 0 > tracing_enabled
echo function_graph > current_tracer
echo funcgraph-abstime > trace_options
echo funcgraph-proc    > trace_options

# Set here the kvm IP addr
addr="hermes-old"

# Set here a threshold of latency in sec
thres="5000"
found="False"
lat=0
prefix=/sys/kernel/debug/tracing

echo 1 > $prefix/events/sched/sched_wakeup/enable
echo 1 > $prefix/events/sched/sched_switch/enable

# Set the filter for functions to trace
echo ''         > set_ftrace_filter  # clear filter functions
echo '*sched*' >> set_ftrace_filter 
echo '*wake*'  >> set_ftrace_filter
echo '*kvm*'   >> set_ftrace_filter

# Reset the function_graph tracer
echo function_graph > $prefix/current_tracer

while [ "$found" != "True" ]
do
        # Flush the previous buffer
        echo trace > $prefix/trace

        echo 1 > $prefix/tracing_enabled
        lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
        echo 0 > $prefix/tracing_enabled

	echo $lat
	found=$(python -c "print float(str($lat).strip())")
        sleep 0.01
done

echo 0 > $prefix/events/sched/sched_wakeup/enable
echo 0 > $prefix/events/sched/sched_switch/enable


echo "Found buggy latency: $lat"
echo "Please send the trace you will find on $prefix/trace"

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Tue, Mar 24, 2009 at 12:44:12PM +0100, Frederic Weisbecker wrote:
> On Sat, Mar 21, 2009 at 03:30:39PM +1030, Kevin Shanahan wrote:
> > On Thu, 2009-03-19 at 07:54 +1030, Kevin Shanahan wrote:
> > > On Wed, 2009-03-18 at 11:46 +1030, Kevin Shanahan wrote:
> > > > On Wed, 2009-03-18 at 01:20 +0100, Frederic Weisbecker wrote:
> > > > > Ok, I've made a small script based on yours which could do this job.
> > > > > You will just have to set yourself a threshold of latency
> > > > > that you consider as buggy. I don't remember the latency you observed.
> > > > > About 5 secs right?
> > > > > 
> > > > > It's the "thres" variable in the script.
> > > > > 
> > > > > The resulting trace should be a mixup of the function graph traces
> > > > > and scheduler events which look like this:
> > > > > 
> > > > >  gnome-screensav-4691  [000]  6716.774277:   4691:120:S ==> [000]     0:140:R <idle>
> > > > >   xfce4-terminal-4723  [001]  6716.774303:   4723:120:R   + [001]  4289:120:S Xorg
> > > > >   xfce4-terminal-4723  [001]  6716.774417:   4723:120:S ==> [001]  4289:120:R Xorg
> > > > >             Xorg-4289  [001]  6716.774427:   4289:120:S ==> [001]     0:140:R <idle>
> > > > > 
> > > > > + is a wakeup and ==> is a context switch.
> > > > > 
> > > > > The script will loop trying some pings and will only keep the trace that matches
> > > > > the latency threshold you defined.
> > > > > 
> > > > > Tell if the following script work for you.
> > > 
> > > ...
> > > 
> > > > Either way, I'll try to get some results in my maintenance window
> > > > tonight.
> > > 
> > > Testing did not go so well. I compiled and booted
> > > 2.6.29-rc8-tip-02630-g93c4989, but had some problems with the system
> > > load when I tried to start tracing - it shot up to around 16-20 or so. I
> > > started shutting down VMs to try and get it under control, but before I
> > > got back to tracing again the machine disappeared off the network -
> > > unresponsive to ping.
> > > 
> > > When I got in this morning, there was nothing on the console, nothing in
> > > the logs to show what went wrong. I will try again, but my next chance
> > > will probably be Saturday. Stay tuned.
> > 
> > Okay, new set of traces have been uploaded to:
> > 
> >   http://disenchant.net/tmp/bug-12465/trace-3/
> > 
> > These were done on the latest tip, which I pulled down this morning:
> > 2.6.29-rc8-tip-02744-gd9937cb.
> > 
> > The system load was very high again when I first tried to trace with
> > sevarl guests running, so I ended up only having the one guest running
> > and thankfully the bug was still reproducable that way.
> > 
> > Fingers crossed this set of traces is able to tell us something.
> > 
> > Regards,
> > Kevin.
> > 
> > 
> 
> Sorry, I've been late to answer.
> As I explained in my previous mail, you trace is only
> a snapshot that happened in 10 msec.
> 
> I experimented different sizes for the ring buffer but even
> a 1 second trace require 20 Mo of memory. And a so huge trace
> would be impractical.
> 
> I think we should keep the trace filters we had previously.
> If you don't minde, could you please retest against latest -tip
> the following updated patch? Iadded the filters, fixed the python
> subshell and also flushed the buffer more nicely according to
> a recent feature in -tip:
> 
> echo > trace 
> 
> instead of switching to nop.
> You will need to pull latest -tip again.
> 
> Thanks a lot Kevin!


Ah you will also need to increase the size of your buffer.
See below:
 
> 
> #!/bin/bash
> 
> # Switch off all CPUs except for one to simplify the trace
> echo 0 > /sys/devices/system/cpu/cpu1/online
> echo 0 > /sys/devices/system/cpu/cpu2/online
> echo 0 > /sys/devices/system/cpu/cpu3/online
> 
> 
> # Make sure debugfs has been mounted
> if [ ! -d /sys/kernel/debug/tracing ]; then
>     mount -t debugfs debugfs /sys/kernel/debug
> fi
> 
> # Set up the trace parameters
> pushd /sys/kernel/debug/tracing || exit 1
> echo 0 > tracing_enabled
> echo function_graph > current_tracer
> echo funcgraph-abstime > trace_options
> echo funcgraph-proc    > trace_options
> 
> # Set here the kvm IP addr
> addr="hermes-old"
> 
> # Set here a threshold of latency in sec
> thres="5000"
> found="False"
> lat=0
> prefix=/sys/kernel/debug/tracing
> 
> echo 1 > $prefix/events/sched/sched_wakeup/enable
> echo 1 > $prefix/events/sched/sched_switch/enable
> 
> # Set the filter for functions to trace
> echo ''         > set_ftrace_filter  # clear filter functions
> echo '*sched*' >> set_ftrace_filter 
> echo '*wake*'  >> set_ftrace_filter
> echo '*kvm*'   >> set_ftrace_filter
> 
> # Reset the function_graph tracer
> echo function_graph > $prefix/current_tracer

Put a

echo 20000 > $prefix/buffer_size_kb

So that we will have enough space (hopefully).

Thanks!

> 
> while [ "$found" != "True" ]
> do
>         # Flush the previous buffer
>         echo trace > $prefix/trace
> 
>         echo 1 > $prefix/tracing_enabled
>         lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
>         echo 0 > $prefix/tracing_enabled
> 
> 	echo $lat
> 	found=$(python -c "print float(str($lat).strip())")
>         sleep 0.01
> done
> 
> echo 0 > $prefix/events/sched/sched_wakeup/enable
> echo 0 > $prefix/events/sched/sched_switch/enable
> 
> 
> echo "Found buggy latency: $lat"
> echo "Please send the trace you will find on $prefix/trace"
> 
> 

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-03-24 at 12:44 +0100, Frederic Weisbecker wrote:
> Sorry, I've been late to answer.
> As I explained in my previous mail, you trace is only
> a snapshot that happened in 10 msec.
> 
> I experimented different sizes for the ring buffer but even
> a 1 second trace require 20 Mo of memory. And a so huge trace
> would be impractical.
> 
> I think we should keep the trace filters we had previously.
> If you don't minde, could you please retest against latest -tip
> the following updated patch? Iadded the filters, fixed the python
> subshell and also flushed the buffer more nicely according to
> a recent feature in -tip:
> 
> echo > trace 
> 
> instead of switching to nop.
> You will need to pull latest -tip again.

Ok, thanks for that. I'll get a new -tip kernel ready to test tonight.
I'm not sure about the change to the python subshell though:

> while [ "$found" != "True" ]
> do
>         # Flush the previous buffer
>         echo trace > $prefix/trace
> 
>         echo 1 > $prefix/tracing_enabled
>         lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
>         echo 0 > $prefix/tracing_enabled
> 
> 	echo $lat
> 	found=$(python -c "print float(str($lat).strip())")
>         sleep 0.01
> done

kmshanah@kulgan:~$ python -c "print float(str(1.234).strip())"
1.234

That's not going to evaluate to "True" at all is it? What happened to
the test against the latency threshold value? Did you mean something
like this?

kmshanah@kulgan:~$ python -c "print float(str(1.234).strip()) > 5000"
False
kmshanah@kulgan:~$ python -c "print float(str(5001.234).strip()) > 5000"
True

Cheers,
Kevin.

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Frederic Weisbecker]

On Thu, Mar 26, 2009 at 10:10:32AM +1030, Kevin Shanahan wrote:
> On Tue, 2009-03-24 at 12:44 +0100, Frederic Weisbecker wrote:
> > Sorry, I've been late to answer.
> > As I explained in my previous mail, you trace is only
> > a snapshot that happened in 10 msec.
> > 
> > I experimented different sizes for the ring buffer but even
> > a 1 second trace require 20 Mo of memory. And a so huge trace
> > would be impractical.
> > 
> > I think we should keep the trace filters we had previously.
> > If you don't minde, could you please retest against latest -tip
> > the following updated patch? Iadded the filters, fixed the python
> > subshell and also flushed the buffer more nicely according to
> > a recent feature in -tip:
> > 
> > echo > trace 
> > 
> > instead of switching to nop.
> > You will need to pull latest -tip again.
> 
> Ok, thanks for that. I'll get a new -tip kernel ready to test tonight.
> I'm not sure about the change to the python subshell though:
> 
> > while [ "$found" != "True" ]
> > do
> >         # Flush the previous buffer
> >         echo trace > $prefix/trace
> > 
> >         echo 1 > $prefix/tracing_enabled
> >         lat=$(ping -c 1 $addr | grep rtt | grep -Eo " [0-9]+.[0-9]+")
> >         echo 0 > $prefix/tracing_enabled
> > 
> > 	echo $lat
> > 	found=$(python -c "print float(str($lat).strip())")
> >         sleep 0.01
> > done
> 
> kmshanah@kulgan:~$ python -c "print float(str(1.234).strip())"
> 1.234
> 
> That's not going to evaluate to "True" at all is it? What happened to
> the test against the latency threshold value? Did you mean something
> like this?
> 
> kmshanah@kulgan:~$ python -c "print float(str(1.234).strip()) > 5000"
> False
> kmshanah@kulgan:~$ python -c "print float(str(5001.234).strip()) > 5000"
> True


Sorry. I guess I was a bit asleep.
It's a mistake. So you can restore how it was.

Thanks.

 
> Cheers,
> Kevin.
> 
> 

Re: [Bug #12465] KVM guests stalling on 2.6.28 (bisected)

[Kevin Shanahan]

On Tue, 2009-03-24 at 12:44 +0100, Frederic Weisbecker wrote:
> As I explained in my previous mail, you trace is only
> a snapshot that happened in 10 msec.
> 
> I experimented different sizes for the ring buffer but even
> a 1 second trace require 20 Mo of memory. And a so huge trace
> would be impractical.
> 
> I think we should keep the trace filters we had previously.
> If you don't minde, could you please retest against latest -tip
> the following updated patch? Iadded the filters, fixed the python
> subshell and also flushed the buffer more nicely according to
> a recent feature in -tip:
> 
> echo > trace 
> 
> instead of switching to nop.
> You will need to pull latest -tip again.

Ok, new set of traces uploaded again here:

  http://disenchant.net/tmp/bug-12465/trace-4/

These were taken using 2.6.29-tip-02749-g398bf09.

Same as last time, it was only necessary to have the one guest running
to reproduce the problem.

Cheers,
Kevin.