Am 13.07.2015 um 17:24 schrieb Gilles Chanteperdrix:
Johann Obermayr wrote:
without your application, there are no large latencies.
with your application see frozen.txt (with latency -f)
I am confused. You mean "our application", not "your application", right?
lrtdrv_monitoring_irq is not part of the code delivered by the Xenomai
project.
We see the problem only if one task (background) is accessing the SRAM
on your PCI-Card. if we stop this task, all is ok.
Again: the Xenomai project does not make PCI-card. So, you probably mean
"our PCI-Card"?
yes, our PCI-Card. (sorry for my bad english)
So we have a higher prior task (pci-locker), that interrupt the
background task, so that the pci bus get free.
I am not sure I understand your explanations. But the trace is pretty clear:
At time -658 the timer is programmed to tick at -561.
:| # event tick@-561 -658 0.112 xntimer_next_local_shot+0xca
:| + func -651 0.145 lrtdrv_monitoring_irq+0x4
[sigmatek_lrt] (irq_hook_handler+0x32 [sigmatek_lrt])
:| + end 0x000000ef -651! 641.640 apic_timer_interrupt+0x52
(<102d0254>)
But at that point the tick is delayed for 600us. And according to the
trace, the last traced function called before that delay is the function
ltdrv_monitoring_irq.
So, I do not know what this irq is doing, but I would suggest having a
close look at it.
hello,
i have disable our lrtdrv_monitoring_irq.
Only have this callback
static void irq_hook_handler(unsigned int irq, unsigned int state)
{
if (fpga_interrupt == irq && state == 0x01)
{
time_fpga_irq = rt_timer_tsc();
}
}
same latency
regards
Johann
-------------- next part --------------
I-pipe frozen back-tracing service on 3.10.0/ipipe release #1
------------------------------------------------------------
CPU: 0, Freeze: 897546816952 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.078 us
+----- Hard IRQs ('|': locked)
|+-- Xenomai
||+- Linux ('*': domain stalled, '+': current, '#': current+stalled)
||| +---------- Delay flag ('+': > 1 us, '!': > 10 us)
||| | +- NMI noise ('N')
||| | |
Type User Val. Time Delay Function (Parent)
:| # func -700 0.222 measureIdleTime+0x9 [sigmatek_lrt]
(taskSwitchXenomai+0x9a [sigmatek_lrt])
:| # func -700 0.163 xntimer_get_overruns+0x8
(xnpod_wait_thread_period+0x93)
:| # func -700 0.136 __ipipe_restore_head+0x4
(ipipe_restore_pipeline_head+0x42)
:| + end 0x80000000 -699 0.188 hard_local_irq_enable+0x16
(__ipipe_restore_head+0x66)
:| + begin 0x80000001 -699 0.173 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x6b)
:| + end 0x80000001 -699 0.144 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0xad)
:| + begin 0x80000000 -699 0.161 hard_local_irq_disable+0x17
(__ipipe_syscall_root+0x38)
:| + end 0x80000000 -699 0.311 __ipipe_syscall_root+0x70
(sysenter_past_esp+0x5b)
: + func -698 0.118 __ipipe_syscall_root+0x5
(sysenter_past_esp+0x5b)
: + func -698 0.120 __ipipe_notify_syscall+0x9
(__ipipe_syscall_root+0x31)
:| + begin 0x80000001 -698 0.188 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x18)
:| + end 0x80000001 -698 0.126 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0x59)
: + func -698 0.120 ipipe_syscall_hook+0x7
(__ipipe_notify_syscall+0x64)
:| + begin 0x80000001 -698 0.145 hard_local_irq_save+0x16
(ipipe_syscall_hook+0x1b)
:| + end 0x80000001 -698 0.126 hard_local_irq_restore+0x15
(ipipe_syscall_hook+0x5b)
: + func -698 0.127 hisyscall_event+0x9
(ipipe_syscall_hook+0x6b)
: + func -697 0.114 __rt_task_wait_period+0x5
(hisyscall_event+0x129)
: + func -697 0.118 rt_task_wait_period+0x4
(__rt_task_wait_period+0x14)
: + func -697 0.123 xnpod_wait_thread_period+0x9
(rt_task_wait_period+0x44)
:| + begin 0x80000000 -697 0.166 hard_local_irq_disable+0x15
(__xnlock_get_irqsave.constprop.43+0x9)
:| # func -697 0.145 xnpod_suspend_thread+0x9
(xnpod_wait_thread_period+0x6c)
:| # func -697 0.167 __xnpod_schedule+0x9
(xnpod_schedule+0x32)
:| # [ 613] -<?>- 99 -697 0.117 __xnpod_schedule+0x58
(xnpod_schedule+0x32)
:| # func -696 0.291 xnsched_pick_next+0x5
(__xnpod_schedule+0xa5)
:| # func -696 0.270 __switch_to+0x9
(__xnpod_schedule+0x3b8)
:| # [ 603] cyclic: 30 -696 0.273 __xnpod_schedule+0x431
(xnpod_schedule+0x32)
:| # func -696 0.118 xnpod_fire_callouts+0x7
(__xnpod_schedule+0x4b4)
:| # func -695 0.117 taskSwitchXenomai+0x9 [sigmatek_lrt]
(xnpod_fire_callouts+0x4c)
:| # func -695 0.135 measureIdleTime+0x9 [sigmatek_lrt]
(taskSwitchXenomai+0x9a [sigmatek_lrt])
:| # func -695 0.279 xnarch_tsc_to_ns+0x6
(measureIdleTime+0xae [sigmatek_lrt])
:| +func -695 0.200 __ipipe_do_sync_pipeline+0x4
(__ipipe_dispatch_irq+0x1c1)
:| +func -695 0.163 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_handle_irq+0x10e)
:| +end 0x000000ef -695! 682.112 apic_timer_interrupt+0x52 (<102d0251>)
:| +begin 0x000000ef -12 0.145 apic_timer_interrupt+0x3a (<10139c1a>)
:| +func -12 0.158 __ipipe_handle_irq+0x7
(apic_timer_interrupt+0x41)
:| +func -12 0.114 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_handle_irq+0xc4)
:| +func -12 0.117 __ipipe_dispatch_irq+0x9
(__ipipe_handle_irq+0xce)
:| +func -12 0.132 __ipipe_ack_hrtimer_irq+0x6
(__ipipe_dispatch_irq+0xa9)
:| +func -12 0.145 lapic_itimer_ack+0x3
(__ipipe_ack_hrtimer_irq+0x59)
:| +func -12 0.170 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_dispatch_irq+0x118)
:| # func -11 0.114 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_dispatch_irq+0x172)
:| # func -11 0.216 xnintr_clock_handler+0x9
(__ipipe_dispatch_irq+0x182)
:| # func -11 0.149 xntimer_tick_aperiodic+0x9
(xnintr_clock_handler+0xb9)
:| # func -11 0.115 xnthread_periodic_handler+0x3
(xntimer_tick_aperiodic+0xa0)
:| # func -11 0.136 xnpod_resume_thread+0x9
(xnthread_periodic_handler+0x20)
:| # [ 613] -<?>- 99 -11 0.273 xnpod_resume_thread+0x39
(xnthread_periodic_handler+0x20)
:| # func -10 0.135 xntimer_next_local_shot+0x9
(xntimer_tick_aperiodic+0x177)
:| # event tick@-5 -10 0.112 xntimer_next_local_shot+0xca
(xntimer_tick_aperiodic+0x177)
:| # func -10 0.133 ipipe_timer_set+0x5
(xntimer_next_local_shot+0xd1)
:| # func -10 0.253 lapic_next_deadline+0x5
(ipipe_timer_set+0x67)
:| # func -10 0.176 __xnpod_schedule+0x9
(xnpod_schedule+0x32)
:| # [ 603] cyclic: 30 -10 0.120 __xnpod_schedule+0x58
(xnpod_schedule+0x32)
:| # func -10 0.135 xnsched_pick_next+0x5
(__xnpod_schedule+0xa5)
:| # func -9 0.366 __ipipe_notify_vm_preemption+0x4
(__xnpod_schedule+0x141)
:| # func -9 0.302 __switch_to+0x9
(__xnpod_schedule+0x3b8)
:| # [ 613] -<?>- 99 -9 0.195 __xnpod_schedule+0x431
(xnpod_schedule+0x32)
:| # func -9 0.121 xnpod_fire_callouts+0x7
(__xnpod_schedule+0x4b4)
:| # func -8 0.144 taskSwitchXenomai+0x9 [sigmatek_lrt]
(xnpod_fire_callouts+0x4c)
:| # func -8 0.221 measureIdleTime+0x9 [sigmatek_lrt]
(taskSwitchXenomai+0x9a [sigmatek_lrt])
:| # func -8 0.237 xntimer_get_overruns+0x8
(xnpod_wait_thread_period+0x93)
:| # func -8 0.149 __ipipe_restore_head+0x4
(ipipe_restore_pipeline_head+0x42)
:| + end 0x80000000 -8 0.194 hard_local_irq_enable+0x16
(__ipipe_restore_head+0x66)
:| + begin 0x80000001 -7 0.182 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x6b)
:| + end 0x80000001 -7 0.158 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0xad)
:| + begin 0x80000000 -7 0.160 hard_local_irq_disable+0x17
(__ipipe_syscall_root+0x38)
:| + end 0x80000000 -7+ 1.064 __ipipe_syscall_root+0x70
(sysenter_past_esp+0x5b)
: + func -6 0.126 __ipipe_syscall_root+0x5
(sysenter_past_esp+0x5b)
: + func -6 0.130 __ipipe_notify_syscall+0x9
(__ipipe_syscall_root+0x31)
:| + begin 0x80000001 -6 0.187 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x18)
:| + end 0x80000001 -5 0.127 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0x59)
: + func -5 0.120 ipipe_syscall_hook+0x7
(__ipipe_notify_syscall+0x64)
:| + begin 0x80000001 -5 0.145 hard_local_irq_save+0x16
(ipipe_syscall_hook+0x1b)
:| + end 0x80000001 -5 0.126 hard_local_irq_restore+0x15
(ipipe_syscall_hook+0x5b)
: + func -5 0.288 hisyscall_event+0x9
(ipipe_syscall_hook+0x6b)
: + func -5 0.242 xnshadow_sys_trace+0x6
(hisyscall_event+0x129)
: + func -4 0.368 ipipe_trace_frozen_reset+0x5
(xnshadow_sys_trace+0x5e)
:| + begin 0x000000ef -4 0.155 apic_timer_interrupt+0x3a
(__ipipe_global_path_lock+0x0)
:| + func -4 0.160 __ipipe_handle_irq+0x7
(apic_timer_interrupt+0x41)
:| + func -4 0.117 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_handle_irq+0xc4)
:| + func -4 0.117 __ipipe_dispatch_irq+0x9
(__ipipe_handle_irq+0xce)
:| + func -3 0.138 __ipipe_ack_hrtimer_irq+0x6
(__ipipe_dispatch_irq+0xa9)
:| + func -3 0.141 lapic_itimer_ack+0x3
(__ipipe_ack_hrtimer_irq+0x59)
:| + func -3 0.154 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_dispatch_irq+0x118)
:| # func -3 0.126 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_dispatch_irq+0x172)
:| # func -3 0.234 xnintr_clock_handler+0x9
(__ipipe_dispatch_irq+0x182)
:| # func -3 0.559 __xnlock_spin+0x4 (__xnlock_get+0x2b)
:| # func -2 0.136 xntimer_tick_aperiodic+0x9
(xnintr_clock_handler+0xb9)
:| # func -2 0.176 xnthread_periodic_handler+0x3
(xntimer_tick_aperiodic+0xa0)
:| # func -2 0.136 xntimer_next_local_shot+0x9
(xntimer_tick_aperiodic+0x177)
:| # event tick@94 -2 0.112 xntimer_next_local_shot+0xca
(xntimer_tick_aperiodic+0x177)
:| # func -2 0.133 ipipe_timer_set+0x5
(xntimer_next_local_shot+0xd1)
:| # func -1 0.356 lapic_next_deadline+0x5
(ipipe_timer_set+0x67)
:| + func -1 0.144 irq_hook_handler+0x3 [sigmatek_lrt]
(__ipipe_handle_irq+0x10e)
:| + end 0x000000ef -1 0.201 apic_timer_interrupt+0x52
(__ipipe_global_path_lock+0x0)
: + func -1 0.132 __ipipe_global_path_lock+0x7
(ipipe_trace_frozen_reset+0x14)
: + func -1 0.136 __ipipe_spin_lock_irqsave+0x6
(__ipipe_global_path_lock+0x16)
:| + begin 0x80000001 0 0.657 hard_local_irq_save+0x16
(__ipipe_spin_lock_irqsave+0x12)
:| # func 0 0.148 __ipipe_spin_unlock_irqcomplete+0x4
(__ipipe_global_path_unlock+0x5f)
:| + end 0x80000001 0 0.166 hard_local_irq_restore+0x15
(__ipipe_spin_unlock_irqcomplete+0x25)
< + freeze 0x00091117 0 0.179 xnshadow_sys_trace+0x67
(hisyscall_event+0x129)
| + begin 0x80000001 0 0.187 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x6b)
| + end 0x80000001 0 0.149 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0xad)
| + begin 0x80000000 0 0.170 hard_local_irq_disable+0x17
(__ipipe_syscall_root+0x38)
| + end 0x80000000 0 0.218 __ipipe_syscall_root+0x70
(sysenter_past_esp+0x5b)
+ func 0 0.130 __ipipe_syscall_root+0x5
(sysenter_past_esp+0x5b)
+ func 1 0.132 __ipipe_notify_syscall+0x9
(__ipipe_syscall_root+0x31)
| + begin 0x80000001 1 0.176 hard_local_irq_save+0x16
(__ipipe_notify_syscall+0x18)
| + end 0x80000001 1 0.126 hard_local_irq_restore+0x15
(__ipipe_notify_syscall+0x59)
+ func 1 0.138 ipipe_syscall_hook+0x7
(__ipipe_notify_syscall+0x64)
| + begin 0x80000001 1 0.000 hard_local_irq_save+0x16
(ipipe_syscall_hook+0x1b)
_______________________________________________
Xenomai mailing list
[email protected]
http://xenomai.org/mailman/listinfo/xenomai
