From: Frederic Weisbecker <fweisbec@gmail.com>
To: Ingo Molnar <mingo@elte.hu>
Cc: Damien Wyart <damien.wyart@free.fr>,
Peter Zijlstra <a.p.zijlstra@chello.nl>,
Mike Galbraith <efault@gmx.de>, "Rafael J. Wysocki" <rjw@sisk.pl>,
Linux Kernel Mailing List <linux-kernel@vger.kernel.org>,
Kernel Testers List <kernel-testers@vger.kernel.org>
Subject: Re: [Bug #12650] Strange load average and ksoftirqd behavior with 2.6.29-rc2-git1
Date: Sun, 15 Feb 2009 15:06:42 +0100 [thread overview]
Message-ID: <20090215140641.GI5835@nowhere> (raw)
In-Reply-To: <20090215110104.GB31351@elte.hu>
On Sun, Feb 15, 2009 at 12:01:04PM +0100, Ingo Molnar wrote:
>
> * Damien Wyart <damien.wyart@free.fr> wrote:
>
> > So I followed the tracing steps in the tutorial (with the 1 sec sleep),
> > which gave me this:
> > http://damien.wyart.free.fr/trace_2.6.29-rc5_ksoftirqd_prob.txt.gz
>
> thanks. There's definitely some weirdness visible in the trace,
> for example:
>
> 0) gpm-1879 => ksoftir-4
> ------------------------------------------
>
> 0) 0.964 us | finish_task_switch();
> 0) ! 1768184 us | }
> 0) | do_softirq() {
> 0) | __do_softirq() {
> 0) | rcu_process_callbacks() {
>
> the 1.7 seconds 'overhead' there must be a fluke - you'd notice it if
> ksoftirqd _really_ took that much time to execute.
>
> One possibility for these symptoms would be broken scheduler timestamps.
> Could you enable absolute timestamp printing via:
>
> echo funcgraph-abstime > trace_options
>
> Also, my guess is that if you boot via idle=poll, the symptoms go away.
> This would strengthen the suspicion that it's scheduler-clock troubles.
>
> Ingo
Looking at the following ksoftirqd quantum, there are some things I don't understand:
------------------------------------------
0) gpm-1879 => ksoftir-4
------------------------------------------
0) 0.681 us | finish_task_switch();
0) ! 7670.083 us | }
0) | do_softirq() {
0) | __do_softirq() {
0) | rcu_process_callbacks() {
0) | __rcu_process_callbacks() {
0) | cpu_quiet() {
0) 0.509 us | _spin_lock_irqsave();
0) | cpu_quiet_msk() {
0) 0.503 us | _spin_unlock_irqrestore();
0) 1.546 us | }
0) 3.617 us | }
0) 4.804 us | }
0) | __rcu_process_callbacks() {
0) 0.496 us | force_quiescent_state();
0) 1.608 us | }
0) 8.043 us | }
0) 0.533 us | _local_bh_enable();
0) + 10.190 us | }
0) + 11.337 us | }
0) 0.537 us | _cond_resched();
0) 0.536 us | kthread_should_stop();
0) | schedule() {
0) 0.516 us | _spin_lock_irq();
0) 0.586 us | update_rq_clock();
0) | deactivate_task() {
0) | dequeue_task() {
0) | dequeue_task_fair() {
0) | update_curr() {
0) 0.519 us | calc_delta_mine();
0) 1.603 us | }
0) 2.667 us | }
0) 3.662 us | }
0) 4.629 us | }
0) 0.937 us | find_busiest_group();
0) 0.493 us | msecs_to_jiffies();
0) 0.501 us | put_prev_task_fair();
0) | pick_next_task() {
0) 0.501 us | pick_next_task_fair();
0) 0.491 us | pick_next_task_rt();
0) 0.494 us | pick_next_task_fair();
0) 0.491 us | pick_next_task_idle();
0) 4.591 us | }
0) 0.501 us | __lock_text_start();
0) 0.699 us | finish_task_switch();
0) ! 289.895 us | }
The two above is the internal of context_switch, which means it entered
there in schedule():
next = pick_next_task(rq, prev);
if (likely(prev != next)) {
sched_info_switch(prev, next);
perf_counter_task_sched_out(prev, cpu);
rq->nr_switches++;
rq->curr = next;
++*switch_count;
context_switch(rq, prev, next); /* unlocks the rq */
/*
* the context switch might have flipped the stack from under
* us, hence refresh the local variables.
*/
cpu = smp_processor_id();
rq = cpu_rq(cpu);
}
But after that we are still in ksoftirqd. As if it bypassed the if (prev != next)
and rescheduled itself.
Well, I guess it's a bit off topic here. Whatever if this a bug in the sched_clock(),
it reminds me a possible problem in sched_clock() I saw with tracers...
0) | do_softirq() {
0) | __do_softirq() {
0) | rcu_process_callbacks() {
0) | __rcu_process_callbacks() {
0) | force_quiescent_state() {
0) 0.478 us | __lock_text_start();
0) 0.489 us | _spin_lock();
0) | rcu_process_dyntick() {
0) 0.496 us | _spin_lock_irqsave();
0) 0.571 us | dyntick_save_progress_counter();
0) | cpu_quiet_msk() {
0) | rcu_start_gp() {
0) 0.496 us | _spin_unlock_irqrestore();
0) 1.533 us | }
0) 2.588 us | }
0) 5.784 us | }
0) 0.493 us | _spin_lock();
0) 0.501 us | _spin_unlock_irqrestore();
0) + 10.959 us | }
0) | file_free_rcu() {
0) 0.551 us | kmem_cache_free();
0) 1.613 us | }
0) + 14.486 us | }
0) | __rcu_process_callbacks() {
0) 0.458 us | force_quiescent_state();
0) 1.573 us | }
0) + 17.661 us | }
0) 0.486 us | _local_bh_enable();
0) + 20.014 us | }
0) + 21.094 us | }
0) 0.546 us | _cond_resched();
0) 0.536 us | kthread_should_stop();
0) | schedule() {
0) 0.514 us | _spin_lock_irq();
0) 0.596 us | update_rq_clock();
0) | deactivate_task() {
0) | dequeue_task() {
0) | dequeue_task_fair() {
0) | update_curr() {
0) 0.500 us | calc_delta_mine();
0) 1.570 us | }
0) 2.632 us | }
0) 3.632 us | }
0) 4.594 us | }
0) 0.846 us | find_busiest_group();
0) 0.471 us | msecs_to_jiffies();
0) 0.506 us | put_prev_task_fair();
0) | pick_next_task() {
0) 0.486 us | pick_next_task_fair();
0) 0.481 us | pick_next_task_rt();
0) 0.484 us | pick_next_task_fair();
0) 0.493 us | pick_next_task_idle();
0) 4.544 us | }
0) 0.506 us | __lock_text_start();
0) 0.554 us | finish_task_switch();
0) + 30.202 us | }
0) | do_softirq() {
0) | __do_softirq() {
0) | rcu_process_callbacks() {
0) | __rcu_process_callbacks() {
0) | cpu_quiet() {
0) 0.493 us | _spin_lock_irqsave();
0) | cpu_quiet_msk() {
0) 0.504 us | _spin_unlock_irqrestore();
0) 1.515 us | }
0) 3.535 us | }
0) 4.692 us | }
0) | __rcu_process_callbacks() {
0) 0.480 us | force_quiescent_state();
0) 1.593 us | }
0) 7.878 us | }
0) 0.491 us | _local_bh_enable();
0) 9.934 us | }
0) + 11.037 us | }
0) 0.529 us | _cond_resched();
0) 0.506 us | kthread_should_stop();
0) | schedule() {
0) 0.499 us | _spin_lock_irq();
0) 0.581 us | update_rq_clock();
0) | deactivate_task() {
0) | dequeue_task() {
0) | dequeue_task_fair() {
0) | update_curr() {
0) 0.493 us | calc_delta_mine();
0) 1.548 us | }
0) 2.583 us | }
0) 3.559 us | }
0) 4.514 us | }
0) 0.797 us | find_busiest_group();
0) 0.481 us | msecs_to_jiffies();
0) 0.499 us | put_prev_task_fair();
0) | pick_next_task() {
0) 0.481 us | pick_next_task_fair();
0) 0.479 us | pick_next_task_rt();
0) 0.483 us | pick_next_task_fair();
0) 0.481 us | pick_next_task_idle();
0) 4.488 us | }
0) 0.506 us | __lock_text_start();
0) 0.672 us | finish_task_switch();
0) ! 928.567 us | }
0) | do_softirq() {
0) | __do_softirq() {
0) | rcu_process_callbacks() {
0) | __rcu_process_callbacks() {
0) | force_quiescent_state() {
0) 0.484 us | __lock_text_start();
0) 0.511 us | _spin_lock();
0) | rcu_process_dyntick() {
0) 0.511 us | _spin_lock_irqsave();
0) 0.564 us | dyntick_save_progress_counter();
0) | cpu_quiet_msk() {
0) | rcu_start_gp() {
0) 0.503 us | _spin_unlock_irqrestore();
0) 1.548 us | }
0) 2.582 us | }
0) 6.102 us | }
0) 0.501 us | _spin_lock();
0) 0.501 us | _spin_unlock_irqrestore();
0) + 11.265 us | }
0) | file_free_rcu() {
0) 0.579 us | kmem_cache_free();
0) 1.643 us | }
0) | file_free_rcu() {
0) 0.549 us | kmem_cache_free();
0) 1.588 us | }
0) + 16.827 us | }
0) | __rcu_process_callbacks() {
0) 0.479 us | force_quiescent_state();
0) 1.593 us | }
0) + 20.024 us | }
0) 0.500 us | _local_bh_enable();
0) + 22.081 us | }
0) + 23.163 us | }
0) 0.523 us | _cond_resched();
0) 0.536 us | kthread_should_stop();
0) | schedule() {
0) 0.506 us | _spin_lock_irq();
0) 0.586 us | update_rq_clock();
0) | deactivate_task() {
0) | dequeue_task() {
0) | dequeue_task_fair() {
0) | update_curr() {
0) 0.516 us | calc_delta_mine();
0) 1.578 us | }
0) 2.628 us | }
0) 3.622 us | }
0) 4.604 us | }
0) 0.917 us | find_busiest_group();
0) 0.484 us | msecs_to_jiffies();
0) 0.501 us | put_prev_task_fair();
0) | pick_next_task() {
0) 0.486 us | pick_next_task_fair();
0) 0.491 us | pick_next_task_rt();
0) | pick_next_task_fair() {
0) 0.486 us | pick_next_task_idle();
0) 4.581 us | }
0) 0.496 us | __lock_text_start();
next prev parent reply other threads:[~2009-02-15 14:06 UTC|newest]
Thread overview: 131+ messages / expand[flat|nested] mbox.gz Atom feed top
2009-02-14 20:35 2.6.29-rc5: Reported regressions from 2.6.28 Rafael J. Wysocki
2009-02-14 20:35 ` [Bug #12414] iwl4965 cannot use "ap auto" on latest 2.6.28/29? Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12444] X hangs following switch from radeonfb console - Bisected Rafael J. Wysocki
2009-02-16 17:52 ` Graham Murray
2009-02-16 21:52 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12418] Repeated ioctl(4, 0x40046445, ..) loop in glxgears Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12490] ath5k related kernel panic in 2.6.29-rc1 Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12419] possible circular locking dependency on i915 dma Rafael J. Wysocki
2009-02-16 3:50 ` Wang Chen
2009-02-14 20:38 ` [Bug #12497] new barrier warnings in 2.6.29-rc1 Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12496] swsusp cannot find resume device (sometimes) Rafael J. Wysocki
2009-02-15 0:05 ` Arjan van de Ven
2009-02-15 14:23 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12491] i915 lockdep warning Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12494] Sony backlight regression from 2.6.28 to 29-rc Rafael J. Wysocki
2009-02-17 10:51 ` Norbert Preining
2009-02-14 20:38 ` [Bug #12499] Problem with using bluetooth adaper connected to usb port Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12501] build bug in eeepc-laptop.c Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12502] pipe_read oops on sh Rafael J. Wysocki
2009-02-15 0:23 ` Adrian McMenamin
2009-02-15 14:27 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12510] 2.6.29-rc2 dies on startup Rafael J. Wysocki
2009-02-16 21:02 ` Ferenc Wagner
2009-02-16 21:12 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12551] end_request: I/O error, dev cciss/c0d0, sector 87435720 Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12610] sync-Regression in 2.6.28.2? Rafael J. Wysocki
2009-02-21 17:56 ` Theodore Tso
2009-02-22 10:02 ` Rafael J. Wysocki
2009-02-23 4:35 ` Greg KH
2009-02-23 5:37 ` Theodore Tso
2009-02-23 16:54 ` [stable] " Greg KH
2009-02-14 20:38 ` [Bug #12609] v2.6.29-rc2 libata sff 32bit PIO regression Rafael J. Wysocki
2009-02-15 4:20 ` Larry Finger
2009-02-15 8:10 ` Jeff Garzik
2009-02-15 12:05 ` Sergei Shtylyov
2009-02-15 16:48 ` Hugh Dickins
2009-02-14 20:38 ` [Bug #12574] possible circular locking dependency detected Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12571] Suspend-resume on Dell Latitude D410 newly broken in 2.6.29-rc* Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12615] boot hangs while bringing up gianfar ethernet Rafael J. Wysocki
2009-02-15 14:42 ` Peter Korsgaard
2009-02-15 21:08 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12613] [Suspend regression][DRM, RADEON] Rafael J. Wysocki
[not found] ` <4997E7D7.60205@numericable.fr>
2009-02-15 10:20 ` etienne
2009-02-14 20:38 ` [Bug #12659] Failure to resume two Sandisk USB flash drives attached to a Belkin USB Busport Mobile (F5U022) Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12617] unable to compile e100 firmware into kernel Rafael J. Wysocki
2009-02-15 17:38 ` David Woodhouse
2009-02-15 19:58 ` Andrey Borzenkov
2009-02-15 21:09 ` Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12618] hackbench [pthread mode] regression with 2.6.29-rc3 Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12650] Strange load average and ksoftirqd behavior with 2.6.29-rc2-git1 Rafael J. Wysocki
2009-02-15 8:09 ` Damien Wyart
2009-02-15 9:00 ` Ingo Molnar
2009-02-15 9:51 ` Damien Wyart
2009-02-15 10:13 ` Ingo Molnar
2009-02-15 10:34 ` Damien Wyart
2009-02-15 10:41 ` Damien Wyart
2009-02-15 10:42 ` Damien Wyart
2009-02-15 10:43 ` Damien Wyart
2009-02-15 11:01 ` Ingo Molnar
2009-02-15 14:06 ` Frederic Weisbecker [this message]
2009-02-15 18:03 ` Damien Wyart
2009-02-15 19:18 ` Damien Wyart
2009-02-15 19:31 ` Ingo Molnar
2009-02-16 8:42 ` Damien Wyart
2009-02-16 9:21 ` Ingo Molnar
2009-02-16 10:49 ` Damien Wyart
2009-02-16 9:25 ` Ingo Molnar
2009-02-16 9:27 ` Ingo Molnar
2009-02-16 9:32 ` Ingo Molnar
2009-02-16 9:50 ` Ingo Molnar
2009-02-16 11:56 ` Damien Wyart
2009-02-16 12:26 ` Ingo Molnar
2009-02-16 13:02 ` Damien Wyart
2009-02-16 13:21 ` Ingo Molnar
2009-02-16 16:06 ` Paul E. McKenney
2009-02-16 18:56 ` Paul E. McKenney
2009-02-16 19:08 ` Frederic Weisbecker
2009-02-16 20:02 ` Frederic Weisbecker
2009-02-16 21:31 ` Paul E. McKenney
2009-02-16 20:09 ` Ingo Molnar
2009-02-16 22:39 ` Paul E. McKenney
2009-02-16 22:51 ` Paul E. McKenney
2009-02-17 9:46 ` Ingo Molnar
2009-02-17 14:01 ` Paul E. McKenney
2009-02-17 15:39 ` Damien Wyart
2009-02-17 16:05 ` Paul E. McKenney
2009-02-17 21:48 ` Ingo Molnar
2009-02-17 4:34 ` Frederic Weisbecker
2009-02-17 15:10 ` Paul E. McKenney
2009-02-17 16:00 ` Frederic Weisbecker
2009-02-17 22:37 ` Frederic Weisbecker
2009-02-17 22:48 ` Paul E. McKenney
2009-02-18 0:38 ` Ingo Molnar
2009-02-18 1:02 ` Paul E. McKenney
2009-02-17 6:11 ` Damien Wyart
2009-02-17 15:11 ` Paul E. McKenney
2009-02-16 20:44 ` Damien Wyart
2009-02-15 10:12 ` Christian Kujau
2009-02-15 10:54 ` Ingo Molnar
2009-02-14 20:38 ` [Bug #12668] USB flash disk surprise disconnect Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12663] Commit 8c7e58e690ae60ab4215b025f433ed4af261e103 breaks resume Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12660] Linux 2.6.28.3 freezing on a 32-bits x86 Thinkpad T43p Rafael J. Wysocki
2009-02-14 23:29 ` Mathieu Desnoyers
2009-02-14 20:38 ` [Bug #12680] Not having a VIA PadLock hardware incurs a long delay in probing on modules insertion attempt Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12681] s2ram: fails to wake up on Acer Extensa 4220 (SMP disabled) Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12670] BUG: unable to handle kernel paging request at pin_to_kill+0x21 Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12671] uvc_status_cleanup(): undefined reference to `input_unregister_device' Rafael J. Wysocki
2009-02-14 20:38 ` [Bug #12705] X200: Brightness broken since 2.6.29-rc4-58-g4c098bc Rafael J. Wysocki
2009-02-15 13:43 ` Matthew Garrett
2009-02-15 14:37 ` Rafael J. Wysocki
2009-02-17 23:05 ` Eric Anholt
2009-02-17 23:13 ` Matthew Garrett
2009-02-17 23:23 ` Jesse Barnes
2009-02-18 9:36 ` Nico Schottelius
2009-02-13 9:33 ` Nico Schottelius
2009-02-13 9:40 ` Nico Schottelius
2009-02-13 13:43 ` Matthew Garrett
2009-03-10 2:28 ` Eric Anholt
2009-03-10 5:38 ` Nico Schottelius
2009-02-13 9:42 ` Ingo Molnar
2009-02-13 18:05 ` Len Brown
2009-02-16 9:06 ` ZhangRui
2009-02-16 10:58 ` Nico Schottelius
2009-02-16 13:13 ` Nico Schottelius
2009-02-16 21:40 ` Norbert Preining
2009-02-16 15:54 ` Nico Schottelius
2009-02-19 9:01 ` Nico Schottelius
2009-02-14 20:38 ` [Bug #12706] Oopses and ACPI problems (Linus 2.6.29-rc4) Rafael J. Wysocki
2009-02-16 7:29 ` 2.6.29-rc5: Reported regressions from 2.6.28 Jarek Poplawski
2009-02-16 21:11 ` Rafael J. Wysocki
-- strict thread matches above, loose matches on Subject: below --
2009-02-08 19:05 2.6.29-rc4: " Rafael J. Wysocki
2009-02-08 19:21 ` [Bug #12650] Strange load average and ksoftirqd behavior with 2.6.29-rc2-git1 Rafael J. Wysocki
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20090215140641.GI5835@nowhere \
--to=fweisbec@gmail.com \
--cc=a.p.zijlstra@chello.nl \
--cc=damien.wyart@free.fr \
--cc=efault@gmx.de \
--cc=kernel-testers@vger.kernel.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mingo@elte.hu \
--cc=rjw@sisk.pl \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).