All of lore.kernel.org
 help / color / mirror / Atom feed
* [Xenomai-core] Port to stmp3xxx (arm based)
@ 2011-09-17 15:15 Bertold Van den Bergh
  2011-09-18 13:09 ` Gilles Chanteperdrix
  0 siblings, 1 reply; 5+ messages in thread
From: Bertold Van den Bergh @ 2011-09-17 15:15 UTC (permalink / raw)
  To: xenomai

[-- Attachment #1: Type: text/plain, Size: 2284 bytes --]

Hello,

I am trying to port Xenomai to the freescale stmp3xxx cpu (I.MX233).

I added TSC code from plat-s3c24xx as this processor also uses a 16
bit downcounter based timer. I run the system tick counter and the TSC
freerunning counter at 32KHz (I plan to speed it up to increase
precision but I have a question about that). I have monitored the TSC
output and it is a monotonic count without jumps forward or backward.
Xenomai and linux boots fine. I can also start xenomai tasks, and they
even appear to work to some extent.

When running the latency test I see the following:
== Sampling period: 1000 us
== Test mode: in-kernel periodic task
== All results in microseconds
warming up...
RTT|  00:00:01  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -3604.750|  -3093.750|       0|     0|  -7781.250|  -3093.750
RTD|  -7781.250|  -3527.531|  -3031.250|       0|     0|  -7781.250|  -3031.250
RTD|  -7781.250|  -3486.687|  -3062.500|       0|     0|  -7781.250|  -3031.250

The problem is even worse when running a userspace task:
== Sampling period: 1000 us
== Test mode: periodic user-mode task
== All results in microseconds
warming up.
RTT|  00:00:00  (periodic user-mode task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|-792025.434|-1243155.380|1279960.742|    3227|     0|-792025.434|1279960.742

Also I'm don't really know how to interpret the results, more
specifically, what does overrun and msw mean?
I have attached an ipipe trace of the kernel mode and usermode task.

I tried to adjust /proc/xenomai/latency to make the values shown in
the latency test positive, but this did not help (they became more
negative).

I attached the results of xenomai-test. I think the problem is with
the clocksource, as xenomai when used with an external (non-timer)
interrupt reacts fast(120us, not sure if this hardware could do
faster, I want to use this to control a hobby robot so it would be
more than fast enough if the timer could do the same) and correctly. I
also attached the timer.c file. The only other files I modified are
IRQ related.

Does someone know how I can start debugging this problem?

[-- Attachment #2: ipipe-kernel.txt --]
[-- Type: text/plain, Size: 10968 bytes --]

------------------------------------------------------------
CPU: 0, Freeze: 32479170 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.000 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)
:|  #*[    0] -<?>-   -1  -150+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  +*end     0x80000000  -148    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0xffffffff  -147+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*event   tick@22679  -144+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  +*end     0xffffffff  -142    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  +*begin   0x80000000  -141    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[   -1] -<?>-   99  -140    0.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000  -140+   2.000  __ipipe_restore_pipeline_head+0x10c (timer_task_proc+0x274)
:|  +*begin   0x80000000  -138+   3.000  timer_task_proc+0x5c (xnarch_thread_trampoline+0x30)
:|  #*event   tick@-127   -135    1.000  xntimer_next_local_shot+0xd8 (xntimer_start_aperiodic+0xdfc)
:|  #*[   -1] -<?>-   99  -134    1.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000  -133    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0x80000000  -132    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[    0] -<?>-   -1  -131    1.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   #end     0xffffffff  -130    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   #begin   0x80000000  -129    1.000  __ipipe_unstall_root+0x34 (__ipipe_restore_root+0x68)
:|   +end     0x80000000  -128    1.000  __ipipe_unstall_root+0x6c (__ipipe_restore_root+0x68)
:|   +begin   0xffffffff  -127+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # [   -1] -<?>-   99  -123+   2.000  xnpod_resume_thread+0x144 (xnthread_timeout_handler+0x2c)
:|  # event   tick@22679  -121+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  # [    0] -<?>-   -1  -119    1.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  + end     0x80000000  -118    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0xffffffff  -117+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # event   tick@22680  -113    1.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  + end     0xffffffff  -112    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  + begin   0x80000000  -111    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [   -1] -<?>-   99  -110    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -109    1.000  __ipipe_restore_pipeline_head+0x10c (timer_task_proc+0x274)
:|  + begin   0x80000000  -108+   3.000  timer_task_proc+0x5c (xnarch_thread_trampoline+0x30)
:|  # event   tick@-95    -105    1.000  xntimer_next_local_shot+0xd8 (xntimer_start_aperiodic+0xdfc)
:|  # [   -1] -<?>-   99  -104+   2.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -102    0.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0x80000000  -102    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [    0] -<?>-   -1  -101    1.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   +end     0xffffffff  -100    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   +begin   0x80000001   -99    1.000  __do_softirq+0x104 (irq_exit+0x68)
:|   #end     0x80000001   -98    1.000  __do_softirq+0x124 (irq_exit+0x68)
:|   #begin   0x80000001   -97    0.000  tick_nohz_stop_sched_tick+0x48 (irq_exit+0xac)
:|   #end     0x80000001   -97+   3.000  tick_nohz_stop_sched_tick+0x68 (irq_exit+0xac)
:|   #begin   0xffffffff   -94+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*[   -1] -<?>-   99   -90+   2.000  xnpod_resume_thread+0x144 (xnthread_timeout_handler+0x2c)
:|  #*event   tick@22679   -88    1.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  #*[    0] -<?>-   -1   -87+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  +*end     0x80000000   -85    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0xffffffff   -84+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*event   tick@22679   -81+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  +*end     0xffffffff   -79    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  +*begin   0x80000000   -78    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[   -1] -<?>-   99   -78    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000   -77    1.000  __ipipe_restore_pipeline_head+0x10c (timer_task_proc+0x274)
:|  +*begin   0x80000000   -76+   4.000  timer_task_proc+0x5c (xnarch_thread_trampoline+0x30)
:|  #*event   tick@-62     -72    1.000  xntimer_next_local_shot+0xd8 (xntimer_start_aperiodic+0xdfc)
:|  #*[   -1] -<?>-   99   -71    1.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000   -70    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0x80000000   -69    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[    0] -<?>-   -1   -68    1.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   #end     0xffffffff   -67    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   #begin   0x80000001   -66    0.000  hrtimer_get_next_event+0x3c (get_next_timer_interrupt+0x1c8)
:|   #end     0x80000001   -66    1.000  hrtimer_get_next_event+0x5c (get_next_timer_interrupt+0x1c8)
:|   #begin   0x80000001   -65    0.000  __ipipe_restore_root+0x3c (hrtimer_get_next_event+0x10c)
:|   #end     0x80000001   -65+   3.000  __ipipe_restore_root+0x5c (hrtimer_get_next_event+0x10c)
:|   #begin   0xffffffff   -62+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*[   -1] -<?>-   99   -58+   2.000  xnpod_resume_thread+0x144 (xnthread_timeout_handler+0x2c)
:|  #*event   tick@22679   -56+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  #*[    0] -<?>-   -1   -54    1.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  +*end     0x80000000   -53    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0xffffffff   -52+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*event   tick@22680   -48    1.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  +*end     0xffffffff   -47    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  +*begin   0x80000000   -46    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[   -1] -<?>-   99   -45    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000   -44    1.000  __ipipe_restore_pipeline_head+0x10c (timer_task_proc+0x274)
:|  +*begin   0x80000000   -43+   3.000  timer_task_proc+0x5c (xnarch_thread_trampoline+0x30)
:|  #*event   tick@-31     -40    1.000  xntimer_next_local_shot+0xd8 (xntimer_start_aperiodic+0xdfc)
:|  #*[   -1] -<?>-   99   -39+   2.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000   -37    0.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0x80000000   -37    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[    0] -<?>-   -1   -36    1.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   #end     0xffffffff   -35    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   #begin   0x80000001   -34    1.000  hrtimer_start_range_ns+0x50 (hrtimer_start+0x2c)
:|   #end     0x80000001   -33+   2.000  hrtimer_start_range_ns+0x74 (hrtimer_start+0x2c)
:|   #begin   0x80000000   -31+   4.000  xnarch_next_htick_shot+0x3c (clockevents_program_event+0xec)
:|   #end     0x80000000   -27    0.000  __ipipe_restore_pipeline_head+0x10c (xnarch_next_htick_shot+0x24c)
:|   #begin   0xffffffff   -27+   5.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*[   -1] -<?>-   99   -22    1.000  xnpod_resume_thread+0x144 (xnthread_timeout_handler+0x2c)
:|  #*event   tick@22679   -21+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  #*[    0] -<?>-   -1   -19+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  +*end     0x80000000   -17    0.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  +*begin   0xffffffff   -17+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*event   tick@22679   -13    1.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  +*end     0xffffffff   -12    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  +*begin   0xffffffff   -11+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  #*event   tick@22679    -8+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  +*end     0xffffffff    -6    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  +*begin   0x80000000    -5    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  #*[   -1] -<?>-   99    -5    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  +*end     0x80000000    -4+   2.000  __ipipe_restore_pipeline_head+0x10c (timer_task_proc+0x274)
:|  +*begin   0x80000001    -2    1.000  __ipipe_spin_lock_irqsave+0x34 (__ipipe_global_path_lock+0x20)
:|  +*end     0x80000001    -1    1.000  __ipipe_spin_unlock_irqcomplete+0x4c (__ipipe_global_path_unlock+0x6c)
<   +*freeze  0xffd1451c     0    0.000  eval_inner_loop+0x78 (timer_task_proc+0x294)
 |  +*begin   0x80000000     0    3.000  timer_task_proc+0x5c (xnarch_thread_trampoline+0x30)
 |  #*event   tick@3         3    1.000  xntimer_next_local_shot+0xd8 (xntimer_start_aperiodic+0xdfc)
 |  #*[   -1] -<?>-   99     4    4.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
 |  #*[   -1] -<?>-   99     8    1.000  xnpod_resume_thread+0x144 (xnthread_timeout_handler+0x2c)
 |  #*event   tick@22679     9    2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
 |  +*end     0x80000000    11    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
 |  +*begin   0x80000000    12    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
 |  #*[    0] -<?>-   -1    12    2.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
 |  +*end     0x80000000    14    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
 |  +*begin   0x80000000    15    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)


[-- Attachment #3: ipipe-user.txt --]
[-- Type: text/plain, Size: 10636 bytes --]

Calibrated minimum trace-point overhead: 0.000 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)
:|   +end     0x80000000  -477    0.000  __ipipe_unstall_root+0x6c (default_idle+0xa0)
:|   +begin   0x80000001  -477    0.000  default_idle+0x48 (cpu_idle+0x40)
:|   #end     0x80000001  -477    0.000  default_idle+0x68 (cpu_idle+0x40)
:|   #begin   0x80000000  -477    0.000  __ipipe_unstall_root+0x34 (default_idle+0x8c)
:|   +end     0x80000000  -477    0.000  __ipipe_unstall_root+0x6c (default_idle+0x8c)
:    +end     0x8000000e  -477! 122.000  default_idle+0x94 (cpu_idle+0x40)
:|   +begin   0xffffffff  -355+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # [  979] -<?>-   99  -351+  10.000  xnpod_resume_thread+0x144 (xnthread_periodic_handler+0x2c)
:|  # event   tick@-196   -341+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  # [    0] -<?>-   -1  -339+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  + end     0x80000000  -337    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0xffffffff  -336+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # event   tick@-196   -333+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  + end     0xffffffff  -331    0.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  + begin   0x80000001  -331    1.000  __xnpod_schedule+0x65c (xnintr_clock_handler+0x284)
:|  + end     0x80000001  -330+   3.000  __xnpod_schedule+0x67c (xnintr_clock_handler+0x284)
:|  + begin   0x80000001  -327    0.000  __xnpod_schedule+0x784 (xnintr_clock_handler+0x284)
:|  + end     0x80000001  -327    1.000  __xnpod_schedule+0x7a0 (xnintr_clock_handler+0x284)
:|  + begin   0x80000000  -326    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [  979] -<?>-   99  -325    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -324    1.000  __ipipe_restore_pipeline_head+0x10c (xnpod_wait_thread_period+0x2c0)
:|  + begin   0x80000001  -323    1.000  __ipipe_dispatch_event+0x118 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001  -322    1.000  __ipipe_dispatch_event+0x1d8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000001  -321    0.000  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001  -321    1.000  __ipipe_dispatch_event+0xd8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000000  -320    0.000  xnpod_wait_thread_period+0x44 (rt_task_wait_period+0x4c)
:|  # [  979] -<?>-   99  -320    0.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -320    0.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0x80000001  -320    1.000  __xnpod_schedule+0x65c (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000001  -319    0.000  __xnpod_schedule+0x67c (xnpod_suspend_thread+0xbf8)
:|  + begin   0x80000001  -319    0.000  __xnpod_schedule+0x784 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000001  -319    1.000  __xnpod_schedule+0x7a0 (xnpod_suspend_thread+0xbf8)
:|  + begin   0x80000000  -318    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [    0] -<?>-   -1  -318    0.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   +end     0xffffffff  -318    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   +begin   0x80000000  -317    0.000  __ipipe_unstall_root+0x34 (default_idle+0xa0)
:|   +end     0x80000000  -317    0.000  __ipipe_unstall_root+0x6c (default_idle+0xa0)
:|   +begin   0x80000001  -317    0.000  default_idle+0x48 (cpu_idle+0x40)
:|   #end     0x80000001  -317    0.000  default_idle+0x68 (cpu_idle+0x40)
:|   #begin   0x80000000  -317    0.000  __ipipe_unstall_root+0x34 (default_idle+0x8c)
:|   +end     0x80000000  -317    0.000  __ipipe_unstall_root+0x6c (default_idle+0x8c)
:    +end     0x8000000e  -317! 122.000  default_idle+0x94 (cpu_idle+0x40)
:|   +begin   0xffffffff  -195+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # [  979] -<?>-   99  -191+  10.000  xnpod_resume_thread+0x144 (xnthread_periodic_handler+0x2c)
:|  # event   tick@-36    -181+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  # [    0] -<?>-   -1  -179+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  + end     0x80000000  -177    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0xffffffff  -176+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # event   tick@-36    -173+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  + end     0xffffffff  -171    0.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  + begin   0x80000001  -171    1.000  __xnpod_schedule+0x65c (xnintr_clock_handler+0x284)
:|  + end     0x80000001  -170+   3.000  __xnpod_schedule+0x67c (xnintr_clock_handler+0x284)
:|  + begin   0x80000001  -167    0.000  __xnpod_schedule+0x784 (xnintr_clock_handler+0x284)
:|  + end     0x80000001  -167    1.000  __xnpod_schedule+0x7a0 (xnintr_clock_handler+0x284)
:|  + begin   0x80000000  -166    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [  979] -<?>-   99  -165    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -164    1.000  __ipipe_restore_pipeline_head+0x10c (xnpod_wait_thread_period+0x2c0)
:|  + begin   0x80000001  -163    1.000  __ipipe_dispatch_event+0x118 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001  -162    1.000  __ipipe_dispatch_event+0x1d8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000001  -161    0.000  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001  -161    1.000  __ipipe_dispatch_event+0xd8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000000  -160    0.000  xnpod_wait_thread_period+0x44 (rt_task_wait_period+0x4c)
:|  # [  979] -<?>-   99  -160    0.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000  -160    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0x80000001  -159    0.000  __xnpod_schedule+0x65c (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000001  -159    0.000  __xnpod_schedule+0x67c (xnpod_suspend_thread+0xbf8)
:|  + begin   0x80000001  -159    0.000  __xnpod_schedule+0x784 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000001  -159    1.000  __xnpod_schedule+0x7a0 (xnpod_suspend_thread+0xbf8)
:|  + begin   0x80000000  -158    0.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [    0] -<?>-   -1  -158    0.000  __xnpod_schedule+0x804 (xnintr_clock_handler+0x284)
:|   +end     0xffffffff  -158    1.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|   +begin   0x80000000  -157    0.000  __ipipe_unstall_root+0x34 (default_idle+0xa0)
:|   +end     0x80000000  -157    0.000  __ipipe_unstall_root+0x6c (default_idle+0xa0)
:|   +begin   0x80000001  -157    0.000  default_idle+0x48 (cpu_idle+0x40)
:|   #end     0x80000001  -157    0.000  default_idle+0x68 (cpu_idle+0x40)
:|   #begin   0x80000000  -157    0.000  __ipipe_unstall_root+0x34 (default_idle+0x8c)
:|   +end     0x80000000  -157    0.000  __ipipe_unstall_root+0x6c (default_idle+0x8c)
:    +end     0x8000000e  -157! 122.000  default_idle+0x94 (cpu_idle+0x40)
:|   +begin   0xffffffff   -35+   4.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # [  979] -<?>-   99   -31+  10.000  xnpod_resume_thread+0x144 (xnthread_periodic_handler+0x2c)
:|  # event   tick@124     -21+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  # [    0] -<?>-   -1   -19+   2.000  __xnpod_schedule+0x154 (xnintr_clock_handler+0x284)
:|  + end     0x80000000   -17    1.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
:|  + begin   0xffffffff   -16+   3.000  __ipipe_grab_irq+0x5c (__irq_svc+0x40)
:|  # event   tick@124     -13+   2.000  xntimer_next_local_shot+0xd8 (xntimer_tick_aperiodic+0xe28)
:|  + end     0xffffffff   -11    0.000  __ipipe_grab_irq+0x74 (__irq_svc+0x40)
:|  + begin   0x80000001   -11    1.000  __xnpod_schedule+0x65c (xnintr_clock_handler+0x284)
:|  + end     0x80000001   -10+   3.000  __xnpod_schedule+0x67c (xnintr_clock_handler+0x284)
:|  + begin   0x80000001    -7    0.000  __xnpod_schedule+0x784 (xnintr_clock_handler+0x284)
:|  + end     0x80000001    -7    1.000  __xnpod_schedule+0x7a0 (xnintr_clock_handler+0x284)
:|  + begin   0x80000000    -6    1.000  xnsched_finish_unlocked_switch+0x38 (__xnpod_schedule+0x7dc)
:|  # [  979] -<?>-   99    -5    1.000  __xnpod_schedule+0x804 (xnpod_suspend_thread+0xbf8)
:|  + end     0x80000000    -4    1.000  __ipipe_restore_pipeline_head+0x10c (xnpod_wait_thread_period+0x2c0)
:|  + begin   0x80000001    -3    1.000  __ipipe_dispatch_event+0x118 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001    -2    1.000  __ipipe_dispatch_event+0x1d8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000001    -1    0.000  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
:|  + end     0x80000001    -1    1.000  __ipipe_dispatch_event+0xd8 (__ipipe_syscall_root+0x88)
:|  + begin   0x80000001     0    0.000  __ipipe_spin_lock_irqsave+0x34 (__ipipe_global_path_lock+0x20)
:|  + end     0x80000001     0    0.000  __ipipe_spin_unlock_irqcomplete+0x4c (__ipipe_global_path_unlock+0x6c)
<   + freeze  0xd238a6a6     0    0.000  xnshadow_sys_trace+0xa4 (hisyscall_event+0x194)
 |  + begin   0x80000001     0    0.000  __ipipe_dispatch_event+0x118 (__ipipe_syscall_root+0x88)
 |  + end     0x80000001     0    1.000  __ipipe_dispatch_event+0x1d8 (__ipipe_syscall_root+0x88)
 |  + begin   0x80000001     1    0.000  __ipipe_dispatch_event+0x40 (__ipipe_syscall_root+0x88)
 |  + end     0x80000001     1    0.000  __ipipe_dispatch_event+0xd8 (__ipipe_syscall_root+0x88)
 |  + begin   0x80000000     1    0.000  xnpod_wait_thread_period+0x44 (rt_task_wait_period+0x4c)
 |  # [  979] -<?>-   99     1    1.000  __xnpod_schedule+0x154 (xnpod_suspend_thread+0xbf8)
 |  + end     0x80000000     2    0.000  __ipipe_restore_pipeline_head+0x10c (__xnpod_schedule+0x5cc)
 |  + begin   0x80000001     2    0.000  __xnpod_schedule+0x65c (xnpod_suspend_thread+0xbf8)
 |  + end     0x80000001     2    0.000  __xnpod_schedule+0x67c (xnpod_suspend_thread+0xbf8)
 |  + begin   0x80000001     2    0.000  __xnpod_schedule+0x784 (xnpod_suspend_thread+0xbf8)


[-- Attachment #4: xeno-test.txt --]
[-- Type: text/plain, Size: 34513 bytes --]

xeno-test: started 
withBusybox is 0
xeno-test: running tests

Thu Jan  1 01:22:41 CET 1970
running: /usr/xenomai/bin/xeno-config --verbose
xeno-config --verbose
        --version="2.5.6"
        --cc="arm-none-linux-gnueabi-gcc"
        --arch="arm"
        --prefix="/usr/xenomai"
        --xeno-cflags="-I/usr/xenomai/include -D_GNU_SOURCE -D_REENTRANT -Wall -pipe -D__XENO__"
        --xeno-ldflags="-L/usr/xenomai/lib -lxenomai -lpthread "
        --posix-cflags=""
        --posix-ldflags="-Wl,@/usr/xenomai/lib/posix.wrappers -L/usr/xenomai/lib -lpthread_rt -lxenomai -lpthread -lrt "
        --library-dir="/usr/xenomai/lib"

Thu Jan  1 01:22:42 CET 1970
running: /usr/xenomai/bin/xeno-info
If some fields are empty or look unusual you may have an old version.
Compare to the current minimal requirements in Documentation/Changes.
 
Linux imx233 2.6.28-bertrix #113 PREEMPT Sat Sep 17 16:32:58 CEST 2011 armv5tejl GNU/Linux
 
util-linux             ng 2.13.1.1)
mount                  ng 2.13.1.1)
module-init-tools      3.4
e2fsprogs              1.41.3
Linux C Library        > libc.2.7
Dynamic linker (ldd)   2.7
Procps                 3.2.7
Net-tools              1.60
Kbd                    89:
Sh-utils               6.10
Modules Loaded         

Thu Jan  1 01:22:51 CET 1970
running: cat /proc/cpuinfo
Processor       : ARM926EJ-S rev 5 (v5l)
BogoMIPS        : 226.09
Features        : swp half thumb fastmult edsp java 
CPU implementer : 0x41
CPU architecture: 5TEJ
CPU variant     : 0x0
CPU part        : 0x926
CPU revision    : 5

Hardware        : STMP378X
Revision        : 0000
Serial          : 0000000000000000

Thu Jan  1 01:22:51 CET 1970
running: md5sum /proc/cpuinfo # cpuinfo fingerprint
57a46e78b638433f2b1c7fcbacf2d1bf  /proc/cpuinfo
CONFIG_IPIPE_WANT_PREEMPTIBLE_SWITCH=y
CONFIG_IPIPE=y
CONFIG_IPIPE_DOMAINS=4
CONFIG_IPIPE_COMPAT=y
CONFIG_IPIPE_DELAYED_ATOMICSW=y
# CONFIG_IPIPE_UNMASKED_CONTEXT_SWITCH is not set
CONFIG_PREEMPT=y
# CONFIG_CPU_FREQ is not set
# CONFIG_PM is not set
CONFIG_IPIPE_DEBUG=y
CONFIG_IPIPE_DEBUG_CONTEXT=y
CONFIG_IPIPE_TRACE=y
CONFIG_IPIPE_TRACE_ENABLE=y
CONFIG_IPIPE_TRACE_MCOUNT=y
CONFIG_IPIPE_TRACE_IRQSOFF=y
CONFIG_IPIPE_TRACE_SHIFT=14
CONFIG_IPIPE_TRACE_VMALLOC=y
CONFIG_IPIPE_TRACE_PANIC=y
CONFIG_IPIPE_TRACE_ENABLE_VALUE=1
CONFIG_DEBUG_PREEMPT=y
# CONFIG_DEBUG_SPINLOCK is not set
# CONFIG_DEBUG_SPINLOCK_SLEEP is not set
CONFIG_PREEMPT_TRACER=y

Thu Jan  1 01:22:52 CET 1970
running: cat /proc/ipipe/Linux
       +----- Handling ([A]ccepted, [G]rabbed, [W]ired, [D]iscarded)
       |+---- Sticky
       ||+--- Locked
       |||+-- Exclusive
       ||||+- Virtual
[IRQ]  |||||
   0:  A....
   1:  A....
   2:  A....
   3:  A....
   4:  A....
   5:  A....
   6:  A....
   7:  A....
   8:  A....
   9:  A....
  10:  A....
  11:  A....
  12:  A....
  13:  A....
  14:  A....
  15:  A....
  16:  A....
  17:  A....
  18:  A....
  19:  A....
  20:  A....
  21:  A....
  22:  A....
  23:  A....
  24:  A....
  25:  A....
  26:  A....
  27:  A....
  28:  A....
  29:  A....
  30:  A....
  31:  A....
  32:  A....
  33:  A....
  34:  A....
  35:  A....
  36:  A....
  37:  A....
  38:  A....
  39:  A....
  40:  A....
  41:  A....
  42:  A....
  43:  A....
  44:  A....
  45:  A....
  46:  A....
  47:  A....
  48:  A....
  49:  A....
  50:  A....
  51:  A....
  52:  A....
  53:  A....
  54:  A....
  55:  A....
  56:  A....
  57:  A....
  58:  A....
  59:  A....
  60:  A....
  61:  A....
  62:  A....
  63:  A....
  64:  A....
  65:  A....
  66:  A....
  67:  A....
  68:  A....
  69:  A....
  70:  A....
  71:  A....
  72:  A....
  73:  A....
  74:  A....
  75:  A....
  76:  A....
  77:  A....
  78:  A....
  79:  A....
  80:  A....
  81:  A....
  82:  A....
  83:  A....
  84:  A....
  85:  A....
  86:  A....
  87:  A....
  88:  A....
  89:  A....
  90:  A....
  91:  A....
  92:  A....
  93:  A....
  94:  A....
  95:  A....
  96:  A....
  97:  A....
  98:  A....
  99:  A....
 100:  A....
 101:  A....
 102:  A....
 103:  A....
 104:  A....
 105:  A....
 106:  A....
 107:  A....
 108:  A....
 109:  A....
 110:  A....
 111:  A....
 112:  A....
 113:  A....
 114:  A....
 115:  A....
 116:  A....
 117:  A....
 118:  A....
 119:  A....
 120:  A....
 121:  A....
 122:  A....
 123:  A....
 124:  A....
 125:  A....
 126:  A....
 127:  A....
 128:  G...V
 129:  G...V
[Domain info]
id=0x00000000
priority=100

Thu Jan  1 01:22:53 CET 1970
running: cat /proc/ipipe/Xenomai
       +----- Handling ([A]ccepted, [G]rabbed, [W]ired, [D]iscarded)
       |+---- Sticky
       ||+--- Locked
       |||+-- Exclusive
       ||||+- Virtual
[IRQ]  |||||
  28:  W..X.
 130:  W...V
[Domain info]
id=0x58454e4f
priority=topmost

Thu Jan  1 01:22:53 CET 1970
running: cat /proc/ipipe/trace
cat: /proc/ipipe/trace: Is a directory

Thu Jan  1 01:22:53 CET 1970
running: cat /proc/ipipe/version
1.12-05

Thu Jan  1 01:22:53 CET 1970
running: generate_loads 1
dd workload started, pids 1116 stored in /var/lock/xeno-test.982.pids

Thu Jan  1 01:22:54 CET 1970
running: cat /proc/interrupts
           CPU0
  0:       4785           -  Debug UART
  3:          0           -  stmp3xxx-battery
 14:       1261           -  stmp3xxx-mmc dma
 15:          4           -  stmp3xxx-mmc error
 16:          0           -  GPIO 0
 17:          0           -  GPIO 1
 18:          0           -  GPIO 2
 22:          0           -  RTC alarm
 28:     896451           -  stmp3xxx_timer
 53:          0           -  stmp3xxx-dcp
 54:          4           -  stmp3xxx-dcp
Err:          0

Thu Jan  1 01:22:54 CET 1970
running: cat /proc/loadavg
1.59 1.14 0.93 2/26 1122

Thu Jan  1 01:22:55 CET 1970
running: cat /proc/meminfo
MemTotal:          59708 kB
MemFree:           29408 kB
Buffers:            7192 kB
Cached:            11752 kB
SwapCached:            0 kB
Active:             9604 kB
Inactive:          11348 kB
Active(anon):       2608 kB
Inactive(anon):        0 kB
Active(file):       6996 kB
Inactive(file):    11348 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:             0 kB
SwapFree:              0 kB
Dirty:                 0 kB
Writeback:             0 kB
AnonPages:          2024 kB
Mapped:             2196 kB
Slab:               2880 kB
SReclaimable:       1532 kB
SUnreclaim:         1348 kB
PageTables:          128 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:       29852 kB
Committed_AS:       4916 kB
VmallocTotal:     188416 kB
VmallocUsed:        2396 kB
VmallocChunk:     185620 kB

Thu Jan  1 01:22:55 CET 1970
running: cat /proc/xenomai/acct
0 0 0 83445 0 00400080 1374656906250 1311450281250 1311450281250 ROOT
0 0 0 1037430 0 00000000 1374656906250 44356843750 44356843750 IRQ28: [timer]

Thu Jan  1 01:22:56 CET 1970
running: cat /proc/xenomai/apc
APC          CPU0
  0:            0    (pipe_wakeup)
  1:        25939    (lostage_handler)
  2:            4    (registry_export)
  3:            0    (pse51_lostage_handler)
  4:            0    (deferred RTDM close)

Thu Jan  1 01:22:56 CET 1970
running: cat /proc/xenomai/faults
TRAP         CPU0
  0:            0    (Data or instruction access)
  1:            0    (Section fault)
  2:            0    (Generic data abort)
  3:            0    (Unknown exception)
  4:            0    (Instruction breakpoint)
  5:            0    (Floating point exception)
  6:            0    (VFP Floating point exception)
  7:            0    (Undefined instruction)
  8:            0    (Unaligned access exception)

Thu Jan  1 01:22:57 CET 1970
running: cat /proc/xenomai/hal
1.12-05

Thu Jan  1 01:22:57 CET 1970
running: cat /proc/xenomai/heap
size=8192:used=8:pagesz=4096  (global sem heap)
size=259584:used=64:pagesz=512  (main heap)
size=129536:used=0:pagesz=512  (stack pool)

Thu Jan  1 01:22:58 CET 1970
running: cat /proc/xenomai/irq
IRQ         CPU0
 28:     1049309         [timer]
130:       77734         [virtual]

Thu Jan  1 01:22:58 CET 1970
running: cat /proc/xenomai/latency
0

Thu Jan  1 01:22:59 CET 1970
running: cat /proc/xenomai/lock
CPU0:
  longest locked section: 656250 ns
  spinning time: 0 ns
  section entry: kernel/xenomai/nucleus/intr.c:111 (xnintr_clock_handler)

Thu Jan  1 01:22:59 CET 1970
running: cat /proc/xenomai/sched
CPU  PID    CLASS  PRI      TIMEOUT   TIMEBASE   STAT       NAME
  0  0      idle    -1      -         master     R          ROOT

Thu Jan  1 01:23:00 CET 1970
running: cat /proc/xenomai/stat
CPU  PID    MSW        CSW        PF    STAT       %CPU  NAME
  0  0      0          83445      0     00400080   88.6  ROOT
  0  0      0          1058852    0     00000000   11.2  IRQ28: [timer]

Thu Jan  1 01:23:00 CET 1970
running: cat /proc/xenomai/timebases
NAME       RESOLUTION     JIFFIES   STATUS
master              1         n/a   enabled,set

Thu Jan  1 01:23:01 CET 1970
running: cat /proc/xenomai/timer
status=on+watchdog:setup=3906250:clock=44161247:timerdev=timrot:clockdev=clksrc_stmp3xxx

Thu Jan  1 01:23:01 CET 1970
running: cat /proc/xenomai/version
2.5.6

Thu Jan  1 01:23:02 CET 1970
running: cat /proc/xenomai/interfaces/native
0

Thu Jan  1 01:23:02 CET 1970
running: cat /proc/xenomai/interfaces/posix
0

Thu Jan  1 01:23:03 CET 1970
running: cat /proc/xenomai/interfaces/rtdm
0

Thu Jan  1 01:23:03 CET 1970
running: cat /proc/xenomai/interfaces/sys
0

Thu Jan  1 01:23:04 CET 1970
running: cat /proc/xenomai/registry/usage
slots=512:used=1:exported=0

Thu Jan  1 01:23:04 CET 1970
running: cat /proc/xenomai/rtdm/fildes
total=128:open=0:free=128

Thu Jan  1 01:23:05 CET 1970
running: cat /proc/xenomai/rtdm/named_devices
Hash    Name                            Driver          /proc
24      rttest-timerbench0              xeno_timerbench rttest-timerbench0
55      rttest-switchtest0              xeno_switchtest rttest-switchtest0

Thu Jan  1 01:23:05 CET 1970
running: cat /proc/xenomai/rtdm/open_fildes
Index   Locked  Device          Owner [PID]

Thu Jan  1 01:23:06 CET 1970
running: cat /proc/xenomai/rtdm/protocol_devices
Hash    ProtocolFamily:SocketType       Driver          /proc

Thu Jan  1 01:23:06 CET 1970
running: cat /proc/xenomai/timerstat/master
CPU  SCHEDULED   FIRED       TIMEOUT     INTERVAL    HANDLER      NAME           
0    1070476     983014      8093750     -           NULL         [host-timer]   
0    1384        1383        227937500   1000000000  xnsched_wat  [watchdog]     

Thu Jan  1 01:23:07 CET 1970
running: top -bn1c
top - 01:23:08 up 23 min,  0 users,  load average: 1.90, 1.23, 0.96
Tasks:  28 total,   2 running,  26 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us, 12.6%sy,  0.0%ni, 87.3%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:     59708k total,    30864k used,    28844k free,     7192k buffers
Swap:        0k total,        0k used,        0k free,    11848k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND            
 1116 root      20   0  1836  524  428 R 67.7  0.9   0:06.78 dd if /dev/zero of 
 1199 root      20   0  2476  992  812 R 14.4  1.7   0:00.52 top -bn1c          
    1 root      20   0  1968  672  584 S  0.0  1.1   0:02.90 init [2]           

Thu Jan  1 01:23:09 CET 1970
running: ./run -- -sh -T 120 -t0 # latency
*
*
* Type ^C to stop this application.
*
*
[ 1402.170000] Get tsc info
== Sampling period: 1000 us
== Test mode: periodic user-mode task
== All results in microseconds
[ 1402.700000] Xenomai: registered exported object dispsem-1282 (semaphores)
warming up...
[ 1404.330000] Xenomai: Switching sampling-1282 to secondary mode after exception #0 from user-space at 0x99b8 (pid 1284)
[ 1404.690000] Xenomai: native: cleaning up sem "dispsem-1282" (ret=0).
[ 1404.700000] Xenomai: unregistered exported object dispsem-1282 (semaphores)
/usr/xenomai/bin/xeno-load: line 180:  1282 Segmentation fault      $suflag $* $cmdargs

Thu Jan  1 01:23:26 CET 1970
running: ./run -- -sh -T 120 -t1 # latency
*
*
* Type ^C to stop this application.
*
*
[ 1419.260000] Get tsc info
== Sampling period: 1000 us
== Test mode: in-kernel periodic task
== All results in microseconds
warming up...
RTT|  00:00:01  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5806.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.687|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.656|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.437|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5803.187|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.437|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5804.406|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.000|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.406|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.375|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.062|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.750|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.500|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.656|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.937|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.562|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTT|  00:00:22  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5800.562|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.125|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.250|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.468|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.500|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.062|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.812|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.812|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.250|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.781|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.125|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.937|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.906|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.812|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.781|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.812|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.718|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTT|  00:00:43  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5801.656|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.000|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.375|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.906|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.406|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.062|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.937|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.343|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5803.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.625|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.093|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.968|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.718|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.812|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTT|  00:01:04  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5801.250|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.125|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.312|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5799.312|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5803.312|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.906|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.281|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.562|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.906|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.406|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.156|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.468|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.375|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.812|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.125|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.656|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.875|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTT|  00:01:25  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5802.437|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.656|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.625|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.031|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.437|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.250|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.093|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.500|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.406|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.531|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.156|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5799.531|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.062|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.687|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5800.218|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTT|  00:01:46  (in-kernel periodic task, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7781.250|  -5801.843|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.437|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.468|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.781|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.187|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.593|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5803.281|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.062|  -3781.250|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5802.343|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.968|  -3750.000|       0|     0|  -7781.250|  -3750.000
RTD|  -7781.250|  -5801.750|  -3781.250|       0|     0|  -7781.250|  -3750.000
---|--param|----range-|--samples
HSD|    min|  99 -100 |      119
---|--param|----range-|--samples
HSD|    avg|  99 -100 |   119518
---|--param|----range-|--samples
HSD|    max|  99 -100 |      119
HSH|--param|--samples-|--average--|---stddev--
HSS|    min|       119|     99.000|      0.000
HSS|    avg|    119518|     99.000|      0.000
HSS|    max|       119|     99.000|      0.000
---|-----------|-----------|-----------|--------|------|-------------------------
RTS|  -7781.250|  -5801.686|  -3750.000|       0|     0|    00:02:00/00:02:00

Thu Jan  1 01:25:42 CET 1970
running: ./run -- -sh -T 120 -t2 # latency
*
*
* Type ^C to stop this application.
*
*
[ 1555.240000] Get tsc info
== Sampling period: 1000 us
== Test mode: in-kernel timer handler
== All results in microseconds
warming up...
RTT|  00:00:01  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6799.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.843|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.312|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.968|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.812|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.750|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.687|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.531|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.937|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.781|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.500|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.250|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6800.187|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTT|  00:00:22  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6797.375|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.625|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.531|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.093|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.750|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.875|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.343|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.687|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.812|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.968|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.531|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.218|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.906|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.000|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.156|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.843|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTT|  00:00:43  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6798.437|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.687|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.468|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.093|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.781|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6800.281|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6800.062|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.062|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.187|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.687|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.937|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.156|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.500|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.968|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.562|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTT|  00:01:04  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6799.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6800.281|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.218|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.093|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.937|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.875|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.093|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.937|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.750|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6796.625|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.187|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.500|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.531|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.906|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.031|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.406|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.375|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.625|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTT|  00:01:25  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6799.375|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.968|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6796.437|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.781|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.312|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.312|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.343|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.562|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.812|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.531|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.343|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.343|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.125|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.875|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.656|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.312|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.468|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.687|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTT|  00:01:46  (in-kernel timer handler, 1000 us period, priority 99)
RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat worst
RTD|  -7843.750|  -6798.593|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.156|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.937|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.500|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.375|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.906|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.250|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.093|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6797.906|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.718|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.250|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6799.000|  -3875.000|       0|     0|  -7843.750|  -3875.000
RTD|  -7843.750|  -6798.437|  -3875.000|       0|     0|  -7843.750|  -3875.000
---|--param|----range-|--samples
HSD|    min|  99 -100 |      119
---|--param|----range-|--samples
HSD|    avg|  99 -100 |   119535
---|--param|----range-|--samples
HSD|    max|  99 -100 |      119
HSH|--param|--samples-|--average--|---stddev--
HSS|    min|       119|     99.000|      0.000
HSS|    avg|    119535|     99.000|      0.000
HSS|    max|       119|     99.000|      0.000
---|-----------|-----------|-----------|--------|------|-------------------------
RTS|  -7843.750|  -6798.628|  -3875.000|       0|     0|    00:02:00/00:02:00

Thu Jan  1 01:27:58 CET 1970
running: ./run -- -T 120 # switchtest
*
*
* Type ^C to stop this application.
*
*
[ 1691.470000] Get tsc info
== Testing FPU check routines...
== FPU check routines: unimplemented, skipping FPU switches tests.


[-- Attachment #5: timer.c --]
[-- Type: text/x-csrc, Size: 8131 bytes --]

/*
 * System timer for Freescale STMP37XX/STMP378X
 *
 * Embedded Alley Solutions, Inc <source@embeddedalley.com>
 *
 * Copyright 2008-2009 Freescale Semiconductor, Inc. All Rights Reserved.
 * Copyright 2008 Embedded Alley Solutions, Inc All Rights Reserved.
 */

/*
 * The code contained herein is licensed under the GNU General Public
 * License. You may obtain a copy of the GNU General Public License
 * Version 2 or later at the following locations:
 *
 * http://www.opensource.org/licenses/gpl-license.html
 * http://www.gnu.org/copyleft/gpl.html
 */
#include <linux/types.h>
#include <linux/kernel.h>
#include <linux/init.h>
#include <linux/device.h>
#include <linux/spinlock.h>
#include <linux/interrupt.h>
#include <linux/sched.h>
#include <linux/smp.h>
#include <linux/clocksource.h>
#include <linux/clockchips.h>
#include <linux/io.h>
#include <linux/leds.h>
#include <linux/irq.h>

#include <mach/hardware.h>
#include <asm/system.h>
#include <asm/mach/irq.h>
#include <asm/mach/time.h>
#include <mach/regs-clkctrl.h>

#include <mach/regs-timrot.h>

#include "common.h"

#ifdef CONFIG_IPIPE
static unsigned long long *tsc;
static unsigned *last_cnt;
static IPIPE_DEFINE_SPINLOCK(timer_lock);

static unsigned long last_free_running_tcnt = 0;
static unsigned long free_running_tcon = 0;
static unsigned long timer_reload=0;
static unsigned long timer_lxlost=0;
static inline unsigned long getticksoffset(void);
static inline unsigned long getticksoffset_tscupdate(void);
unsigned long stmp3xxx__gettimeoffset(void);
#ifdef CONFIG_NO_IDLE_HZ
#error "dynamic tick timer not yet supported with IPIPE"
#endif                          /* CONFIG_NO_IDLE_HZ */
int __ipipe_mach_timerint = IRQ_TIMER0;
EXPORT_SYMBOL(__ipipe_mach_timerint);

int __ipipe_mach_timerstolen = 0;
EXPORT_SYMBOL(__ipipe_mach_timerstolen);

unsigned int __ipipe_mach_ticks_per_jiffy;
EXPORT_SYMBOL(__ipipe_mach_ticks_per_jiffy);

static int init_done=0;
#endif
static irqreturn_t
stmp3xxx_timer_interrupt(int irq, void *dev_id)
{
	struct clock_event_device *c = dev_id;
#ifndef CONFIG_IPIPE
	
	HW_TIMROT_TIMCTRLn_CLR(0, (1<<15));
#endif
	c->event_handler(c);
	return IRQ_HANDLED;
}

static cycle_t stmp3xxx_clock_read(void)
{

	unsigned long hwsource=~((HW_TIMROT_TIMCOUNTn_RD(2) & 0xFFFF0000) >> 16);
	return hwsource;
}

static int
stmp3xxx_timrot_set_next_event(unsigned long delta,
		struct clock_event_device *dev)
{
	HW_TIMROT_TIMCOUNTn_WR(0, delta+0); /* reload */
	return 0;
}

static void
stmp3xxx_timrot_set_mode(enum clock_event_mode mode,
		struct clock_event_device *dev)
{
	printk("Set_mode (ignored) %u\n",mode);
}

static struct clock_event_device ckevt_timrot = {
	.name		= "timrot",
	.features	= CLOCK_EVT_FEAT_ONESHOT,
	.shift		= 30,
	.cpumask	= CPU_MASK_CPU0,
	.set_next_event	= stmp3xxx_timrot_set_next_event,
	.set_mode	= stmp3xxx_timrot_set_mode,
};

static struct clocksource cksrc_stmp3xxx = {
	.name           = "cksrc_stmp3xxx",
	.rating         = 250,
	.read           = stmp3xxx_clock_read,
	.mask           = CLOCKSOURCE_MASK(16),
	.shift          = 10,
	.flags		= CLOCK_SOURCE_IS_CONTINUOUS,
};

static struct irqaction stmp3xxx_timer_irq = {
	.name		= "stmp3xxx_timer",
	.flags		= IRQF_DISABLED | IRQF_TIMER,
	.handler	= stmp3xxx_timer_interrupt,
	.dev_id		= &ckevt_timrot,
};


/*
 * Set up timer interrupt, and return the current time in seconds.
 */
static inline void __init stmp3xxx_time_init()
{
	cksrc_stmp3xxx.mult = clocksource_hz2mult(CLOCK_TICK_RATE,
				cksrc_stmp3xxx.shift);


	ckevt_timrot.mult = div_sc(CLOCK_TICK_RATE, NSEC_PER_SEC,
				ckevt_timrot.shift);
	ckevt_timrot.min_delta_ns = clockevent_delta2ns(2, &ckevt_timrot);
	ckevt_timrot.max_delta_ns = clockevent_delta2ns(0xFFF, &ckevt_timrot);


	HW_TIMROT_ROTCTRL_CLR(BM_TIMROT_ROTCTRL_SFTRST |
				BM_TIMROT_ROTCTRL_CLKGATE);
	HW_TIMROT_TIMCOUNTn_WR(0, 0);
	HW_TIMROT_TIMCOUNTn_WR(1, 0);

	HW_TIMROT_TIMCTRLn_WR(0,
			      (BF_TIMROT_TIMCTRLn_SELECT(8) |  /* 32KHz */
			       BF_TIMROT_TIMCTRLn_PRESCALE(0) |
			       BM_TIMROT_TIMCTRLn_RELOAD |
			       BM_TIMROT_TIMCTRLn_UPDATE |
			       BM_TIMROT_TIMCTRLn_IRQ_EN));
	HW_TIMROT_TIMCTRLn_WR(2,
			      (BF_TIMROT_TIMCTRLn_SELECT(0x8) |  /* 3Mhzz */
			       BF_TIMROT_TIMCTRLn_PRESCALE(0) |
			       BM_TIMROT_TIMCTRLn_RELOAD |
			       BM_TIMROT_TIMCTRLn_UPDATE));

	HW_TIMROT_TIMCOUNTn_WR(0, CLOCK_TICK_RATE / HZ - 1);
	HW_TIMROT_TIMCOUNTn_WR(2, 0xFFFF); /* reload */

	init_done=1;
#ifdef CONFIG_IPIPE
        tsc = (unsigned long long *)__ipipe_tsc_area;
        last_cnt = (unsigned *)(tsc + 1);             

        __ipipe_mach_ticks_per_jiffy = CLOCK_TICK_RATE / HZ;
#endif /* CONFIG_IPIPE */

	setup_irq(IRQ_TIMER0, &stmp3xxx_timer_irq);
	clocksource_register(&cksrc_stmp3xxx);
	clockevents_register_device(&ckevt_timrot);
	printk("HW_CLKCTRL_XBUS %X",HW_CLKCTRL_XBUS_RD());
}

static void __init stmp3xxx_init_timer(void)
{
	stmp3xxx_time_init();
}


#define stmp3xxx_suspend_timer	NULL
#define	stmp3xxx_resume_timer	NULL

#ifdef CONFIG_IPIPE

void __ipipe_mach_set_dec(unsigned long delay)
{
        unsigned long flags;
	if(delay>=6){  //Datasheet says nothing about a minimum timer interval, but it seems that setting it to less than 6 makes it fire too late.
		       //(It counts to 0, wraps to the set value, counts to zero and only then gives its interrupt)
		spin_lock_irqsave(&timer_lock, flags);
		if(delay>0xFFFF) {
			printk("set_dec value too high.\n");
			delay=0xFFFF;
		}
		timer_reload=delay;
        	timer_lxlost += getticksoffset_tscupdate();
		HW_TIMROT_TIMCOUNTn_WR(0, delay - 1);
        	spin_unlock_irqrestore(&timer_lock, flags);
	}else{
                ipipe_trigger_irq(IRQ_TIMER0);
	}
}


void __ipipe_mach_acktimer(void)
{
	HW_TIMROT_TIMCTRLn_CLR(0, (1<<15));
        getticksoffset_tscupdate();
}


EXPORT_SYMBOL(__ipipe_mach_set_dec);

void __ipipe_mach_release_timer(void)
{
	printk("Releasetimer\n");
        __ipipe_mach_set_dec(__ipipe_mach_ticks_per_jiffy);
}

EXPORT_SYMBOL(__ipipe_mach_release_timer);

unsigned long __ipipe_mach_get_dec(void)
{
        return ((HW_TIMROT_TIMCOUNTn_RD(0) & 0xFFFF0000) >> 16);
}

#endif
struct sys_timer stmp3xxx_timer = {
	.init		= stmp3xxx_init_timer,
	.suspend	= stmp3xxx_suspend_timer,
#ifdef CONFIG_IPIPE
	//.offset 	= stmp3xxx__gettimeoffset,
#endif
	.resume		= stmp3xxx_resume_timer,
};

#ifdef CONFIG_IPIPE
int __ipipe_check_tickdev(const char *devname)
{	
	printk("Chck_tickdev %s %s\n",devname, ckevt_timrot.name);
        return !strcmp(devname, ckevt_timrot.name);
}
#endif /* CONFIG_IPIPE */

#ifdef CONFIG_IPIPE
notrace unsigned long long __ipipe_mach_get_tsc(void)
{
	unsigned long long result;
        unsigned long flags;

        local_irq_save_hw_notrace(flags);
        spin_lock(&timer_lock);
        result = *tsc + getticksoffset();
        spin_unlock(&timer_lock);
        local_irq_restore_hw_notrace(flags);
//	printk("Current TSC %llu\n",result);
        return result;
}
EXPORT_SYMBOL(__ipipe_mach_get_tsc);
void __ipipe_mach_get_tscinfo(struct __ipipe_tscinfo *info)
{
	info->type = IPIPE_TSC_TYPE_DECREMENTER;
        info->u.dec.counter = (unsigned *)0x80068070;
        info->u.dec.mask = 0xffff0000;
        info->u.dec.last_cnt = last_cnt;
        info->u.dec.tsc = tsc;
	printk("Get tsc info\n");
}

static inline unsigned long timer_freerunning_getvalue(void)
{
        return ((HW_TIMROT_TIMCOUNTn_RD(2) & 0xFFFF0000) >> 16);
}

static inline unsigned long timer_freerunning_getticksoffset(unsigned long tval)
{
        long tdone;

        tdone =  last_free_running_tcnt - tval;
        if (tdone < 0)
                tdone += 0x10000;

        return tdone;
}

static inline unsigned long getticksoffset(void)
{
        return timer_freerunning_getticksoffset(timer_freerunning_getvalue());
}

static inline unsigned long getticksoffset_tscupdate(void)
{
        unsigned long tval;
        unsigned long ticks;

        tval = timer_freerunning_getvalue();
        ticks = timer_freerunning_getticksoffset(tval);
        last_free_running_tcnt = tval;
        *tsc += ticks;
        *last_cnt = last_free_running_tcnt;
        return ticks;
}


#endif     


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Xenomai-core] Port to stmp3xxx (arm based)
  2011-09-17 15:15 [Xenomai-core] Port to stmp3xxx (arm based) Bertold Van den Bergh
@ 2011-09-18 13:09 ` Gilles Chanteperdrix
  2011-09-18 14:43   ` Bertold Van den Bergh
  0 siblings, 1 reply; 5+ messages in thread
From: Gilles Chanteperdrix @ 2011-09-18 13:09 UTC (permalink / raw)
  To: Bertold Van den Bergh; +Cc: xenomai

On 09/17/2011 05:15 PM, Bertold Van den Bergh wrote:
> Hello,
> 
> I am trying to port Xenomai to the freescale stmp3xxx cpu (I.MX233).
> 
> I added TSC code from plat-s3c24xx as this processor also uses a 16
> bit downcounter based timer. I run the system tick counter and the TSC
> freerunning counter at 32KHz (I plan to speed it up to increase
> precision but I have a question about that). I have monitored the TSC
> output and it is a monotonic count without jumps forward or backward.
> Xenomai and linux boots fine. I can also start xenomai tasks, and they
> even appear to work to some extent.

The mask member filled by __ipipe_mach_get_tscinfo is wrong, the right
mask for a 16 bits counter is 0x0000ffff

-- 
                                                                Gilles.


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Xenomai-core] Port to stmp3xxx (arm based)
  2011-09-18 13:09 ` Gilles Chanteperdrix
