From: Sebastian Smolorz <smolorz@domain.hid>
To: philippe.gerum@domain.hid
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai-help] High latencies on Core2Duo
Date: Fri, 13 Jun 2008 09:55:14 +0200 [thread overview]
Message-ID: <485227E2.3030603@domain.hid> (raw)
In-Reply-To: <485174A7.7040505@domain.hid>
[-- Attachment #1: Type: text/plain, Size: 114 bytes --]
Philippe Gerum wrote:
> Could you run another trace with that patch applied? TIA,
Here it comes.
--
Sebastian
[-- Attachment #2: ipipe_trace_4 --]
[-- Type: text/plain, Size: 10519 bytes --]
I-pipe frozen back-tracing service on 2.6.25/ipipe-2.0-08
------------------------------------------------------------
CPU: 0, Freeze: 1123934938236 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.130 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- <unused>
|||+-- Xenomai
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
: #func -300 0.170 ipipe_check_context+0x9 (_spin_lock+0x15)
: #func -299 0.135 __update_rq_clock+0xe (scheduler_tick+0x55)
: #func -299 0.225 native_sched_clock+0xe (__update_rq_clock+0x22)
: #func -299 0.165 native_read_tsc+0x8 (native_sched_clock+0x4f)
: #func -299 0.170 ipipe_check_context+0x9 (native_sched_clock+0x5d)
: #func -299 0.300 __ipipe_restore_root+0x8 (native_sched_clock+0xc5)
: #func -298 0.225 task_tick_fair+0xb (scheduler_tick+0xeb)
: #func -298 0.165 update_curr+0xd (task_tick_fair+0x1c)
: #func -298 0.160 update_curr+0xd (task_tick_fair+0x1c)
: #func -298 0.125 _spin_unlock+0x8 (scheduler_tick+0x1c5)
: #func -298 0.115 ipipe_check_context+0x9 (_spin_unlock+0x14)
: #func -298 0.190 idle_cpu+0x8 (scheduler_tick+0x1cd)
: #func -297 0.240 run_posix_cpu_timers+0xe (update_process_times+0x49)
: #func -297 0.160 profile_tick+0xa (tick_sched_timer+0x78)
: #func -297 0.160 hrtimer_forward+0xe (tick_sched_timer+0x97)
: #func -297 0.160 ktime_add_safe+0xb (hrtimer_forward+0xdb)
: #func -297 0.110 _spin_lock+0x9 (__run_hrtimer+0x48)
: #func -297 0.170 ipipe_check_context+0x9 (_spin_lock+0x15)
: #func -296 0.155 enqueue_hrtimer+0xe (__run_hrtimer+0x69)
: #func -296 0.185 rb_insert_color+0xe (enqueue_hrtimer+0xe0)
: #func -296 0.120 _spin_unlock+0x8 (hrtimer_interrupt+0xf9)
: #func -296 0.160 ipipe_check_context+0x9 (_spin_unlock+0x14)
: #func -296 0.120 tick_program_event+0xe (hrtimer_interrupt+0x12e)
: #func -296 0.110 ktime_get+0xc (tick_program_event+0x29)
: #func -295 0.105 ktime_get_ts+0xa (ktime_get+0x16)
: #func -295 0.120 getnstimeofday+0xe (ktime_get_ts+0x19)
: #func -295 0.110 read_tsc+0x8 (getnstimeofday+0x34)
: #func -295 0.175 native_read_tsc+0x8 (read_tsc+0xd)
: #func -295 0.150 set_normalized_timespec+0x8 (ktime_get_ts+0x40)
: #func -295 0.265 clockevents_program_event+0xe (tick_program_event+0x36)
: #func -295 0.130 xnarch_next_htick_shot+0xa (clockevents_program_event+0xc5)
:| #begin 0x80000000 -294 0.165 xnarch_next_htick_shot+0x1e (clockevents_program_event+0xc5)
:| *#func -294 0.190 xntimer_start_aperiodic+0xe (xnarch_next_htick_shot+0x90)
:| *#func -294 0.245 xnarch_ns_to_tsc+0xe (xntimer_start_aperiodic+0x63)
:| *#func -294 0.120 __ipipe_restore_pipeline_head+0x9 (xnarch_next_htick_shot+0xdb)
:| #end 0x80000000 -294 0.205 __ipipe_restore_pipeline_head+0x94 (xnarch_next_htick_shot+0xdb)
: #func -294 0.155 irq_exit+0x8 (smp_apic_timer_interrupt+0x66)
: #func -293 0.125 ipipe_check_context+0x9 (irq_exit+0x12)
: #func -293 0.135 do_softirq+0x9 (irq_exit+0x47)
: #func -293 0.160 ipipe_check_context+0x9 (do_softirq+0x23)
: #func -293 0.115 __do_softirq+0xe (do_softirq+0x62)
: #func -293 0.130 ipipe_check_context+0x9 (__do_softirq+0x2e)
: #func -293 0.120 __ipipe_unstall_root+0x8 (__do_softirq+0x69)
:| #begin 0x80000000 -293 0.160 __ipipe_unstall_root+0x1a (__do_softirq+0x69)
:| +end 0x80000000 -292 0.340 __ipipe_unstall_root+0x54 (__do_softirq+0x69)
: +func -292 0.160 run_timer_softirq+0xe (__do_softirq+0x77)
: +func -292 0.275 hrtimer_run_pending+0xe (run_timer_softirq+0x22)
: +func -292 0.120 _spin_lock_irq+0x9 (run_timer_softirq+0x37)
: +func -292 0.170 ipipe_check_context+0x9 (_spin_lock_irq+0x15)
: #func -291 0.290 ipipe_check_context+0x9 (_spin_lock_irq+0x33)
: #func -291 0.140 _spin_unlock_irq+0x8 (run_timer_softirq+0x155)
: #func -291 0.130 __ipipe_unstall_root+0x8 (_spin_unlock_irq+0xf)
:| #begin 0x80000000 -291 0.145 __ipipe_unstall_root+0x1a (_spin_unlock_irq+0xf)
:| +end 0x80000000 -291 0.130 __ipipe_unstall_root+0x54 (_spin_unlock_irq+0xf)
: +func -291 0.145 ipipe_check_context+0x9 (_spin_unlock_irq+0x19)
: +func -290 0.170 ipipe_check_context+0x9 (__do_softirq+0xa1)
: #func -290 0.195 _local_bh_enable+0x8 (__do_softirq+0xfb)
: #func -290 0.160 ipipe_check_context+0x9 (_local_bh_enable+0x89)
: #func -290 0.165 __ipipe_restore_root+0x8 (do_softirq+0x75)
: #func -290 0.145 idle_cpu+0x8 (irq_exit+0x62)
: #func -290 0.185 ipipe_check_context+0x9 (irq_exit+0x82)
:| #func -289 0.150 __ipipe_unstall_iret_root+0x9 (restore_nocheck_notrace+0x0)
:| +end 0x8000000d -289 0.360 __ipipe_unstall_iret_root+0x6f (restore_nocheck_notrace+0x0)
:| #end 0xffffff16 -289 0.220 ipipe_ipi3+0x3d (<080fabb8>)
: #func -289 0.160 __ipipe_unstall_iret_root+0x9 (restore_nocheck_notrace+0x0)
:| #begin 0x80000000 -288 0.135 __ipipe_unstall_iret_root+0x1e (restore_nocheck_notrace+0x0)
:| +end 0x8000000d -288! 277.195 __ipipe_unstall_iret_root+0x6f (restore_nocheck_notrace+0x0)
:| +begin 0xffffff16 -11 0.240 ipipe_ipi3+0x2e (<080c81c5>)
:| +func -11 0.195 __ipipe_handle_irq+0xe (ipipe_ipi3+0x33)
:| +func -11 0.280 __ipipe_ack_apic+0x8 (__ipipe_handle_irq+0x76)
:| +func -10 0.200 __ipipe_dispatch_wired+0xe (__ipipe_handle_irq+0x7f)
:| # func -10 0.205 xnintr_clock_handler+0xe (__ipipe_dispatch_wired+0xe0)
:| # func -10 0.185 xntimer_tick_aperiodic+0xe (xnintr_clock_handler+0x65)
:| # func -10 0.165 xnthread_periodic_handler+0x8 (xntimer_tick_aperiodic+0x96)
:| # func -10 0.175 xnpod_resume_thread+0xe (xnthread_periodic_handler+0x28)
:| # [ 5564] -<?>- 99 -9 0.355 xnpod_resume_thread+0x99 (xnthread_periodic_handler+0x28)
:| # func -9 0.290 xntimer_next_local_shot+0xe (xntimer_tick_aperiodic+0x1af)
:| # func -9 0.706 xnpod_schedule+0xe (xnintr_clock_handler+0x108)
:| # [13831] -<?>- -1 -8 0.435 xnpod_schedule+0xe2 (xnintr_clock_handler+0x108)
:| # func -8 0.456 xnarch_switch_to+0xe (xnpod_schedule+0x492)
:| # func -7 0.571 __switch_to+0xe (xnarch_switch_to+0x270)
:| # [ 5564] -<?>- 99 -7 0.415 xnpod_schedule+0x4cd (xnpod_suspend_thread+0x18a)
:| # func -6 0.170 xntimer_get_overruns+0xe (xnpod_wait_thread_period+0xe5)
:| # func -6 0.135 __ipipe_restore_pipeline_head+0x9 (xnpod_wait_thread_period+0x145)
:| + end 0x80000000 -6 0.395 __ipipe_restore_pipeline_head+0x94 (xnpod_wait_thread_period+0x145)
:| + begin 0x80000001 -6 0.260 __ipipe_dispatch_event+0x109 (__ipipe_syscall_root+0x8d)
:| + end 0x80000001 -5+ 1.533 __ipipe_dispatch_event+0x1db (__ipipe_syscall_root+0x8d)
: + func -4 0.155 __ipipe_syscall_root+0xa (system_call+0x29)
: + func -4 0.130 __ipipe_dispatch_event+0xe (__ipipe_syscall_root+0x8d)
:| + begin 0x80000001 -3 0.170 __ipipe_dispatch_event+0x2c (__ipipe_syscall_root+0x8d)
:| + end 0x80000001 -3 0.165 __ipipe_dispatch_event+0xd6 (__ipipe_syscall_root+0x8d)
: + func -3 0.531 hisyscall_event+0xe (__ipipe_dispatch_event+0xe6)
: + func -3 0.435 xnshadow_sys_trace+0xb (hisyscall_event+0x13b)
: + func -2 0.230 ipipe_trace_frozen_reset+0xa (xnshadow_sys_trace+0x62)
: + func -2 0.290 __ipipe_global_path_lock+0xb (ipipe_trace_frozen_reset+0xf)
: + func -2 0.115 __ipipe_spin_lock_irqsave+0xa (__ipipe_global_path_lock+0x15)
:| + begin 0x80000001 -2+ 1.678 __ipipe_spin_lock_irqsave+0x21 (__ipipe_global_path_lock+0x15)
:| # func 0 0.170 __ipipe_spin_unlock_irqcomplete+0xa (__ipipe_global_path_unlock+0x61)
:| + end 0x80000001 0 0.165 __ipipe_spin_unlock_irqcomplete+0x49 (__ipipe_global_path_unlock+0x61)
< + freeze 0x00033eae 0 0.145 xnshadow_sys_trace+0x6b (hisyscall_event+0x13b)
| + begin 0x80000001 0 0.150 __ipipe_dispatch_event+0x109 (__ipipe_syscall_root+0x8d)
| + end 0x80000001 0 0.531 __ipipe_dispatch_event+0x1db (__ipipe_syscall_root+0x8d)
+ func 0 0.135 __ipipe_syscall_root+0xa (system_call+0x29)
+ func 0 0.125 __ipipe_dispatch_event+0xe (__ipipe_syscall_root+0x8d)
| + begin 0x80000001 1 0.120 __ipipe_dispatch_event+0x2c (__ipipe_syscall_root+0x8d)
| + end 0x80000001 1 0.140 __ipipe_dispatch_event+0xd6 (__ipipe_syscall_root+0x8d)
+ func 1 0.185 hisyscall_event+0xe (__ipipe_dispatch_event+0xe6)
+ func 1 0.135 __rt_task_wait_period+0xd (hisyscall_event+0x13b)
+ func 1 0.125 rt_task_wait_period+0x8 (__rt_task_wait_period+0x34)
+ func 1 0.000N xnpod_wait_thread_period+0xe (rt_task_wait_period+0x42)
next prev parent reply other threads:[~2008-06-13 7:55 UTC|newest]
Thread overview: 12+ messages / expand[flat|nested] mbox.gz Atom feed top
2008-06-12 8:21 [Xenomai-help] High latencies on Core2Duo Sebastian Smolorz
2008-06-12 9:08 ` Gilles Chanteperdrix
2008-06-12 11:27 ` Sebastian Smolorz
2008-06-12 19:10 ` Philippe Gerum
2008-06-13 7:55 ` Sebastian Smolorz [this message]
2008-06-13 9:20 ` Philippe Gerum
2008-06-13 9:29 ` Sebastian Smolorz
2008-06-14 1:20 ` Naihong Tang
2008-06-15 8:13 ` Philippe Gerum
2008-06-15 12:24 ` Gilles Chanteperdrix
2008-06-16 8:44 ` Sebastian Smolorz
2008-06-16 9:13 ` Philippe Gerum
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=485227E2.3030603@domain.hid \
--to=smolorz@domain.hid \
--cc=philippe.gerum@domain.hid \
--cc=xenomai@xenomai.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.