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"
<[email protected]> said:
> [email protected] 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
[email protected]
https://mail.gna.org/listinfo/xenomai-help
