I am also finding that tasks are frequently hanging, causing ipipetraces with "INFO: task xxx:xxx blocked for more than 120 seconds". Ihave just had this with apt-get update, and was previously getting itwith grub-install. Could this be related?
Thanks again On Friday, 15 October, 2010 10:21am, edward.robb...@oxfordtechnologies.co.uk said: On Saturday, 4 September, 2010 9:51am, "Philippe Gerum" <r...@xenomai.org> said: > On Fri, 2010-09-03 at 17:30 +0100, > edward.robb...@oxfordtechnologies.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 t...@45 -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)
_______________________________________________ Xenomai-help mailing list Xenomai-help@gna.org https://mail.gna.org/listinfo/xenomai-help