From: edward.robbins@domain.hid
To: Philippe Gerum <rpm@xenomai.org>
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai-help] Very high latencies under stress testing
Date: Fri, 15 Oct 2010 10:21:59 +0100 (BST) [thread overview]
Message-ID: <1287134519.029617765@domain.hid> (raw)
In-Reply-To: <1283590285.1709.2153.camel@domain.hid>
[-- Attachment #1: Type: text/plain, Size: 12164 bytes --]
On Saturday, 4 September, 2010 9:51am, "Philippe Gerum" <rpm@xenomai.org> said:
> On Fri, 2010-09-03 at 17:30 +0100,
> edward.robbins@domain.hidhnologies.co.uk wrote:
> > Today I have tried using the intel video driver with the option "NoAccel",
> and that seems to stop the high latencies; with this option I can kill X, restart
> it, and run glxgears without issues, all while compiling the linux kernel and
> having xeno-test or latency running. The highest latency I have gotten so far is
> 18uS.
> >
> > However, if anyone is interested I have made a trace without the NoAccel
> option, when the latency jumped to 1113uS upon starting X, attached.
> >
>
> Please try this patch. Your trace log reveals that we are only virtually
> masking interrupts while flushing the TLB, which is quite wrong.
>
Hi Phillipe,
I have tried the patch, and the only noticeable difference is that now when I have the NoAccel option set I am getting high latencies when I make actions such as killing the X server. Below is the ipipe trace. I presume this is going to be a problem even if I am not running X?
Thanks again,
Edward
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01
------------------------------------------------------------
CPU: 0, Freeze: 4761785881144 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.131 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 -2144 0.326 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| # func -2143 0.390 __switch_to_xtra+0x8 (__switch_to+0x255)
:| # [ 3276] Xorg -1 -2143 0.427 __xnpod_schedule+0x834 (xnintr_clock_handler+0x130)
:| +func -2143 0.408 __ipipe_walk_pipeline+0x11 (__ipipe_dispatch_wired_nocheck+0x1da)
:| +end 0x000000f6 -2142 0.416 common_interrupt+0x39 (debug_smp_processor_id+0x97)
:| +begin 0x80000001 -2142 0.240 debug_smp_processor_id+0x44 (smp_call_function_single+0x122)
:| +end 0x80000001 -2141 0.262 debug_smp_processor_id+0x94 (smp_call_function_single+0x122)
: +func -2141 0.221 generic_exec_single+0x11 (smp_call_function_single+0x160)
: +func -2141 0.195 _spin_lock_irqsave+0x7 (generic_exec_single+0x3d)
: +func -2141 0.195 ipipe_check_context+0x11 (_spin_lock_irqsave+0x1b)
:| +begin 0x80000001 -2141 0.262 ipipe_check_context+0x33 (_spin_lock_irqsave+0x1b)
:| +end 0x80000001 -2140 0.244 ipipe_check_context+0xda (_spin_lock_irqsave+0x1b)
: #func -2140 0.206 add_preempt_count+0x9 (_spin_lock_irqsave+0x4c)
: #func -2140 0.202 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #begin 0x80000001 -2140 0.259 ipipe_check_context+0x33 (add_preempt_count+0x1c)
:| #end 0x80000001 -2139 0.251 ipipe_check_context+0xda (add_preempt_count+0x1c)
: #func -2139 0.195 _spin_unlock_irqrestore+0x4 (generic_exec_single+0x5d)
: #func -2139 0.191 __ipipe_restore_root+0xb (_spin_unlock_irqrestore+0x21)
:| #begin 0x80000001 -2139 0.236 __ipipe_restore_root+0x2d (_spin_unlock_irqrestore+0x21)
:| #end 0x80000001 -2139 0.236 __ipipe_restore_root+0x7d (_spin_unlock_irqrestore+0x21)
: #func -2138 0.191 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1)
:| #begin 0x80000000 -2138 0.266 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1)
:| +end 0x80000000 -2138 0.213 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1)
: +func -2138 0.206 sub_preempt_count+0x9 (_spin_unlock_irqrestore+0x2b)
: +func -2137 0.206 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2137 0.259 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2137 0.255 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2137 0.221 native_send_call_func_single_ipi+0x4 (generic_exec_single+0x6b)
: +func -2136 0.199 flat_send_IPI_mask+0x11 (native_send_call_func_single_ipi+0x34)
:| +begin 0x80000001 -2136 0.247 flat_send_IPI_mask+0x36 (native_send_call_func_single_ipi+0x34)
:| +end 0x80000001 -2136 0.228 flat_send_IPI_mask+0x8e (native_send_call_func_single_ipi+0x34)
: +func -2136 0.206 sub_preempt_count+0x9 (smp_call_function_single+0x173)
: +func -2136 0.191 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2135 0.262 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2135 0.191 sub_preempt_count+0x9 (smp_call_function+0x47)
: +func -2135 0.187 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| +begin 0x80000001 -2135 0.244 ipipe_check_context+0x33 (sub_preempt_count+0x1c)
:| +end 0x80000001 -2134 0.232 ipipe_check_context+0xda (sub_preempt_count+0x1c)
: +func -2134 0.187 ipipe_check_context+0x11 (set_mtrr+0x77)
:| +begin 0x80000001 -2134 0.251 ipipe_check_context+0x33 (set_mtrr+0x77)
:| +end 0x80000001 -2134! 10.477 ipipe_check_context+0xda (set_mtrr+0x77)
: #func -2123 0.206 generic_set_mtrr+0x11 (set_mtrr+0xdc)
: #func -2123 0.202 ipipe_check_context+0x11 (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2123 0.262 ipipe_check_context+0x33 (generic_set_mtrr+0x42)
:| #end 0x80000001 -2122 0.259 ipipe_check_context+0xda (generic_set_mtrr+0x42)
:| #begin 0x80000001 -2122 0.221 generic_set_mtrr+0x85 (set_mtrr+0xdc)
:| #func -2122 0.199 prepare_set+0x4 (generic_set_mtrr+0x8a)
:| #func -2122 0.213 _spin_lock+0x9 (prepare_set+0x15)
:| #func -2122 0.191 add_preempt_count+0x9 (_spin_lock+0x1b)
:| #func -2121! 1840.932 ipipe_check_context+0x11 (add_preempt_count+0x1c)
:| #func -280! 55.546 mtrr_wrmsr+0xd (prepare_set+0x79)
:| #func -225! 53.303 mtrr_wrmsr+0xd (generic_set_mtrr+0x111)
:| #func -172! 52.380 mtrr_wrmsr+0xd (generic_set_mtrr+0x129)
:| #func -119! 50.782 post_set+0x4 (generic_set_mtrr+0x12e)
:| #func -68! 40.665 mtrr_wrmsr+0xd (post_set+0x25)
:| #func -28+ 1.185 _spin_unlock+0x4 (post_set+0x4f)
:| #func -27 0.356 sub_preempt_count+0x9 (_spin_unlock+0x15)
:| #func -26 0.900 ipipe_check_context+0x11 (sub_preempt_count+0x1c)
:| #end 0x80000001 -25+ 1.050 generic_set_mtrr+0x13f (set_mtrr+0xdc)
:| #begin 0x000000f6 -24 0.566 common_interrupt+0x20 (generic_set_mtrr+0x142)
:| #func -24 0.468 __ipipe_handle_irq+0x11 (common_interrupt+0x27)
:| #func -23 0.266 irq_to_desc+0x4 (__ipipe_handle_irq+0x134)
:| #func -23 0.397 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c)
:| #func -23 0.465 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d)
:| #func -22 0.348 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147)
:| #func -22 0.450 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba)
:| #*func -21 0.634 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b)
:| #*func -21 0.892 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81)
:| #*func -20 0.352 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d)
:| #*func -19 0.585 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d)
:| #*[ 3272] -<?>- 99 -19 0.682 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d)
:| #*func -18 0.318 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191)
:| #*event tick@domain.hid -18 0.285 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191)
:| #*func -18 0.420 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5)
:| #*func -17 0.517 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130)
:| #*[ 3276] Xorg -1 -17 0.296 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130)
:| #*func -16+ 1.601 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3)
:| #*func -15+ 1.091 __phys_addr+0x4 (__xnpod_schedule+0x562)
:| #*func -14 0.697 __switch_to_xtra+0x8 (__switch_to+0x255)
:| #*[ 3272] -<?>- 99 -13 0.945 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281)
:| #*func -12 0.495 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c)
:| #*func -11 0.307 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb)
:| +*end 0x80000000 -11+ 1.526 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb)
:| +*begin 0x80000001 -10 0.442 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -9 0.341 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -9+ 4.351 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
: +*func -5 0.322 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
: +*func -4 0.202 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
:| +*begin 0x80000001 -4 0.510 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
:| +*end 0x80000001 -3 0.266 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
: +*func -3 0.791 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
: +*func -2 0.528 xnshadow_sys_trace+0x7 (hisyscall_event+0x151)
: +*func -2 0.300 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69)
: +*func -2 0.199 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c)
: +*func -1 0.187 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15)
:| +*begin 0x80000001 -1+ 1.226 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15)
:| #*func 0 0.262 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d)
:| +*end 0x80000001 0 0.229 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d)
< +*freeze 0x001f3e65 0 0.225 xnshadow_sys_trace+0x73 (hisyscall_event+0x151)
| +*begin 0x80000001 0 0.251 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 0 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 0 0.708 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.199 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35)
+*func 1 0.183 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd)
| +*begin 0x80000001 1 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd)
| +*end 0x80000001 2 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd)
+*func 2 0.352 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7)
+*func 2 0.281 __rt_task_wait_period+0xb (hisyscall_event+0x151)
+*func 2 0.000 rt_task_wait_period+0x4 (__rt_task_wait_period+0x1c)
[-- Attachment #2: Type: text/html, Size: 22243 bytes --]
next prev parent reply other threads:[~2010-10-15 9:21 UTC|newest]
Thread overview: 38+ messages / expand[flat|nested] mbox.gz Atom feed top
2010-08-13 14:17 [Xenomai-help] Very high latencies under stress testing edward.robbins
2010-08-13 14:35 ` Gilles Chanteperdrix
2010-08-16 12:13 ` edward.robbins
2010-08-16 12:32 ` Gilles Chanteperdrix
2010-09-03 16:30 ` edward.robbins
2010-09-04 8:51 ` Philippe Gerum
2010-10-15 9:21 ` edward.robbins [this message]
2010-10-15 11:54 ` edward.robbins
2010-10-15 13:51 ` Gilles Chanteperdrix
2010-10-15 14:13 ` edward.robbins
2010-10-15 14:25 ` Gilles Chanteperdrix
2010-10-15 14:33 ` Philippe Gerum
2010-10-19 13:52 ` edward.robbins
2010-10-19 20:01 ` Gilles Chanteperdrix
2010-10-23 11:08 ` edward.robbins
2010-10-23 11:13 ` Gilles Chanteperdrix
2010-10-23 11:22 ` edward.robbins
2010-10-23 11:36 ` Gilles Chanteperdrix
2010-10-23 13:45 ` edward.robbins
2010-10-23 13:51 ` Gilles Chanteperdrix
2010-10-23 13:56 ` edward.robbins
2010-10-23 13:58 ` Gilles Chanteperdrix
2010-10-23 14:32 ` edward.robbins
2010-10-23 14:37 ` Gilles Chanteperdrix
2010-10-23 14:48 ` edward.robbins
2010-10-23 15:16 ` edward.robbins
2010-10-23 14:10 ` Gilles Chanteperdrix
2010-08-13 14:40 ` Philippe Gerum
2010-08-13 16:15 ` Philippe Gerum
-- strict thread matches above, loose matches on Subject: below --
2010-10-23 14:54 edward.robbins
2010-10-23 15:37 ` Gilles Chanteperdrix
2010-10-23 16:21 ` edward.robbins
2010-10-23 16:26 ` edward.robbins
2010-10-23 18:46 ` edward.robbins
2010-10-23 21:52 ` Gilles Chanteperdrix
2010-10-24 15:55 ` edward.robbins
2010-10-23 16:13 ` Gilles Chanteperdrix
2010-10-23 16:22 ` Gilles Chanteperdrix
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=1287134519.029617765@domain.hid \
--to=edward.robbins@domain.hid \
--cc=rpm@xenomai.org \
--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.