From: Thomas Charbonnel <thomas@undata.org>
To: Ingo Molnar <mingo@elte.hu>
Cc: Lee Revell <rlrevell@joe-job.com>,
Daniel Schmitt <pnambic@unu.nu>, "K.R. Foley" <kr@cybsft.com>,
Felipe Alfaro Solana <lkml@felipe-alfaro.com>,
linux-kernel <linux-kernel@vger.kernel.org>,
Mark_H_Johnson@raytheon.com
Subject: Re: [patch] voluntary-preempt-2.6.9-rc1-bk4-Q5
Date: Tue, 31 Aug 2004 21:23:48 +0200 [thread overview]
Message-ID: <1093980227.8005.14.camel@localhost> (raw)
In-Reply-To: <20040830180011.GA7419@elte.hu>
Ingo Molnar wrote :
(...)
> > and a weird one with do_timer (called from do_IRQ) taking more than 1ms
> > to complete :
> > http://www.undata.org/~thomas/do_irq.trace
>
> hm, indeed this is a weird one. 1 msec is too close to the timer
> frequency to be accidental. According to the trace:
>
> 00010000 0.002ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event)
> 00010001 0.002ms (+0.000ms): mark_offset_tsc (timer_interrupt)
> 00010001 1.028ms (+1.025ms): do_timer (timer_interrupt)
> 00010001 1.028ms (+0.000ms): update_process_times (do_timer)
>
> the latency happened between the beginning of mark_offset_tsc() and the
> calling of do_timer() - i.e. the delay happened somewhere within
> mark_offset_tsc() itself. Is this an SMP system?
>
> Ingo
It isn't an SMP system, but here are some other traces that can prove
useful :
preemption latency trace v1.0.2
-------------------------------
latency: 567 us, entries: 35 (35)
-----------------
| task: swapper/0, uid:0 nice:0 policy:0 rt_prio:0
-----------------
=> started at: do_IRQ+0x19/0x190
=> ended at: do_IRQ+0x13d/0x190
=======>
00010000 0.000ms (+0.000ms): do_IRQ (common_interrupt)
00010000 0.000ms (+0.000ms): do_IRQ (default_idle)
00010001 0.000ms (+0.000ms): mask_and_ack_8259A (do_IRQ)
00010001 0.002ms (+0.002ms): generic_redirect_hardirq (do_IRQ)
00010000 0.002ms (+0.000ms): generic_handle_IRQ_event (do_IRQ)
00010000 0.002ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event)
00010001 0.003ms (+0.000ms): mark_offset_tsc (timer_interrupt)
00010001 0.562ms (+0.559ms): do_timer (timer_interrupt)
00010001 0.562ms (+0.000ms): update_process_times (do_timer)
00010001 0.562ms (+0.000ms): update_one_process (update_process_times)
00010001 0.562ms (+0.000ms): run_local_timers (update_process_times)
00010001 0.562ms (+0.000ms): raise_softirq (update_process_times)
00010001 0.562ms (+0.000ms): scheduler_tick (update_process_times)
00010001 0.562ms (+0.000ms): sched_clock (scheduler_tick)
00010001 0.563ms (+0.000ms): update_wall_time (do_timer)
00010001 0.563ms (+0.000ms): update_wall_time_one_tick
(update_wall_time)
00010001 0.563ms (+0.000ms): profile_tick (timer_interrupt)
00010001 0.563ms (+0.000ms): profile_hook (profile_tick)
00010002 0.563ms (+0.000ms): notifier_call_chain (profile_hook)
00010001 0.564ms (+0.000ms): profile_hit (timer_interrupt)
00010001 0.564ms (+0.000ms): generic_note_interrupt (do_IRQ)
00010001 0.564ms (+0.000ms): end_8259A_irq (do_IRQ)
00010001 0.564ms (+0.000ms): enable_8259A_irq (do_IRQ)
00000001 0.565ms (+0.000ms): do_softirq (do_IRQ)
00000001 0.565ms (+0.000ms): __do_softirq (do_softirq)
00000001 0.565ms (+0.000ms): wake_up_process (do_softirq)
00000001 0.565ms (+0.000ms): try_to_wake_up (wake_up_process)
00000001 0.566ms (+0.000ms): task_rq_lock (try_to_wake_up)
00000002 0.566ms (+0.000ms): activate_task (try_to_wake_up)
00000002 0.566ms (+0.000ms): sched_clock (activate_task)
00000002 0.566ms (+0.000ms): recalc_task_prio (activate_task)
00000002 0.566ms (+0.000ms): effective_prio (recalc_task_prio)
00000002 0.567ms (+0.000ms): enqueue_task (activate_task)
00000001 0.567ms (+0.000ms): preempt_schedule (try_to_wake_up)
00000001 0.567ms (+0.000ms): sub_preempt_count (do_IRQ)
preemption latency trace v1.0.2
-------------------------------
latency: 624 us, entries: 35 (35)
-----------------
| task: swapper/0, uid:0 nice:0 policy:0 rt_prio:0
-----------------
=> started at: do_IRQ+0x19/0x190
=> ended at: do_IRQ+0x13d/0x190
=======>
00010000 0.000ms (+0.000ms): do_IRQ (common_interrupt)
00010000 0.000ms (+0.000ms): do_IRQ (default_idle)
00010001 0.000ms (+0.000ms): mask_and_ack_8259A (do_IRQ)
00010001 0.613ms (+0.612ms): generic_redirect_hardirq (do_IRQ)
00010000 0.613ms (+0.000ms): generic_handle_IRQ_event (do_IRQ)
00010000 0.613ms (+0.000ms): timer_interrupt (generic_handle_IRQ_event)
00010001 0.613ms (+0.000ms): mark_offset_tsc (timer_interrupt)
00010001 0.619ms (+0.005ms): do_timer (timer_interrupt)
00010001 0.619ms (+0.000ms): update_process_times (do_timer)
00010001 0.619ms (+0.000ms): update_one_process (update_process_times)
00010001 0.619ms (+0.000ms): run_local_timers (update_process_times)
00010001 0.619ms (+0.000ms): raise_softirq (update_process_times)
00010001 0.619ms (+0.000ms): scheduler_tick (update_process_times)
00010001 0.619ms (+0.000ms): sched_clock (scheduler_tick)
00010001 0.620ms (+0.000ms): update_wall_time (do_timer)
00010001 0.620ms (+0.000ms): update_wall_time_one_tick
(update_wall_time)
00010001 0.620ms (+0.000ms): profile_tick (timer_interrupt)
00010001 0.620ms (+0.000ms): profile_hook (profile_tick)
00010002 0.620ms (+0.000ms): notifier_call_chain (profile_hook)
00010001 0.621ms (+0.000ms): profile_hit (timer_interrupt)
00010001 0.621ms (+0.000ms): generic_note_interrupt (do_IRQ)
00010001 0.621ms (+0.000ms): end_8259A_irq (do_IRQ)
00010001 0.621ms (+0.000ms): enable_8259A_irq (do_IRQ)
00000001 0.622ms (+0.000ms): do_softirq (do_IRQ)
00000001 0.622ms (+0.000ms): __do_softirq (do_softirq)
00000001 0.622ms (+0.000ms): wake_up_process (do_softirq)
00000001 0.622ms (+0.000ms): try_to_wake_up (wake_up_process)
00000001 0.623ms (+0.000ms): task_rq_lock (try_to_wake_up)
00000002 0.623ms (+0.000ms): activate_task (try_to_wake_up)
00000002 0.623ms (+0.000ms): sched_clock (activate_task)
00000002 0.623ms (+0.000ms): recalc_task_prio (activate_task)
00000002 0.623ms (+0.000ms): effective_prio (recalc_task_prio)
00000002 0.623ms (+0.000ms): enqueue_task (activate_task)
00000001 0.624ms (+0.000ms): preempt_schedule (try_to_wake_up)
00000001 0.624ms (+0.000ms): sub_preempt_count (do_IRQ)
As you can see ~1ms was probably an accident, and the latency does not
always come from do_timer. The constant is do_IRQ interrupting the idle
thread.
Thomas
next prev parent reply other threads:[~2004-08-31 19:27 UTC|newest]
Thread overview: 122+ messages / expand[flat|nested] mbox.gz Atom feed top
2004-08-23 22:18 [patch] PPC/PPC64 port of voluntary preempt patch Scott Wood
2004-08-24 6:14 ` [patch] voluntary-preempt-2.6.8.1-P9 Ingo Molnar
2004-08-24 17:43 ` K.R. Foley
2004-08-24 20:32 ` Lee Revell
2004-08-24 20:53 ` Scott Wood
2004-08-24 19:20 ` K.R. Foley
2004-08-24 22:47 ` Lee Revell
2004-08-25 2:00 ` Lee Revell
2004-08-25 3:17 ` K.R. Foley
2004-08-25 3:22 ` Lee Revell
2004-08-25 14:34 ` K.R. Foley
2004-08-25 16:00 ` K.R. Foley
2004-08-25 3:26 ` K.R. Foley
2004-08-25 9:58 ` [patch] voluntary-preempt-2.6.8.1-P9 : oprofile latency at 3.3ms P.O. Gaillard
2004-08-26 21:39 ` [patch] voluntary-preempt-2.6.8.1-P9 Lee Revell
2004-08-27 16:54 ` Lee Revell
2004-08-28 7:37 ` Ingo Molnar
2004-08-28 15:10 ` Lee Revell
2004-08-28 12:14 ` Ingo Molnar
2004-08-30 9:27 ` voluntary-preempt-2.6.8.1-P9 : big latency when logging on console P.O. Gaillard
2004-08-30 9:41 ` Ingo Molnar
2004-08-30 12:25 ` P.O. Gaillard
2004-08-30 9:48 ` [patch] voluntary-preempt-2.6.8.1-P9 : a few submillisecond latencies P.O. Gaillard
2004-08-28 12:03 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q0 Ingo Molnar
2004-08-28 16:18 ` Felipe Alfaro Solana
2004-08-28 16:50 ` K.R. Foley
2004-08-28 17:52 ` Lee Revell
2004-08-28 19:44 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q2 Ingo Molnar
2004-08-28 20:01 ` Lee Revell
2004-08-28 20:04 ` Ingo Molnar
2004-08-28 20:08 ` Lee Revell
2004-08-28 20:10 ` Daniel Schmitt
2004-08-28 20:31 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q3 Ingo Molnar
2004-08-28 21:10 ` Lee Revell
2004-08-28 21:13 ` Ingo Molnar
2004-08-28 21:16 ` Lee Revell
2004-08-28 23:51 ` Lee Revell
2004-08-29 2:35 ` Lee Revell
2004-08-29 5:43 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q4 Ingo Molnar
2004-08-29 6:57 ` Lee Revell
2004-08-29 18:01 ` Ingo Molnar
2004-08-29 19:06 ` Ingo Molnar
2004-08-30 0:47 ` K.R. Foley
2004-08-30 3:42 ` K.R. Foley
2004-08-30 13:06 ` Alan Cox
2004-08-30 17:37 ` Ingo Molnar
2004-08-31 16:39 ` K.R. Foley
2004-08-30 9:06 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q5 Ingo Molnar
2004-08-30 14:25 ` Thomas Charbonnel
2004-08-30 18:00 ` Ingo Molnar
2004-08-31 19:23 ` Thomas Charbonnel [this message]
2004-08-31 19:30 ` Ingo Molnar
2004-08-31 19:45 ` Thomas Charbonnel
2004-08-31 6:40 ` Lee Revell
2004-08-31 6:53 ` Ingo Molnar
2004-08-31 23:03 ` Lee Revell
2004-09-01 15:52 ` Martin Josefsson
2004-09-01 21:15 ` Lee Revell
2004-09-01 21:30 ` Lee Revell
2004-08-31 7:06 ` Ingo Molnar
2004-08-31 19:21 ` Lee Revell
2004-08-31 19:37 ` Ingo Molnar
2004-08-31 19:47 ` Lee Revell
2004-08-31 19:51 ` Ingo Molnar
2004-08-31 20:09 ` Ingo Molnar
2004-08-31 20:10 ` Lee Revell
2004-08-31 20:14 ` Ingo Molnar
2004-08-31 20:20 ` Ingo Molnar
2004-08-31 20:34 ` Lee Revell
2004-08-31 20:39 ` Ingo Molnar
2004-08-31 20:41 ` Lee Revell
2004-08-31 17:40 ` Peter Zijlstra
2004-09-01 1:43 ` Lee Revell
2004-09-01 2:30 ` Lee Revell
2004-09-01 7:27 ` Lee Revell
2004-09-01 8:29 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q6 Ingo Molnar
2004-09-01 13:51 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q7 Ingo Molnar
2004-09-01 17:09 ` Thomas Charbonnel
2004-09-01 19:03 ` K.R. Foley
2004-09-01 20:11 ` Peter Zijlstra
2004-09-01 20:16 ` Lee Revell
2004-09-01 20:53 ` K.R. Foley
[not found] ` <41367E5D.3040605@cybsft.com>
2004-09-02 5:37 ` Ingo Molnar
2004-09-02 5:40 ` Ingo Molnar
2004-08-30 12:52 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q3 Ingo Molnar
2004-08-29 7:40 ` Matt Heler
2004-08-24 19:51 ` [patch] PPC/PPC64 port of voluntary preempt patch Scott Wood
2004-08-26 3:17 ` Lee Revell
2004-08-26 16:38 ` Scott Wood
2004-08-27 1:18 ` Fernando Pablo Lopez-Lezcano
2004-08-28 12:36 ` Ingo Molnar
2004-08-28 13:01 ` [patch] voluntary-preempt-2.6.9-rc1-bk4-Q1 Ingo Molnar
2004-08-30 1:06 ` Fernando Pablo Lopez-Lezcano
-- strict thread matches above, loose matches on Subject: below --
2004-08-30 19:13 [patch] voluntary-preempt-2.6.9-rc1-bk4-Q5 Mark_H_Johnson
2004-08-30 19:21 ` Ingo Molnar
2004-08-31 8:49 ` Ingo Molnar
2004-09-02 6:33 ` Ingo Molnar
2004-08-30 22:04 Mark_H_Johnson
2004-08-31 6:31 ` Ingo Molnar
2004-09-01 7:30 ` Ingo Molnar
2004-08-31 12:46 Mark_H_Johnson
2004-08-31 15:17 Mark_H_Johnson
2004-08-31 17:20 ` Lee Revell
2004-08-31 18:09 ` Lee Revell
2004-08-31 18:53 ` Takashi Iwai
2004-08-31 18:56 ` Ingo Molnar
2004-09-02 16:59 ` Jaroslav Kysela
2004-09-02 17:50 ` Lee Revell
2004-08-31 18:19 ` Takashi Iwai
2004-08-31 18:48 ` Ingo Molnar
2004-08-31 19:02 ` Takashi Iwai
2004-08-31 18:50 ` Ingo Molnar
2004-08-31 20:10 Mark_H_Johnson
2004-08-31 20:37 ` Ingo Molnar
[not found] <2yiVZ-IZ-15@gated-at.bofh.it>
[not found] ` <2ylhi-2hg-3@gated-at.bofh.it>
[not found] ` <2ynLU-42D-7@gated-at.bofh.it>
[not found] ` <2yqJJ-5ZL-1@gated-at.bofh.it>
[not found] ` <2yQkS-6Zh-13@gated-at.bofh.it>
[not found] ` <2zaCV-4FE-3@gated-at.bofh.it>
[not found] ` <2zaWk-4Yj-9@gated-at.bofh.it>
[not found] ` <2zmE8-4Zz-11@gated-at.bofh.it>
[not found] ` <2zngP-5wD-9@gated-at.bofh.it>
[not found] ` <2zngP-5wD-7@gated-at.bofh.it>
[not found] ` <2znJS-5Pm-25@gated-at.bofh.it>
2004-08-31 23:06 ` Andi Kleen
[not found] ` <2znJS-5Pm-27@gated-at.bofh.it>
[not found] ` <2znJS-5Pm-29@gated-at.bofh.it>
[not found] ` <2znJS-5Pm-31@gated-at.bofh.it>
[not found] ` <2znJS-5Pm-33@gated-at.bofh.it>
2004-08-31 23:10 ` Andi Kleen
2004-09-01 7:05 ` Ingo Molnar
2004-09-01 14:37 Mark_H_Johnson
2004-09-01 19:31 ` Takashi Iwai
2004-09-01 15:21 Mark_H_Johnson
2004-09-02 22:24 ` Ingo Molnar
[not found] <OFD220F58F.002C5901-ON86256F02.005C2FB1-86256F02.005C2FD5@raytheon.com>
2004-09-01 17:09 ` Ingo Molnar
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=1093980227.8005.14.camel@localhost \
--to=thomas@undata.org \
--cc=Mark_H_Johnson@raytheon.com \
--cc=kr@cybsft.com \
--cc=linux-kernel@vger.kernel.org \
--cc=lkml@felipe-alfaro.com \
--cc=mingo@elte.hu \
--cc=pnambic@unu.nu \
--cc=rlrevell@joe-job.com \
/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