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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.