From: Gunter Ohrner <G.Ohrner@post.rwth-aachen.de>
To: linux-kernel@vger.kernel.org
Subject: Re: 2.6.15-rc5-rt2 slowness
Date: Fri, 16 Dec 2005 12:42:04 +0100 [thread overview]
Message-ID: <dnu9ak$k5o$1@sea.gmane.org> (raw)
In-Reply-To: dnu8ku$ie4$1@sea.gmane.org
[-- Attachment #1: Type: text/plain, Size: 474 bytes --]
Gunter Ohrner wrote:
> the other is a high system load and bad responsiveness of the system as a
> whole. I didn't even bother to measure timer/sleep jitters as the system
> was dog slow and the fans started to run a full speed nearly immediately.
Ok, I recompiled the kernel with some debug options and attached
a /proc/latency_trace output, hoping it will be helpful to track down the
problem...
Please tell me if there's anything else I should do.
Greetings,
Gunter
[-- Attachment #2: lat_trace.log --]
[-- Type: text/plain, Size: 6646 bytes --]
preemption latency trace v1.1.5 on 2.6.15-rc5-rt2.zb.20051216.1
--------------------------------------------------------------------
latency: 45 us, #94/94, CPU#0 | (M:rt VP:0, KP:0, SP:1 HP:1)
-----------------
| task: IRQ 12-733 (uid:0 nice:-5 policy:1 rt_prio:47)
-----------------
_------=> CPU#
/ _-----=> irqs-off
| / _----=> need-resched
|| / _---=> hardirq/softirq
||| / _--=> preempt-depth
|||| /
||||| delay
cmd pid ||||| time | caller
\ / ||||| \ | /
konquero-4635 0D.h3 0us : __trace_start_sched_wakeup (try_to_wake_up)
konquero-4635 0D.h3 1us : __trace_start_sched_wakeup <<...>-733> (34 0)
konquero-4635 0Dnh2 1us : try_to_wake_up <<...>-733> (34 74)
konquero-4635 0Dnh2 1us : check_raw_flags (try_to_wake_up)
konquero-4635 0Dnh1 1us : preempt_schedule (try_to_wake_up)
konquero-4635 0Dnh1 1us : wake_up_process (redirect_hardirq)
konquero-4635 0Dnh. 2us : preempt_schedule (__do_IRQ)
konquero-4635 0Dnh. 2us : irq_exit (do_IRQ)
konquero-4635 0Dn.. 2us : __schedule (work_resched)
konquero-4635 0Dn.. 3us : profile_hit (__schedule)
konquero-4635 0Dn.1 3us : sched_clock (__schedule)
konquero-4635 0D..2 5us : trace_array (__schedule)
konquero-4635 0D..2 6us : trace_array <<...>-733> (34 34)
konquero-4635 0D..2 6us : trace_array <konquero-4635> (74 78)
konquero-4635 0D..2 7us : trace_array <<...>-4458> (74 78)
konquero-4635 0D..2 7us : trace_array <<...>-4621> (75 78)
konquero-4635 0D..2 7us : trace_array <<...>-5894> (76 78)
konquero-4635 0D..2 8us : trace_array <<...>-5892> (77 78)
konquero-4635 0D..2 8us+: trace_array (__schedule)
<...>-733 0D..2 11us : __switch_to (__schedule)
<...>-733 0D..2 11us : __schedule <konquero-4635> (74 34)
<...>-733 0D.h2 13us : do_IRQ (c030af09 0 0)
<...>-733 0D.h3 13us+: mask_and_ack_8259A (__do_IRQ)
<...>-733 0D.h4 16us : check_raw_flags (mask_and_ack_8259A)
<...>-733 0D.h3 16us : redirect_hardirq (__do_IRQ)
<...>-733 0D.h2 16us : handle_IRQ_event (__do_IRQ)
<...>-733 0D.h2 17us : timer_interrupt (handle_IRQ_event)
<...>-733 0D.h2 18us : handle_nextevent_tick_update (timer_interrupt)
<...>-733 0D.h2 18us : hrtimer_interrupt (handle_nextevent_tick_update)
<...>-733 0D.h2 19us : get_monotonic_clock (hrtimer_interrupt)
<...>-733 0D.h2 19us : acpi_pm_read (get_monotonic_clock)
<...>-733 0D.h2 20us : get_check_value (get_monotonic_clock)
<...>-733 0D.h3 21us : check_raw_flags (get_check_value)
<...>-733 0D.h2 21us : check_monotonic_clock (get_monotonic_clock)
<...>-733 0D.h3 21us : check_raw_flags (check_monotonic_clock)
<...>-733 0D.h2 22us : clockevents_set_next_event (hrtimer_interrupt)
<...>-733 0D.h2 22us : get_monotonic_clock (clockevents_set_next_event)
<...>-733 0D.h2 23us : acpi_pm_read (get_monotonic_clock)
<...>-733 0D.h2 23us : get_check_value (get_monotonic_clock)
<...>-733 0D.h3 24us : check_raw_flags (get_check_value)
<...>-733 0D.h2 24us : check_monotonic_clock (get_monotonic_clock)
<...>-733 0D.h3 24us : check_raw_flags (check_monotonic_clock)
<...>-733 0D.h2 25us+: pit_next_event (clockevents_set_next_event)
<...>-733 0D.h3 29us : check_raw_flags (pit_next_event)
<...>-733 0D.h2 29us : handle_tick (handle_nextevent_tick_update)
<...>-733 0D.h3 29us : do_timer (handle_tick)
<...>-733 0D.h2 30us : handle_update (handle_nextevent_tick_update)
<...>-733 0D.h2 30us : update_process_times (handle_update)
<...>-733 0D.h2 31us : account_system_time (update_process_times)
<...>-733 0D.h2 31us : run_local_timers (update_process_times)
<...>-733 0D.h2 31us : raise_softirq (run_local_timers)
<...>-733 0D.h2 32us : wakeup_softirqd (raise_softirq)
<...>-733 0D.h2 32us : wake_up_process (wakeup_softirqd)
<...>-733 0D.h2 32us : check_preempt_wakeup (wake_up_process)
<...>-733 0D.h2 33us : try_to_wake_up (wake_up_process)
<...>-733 0D.h3 33us : activate_task (try_to_wake_up)
<...>-733 0D.h3 33us : sched_clock (activate_task)
<...>-733 0D.h3 33us : activate_task <<...>-3> (62 6)
<...>-733 0D.h3 33us : enqueue_task (activate_task)
<...>-733 0D.h3 34us : check_raw_flags (try_to_wake_up)
<...>-733 0D.h2 34us : wake_up_process (wakeup_softirqd)
<...>-733 0D.h2 34us : check_raw_flags (raise_softirq)
<...>-733 0D.h2 34us : rcu_pending (update_process_times)
<...>-733 0D.h2 35us : rcu_check_callbacks (update_process_times)
<...>-733 0D.h2 35us : rcu_try_flip (rcu_check_callbacks)
<...>-733 0D.h3 36us : check_raw_flags (rcu_try_flip)
<...>-733 0D.h3 36us : __rcu_advance_callbacks (rcu_check_callbacks)
<...>-733 0D.h3 36us : check_raw_flags (rcu_check_callbacks)
<...>-733 0D.h2 36us : __tasklet_schedule (rcu_check_callbacks)
<...>-733 0D.h2 37us : wakeup_softirqd (__tasklet_schedule)
<...>-733 0D.h2 37us : wake_up_process (wakeup_softirqd)
<...>-733 0D.h2 37us : check_preempt_wakeup (wake_up_process)
<...>-733 0D.h2 38us : try_to_wake_up (wake_up_process)
<...>-733 0D.h3 38us : activate_task (try_to_wake_up)
<...>-733 0D.h3 38us : sched_clock (activate_task)
<...>-733 0D.h3 38us : activate_task <<...>-7> (62 7)
<...>-733 0D.h3 38us : enqueue_task (activate_task)
<...>-733 0D.h3 39us : check_raw_flags (try_to_wake_up)
<...>-733 0D.h2 39us : wake_up_process (wakeup_softirqd)
<...>-733 0D.h2 39us : check_raw_flags (__tasklet_schedule)
<...>-733 0D.h2 39us : scheduler_tick (update_process_times)
<...>-733 0D.h2 39us : sched_clock (scheduler_tick)
<...>-733 0D.h2 40us : softlockup_tick (update_process_times)
<...>-733 0D.h2 40us : touch_light_softlockup_watchdog (softlockup_tick)
<...>-733 0D.h3 41us : note_interrupt (__do_IRQ)
<...>-733 0D.h3 41us : enable_8259A_irq (__do_IRQ)
<...>-733 0D.h4 42us : check_raw_flags (enable_8259A_irq)
<...>-733 0D.h2 43us : irq_exit (do_IRQ)
<...>-733 0D..2 43us < (608)
<...>-733 0...1 43us : trace_stop_sched_switched (__schedule)
<...>-733 0D..2 44us : trace_stop_sched_switched <<...>-733> (34 0)
<...>-733 0D..2 45us : trace_stop_sched_switched (__schedule)
vim:ft=help
next prev parent reply other threads:[~2005-12-16 11:46 UTC|newest]
Thread overview: 56+ messages / expand[flat|nested] mbox.gz Atom feed top
2005-12-16 11:30 2.6.15-rc5-rt2 slowness Gunter Ohrner
2005-12-16 11:42 ` Gunter Ohrner [this message]
2005-12-16 12:04 ` Gunter Ohrner
2005-12-16 12:34 ` Steven Rostedt
2005-12-16 12:32 ` Steven Rostedt
2005-12-16 22:58 ` john stultz
2005-12-17 0:22 ` Gunter Ohrner
2005-12-17 3:51 ` Steven Rostedt
2005-12-17 3:33 ` Steven Rostedt
2005-12-17 22:57 ` Steven Rostedt
2005-12-18 16:05 ` K.R. Foley
2005-12-20 13:32 ` Ingo Molnar
2005-12-20 13:38 ` Steven Rostedt
2005-12-20 13:57 ` Ingo Molnar
2005-12-20 14:04 ` Steven Rostedt
2005-12-20 14:33 ` Steven Rostedt
2005-12-20 15:07 ` Ingo Molnar
2005-12-20 15:16 ` Steven Rostedt
2005-12-20 15:44 ` [PATCH RT 00/02] SLOB optimizations Steven Rostedt
2005-12-20 15:56 ` Steven Rostedt
2005-12-20 15:58 ` Ingo Molnar
2005-12-20 16:13 ` Ingo Molnar
2005-12-20 16:29 ` Steven Rostedt
2005-12-20 16:39 ` Steven Rostedt
2005-12-20 18:19 ` Matt Mackall
2005-12-20 19:15 ` Steven Rostedt
2005-12-20 19:43 ` Matt Mackall
2005-12-20 20:06 ` Steven Rostedt
2005-12-20 20:15 ` Pekka Enberg
2005-12-20 21:42 ` Steven Rostedt
2005-12-20 21:52 ` Christoph Lameter
2005-12-20 22:11 ` Steven Rostedt
2005-12-21 6:36 ` Ingo Molnar
2005-12-21 12:50 ` Steven Rostedt
2005-12-21 6:56 ` Ingo Molnar
2005-12-21 7:16 ` Pekka J Enberg
2005-12-21 7:50 ` Ingo Molnar
2005-12-21 13:13 ` Steven Rostedt
2005-12-21 15:34 ` [PATCH] SLAB - have index_of bug at compile time Steven Rostedt
2005-12-21 7:20 ` [PATCH RT 00/02] SLOB optimizations Eric Dumazet
2005-12-21 7:43 ` Ingo Molnar
2005-12-21 8:02 ` Eric Dumazet
2005-12-22 18:02 ` Zwane Mwaikambo
2005-12-22 21:11 ` Ingo Molnar
2005-12-22 21:39 ` Eric Dumazet
2005-12-22 21:44 ` George Anzinger
2005-12-22 22:00 ` Eric Dumazet
2005-12-22 22:08 ` Eric Dumazet
2005-12-23 19:22 ` Zwane Mwaikambo
2005-12-21 13:02 ` Steven Rostedt
2005-12-21 2:30 ` Nick Piggin
2005-12-21 2:41 ` Steven Rostedt
2005-12-20 15:44 ` [PATCH RT 01/02] SLOB - remove bigblock list Steven Rostedt
2005-12-20 15:44 ` [PATCH RT 02/02] SLOB - break SLOB up by caches Steven Rostedt
2005-12-20 14:07 ` 2.6.15-rc5-rt2 slowness Steven Rostedt
2005-12-20 15:26 ` K.R. Foley
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='dnu9ak$k5o$1@sea.gmane.org' \
--to=g.ohrner@post.rwth-aachen.de \
--cc=linux-kernel@vger.kernel.org \
/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