@ 2011-09-18 14:43   ` Bertold Van den Bergh
  2011-09-18 14:51     ` Gilles Chanteperdrix
  2011-09-18 17:33     ` Gilles Chanteperdrix
  0 siblings, 2 replies; 5+ messages in thread
From: Bertold Van den Bergh @ 2011-09-18 14:43 UTC (permalink / raw)
  To: xenomai

Hello,

Thanks for the reply. The timer register has the following layout: bit
0-15: reload, bit 16-31: counter. Thats why I put 0xFFFF0000. Looking
at the code this cannot work so I added an extra field to indicate the
shift after applying the mask.

Now the userspace latency test prorgam gives valid latencies, sadly
it's still -1ms to 3ms latency.

How should I proceed troubleshooting this?
Looking at the ipipe trace it looks the task is brought op quite fast
after the interrupt fires so I think it is set at the wrong time, I'm
going to look into this.

Sincerely,
Bertold Van den Bergh
On Sun, Sep 18, 2011 at 3:09 PM, Gilles Chanteperdrix
<gilles.chanteperdrix@xenomai.org> wrote:
> On 09/17/2011 05:15 PM, Bertold Van den Bergh wrote:
>> Hello,
>>
>> I am trying to port Xenomai to the freescale stmp3xxx cpu (I.MX233).
>>
>> I added TSC code from plat-s3c24xx as this processor also uses a 16
>> bit downcounter based timer. I run the system tick counter and the TSC
>> freerunning counter at 32KHz (I plan to speed it up to increase
>> precision but I have a question about that). I have monitored the TSC
>> output and it is a monotonic count without jumps forward or backward.
>> Xenomai and linux boots fine. I can also start xenomai tasks, and they
>> even appear to work to some extent.
>
> The mask member filled by __ipipe_mach_get_tscinfo is wrong, the right
> mask for a 16 bits counter is 0x0000ffff
>
> --
>                                                                Gilles.
>


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Xenomai-core] Port to stmp3xxx (arm based)
  2011-09-18 14:43   ` Bertold Van den Bergh
