I captured this 3+ ms latency trace when killing a process with a few
thousand threads. Can a cond_resched be added to this code path?
preemption latency trace v1.1.5 on 2.6.14-rt22
--------------------------------------------------------------------
latency: 3321 us, #2830/2830, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
-----------------
| task: softirq-timer/0-3 (uid:0 nice:0 policy:1 rt_prio:1)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
bash-17992 0D.h2 1us : __trace_start_sched_wakeup (try_to_wake_up)
bash-17992 0D.h2 1us : __trace_start_sched_wakeup <<...>-3> (62 0)
bash-17992 0D.h. 2us : wake_up_process (wakeup_softirqd)
bash-17992 0D.h. 3us : rcu_check_callbacks (update_process_times)
bash-17992 0D.h. 3us : idle_cpu (rcu_check_callbacks)
bash-17992 0D.h. 4us : __tasklet_schedule (rcu_check_callbacks)
bash-17992 0D.h. 5us : wakeup_softirqd (__tasklet_schedule)
bash-17992 0D.h. 6us : wake_up_process (wakeup_softirqd)
bash-17992 0D.h. 6us : try_to_wake_up (wake_up_process)
bash-17992 0D.h1 7us : activate_task (try_to_wake_up)
bash-17992 0D.h1 8us : sched_clock (activate_task)
bash-17992 0D.h1 9us : recalc_task_prio (activate_task)
bash-17992 0D.h1 10us : __recalc_task_prio (recalc_task_prio)
bash-17992 0D.h1 10us : __recalc_task_prio <<...>-7> (62 62)
bash-17992 0D.h1 11us : activate_task <<...>-7> (62 d)
bash-17992 0D.h1 12us : enqueue_task (activate_task)
bash-17992 0D.h1 12us : __trace_start_sched_wakeup (try_to_wake_up)
bash-17992 0D.h. 14us : wake_up_process (wakeup_softirqd)
bash-17992 0D.h. 14us : scheduler_tick (update_process_times)
bash-17992 0D.h. 15us : sched_clock (scheduler_tick)
bash-17992 0D.h1 16us : task_timeslice (scheduler_tick)
bash-17992 0D.h. 17us : run_posix_cpu_timers (update_process_times)
bash-17992 0D.h1 19us : note_interrupt (__do_IRQ)
bash-17992 0D.h1 19us : end_8259A_irq (__do_IRQ)
bash-17992 0D.h1 20us+: enable_8259A_irq (end_8259A_irq)
bash-17992 0Dnh1 22us : irq_exit (do_IRQ)
bash-17992 0Dn.1 23us < (608)
bash-17992 0.n.1 24us : eligible_child (do_wait)
bash-17992 0.n.1 25us : eligible_child (do_wait)
bash-17992 0.n.1 26us : eligible_child (do_wait)
bash-17992 0.n.1 28us : eligible_child (do_wait)
bash-17992 0.n.1 29us : eligible_child (do_wait)
[ 3000+ of these deleted ]
bash-17992 0.n.1 3296us : eligible_child (do_wait)
bash-17992 0.n.1 3297us : eligible_child (do_wait)
bash-17992 0.n.1 3298us : eligible_child (do_wait)
bash-17992 0.n.1 3299us : eligible_child (do_wait)
bash-17992 0.n.1 3300us : eligible_child (do_wait)
bash-17992 0.n.1 3301us : eligible_child (do_wait)
bash-17992 0.n.1 3303us : eligible_child (do_wait)
bash-17992 0.n.1 3304us : next_thread (do_wait)
bash-17992 0.n.. 3305us : preempt_schedule (do_wait)
bash-17992 0Dn.. 3306us : __schedule (preempt_schedule)
bash-17992 0Dn.. 3307us : profile_hit (__schedule)
bash-17992 0Dn.1 3308us+: sched_clock (__schedule)
<...>-3 0D..2 3314us+: __switch_to (__schedule)
<...>-3 0D..2 3316us : __schedule <bash-17992> (73 62)
<...>-3 0...1 3317us : trace_stop_sched_switched (__schedule)
<...>-3 0D..2 3318us : trace_stop_sched_switched <<...>-3> (62 0)
<...>-3 0D..2 3320us : trace_stop_sched_switched (__schedule)
* Lee Revell <[email protected]> wrote:
> I captured this 3+ ms latency trace when killing a process with a few
> thousand threads. Can a cond_resched be added to this code path?
> bash-17992 0.n.1 29us : eligible_child (do_wait)
>
> [ 3000+ of these deleted ]
>
> bash-17992 0.n.1 3296us : eligible_child (do_wait)
Atomicity of signal delivery is pretty much a must, so i'm not sure this
particular latency can be fixed, short of running PREEMPT_RT. Paul E.
McKenney is doing some excellent stuff by RCU-ifying the task lookup and
signal code, but i'm not sure whether it could cover do_wait().
Ingo
On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
>
> * Lee Revell <[email protected]> wrote:
>
> > I captured this 3+ ms latency trace when killing a process with a few
> > thousand threads. Can a cond_resched be added to this code path?
>
> > bash-17992 0.n.1 29us : eligible_child (do_wait)
> >
> > [ 3000+ of these deleted ]
> >
> > bash-17992 0.n.1 3296us : eligible_child (do_wait)
>
> Atomicity of signal delivery is pretty much a must, so i'm not sure this
> particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> signal code, but i'm not sure whether it could cover do_wait().
Took a quick break from repeatedly shooting myself in the foot with
RCU read-side priority boosting (still have a few toes left) to take
a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
non-trivial, and I am concerned about races with exit.
Any thoughts on whether the latency is due to contention on the
tasklist lock vs. the "goto repeat" in do_wait()?
Thanx, Paul
On Tue, 2005-12-20 at 17:47 -0800, Paul E. McKenney wrote:
> On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
> >
> > * Lee Revell <[email protected]> wrote:
> >
> > > I captured this 3+ ms latency trace when killing a process with a few
> > > thousand threads. Can a cond_resched be added to this code path?
> >
> > > bash-17992 0.n.1 29us : eligible_child (do_wait)
> > >
> > > [ 3000+ of these deleted ]
> > >
> > > bash-17992 0.n.1 3296us : eligible_child (do_wait)
> >
> > Atomicity of signal delivery is pretty much a must, so i'm not sure this
> > particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> > McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> > signal code, but i'm not sure whether it could cover do_wait().
>
> Took a quick break from repeatedly shooting myself in the foot with
> RCU read-side priority boosting (still have a few toes left) to take
> a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
> non-trivial, and I am concerned about races with exit.
>
> Any thoughts on whether the latency is due to contention on the
> tasklist lock vs. the "goto repeat" in do_wait()?
It's a UP system so I'd be surprised if there were any contention.
Lee
On Tue, Dec 20, 2005 at 10:32:48PM -0500, Lee Revell wrote:
> On Tue, 2005-12-20 at 17:47 -0800, Paul E. McKenney wrote:
> > On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
> > >
> > > * Lee Revell <[email protected]> wrote:
> > >
> > > > I captured this 3+ ms latency trace when killing a process with a few
> > > > thousand threads. Can a cond_resched be added to this code path?
> > >
> > > > bash-17992 0.n.1 29us : eligible_child (do_wait)
> > > >
> > > > [ 3000+ of these deleted ]
> > > >
> > > > bash-17992 0.n.1 3296us : eligible_child (do_wait)
> > >
> > > Atomicity of signal delivery is pretty much a must, so i'm not sure this
> > > particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> > > McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> > > signal code, but i'm not sure whether it could cover do_wait().
> >
> > Took a quick break from repeatedly shooting myself in the foot with
> > RCU read-side priority boosting (still have a few toes left) to take
> > a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
> > non-trivial, and I am concerned about races with exit.
> >
> > Any thoughts on whether the latency is due to contention on the
> > tasklist lock vs. the "goto repeat" in do_wait()?
>
> It's a UP system so I'd be surprised if there were any contention.
Couldn't there be contention due to preemption of someone holding
the tasklist lock?
Thanx, Paul
On Wed, 2005-12-21 at 05:36 -0800, Paul E. McKenney wrote:
> On Tue, Dec 20, 2005 at 10:32:48PM -0500, Lee Revell wrote:
> > On Tue, 2005-12-20 at 17:47 -0800, Paul E. McKenney wrote:
> > > On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
> > > >
> > > > * Lee Revell <[email protected]> wrote:
> > > >
> > > > > I captured this 3+ ms latency trace when killing a process with a few
> > > > > thousand threads. Can a cond_resched be added to this code path?
> > > >
> > > > > bash-17992 0.n.1 29us : eligible_child (do_wait)
> > > > >
> > > > > [ 3000+ of these deleted ]
> > > > >
> > > > > bash-17992 0.n.1 3296us : eligible_child (do_wait)
> > > >
> > > > Atomicity of signal delivery is pretty much a must, so i'm not sure this
> > > > particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> > > > McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> > > > signal code, but i'm not sure whether it could cover do_wait().
> > >
> > > Took a quick break from repeatedly shooting myself in the foot with
> > > RCU read-side priority boosting (still have a few toes left) to take
> > > a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
> > > non-trivial, and I am concerned about races with exit.
> > >
> > > Any thoughts on whether the latency is due to contention on the
> > > tasklist lock vs. the "goto repeat" in do_wait()?
> >
> > It's a UP system so I'd be surprised if there were any contention.
>
> Couldn't there be contention due to preemption of someone holding
> the tasklist lock?
But I'm running with PREEMPT_DESKTOP (specifically I configured a system
to have the exact same preemption model as mainline - PREEMPT_DESKTOP
with no soft/hardirq preemption) so holding a spinlock will disable
preemption.
Lee
On Wed, Dec 21, 2005 at 02:54:18PM -0500, Lee Revell wrote:
> On Wed, 2005-12-21 at 05:36 -0800, Paul E. McKenney wrote:
> > On Tue, Dec 20, 2005 at 10:32:48PM -0500, Lee Revell wrote:
> > > On Tue, 2005-12-20 at 17:47 -0800, Paul E. McKenney wrote:
> > > > On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
> > > > >
> > > > > * Lee Revell <[email protected]> wrote:
> > > > >
> > > > > > I captured this 3+ ms latency trace when killing a process with a few
> > > > > > thousand threads. Can a cond_resched be added to this code path?
> > > > >
> > > > > > bash-17992 0.n.1 29us : eligible_child (do_wait)
> > > > > >
> > > > > > [ 3000+ of these deleted ]
> > > > > >
> > > > > > bash-17992 0.n.1 3296us : eligible_child (do_wait)
> > > > >
> > > > > Atomicity of signal delivery is pretty much a must, so i'm not sure this
> > > > > particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> > > > > McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> > > > > signal code, but i'm not sure whether it could cover do_wait().
> > > >
> > > > Took a quick break from repeatedly shooting myself in the foot with
> > > > RCU read-side priority boosting (still have a few toes left) to take
> > > > a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
> > > > non-trivial, and I am concerned about races with exit.
> > > >
> > > > Any thoughts on whether the latency is due to contention on the
> > > > tasklist lock vs. the "goto repeat" in do_wait()?
> > >
> > > It's a UP system so I'd be surprised if there were any contention.
> >
> > Couldn't there be contention due to preemption of someone holding
> > the tasklist lock?
>
> But I'm running with PREEMPT_DESKTOP (specifically I configured a system
> to have the exact same preemption model as mainline - PREEMPT_DESKTOP
> with no soft/hardirq preemption) so holding a spinlock will disable
> preemption.
My head just exploded. I will see about getting you a
CONFIG_FREAKING_INSANE patch, if you are willing to test it.
Thanx, Paul
On Thu, 2005-12-22 at 20:07 -0800, Paul E. McKenney wrote:
> On Wed, Dec 21, 2005 at 02:54:18PM -0500, Lee Revell wrote:
> > On Wed, 2005-12-21 at 05:36 -0800, Paul E. McKenney wrote:
> > > On Tue, Dec 20, 2005 at 10:32:48PM -0500, Lee Revell wrote:
> > > > On Tue, 2005-12-20 at 17:47 -0800, Paul E. McKenney wrote:
> > > > > On Tue, Dec 20, 2005 at 05:24:42AM +0100, Ingo Molnar wrote:
> > > > > >
> > > > > > * Lee Revell <[email protected]> wrote:
> > > > > >
> > > > > > > I captured this 3+ ms latency trace when killing a process with a few
> > > > > > > thousand threads. Can a cond_resched be added to this code path?
> > > > > >
> > > > > > > bash-17992 0.n.1 29us : eligible_child (do_wait)
> > > > > > >
> > > > > > > [ 3000+ of these deleted ]
> > > > > > >
> > > > > > > bash-17992 0.n.1 3296us : eligible_child (do_wait)
> > > > > >
> > > > > > Atomicity of signal delivery is pretty much a must, so i'm not sure this
> > > > > > particular latency can be fixed, short of running PREEMPT_RT. Paul E.
> > > > > > McKenney is doing some excellent stuff by RCU-ifying the task lookup and
> > > > > > signal code, but i'm not sure whether it could cover do_wait().
> > > > >
> > > > > Took a quick break from repeatedly shooting myself in the foot with
> > > > > RCU read-side priority boosting (still have a few toes left) to take
> > > > > a quick look at this. The TASK_TRACED and TASK_STOPPED cases seem
> > > > > non-trivial, and I am concerned about races with exit.
> > > > >
> > > > > Any thoughts on whether the latency is due to contention on the
> > > > > tasklist lock vs. the "goto repeat" in do_wait()?
> > > >
> > > > It's a UP system so I'd be surprised if there were any contention.
> > >
> > > Couldn't there be contention due to preemption of someone holding
> > > the tasklist lock?
> >
> > But I'm running with PREEMPT_DESKTOP (specifically I configured a system
> > to have the exact same preemption model as mainline - PREEMPT_DESKTOP
> > with no soft/hardirq preemption) so holding a spinlock will disable
> > preemption.
>
> My head just exploded. I will see about getting you a
> CONFIG_FREAKING_INSANE patch, if you are willing to test it.
I'm not sure I know what you mean but sure, I'll try whatever you come
up with.
Lee