Argh.. okay. Something is still wrong..very wrong..and went wrong fairly early in the test I think. Latencies went up to around 4500. I've attached a trace. Any clues?
Edward On Saturday, 23 October, 2010 12:36pm, "Gilles Chanteperdrix" <gilles.chanteperd...@xenomai.org> said: > edward.robb...@oxfordtechnologies.co.uk wrote: >> Yep, sorry the words got to the keyboard bypassing my brain... it's built >> already... > > So, you are all set-up I guess. In one terminal, launch latency, in > another terminal, launch dohell. When, in that second terminal, you see: > > Listening on any address 5566 > > From another computer, run: > netcat the-box-where-dohell-runs 5566 > /dev/null > > We can probably do something simpler with the inetd "discard" service, > but I have not tried yet. > > -- > Gilles. >
I-pipe frozen back-tracing service on 2.6.32.15-xenomai-2.5.4/ipipe-2.7-01 ------------------------------------------------------------ CPU: 0, Freeze: 35710222406884 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) :| #begin 0x80000000 -4505 0.251 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1) :| +end 0x80000000 -4504 0.210 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1) : +func -4504 0.225 file_free_rcu+0x9 (__rcu_process_callbacks+0x1ee) : +func -4504 0.202 kmem_cache_free+0x11 (file_free_rcu+0x33) : +func -4504 0.195 ipipe_check_context+0x11 (kmem_cache_free+0x29) :| +begin 0x80000001 -4503 0.251 ipipe_check_context+0x33 (kmem_cache_free+0x29) :| +end 0x80000001 -4503 0.236 ipipe_check_context+0xda (kmem_cache_free+0x29) :| #begin 0x80000001 -4503 0.236 debug_smp_processor_id+0x44 (kmem_cache_free+0x57) :| #end 0x80000001 -4503 0.217 debug_smp_processor_id+0x94 (kmem_cache_free+0x57) : #func -4502 0.206 __ipipe_restore_root+0xb (kmem_cache_free+0x231) :| #begin 0x80000001 -4502 0.225 __ipipe_restore_root+0x2d (kmem_cache_free+0x231) :| #end 0x80000001 -4502 0.202 __ipipe_restore_root+0x7d (kmem_cache_free+0x231) : #func -4502 0.199 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1) :| #begin 0x80000000 -4502 0.255 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1) :| +end 0x80000000 -4501 0.217 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1) : +func -4501 0.198 ipipe_check_context+0x11 (__rcu_process_callbacks+0x20e) :| +begin 0x80000001 -4501 0.240 ipipe_check_context+0x33 (__rcu_process_callbacks+0x20e) :| +end 0x80000001 -4501 0.274 ipipe_check_context+0xda (__rcu_process_callbacks+0x20e) : #func -4500 0.198 __ipipe_restore_root+0xb (__rcu_process_callbacks+0x309) :| #begin 0x80000001 -4500 0.221 __ipipe_restore_root+0x2d (__rcu_process_callbacks+0x309) :| #end 0x80000001 -4500 0.228 __ipipe_restore_root+0x7d (__rcu_process_callbacks+0x309) : #func -4500 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1) :| #begin 0x80000000 -4500 0.236 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1) :| +end 0x80000000 -4499 0.221 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1) : +func -4499 0.191 raise_softirq+0x7 (__rcu_process_callbacks+0x31a) : +func -4499 0.198 ipipe_check_context+0x11 (raise_softirq+0x1a) :| +begin 0x80000001 -4499 0.251 ipipe_check_context+0x33 (raise_softirq+0x1a) :| +end 0x80000001 -4499 0.243 ipipe_check_context+0xda (raise_softirq+0x1a) : #func -4498 0.195 __ipipe_restore_root+0xb (raise_softirq+0x86) :| #begin 0x80000001 -4498 0.236 __ipipe_restore_root+0x2d (raise_softirq+0x86) :| #end 0x80000001 -4498 0.202 __ipipe_restore_root+0x7d (raise_softirq+0x86) : #func -4498 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1) :| #begin 0x80000000 -4497 0.236 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1) :| +end 0x80000000 -4497 0.217 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1) :| +begin 0x80000001 -4497 0.225 debug_smp_processor_id+0x44 (rcu_process_callbacks+0x42) :| +end 0x80000001 -4497 0.217 debug_smp_processor_id+0x94 (rcu_process_callbacks+0x42) : +func -4497 0.206 __rcu_process_callbacks+0x11 (rcu_process_callbacks+0x5b) : +func -4496 0.198 force_quiescent_state+0x11 (__rcu_process_callbacks+0x6c) : +func -4496 0.191 rcu_process_gp_end+0xd (__rcu_process_callbacks+0x78) : +func -4496 0.187 ipipe_check_context+0x11 (rcu_process_gp_end+0x21) :| +begin 0x80000001 -4496 0.247 ipipe_check_context+0x33 (rcu_process_gp_end+0x21) :| +end 0x80000001 -4496 0.243 ipipe_check_context+0xda (rcu_process_gp_end+0x21) : #func -4495 0.187 __ipipe_restore_root+0xb (rcu_process_gp_end+0x79) :| #begin 0x80000001 -4495 0.236 __ipipe_restore_root+0x2d (rcu_process_gp_end+0x79) :| #end 0x80000001 -4495 0.210 __ipipe_restore_root+0x7d (rcu_process_gp_end+0x79) : #func -4495 0.187 __ipipe_unstall_root+0x9 (__ipipe_restore_root+0xb1) :| #begin 0x80000000 -4494 0.240 __ipipe_unstall_root+0x20 (__ipipe_restore_root+0xb1) :| +end 0x80000000 -4494 0.221 __ipipe_unstall_root+0xce (__ipipe_restore_root+0xb1) : +func -4494 0.195 check_for_new_grace_period+0xb (__rcu_process_callbacks+0x84) : +func -4494! 4474.777 ipipe_check_context+0x11 (check_for_new_grace_period+0x22) :| +begin 0x000000f6 -19 0.228 common_interrupt+0x20 (__ipipe_trace+0x729) :| +func -19 0.251 __ipipe_handle_irq+0x11 (common_interrupt+0x27) :| +func -19 0.202 irq_to_desc+0x4 (__ipipe_handle_irq+0x134) :| +func -18 0.195 __ipipe_ack_apic+0x4 (__ipipe_handle_irq+0x13c) :| +func -18 0.228 native_apic_mem_write+0x4 (__ipipe_ack_apic+0x1d) :| +func -18 0.221 __ipipe_dispatch_wired+0xd (__ipipe_handle_irq+0x147) :| +func -18 0.270 __ipipe_dispatch_wired_nocheck+0x11 (__ipipe_dispatch_wired+0xba) :| # func -17 0.240 xnintr_clock_handler+0xb (__ipipe_dispatch_wired_nocheck+0x12b) :| # func -17 0.243 xntimer_tick_aperiodic+0xb (xnintr_clock_handler+0x81) :| # func -17 0.202 xnthread_periodic_handler+0x4 (xntimer_tick_aperiodic+0x8d) :| # func -17 0.221 xnpod_resume_thread+0x11 (xnthread_periodic_handler+0x2d) :| # [31843] -<?>- 99 -17 0.461 xnpod_resume_thread+0xfa (xnthread_periodic_handler+0x2d) :| # func -16 0.206 xntimer_next_local_shot+0x9 (xntimer_tick_aperiodic+0x191) :| # event t...@25 -16 0.210 xntimer_next_local_shot+0xb0 (xntimer_tick_aperiodic+0x191) :| # func -16 0.251 native_apic_mem_write+0x4 (xntimer_next_local_shot+0xe5) :| # func -15 0.274 __xnpod_schedule+0x11 (xnintr_clock_handler+0x130) :| # [17400] -<?>- -1 -15 0.221 __xnpod_schedule+0x189 (xnintr_clock_handler+0x130) :| # func -15 0.409 xnsched_pick_next+0x4 (__xnpod_schedule+0x1e3) :| # func -14 0.536 __phys_addr+0x4 (__xnpod_schedule+0x562) :| # [31843] -<?>- 99 -14 0.375 __xnpod_schedule+0x834 (xnpod_suspend_thread+0x281) :| # func -14 0.247 xntimer_get_overruns+0x8 (xnpod_wait_thread_period+0x14c) :| # func -13 0.214 __ipipe_restore_pipeline_head+0x7 (xnpod_wait_thread_period+0x1cb) :| + end 0x80000000 -13 0.521 __ipipe_restore_pipeline_head+0x137 (xnpod_wait_thread_period+0x1cb) :| + begin 0x00000039 -13 0.244 common_interrupt+0x20 (__ipipe_restore_pipeline_head+0x139) :| + func -12 0.656 __ipipe_handle_irq+0x11 (common_interrupt+0x27) :| + func -12 0.337 __ipipe_set_irq_pending+0xd (__ipipe_handle_irq+0x173) :| + func -11 0.304 irq_to_desc+0x4 (__ipipe_handle_irq+0x18b) :| + func -11 0.401 __ipipe_ack_fasteoi_irq+0x4 (__ipipe_handle_irq+0x194) :| + func -11 0.292 ack_apic_level+0xd (__ipipe_ack_fasteoi_irq+0x10) :| + func -10 0.394 native_apic_mem_read+0x4 (ack_apic_level+0x4d) :| + func -10+ 2.134 io_apic_modify_irq+0xb (ack_apic_level+0xb6) :| + func -8+ 1.432 io_apic_sync+0x4 (io_apic_modify_irq+0x9e) :| + func -6 0.296 native_apic_mem_write+0x4 (ack_apic_level+0xd0) :| + end 0x00000039 -6 0.468 common_interrupt+0x39 (__ipipe_restore_pipeline_head+0x139) :| + begin 0x80000001 -6 0.262 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd) :| + end 0x80000001 -5 0.214 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd) :| + begin 0x80000001 -5+ 1.488 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35) : + func -4 0.210 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35) : + func -3 0.195 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd) :| + begin 0x80000001 -3 0.262 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd) :| + end 0x80000001 -3 0.199 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd) : + func -3 0.570 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7) : + func -2 0.371 xnshadow_sys_trace+0x7 (hisyscall_event+0x151) : + func -2 0.337 ipipe_trace_frozen_reset+0xb (xnshadow_sys_trace+0x69) : + func -2 0.202 __ipipe_global_path_lock+0x4 (ipipe_trace_frozen_reset+0x1c) : + func -1 0.199 __ipipe_spin_lock_irqsave+0xb (__ipipe_global_path_lock+0x15) :| + begin 0x80000001 -1+ 1.110 __ipipe_spin_lock_irqsave+0x2a (__ipipe_global_path_lock+0x15) :| # func 0 0.273 __ipipe_spin_unlock_irqcomplete+0xb (__ipipe_global_path_unlock+0x7d) :| + end 0x80000001 0 0.244 __ipipe_spin_unlock_irqcomplete+0xcf (__ipipe_global_path_unlock+0x7d) < + freeze 0x00442d3e 0 0.266 xnshadow_sys_trace+0x73 (hisyscall_event+0x151) | + begin 0x80000001 0 0.270 __ipipe_dispatch_event+0x1d9 (__ipipe_syscall_root+0xcd) | + end 0x80000001 0 0.229 __ipipe_dispatch_event+0x3f0 (__ipipe_syscall_root+0xcd) | + begin 0x80000001 0 0.386 __ipipe_syscall_root+0xec (__ipipe_syscall_root_thunk+0x35) + func 1 0.214 __ipipe_syscall_root+0x11 (__ipipe_syscall_root_thunk+0x35) + func 1 0.198 __ipipe_dispatch_event+0x11 (__ipipe_syscall_root+0xcd) | + begin 0x80000001 1 0.277 __ipipe_dispatch_event+0x34 (__ipipe_syscall_root+0xcd) | + end 0x80000001 1 0.225 __ipipe_dispatch_event+0x1a6 (__ipipe_syscall_root+0xcd) + func 2 0.225 hisyscall_event+0x11 (__ipipe_dispatch_event+0x1b7) + func 2 0.187 __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