@ 2011-09-18 14:51     ` Gilles Chanteperdrix
  2011-09-18 17:33     ` Gilles Chanteperdrix
  1 sibling, 0 replies; 5+ messages in thread
From: Gilles Chanteperdrix @ 2011-09-18 14:51 UTC (permalink / raw)
  To: Bertold Van den Bergh; +Cc: xenomai

On 09/18/2011 04:43 PM, Bertold Van den Bergh wrote:
> Hello,
> 
> Thanks for the reply. The timer register has the following layout: bit
> 0-15: reload, bit 16-31: counter. Thats why I put 0xFFFF0000. Looking
> at the code this cannot work so I added an extra field to indicate the
> shift after applying the mask.

You should really upgrade your I-pipe tree to a more recent one, where
the support for tsc emulation was factored. You would add the new case
to the tsc implementations in kernel-space, and nowhere else. When you
are done, please send a patch.

> 
> Now the userspace latency test prorgam gives valid latencies, sadly
> it's still -1ms to 3ms latency.
> 
> How should I proceed troubleshooting this?
> Looking at the ipipe trace it looks the task is brought op quite fast
> after the interrupt fires so I think it is set at the wrong time, I'm
> going to look into this.

The I-pipe tracer has a trace point at the point where the timer was
supposed to tick.

