From: "CHABAL David" <david.chabal@domain.hid>
To: rpm@xenomai.org
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai-help] awful latencies (~110us)
Date: Fri, 05 Oct 2007 12:29:14 +0200 [thread overview]
Message-ID: <470611FA.30103@domain.hid> (raw)
In-Reply-To: <1191576011.20623.114.camel@domain.hid>
[-- Attachment #1: Type: text/plain, Size: 1631 bytes --]
Philippe Gerum a écrit :
> On Fri, 2007-10-05 at 11:04 +0200, CHABAL David wrote:
>> Gilles Chanteperdrix a écrit :
>>> On 10/5/07, CHABAL David <david.chabal@domain.hid> wrote:
>>>> Hello all,
>>>>
>>>> My box is a Pentium III 733 Mhz/256Mo with Linux 2.6.20 and Xenomai
>> 2.3.3.
>>>> When I run the latency test included in the testsuite, I get some
>>>> horrible results like:
>>>>
>
> You first need to upgrade your Adeos patch in order to avoid a deadly
> tracer issue in earlier versions:
> http://download.gna.org/adeos/patches/v2.6/i386/older/adeos-ipipe-2.6.20-i386-1.8-08.patch
>
> Then, please switch on CONFIG_IPIPE_TRACE, CONFIG_IPIPE_TRACE_MCOUNT,
> CONFIG_IPIPE_TRACE_IRQSOFF, and eventually run the following on the
> target kernel:
>
> # echo 1 > /proc/ipipe/trace/enable
> # /usr/xenomai/bin/latency -f
> ... wait for a high latency ...
> # echo 128 > /proc/ipipe/trace/back_trace_points
> # cat /proc/ipipe/trace/frozen
>
> Sending us back the output of the last command would help.
>
Gilles and Philippe, thank you for your help.
The results below come from a patched kernel with adeos 1.8.08:
RTT| 00:07:22 (periodic user-mode task, 100 us period, priority 99)
RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat
worst
RTD| 4.722| 12.411| 93.529| 0| 3.129|
122.269
RTD| 4.347| 13.690| 93.802| 0| 3.129|
122.269
---|------------|------------|------------|--------|-------------------------
RTS| 3.129| 10.194| 122.269| 0| 00:07:24/00:07:24
David
[-- Attachment #2: frozen --]
[-- Type: text/plain, Size: 8581 bytes --]
I-pipe frozen back-tracing service on 2.6.20/ipipe-1.8-08
------------------------------------------------------------
******** WARNING ********
The following debugging options will increase the observed latencies:
o CONFIG_XENO_OPT_DEBUG
Freeze: 620918235066 cycles, Trace Points: 128 (+10)
Calibrated minimum trace-point overhead: 0.248 us
+--------------- Hard IRQs ('|': locked)
| +- Delay flag ('+': > 1 us, '!': > 10 us)
| |
Type Time Function (Parent)
: func -145 iowrite16 (issue_and_wait)
: func -144+ ioread16 (issue_and_wait)
: func -137+ ioread32 (boomerang_start_xmit)
: func -136 iowrite16 (boomerang_start_xmit)
: func -136 __ipipe_restore_root (boomerang_start_xmit)
: func -135 __ipipe_unstall_root (__ipipe_restore_root)
:|begin -135 __ipipe_unstall_root (__ipipe_restore_root)
:|end -135 __ipipe_unstall_root (__ipipe_restore_root)
: func -134 ipipe_check_context (boomerang_start_xmit)
: func -134 ipipe_check_context (__qdisc_run)
: func -133 ipipe_check_context (__qdisc_run)
: func -133 pfifo_fast_dequeue (__qdisc_run)
: func -133 ipipe_check_context (dev_queue_xmit)
: func -132 local_bh_enable (dev_queue_xmit)
: func -132 ipipe_check_context (local_bh_enable)
: func -132 update_send_head (__tcp_push_pending_frames)
: func -131 tcp_init_tso_segs (__tcp_push_pending_frames)
: func -131 tcp_set_skb_tso_segs (tcp_init_tso_segs)
: func -131 tcp_transmit_skb (__tcp_push_pending_frames)
: func -130 skb_clone (tcp_transmit_skb)
: func -129 __tcp_select_window (tcp_transmit_skb)
: func -129 tcp_v4_send_check (tcp_transmit_skb)
: func -128 ip_queue_xmit (tcp_transmit_skb)
: func -128 __sk_dst_check (ip_queue_xmit)
: func -127 ip_output (ip_queue_xmit)
: func -127 dev_queue_xmit (ip_output)
: func -127 local_bh_disable (dev_queue_xmit)
: func -126 ipipe_check_context (dev_queue_xmit)
: func -126 pfifo_fast_enqueue (dev_queue_xmit)
: func -126 __qdisc_run (dev_queue_xmit)
: func -125 pfifo_fast_dequeue (__qdisc_run)
: func -125 ipipe_check_context (__qdisc_run)
: func -125 ipipe_check_context (__qdisc_run)
: func -124 dev_hard_start_xmit (__qdisc_run)
: func -124 ipipe_check_context (dev_hard_start_xmit)
: func -124 skb_clone (dev_hard_start_xmit)
: func -123 kmem_cache_alloc (skb_clone)
: func -123 ipipe_check_context (kmem_cache_alloc)
: func -123 __ipipe_restore_root (kmem_cache_alloc)
: func -123 __ipipe_unstall_root (__ipipe_restore_root)
:|begin -122 __ipipe_unstall_root (__ipipe_restore_root)
:|end -122 __ipipe_unstall_root (__ipipe_restore_root)
: func -121 packet_rcv_spkt (dev_hard_start_xmit)
: func -121 strlcpy (packet_rcv_spkt)
: func -121 sock_queue_rcv_skb (packet_rcv_spkt)
: func -120 local_bh_disable (sock_queue_rcv_skb)
: func -120 sk_run_filter (sock_queue_rcv_skb)
: func -119 local_bh_enable (sock_queue_rcv_skb)
: func -119 ipipe_check_context (local_bh_enable)
: func -119 kfree_skb (packet_rcv_spkt)
: func -119 __kfree_skb (kfree_skb)
: func -118 kfree_skbmem (__kfree_skb)
: func -118 skb_release_data (kfree_skbmem)
: func -117 kmem_cache_free (kfree_skbmem)
: func -117 ipipe_check_context (kmem_cache_free)
: func -117 __ipipe_restore_root (kmem_cache_free)
: func -117 __ipipe_unstall_root (__ipipe_restore_root)
:|begin -116 __ipipe_unstall_root (__ipipe_restore_root)
:|end -116 __ipipe_unstall_root (__ipipe_restore_root)
: func -115 ipipe_check_context (dev_hard_start_xmit)
: func -115 boomerang_start_xmit (dev_hard_start_xmit)
: func -115 ipipe_check_context (boomerang_start_xmit)
: func -114 ipipe_check_context (boomerang_start_xmit)
: func -114 issue_and_wait (boomerang_start_xmit)
: func -114 iowrite16 (issue_and_wait)
: func -113! ioread16 (issue_and_wait)
:|begin -84 common_interrupt (ioread16)
:|func -83 __ipipe_handle_irq (common_interrupt)
:|func -83 __ipipe_ack_irq (__ipipe_handle_irq)
:|func -82 __ipipe_ack_level_irq (__ipipe_ack_irq)
:|func -82 mask_and_ack_8259A (__ipipe_ack_level_irq)
:|func -82+ __ipipe_spin_lock_irqsave (mask_and_ack_8259A)
:|func -78 __ipipe_spin_unlock_irqrestore (mask_and_ack_8259A)
:|func -78 __ipipe_dispatch_wired (__ipipe_handle_irq)
:|func -77 xnintr_clock_handler (__ipipe_dispatch_wired)
:|func -77 xnintr_irq_handler (xnintr_clock_handler)
:|func -77 xnpod_announce_tick (xnintr_irq_handler)
:|func -76 xntimer_do_tick_aperiodic (xnpod_announce_tick)
:|func -76 xnthread_periodic_handler (xntimer_do_tick_aperiodic)
:|func -76 xnpod_resume_thread (xnthread_periodic_handler)
:|[ 3937] -75+ xnpod_resume_thread (xnthread_periodic_handler)
:|func -72 xnpod_schedule (xnintr_irq_handler)
:|[ 3497] -72+ xnpod_schedule (xnintr_irq_handler)
:|func -71 __switch_to (xnpod_schedule)
:|[ 3937] -70 xnpod_schedule (xnpod_suspend_thread)
:|func -70 __ipipe_restore_pipeline_head (xnpod_wait_thread_period)
:|end -69+ __ipipe_restore_pipeline_head (xnpod_wait_thread_period)
:|begin -63 common_interrupt (__ipipe_restore_pipeline_head)
:|func -62 __ipipe_handle_irq (common_interrupt)
:|func -62 __ipipe_ack_irq (__ipipe_handle_irq)
:|func -62 __ipipe_ack_level_irq (__ipipe_ack_irq)
:|func -61 mask_and_ack_8259A (__ipipe_ack_level_irq)
:|func -61! __ipipe_spin_lock_irqsave (mask_and_ack_8259A)
:|func -40 __ipipe_spin_unlock_irqrestore (mask_and_ack_8259A)
:|func -40 __ipipe_walk_pipeline (__ipipe_handle_irq)
:|end -39+ common_interrupt (__ipipe_restore_pipeline_head)
:|begin -32 common_interrupt (__ipipe_restore_pipeline_head)
:|func -32 __ipipe_handle_irq (common_interrupt)
:|func -31 __ipipe_ack_irq (__ipipe_handle_irq)
:|func -31 __ipipe_ack_level_irq (__ipipe_ack_irq)
:|func -31 mask_and_ack_8259A (__ipipe_ack_level_irq)
:|func -30+ __ipipe_spin_lock_irqsave (mask_and_ack_8259A)
:|func -25 __ipipe_spin_unlock_irqrestore (mask_and_ack_8259A)
:|func -24 __ipipe_dispatch_wired (__ipipe_handle_irq)
:|func -24 xnintr_clock_handler (__ipipe_dispatch_wired)
:|func -23 xnintr_irq_handler (xnintr_clock_handler)
:|func -23 xnpod_announce_tick (xnintr_irq_handler)
:|func -23 xntimer_do_tick_aperiodic (xnpod_announce_tick)
:|func -22+ xnthread_periodic_handler (xntimer_do_tick_aperiodic)
:|func -13 rthal_irq_host_pend (xnintr_irq_handler)
:|func -13 __ipipe_schedule_irq (rthal_irq_host_pend)
:|func -12 __ipipe_walk_pipeline (__ipipe_handle_irq)
:|end -12 common_interrupt (__ipipe_restore_pipeline_head)
:|begin -11 __ipipe_dispatch_event (__ipipe_syscall_root)
:|end -11+ __ipipe_dispatch_event (__ipipe_syscall_root)
: func -8 __ipipe_syscall_root (system_call)
: func -7 __ipipe_dispatch_event (__ipipe_syscall_root)
:|begin -7 __ipipe_dispatch_event (__ipipe_syscall_root)
:|end -6 __ipipe_dispatch_event (__ipipe_syscall_root)
: func -6+ hisyscall_event (__ipipe_dispatch_event)
: func -5+ xnshadow_sys_trace (hisyscall_event)
: func -4 ipipe_trace_frozen_reset (xnshadow_sys_trace)
: func -3 __ipipe_global_path_lock (ipipe_trace_frozen_reset)
: func -3 __ipipe_spin_lock_irqsave (__ipipe_global_path_lock)
:|begin -2+ __ipipe_spin_lock_irqsave (__ipipe_global_path_lock)
:|func 0 __ipipe_spin_unlock_irqcomplete (__ipipe_global_path_unlock)
:|end 0 __ipipe_spin_unlock_irqcomplete (__ipipe_global_path_unlock)
< freeze 0 xnshadow_sys_trace (hisyscall_event)
|begin 0 __ipipe_dispatch_event (__ipipe_syscall_root)
|end 0 __ipipe_dispatch_event (__ipipe_syscall_root)
func 1 __ipipe_syscall_root (system_call)
func 2 __ipipe_dispatch_event (__ipipe_syscall_root)
|begin 2 __ipipe_dispatch_event (__ipipe_syscall_root)
|end 2 __ipipe_dispatch_event (__ipipe_syscall_root)
func 3 hisyscall_event (__ipipe_dispatch_event)
func 3 __rt_task_wait_period (hisyscall_event)
func 3 rt_task_wait_period (__rt_task_wait_period)
func 4 xnpod_wait_thread_period (rt_task_wait_period)
next prev parent reply other threads:[~2007-10-05 10:29 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 [this message]
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
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=470611FA.30103@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.