From: "CHABAL David" <david.chabal@domain.hid>
To: rpm@xenomai.org
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai-help] awful latencies (~110us)
Date: Wed, 17 Oct 2007 16:52:56 +0200 [thread overview]
Message-ID: <471621C8.9070006@domain.hid> (raw)
In-Reply-To: <1192628763.5973.16.camel@domain.hid>
[-- Attachment #1: Type: text/plain, Size: 597 bytes --]
>
> Grmmff... I think the PIC on this box has some deep troubles; please try
> this patch, in replacement of the previous ipipe_trace_special
> instrumentation:
>
RTD| 8.348| 10.387| 43.647| 0| 6.098|
80.440
---|------------|------------|------------|--------|-------------------------
RTS| 6.098| 10.020| 80.440| 0| 00:17:20/00:17:20
[root@domain.hid bin]#
IRQ handling takes 17µs in the worst case.
It takes a long time to write 3 poor bytes...
May be is it a SMI problem ??? (Globally disable SMI is on)
David
[-- Attachment #2: freeze.txt --]
[-- Type: text/plain, Size: 13185 bytes --]
I-pipe frozen back-tracing service on 2.6.20/ipipe-1.10-08
------------------------------------------------------------
CPU: 0, Freeze: 1199670455059 cycles, Trace Points: 128 (+10)
Calibrated minimum trace-point overhead: 0.258 us
+----- Hard IRQs ('|': locked)
|+---- <unused>
||+--- Xenomai
|||+-- IShield
||||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||||| | +- NMI noise ('N')
||||| | |
Type User Val. Time Delay Function (Parent)
: +func -127 0.340 skb_release_data+0xa (kfree_skbmem+0x10)
: +func -127 0.271 kmem_cache_free+0xe (kfree_skbmem+0x3d)
: +func -126 0.315 ipipe_check_context+0xc (kmem_cache_free+0x40)
: #func -126 0.334 __ipipe_restore_root+0x8 (kmem_cache_free+0x84)
: #func -126 0.300 __ipipe_unstall_root+0x8 (__ipipe_restore_root+0x27)
:| #begin 0x80000000 -126 0.377 __ipipe_unstall_root+0x4d (__ipipe_restore_root+0x27)
:| +end 0x80000000 -125 0.420 __ipipe_unstall_root+0x3f (__ipipe_restore_root+0x27)
: +func -125 0.307 ipipe_check_context+0xc (dev_hard_start_xmit+0x10d)
: +func -124 0.345 boomerang_start_xmit+0xe (dev_hard_start_xmit+0x1cb)
: +func -124 0.285 ipipe_check_context+0xc (boomerang_start_xmit+0x123)
: #func -124 0.353 ipipe_check_context+0xc (boomerang_start_xmit+0x163)
: #func -123 0.275 issue_and_wait+0xe (boomerang_start_xmit+0x170)
: #func -123 0.403 iowrite16+0x8 (issue_and_wait+0x2a)
: #func -123+ 5.960 ioread16+0x8 (issue_and_wait+0x45)
: #func -117+ 7.038 ioread32+0x8 (boomerang_start_xmit+0x188)
: #func -110 0.459 iowrite16+0x8 (boomerang_start_xmit+0x1c9)
: #func -109 0.352 __ipipe_restore_root+0x8 (boomerang_start_xmit+0x1d0)
: #func -109 0.385 __ipipe_unstall_root+0x8 (__ipipe_restore_root+0x27)
:| #begin 0x80000000 -109 0.341 __ipipe_unstall_root+0x4d (__ipipe_restore_root+0x27)
:| +end 0x80000000 -108 0.353 __ipipe_unstall_root+0x3f (__ipipe_restore_root+0x27)
: +func -108 0.346 ipipe_check_context+0xc (boomerang_start_xmit+0x1da)
: +func -108 0.274 ipipe_check_context+0xc (__qdisc_run+0x134)
: +func -107 0.285 ipipe_check_context+0xc (__qdisc_run+0x7a)
: +func -107 0.300 pfifo_fast_dequeue+0x9 (__qdisc_run+0x99)
: +func -107 0.271 ipipe_check_context+0xc (dev_queue_xmit+0x93)
: +func -106 0.281 local_bh_enable+0xb (dev_queue_xmit+0xa1)
: +func -106 0.338 ipipe_check_context+0xc (local_bh_enable+0x52)
: +func -106 0.390 update_send_head+0xa (__tcp_push_pending_frames+0x122)
: +func -105 0.381 tcp_cwnd_validate+0x8 (__tcp_push_pending_frames+0x2d3)
: +func -105 0.554 tcp_check_space+0x9 (tcp_rcv_established+0x410)
: +func -104 0.378 ipipe_check_context+0xc (tcp_v4_rcv+0x58a)
: +func -104 0.379 ipipe_check_context+0xc (ip_local_deliver+0xe7)
: +func -104 0.334 ipipe_check_context+0xc (netif_receive_skb+0x172)
: +func -103 0.331 ipipe_check_context+0xc (process_backlog+0x4a)
: #func -103 0.371 __ipipe_unstall_root+0x8 (process_backlog+0x84)
:| #begin 0x80000000 -103 0.322 __ipipe_unstall_root+0x4d (process_backlog+0x84)
:| +end 0x80000000 -102 0.371 __ipipe_unstall_root+0x3f (process_backlog+0x84)
: +func -102 0.341 netif_receive_skb+0xe (process_backlog+0x8e)
: +func -102 0.418 ipipe_check_context+0xc (netif_receive_skb+0x7f)
: +func -101 0.295 packet_rcv_spkt+0x14 (netif_receive_skb+0x14a)
: +func -101 0.269 skb_clone+0xe (packet_rcv_spkt+0xcc)
: +func -101 0.269 kmem_cache_alloc+0x14 (skb_clone+0x3c)
: +func -100 0.307 ipipe_check_context+0xc (kmem_cache_alloc+0x27)
: #func -100 0.355 __ipipe_restore_root+0x8 (kmem_cache_alloc+0x68)
: #func -100 0.375 __ipipe_unstall_root+0x8 (__ipipe_restore_root+0x27)
:| #begin 0x80000000 -99 0.448 __ipipe_unstall_root+0x4d (__ipipe_restore_root+0x27)
:| +end 0x80000000 -99 0.509 __ipipe_unstall_root+0x3f (__ipipe_restore_root+0x27)
: +func -98 0.356 kfree_skb+0x8 (packet_rcv_spkt+0xd5)
: +func -98 0.396 strlcpy+0x14 (packet_rcv_spkt+0x8e)
: +func -98 0.265 sock_queue_rcv_skb+0x14 (packet_rcv_spkt+0xa0)
: +func -97 0.285 local_bh_disable+0x8 (sock_queue_rcv_skb+0x45)
: +func -97 0.540 sk_run_filter+0x14 (sock_queue_rcv_skb+0x5c)
: +func -97 0.281 local_bh_enable+0xb (sock_queue_rcv_skb+0xd5)
: +func -96 0.289 ipipe_check_context+0xc (local_bh_enable+0x52)
: +func -96 0.295 kfree_skb+0x8 (packet_rcv_spkt+0xab)
: +func -96 0.269 __kfree_skb+0x11 (kfree_skb+0x1e)
: +func -95 0.336 kfree_skbmem+0x9 (__kfree_skb+0x47)
: +func -95 0.362 skb_release_data+0xa (kfree_skbmem+0x10)
: +func -95 0.327 kmem_cache_free+0xe (kfree_skbmem+0x3d)
: +func -94 0.278 ipipe_check_context+0xc (kmem_cache_free+0x40)
: #func -94 0.334 __ipipe_restore_root+0x8 (kmem_cache_free+0x84)
: #func -94 0.371 __ipipe_unstall_root+0x8 (__ipipe_restore_root+0x27)
:| #begin 0x80000000 -93 0.344 __ipipe_unstall_root+0x4d (__ipipe_restore_root+0x27)
:| +end 0x80000000 -93 0.445 __ipipe_unstall_root+0x3f (__ipipe_restore_root+0x27)
: +func -93 0.493 ip_rcv+0x14 (netif_receive_skb+0x166)
: +func -92 0.306 ip_route_input+0x11 (ip_rcv+0x338)
: +func -92 0.321 rt_hash_code+0x9 (ip_route_input+0x3d)
: +func -91 0.403 ipipe_check_context+0xc (ip_route_input+0x49)
: +func -91 0.385 ipipe_check_context+0xc (ip_route_input+0xd2)
: +func -91 0.311 ip_local_deliver+0xe (ip_rcv+0x226)
: +func -90 0.374 ipipe_check_context+0xc (ip_local_deliver+0x6d)
: +func -90 0.614 tcp_v4_rcv+0xe (ip_local_deliver+0xa8)
:| +begin 0xffffff16 -89 0.375 ipipe_ipi3+0x2e (tcp_v4_rcv+0xfa)
:| +func -89 0.368 __ipipe_handle_irq+0x14 (ipipe_ipi3+0x33)
:| +func -89 0.337 __ipipe_ack_apic+0x8 (__ipipe_handle_irq+0x8f)
:| +func -88 0.382 __ipipe_dispatch_wired+0x16 (__ipipe_handle_irq+0x4f)
:| # func -88 0.370 xnintr_clock_handler+0x8 (__ipipe_dispatch_wired+0xaa)
:| # func -88 0.353 xnintr_irq_handler+0xe (xnintr_clock_handler+0x17)
:| # func -87 0.353 xnpod_announce_tick+0x8 (xnintr_irq_handler+0x3b)
:| # func -87 0.500 xntimer_do_tick_aperiodic+0xe (xnpod_announce_tick+0xf)
:| # func -86 0.301 xnthread_periodic_handler+0x8 (xntimer_do_tick_aperiodic+0x217)
:| # func -86 0.322 xnpod_resume_thread+0xe (xnthread_periodic_handler+0x2c)
:| # [ 3875] samplin 99 -86+ 1.013 xnpod_resume_thread+0x5d (xnthread_periodic_handler+0x2c)
:| # func -85 0.404 xnpod_schedule+0xe (xnintr_irq_handler+0x135)
:| # [ 3463] konsole -1 -84+ 1.075 xnpod_schedule+0x97 (xnintr_irq_handler+0x135)
:| # func -83 0.647 __switch_to+0xe (xnpod_schedule+0x498)
:| # [ 3875] samplin 99 -83 0.629 xnpod_schedule+0x570 (xnpod_suspend_thread+0x19b)
:| # func -82 0.327 __ipipe_restore_pipeline_head+0x12 (xnpod_wait_thread_period+0x138)
:| + end 0x80000000 -82! 26.569 __ipipe_restore_pipeline_head+0x7e (xnpod_wait_thread_period+0x138)
:| + begin 0xfffffff1 -55 0.371 common_interrupt+0x29 (__ipipe_restore_pipeline_head+0x82)
:| + func -55 0.886 __ipipe_handle_irq+0x14 (common_interrupt+0x2e)
:| + func -54 0.540 __ipipe_set_irq_pending+0x16 (__ipipe_handle_irq+0x124)
:| + func -53 0.457 __ipipe_ack_irq+0x8 (__ipipe_handle_irq+0x13d)
:| + func -53 0.323 __ipipe_ack_level_irq+0x12 (__ipipe_ack_irq+0x19)
:| + func -52 0.303 mask_and_ack_8259A+0x14 (__ipipe_ack_level_irq+0x22)
:| + func -52 0.308 __ipipe_spin_lock_irqsave+0x9 (mask_and_ack_8259A+0x29)
:| # (0x77) 0x0000000e -52! 16.894 mask_and_ack_8259A+0x3f (__ipipe_ack_level_irq+0x22)
:| # (0x99) 0x0000000e -35 0.310 mask_and_ack_8259A+0x7b (__ipipe_ack_level_irq+0x22)
:| # func -35 0.386 __ipipe_spin_unlock_irqrestore+0x9 (mask_and_ack_8259A+0x87)
:| + func -34 0.370 __ipipe_walk_pipeline+0xa (__ipipe_handle_irq+0x62)
:| + end 0xfffffff1 -34+ 6.810 common_interrupt+0x38 (__ipipe_restore_pipeline_head+0x82)
:| + begin 0xfffffffa -27 0.379 common_interrupt+0x29 (__ipipe_restore_pipeline_head+0x82)
:| + func -27 0.364 __ipipe_handle_irq+0x14 (common_interrupt+0x2e)
:| + func -26 0.307 __ipipe_set_irq_pending+0x16 (__ipipe_handle_irq+0x124)
:| + func -26 0.285 __ipipe_ack_irq+0x8 (__ipipe_handle_irq+0x13d)
:| + func -26 0.278 __ipipe_ack_level_irq+0x12 (__ipipe_ack_irq+0x19)
:| + func -25 0.284 mask_and_ack_8259A+0x14 (__ipipe_ack_level_irq+0x22)
:| + func -25 0.290 __ipipe_spin_lock_irqsave+0x9 (mask_and_ack_8259A+0x29)
:| # (0x77) 0x00000005 -25! 12.952 mask_and_ack_8259A+0x3f (__ipipe_ack_level_irq+0x22)
:| # (0x99) 0x00000005 -12 0.288 mask_and_ack_8259A+0x7b (__ipipe_ack_level_irq+0x22)
:| # func -12 0.355 __ipipe_spin_unlock_irqrestore+0x9 (mask_and_ack_8259A+0x87)
:| + func -11 0.327 __ipipe_walk_pipeline+0xa (__ipipe_handle_irq+0x62)
:| + end 0xfffffffa -11 0.760 common_interrupt+0x38 (__ipipe_restore_pipeline_head+0x82)
:| + begin 0x80000001 -10 0.463 __ipipe_dispatch_event+0x1b1 (__ipipe_syscall_root+0x44)
:| + end 0x80000001 -10+ 3.172 __ipipe_dispatch_event+0x17e (__ipipe_syscall_root+0x44)
: + func -7 0.314 __ipipe_syscall_root+0xa (system_call+0x29)
: + func -6 0.326 __ipipe_dispatch_event+0xe (__ipipe_syscall_root+0x44)
:| + begin 0x80000001 -6 0.407 __ipipe_dispatch_event+0x1d0 (__ipipe_syscall_root+0x44)
:| + end 0x80000001 -6 0.356 __ipipe_dispatch_event+0x1c0 (__ipipe_syscall_root+0x44)
: + func -5+ 1.032 hisyscall_event+0x14 (__ipipe_dispatch_event+0xc0)
: + func -4+ 1.234 xnshadow_sys_trace+0x16 (hisyscall_event+0x189)
: + func -3 0.442 ipipe_trace_frozen_reset+0x9 (xnshadow_sys_trace+0xd7)
: + func -2 0.271 __ipipe_global_path_lock+0x8 (ipipe_trace_frozen_reset+0x13)
: + func -2 0.303 __ipipe_spin_lock_irqsave+0x9 (__ipipe_global_path_lock+0x12)
:| + begin 0x80000001 -2+ 1.545 __ipipe_spin_lock_irqsave+0x4b (__ipipe_global_path_lock+0x12)
:| # func 0 0.413 __ipipe_spin_unlock_irqcomplete+0x9 (__ipipe_global_path_unlock+0x63)
:| + end 0x80000001 0 0.422 __ipipe_spin_unlock_irqcomplete+0x38 (__ipipe_global_path_unlock+0x63)
< + freeze 0x00013a38 0 0.454 xnshadow_sys_trace+0xa0 (hisyscall_event+0x189)
| + begin 0x80000001 0 0.363 __ipipe_dispatch_event+0x1b1 (__ipipe_syscall_root+0x44)
| + end 0x80000001 0 0.886 __ipipe_dispatch_event+0x17e (__ipipe_syscall_root+0x44)
+ func 1 0.292 __ipipe_syscall_root+0xa (system_call+0x29)
+ func 1 0.293 __ipipe_dispatch_event+0xe (__ipipe_syscall_root+0x44)
| + begin 0x80000001 2 0.322 __ipipe_dispatch_event+0x1d0 (__ipipe_syscall_root+0x44)
| + end 0x80000001 2 0.329 __ipipe_dispatch_event+0x1c0 (__ipipe_syscall_root+0x44)
+ func 2 0.412 hisyscall_event+0x14 (__ipipe_dispatch_event+0xc0)
+ func 3 0.315 __rt_task_wait_period+0x11 (hisyscall_event+0x189)
+ func 3 0.364 rt_task_wait_period+0x8 (__rt_task_wait_period+0x21)
+ func 4 0.000 xnpod_wait_thread_period+0xe (rt_task_wait_period+0x38)
next prev parent reply other threads:[~2007-10-17 14:52 UTC|newest]
Thread overview: 30+ messages / expand[flat|nested] mbox.gz Atom feed top
2007-10-05 7:52 [Xenomai-help] awful latencies (~110us) CHABAL David
2007-10-05 8:30 ` Gilles Chanteperdrix
2007-10-05 9:04 ` CHABAL David
2007-10-05 9:20 ` Philippe Gerum
2007-10-05 10:29 ` CHABAL David
2007-10-05 12:35 ` Jan Kiszka
2007-10-05 14:02 ` Philippe Gerum
2007-10-08 12:46 ` CHABAL David
2007-10-10 11:30 ` Philippe Gerum
2007-10-12 14:05 ` CHABAL David
2007-10-12 14:21 ` Jan Kiszka
2007-10-12 14:26 ` CHABAL David
2007-10-12 15:34 ` Philippe Gerum
2007-10-12 15:49 ` Jan Kiszka
2007-10-12 16:43 ` Philippe Gerum
2007-10-17 8:25 ` CHABAL David
2007-10-17 8:41 ` Philippe Gerum
2007-10-17 8:55 ` CHABAL David
2007-10-17 9:17 ` Philippe Gerum
2007-10-17 13:14 ` CHABAL David
2007-10-17 13:46 ` Philippe Gerum
2007-10-17 14:52 ` CHABAL David [this message]
2007-10-17 15:24 ` Philippe Gerum
2007-10-17 15:46 ` CHABAL David
2007-10-17 16:05 ` Philippe Gerum
2007-10-18 12:38 ` CHABAL David
2007-10-18 13:18 ` Philippe Gerum
2007-10-22 14:28 ` CHABAL David
2007-10-17 8:56 ` Philippe Gerum
2007-10-17 8:43 ` 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=471621C8.9070006@domain.hid \
--to=david.chabal@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.