-- 
                                                                Gilles.


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Xenomai-core] Port to stmp3xxx (arm based)
  2011-09-18 14:43   ` Bertold Van den Bergh
  2011-09-18 14:51     ` Gilles Chanteperdrix
@ 2011-09-18 17:33     ` Gilles Chanteperdrix
  1 sibling, 0 replies; 5+ messages in thread
From: Gilles Chanteperdrix @ 2011-09-18 17:33 UTC (permalink / raw)
  To: Bertold Van den Bergh; +Cc: xenomai

On 09/18/2011 04:43 PM, Bertold Van den Bergh wrote:
> Hello,
> 
> Thanks for the reply. The timer register has the following layout: bit
> 0-15: reload, bit 16-31: counter. Thats why I put 0xFFFF0000. Looking
> at the code this cannot work so I added an extra field to indicate the
> shift after applying the mask.
> 
> Now the userspace latency test prorgam gives valid latencies, sadly
> it's still -1ms to 3ms latency.
> 
> How should I proceed troubleshooting this?
> Looking at the ipipe trace it looks the task is brought op quite fast
> after the interrupt fires so I think it is set at the wrong time, I'm
> going to look into this.

Note that you probably have not enabled CONFIG_IPIPE_TRACE_MCOUNT, you
should enable it to get more complete traces.


-- 
                                                                Gilles.


^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2011-09-18 17:33 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2011-09-17 15:15 [Xenomai-core] Port to stmp3xxx (arm based) Bertold Van den Bergh
2011-09-18 13:09 ` Gilles Chanteperdrix
2011-09-18 14:43   ` Bertold Van den Bergh
2011-09-18 14:51     ` Gilles Chanteperdrix
2011-09-18 17:33     ` Gilles Chanteperdrix

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.