LinuxLists.cc - 2.6.29-rc8: Reported regressions 2.6.27 -> 2.6.28

[permalink] [raw]

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

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 <[email protected]>
Date : 2008-11-18 12:07 (117 days old)
Handled-By : Takashi Iwai <[email protected]>

2009-03-14 21:57:26

[permalink] [raw]

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

2009-03-14 21:57:41

[permalink] [raw]

Subject: [Bug #12411] 2.6.28: BUG in r8169

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 <[email protected]>
Date : 2008-12-31 18:37 (74 days old)
References : http://marc.info/?l=linux-kernel&m=123074869611409&w=4

2009-03-14 21:58:01

[permalink] [raw]

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

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 <[email protected]>
Date : 2008-12-12 9:35 (93 days old)
References : http://marc.info/?l=linux-kernel&m=122907463518593&w=4

2009-03-14 21:59:09

[permalink] [raw]

Subject: [Bug #12421] GPF on 2.6.28 and 2.6.28-rc9-git3, e1000e and e1000 issues

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=12421
Subject : GPF on 2.6.28 and 2.6.28-rc9-git3, e1000e and e1000 issues
Submitter : Doug Bazarnic <[email protected]>
Date : 2009-01-09 21:26 (65 days old)
References : http://marc.info/?l=linux-kernel&m=123153653120204&w=4

2009-03-14 21:58:27

[permalink] [raw]

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

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 <[email protected]>
Date : 2008-12-22 9:37 (83 days old)
References : http://marc.info/?l=linux-kernel&m=122993873320150&w=4

2009-03-14 21:59:32

[permalink] [raw]

Subject: [Bug #12645] DMI low-memory-protect quirk causes resume hang on Samsung NC10

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=12645
Subject : DMI low-memory-protect quirk causes resume hang on Samsung NC10
Submitter : Patrick Walton <[email protected]>
Date : 2009-02-06 18:35 (37 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=0af40a4b1050c050e62eb1dc30b82d5ab22bf221

2009-03-14 21:58:47

[permalink] [raw]

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

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 <[email protected]>
Date : 2008-12-12 18:49 (93 days old)
References : http://marc.info/?l=linux-kernel&m=122910784006472&w=4
http://marc.info/?l=linux-kernel&m=122907511319288&w=4

2009-03-14 21:59:46

[permalink] [raw]

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

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 <[email protected]>
Date : 2009-02-01 19:59 (42 days old)
References : http://marc.info/?l=linux-kernel&m=123351836213969&w=4

2009-03-14 22:00:09

[permalink] [raw]

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

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 <[email protected]>
Date : 2009-01-28 16:41 (46 days old)
References : http://marc.info/?l=linux-kernel&m=123316111415677&w=4
Handled-By : FUJITA Tomonori <[email protected]>
Patch : http://marc.info/?l=linux-scsi&m=123371501613019&w=2

2009-03-14 22:00:37

[permalink] [raw]

Subject: [Bug #12690] DPMS (LCD powersave, poweroff) don't work

2009-03-14 22:00:53

[permalink] [raw]

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

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 <[email protected]>
Date : 2009-01-13 21:19 (61 days old)
References : http://marc.info/?l=linux-kernel&m=123188160811322&w=4
Handled-By : Francois Romieu <[email protected]>

2009-03-14 22:01:21

[permalink] [raw]

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

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 <[email protected]>
Date : 2009-01-10 21:53 (64 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=6902c0bead4ce266226fc0c5b3828b850bdc884a
References : http://marc.info/?l=linux-kernel&m=123162486415366&w=4

2009-03-14 22:01:52

[permalink] [raw]

Subject: [Bug #12634] video distortion and lockup with i830 video chip and 2.6.28.3

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=12634
Subject : video distortion and lockup with i830 video chip and 2.6.28.3
Submitter : Bob Raitz <[email protected]>
Date : 2009-02-04 21:10 (39 days old)

2009-03-14 22:01:36

[permalink] [raw]

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

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 <[email protected]>
Date : 2009-01-17 03:37 (57 days old)
Handled-By : Avi Kivity <[email protected]>

2009-03-14 22:02:19

[permalink] [raw]

Subject: [Bug #12798] No wake up after suspend.

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=12798
Subject : No wake up after suspend.
Submitter : Michal Graczyk <[email protected]>
Date : 2009-03-01 15:30 (14 days old)
Handled-By : Zhang Rui <[email protected]>
Patch : http://bugzilla.kernel.org/attachment.cgi?id=20402&action=view

2009-03-14 22:02:50

[permalink] [raw]

Subject: [Bug #12835] Regression in backlight detection

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=12835
Subject : Regression in backlight detection
Submitter : Michael Spang <[email protected]>
Date : 2009-02-24 5:41 (19 days old)
References : http://marc.info/?l=linux-kernel&m=123545411502396&w=4
Handled-By : Michael Spang <[email protected]>
Patch : http://marc.info/?l=linux-kernel&m=123545411502396&w=4

2009-03-14 22:02:34

[permalink] [raw]

Subject: [Bug #12868] iproute2 and regressing "ipv6: convert tunnels to net_device_ops"

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=12868
Subject : iproute2 and regressing "ipv6: convert tunnels to net_device_ops"
Submitter : Jan Engelhardt <[email protected]>
Date : 2009-03-09 14:46 (6 days old)
First-Bad-Commit: http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=1326c3d5a4b792a2b15877feb7fb691f8945d203
References : http://marc.info/?l=linux-netdev&m=123660999632730&w=4

2009-03-14 22:03:16

[permalink] [raw]

Subject: [Bug #12818] iwlagn broken after suspend to RAM (iwlagn: MAC is in deep sleep!)

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=12818
Subject : iwlagn broken after suspend to RAM (iwlagn: MAC is in deep sleep!)
Submitter : Stefan Seyfried <[email protected]>
Date : 2009-03-04 08:32 (11 days old)

2009-03-15 09:04:21

[permalink] [raw]

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

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 <[email protected]>
> Date : 2009-01-17 03:37 (57 days old)
> Handled-By : Avi Kivity <[email protected]>

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

Cheers,
Kevin.

2009-03-15 09:19:21

[permalink] [raw]

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

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 <[email protected]>
>> Date : 2009-01-17 03:37 (57 days old)
>> Handled-By : Avi Kivity <[email protected]>
>>
>
> 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

2009-03-15 09:48:56

by Ingo Molnar

[permalink] [raw]

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

* Avi Kivity <[email protected]> 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 <[email protected]>
>>> Date : 2009-01-17 03:37 (57 days old)
>>> Handled-By : Avi Kivity <[email protected]>
>>>
>>
>> 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

2009-03-15 09:58:00

[permalink] [raw]

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

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

2009-03-15 10:04:21

by Ingo Molnar

[permalink] [raw]

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

* Avi Kivity <[email protected]> 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

2009-03-15 10:14:23

[permalink] [raw]

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

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

2009-03-16 09:57:40

[permalink] [raw]

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

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 <[email protected]>
>> Date : 2009-01-17 03:37 (57 days old)
>> Handled-By : Avi Kivity <[email protected]>
>>
>
> 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

2009-03-16 12:46:57

[permalink] [raw]

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

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 <[email protected]>
> >> Date : 2009-01-17 03:37 (57 days old)
> >> Handled-By : Avi Kivity <[email protected]>
> >>
> >
> > 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.

2009-03-16 20:07:55

[permalink] [raw]

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

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 <[email protected]>
> > >> Date : 2009-01-17 03:37 (57 days old)
> > >> Handled-By : Avi Kivity <[email protected]>
> > >>
> > >
> > > 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 [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2009-03-16 22:55:59

[permalink] [raw]

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

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.

2009-03-17 00:54:01

by FUJITA Tomonori

[permalink] [raw]

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

On Sat, 14 Mar 2009 20:20:17 +0100 (CET)
"Rafael J. Wysocki" <[email protected]> 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 <[email protected]>
> Date : 2009-01-28 16:41 (46 days old)
> References : http://marc.info/?l=linux-kernel&m=123316111415677&w=4
> Handled-By : FUJITA Tomonori <[email protected]>
> Patch : http://marc.info/?l=linux-scsi&m=123371501613019&w=2

This still should be listed. I think that the fix (in James'
scsi-misc) will be merged to 2.6.30-rc1 then be backported.

2009-03-17 14:52:53

by James Bottomley

[permalink] [raw]

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

On Tue, 2009-03-17 at 09:53 +0900, FUJITA Tomonori wrote:
> On Sat, 14 Mar 2009 20:20:17 +0100 (CET)
> "Rafael J. Wysocki" <[email protected]> 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 <[email protected]>
> > Date : 2009-01-28 16:41 (46 days old)
> > References : http://marc.info/?l=linux-kernel&m=123316111415677&w=4
> > Handled-By : FUJITA Tomonori <[email protected]>
> > Patch : http://marc.info/?l=linux-scsi&m=123371501613019&w=2
>
> This still should be listed. I think that the fix (in James'
> scsi-misc) will be merged to 2.6.30-rc1 then be backported.

It hasn't shown any problems at all under test in -next ... hopefully
under a reasonable test pool. I think we can move it across for current
bug fixes (crosses fingers).

James

2009-03-18 00:20:24

[permalink] [raw]

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

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.
>
>

2009-03-18 01:16:48

[permalink] [raw]

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

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"

2009-03-18 02:24:26

[permalink] [raw]

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

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"
>
>

2009-03-18 21:24:24

[permalink] [raw]

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

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.

2009-03-21 05:01:00

[permalink] [raw]

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

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.

2009-03-21 14:08:55

[permalink] [raw]

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

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.
>
>

2009-03-21 14:44:35

by Michael Riepe

[permalink] [raw]

Subject: ptrace performance (was: [Bug #12208] uml is very slow on 2.6.28 host)

Disclaimer: I'm not using UML, but these problems may be related.

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

The other day I noticed a dramatic ptrace slowdown between 2.6.27 and
2.6.28.x (verified with 2.6.28.8). In particular, a command like

dd if=/dev/zero of=/dev/null bs=1024k count=1024

will normally report a throughput in the GB/s range. On 2.6.27, this is
also true if you run

strace -o /dev/null <dd command as above>

which is only a little slower. But if I do the same on 2.6.28.x, I get a
throughput of about 100 MB/s or less, i.e. less than 10%. I tried the
commands on three different machines (an Athlon64 3000+, a Core Duo
T2400 and an Atom 330), and they all behave similar. The more system
calls a program uses, the worse the slowdown (try the dd command with
bs=16k and count=65536, for example - but don't hold your breath).

Interestingly, the CPUs are mostly idle while the command is executing
on 2.6.28.x, but there is a high (system) load on 2.6.27. Therefore, I
suspect that it's a scheduling or maybe timer problem that was
introduced between 2.6.27 and 2.6.28. I haven't had the time to check
the rc kernels yet; perhaps someone else can run a quick check to verify
that it's gone in the latest 2.6.29-rc.

--
Michael "Tired" Riepe <[email protected]>
X-Tired: Each morning I get up I die a little

2009-03-21 15:23:33

by Ingo Molnar

[permalink] [raw]

Subject: Re: ptrace performance (was: [Bug #12208] uml is very slow on 2.6.28 host)

* Michael Riepe <[email protected]> wrote:

> Disclaimer: I'm not using UML, but these problems may be related.
>
> > Bug-Entry : http://bugzilla.kernel.org/show_bug.cgi?id=12208
> > Subject : uml is very slow on 2.6.28 host
> > Submitter : Miklos Szeredi <[email protected]>
> > Date : 2008-12-12 9:35 (93 days old)
> > References : http://marc.info/?l=linux-kernel&m=122907463518593&w=4
>
> The other day I noticed a dramatic ptrace slowdown between 2.6.27 and
> 2.6.28.x (verified with 2.6.28.8). In particular, a command like
>
> dd if=/dev/zero of=/dev/null bs=1024k count=1024
>
> will normally report a throughput in the GB/s range. On 2.6.27, this is
> also true if you run
>
> strace -o /dev/null <dd command as above>
>
> which is only a little slower. But if I do the same on 2.6.28.x, I
> get a throughput of about 100 MB/s or less, i.e. less than 10%. I
> tried the commands on three different machines (an Athlon64 3000+,
> a Core Duo T2400 and an Atom 330), and they all behave similar.
> The more system calls a program uses, the worse the slowdown (try
> the dd command with bs=16k and count=65536, for example - but
> don't hold your breath).
>
> Interestingly, the CPUs are mostly idle while the command is
> executing on 2.6.28.x, but there is a high (system) load on
> 2.6.27. Therefore, I suspect that it's a scheduling or maybe timer
> problem that was introduced between 2.6.27 and 2.6.28. I haven't
> had the time to check the rc kernels yet; perhaps someone else can
> run a quick check to verify that it's gone in the latest
> 2.6.29-rc.

that's almost certainly due to the wait_task_inactive() change. Does
the patch below improve things?

Ingo

diff --git a/kernel/sched.c b/kernel/sched.c
index 3e827b8..2d60f23 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -2119,7 +2119,8 @@ unsigned long wait_task_inactive(struct task_struct *p, long match_state)
* yield - it could be a while.
*/
if (unlikely(on_rq)) {
- schedule_timeout_uninterruptible(1);
+ cpu_relax();
+ cond_resched();
continue;
}

2009-03-21 17:03:21

by Michael Riepe

[permalink] [raw]

Subject: Re: ptrace performance

Ingo Molnar wrote:

> that's almost certainly due to the wait_task_inactive() change. Does
> the patch below improve things?

That makes it *much* better - dd reports more than 3 GB/s on the Core
Duo. I'll have to check the other systems later; they're busy at the moment.

--
Michael "Tired" Riepe <[email protected]>
X-Tired: Each morning I get up I die a little

2009-03-24 11:44:34

[permalink] [raw]

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

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"

2009-03-24 11:47:38

[permalink] [raw]

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

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"
>
>

2009-03-25 23:40:54

[permalink] [raw]

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

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.

2009-03-25 23:48:26

[permalink] [raw]

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

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.
>
>

2009-03-26 20:23:23