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 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.