Hello and thank you for the answer. It worked.
Here is a test of rtt-responder on qemu. I also attached it to this email.
I use the ipipe-trace api to freeze tracing from C code.
I see that rtdm_fd_recvmsg and rtdm_fd_sendmsg are called
(and I wanted to see that).
I have some questions (I have some ideas but just want to be sure).
Please answer to those that are important.
1. On Hard IRQs column, I see only ':' and space; what do they mean?
What does mean ('|': locked) from Hard IRQs?
2. On Xenomai column I see only '|' and space; what do they mean?
3. What does the following column mean:
Linux ('*': domain stalled, '+': current, '#': current+stalled)
4. Type 'func' I think it means a function is called; correct?
What do 'begin' and 'end' mean on the Type column? Are they important?
5. NMI noise 'N' ?
I-pipe frozen back-tracing service on 4.14.71/ipipe release #2112
------------------------------------------------------------
CPU: 0, Freeze: 1176197529135 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.074 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 -27 0.574 xnsynch_wakeup_one_sleeper+0x0
(rtdm_sem_up+0xed)
:|# func -26 0.406 xnthread_resume+0x0
(xnsynch_wakeup_one_sleeper+0x14a)
:|# [ 121] rtt-res 81 -26 0.184 xnthread_resume+0x113 (<00000000>)
:|# func -26 0.149 xnsched_rt_enqueue+0x0
(xnthread_resume+0x14f)
:|# func -26 0.335 xnsched_addq_tail+0x0
(xnthread_resume+0x14f)
:|# func -25 0.185 ___xnsched_run+0x0 (rtdm_sem_up+0x18d)
:|# func -25 0.202 ___xnsched_run.part.63+0x0
(rtdm_sem_up+0x18d)
:|# [ 100] rtnet-s 98 -25 0.165 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -25 0.207 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -25 0.160 xnsched_rt_requeue+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.193 xnsched_addq+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.165 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -24 0.200 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -24 0.198 xnlock_dbg_release+0x0
(rtdm_sem_up+0x1b2)
:|# func -24 0.156 __ipipe_restore_head+0x0
(rtdm_sem_up+0x14c)
:|+ end 0x80000000 -23 0.142 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -23 0.193 rt_udp_rcv+0xe4 [rtudp] (<00000000>)
:|# func -23 0.156 xnsched_lock+0x0
(rt_udp_rcv+0x11c [rtudp])
:|# func -23 0.185 xnsched_unlock+0x0
(rt_udp_rcv+0x136 [rtudp])
:|# func -23 0.156 __ipipe_restore_head+0x0
(rt_udp_rcv+0x15a [rtudp])
:|+ end 0x80000000 -23 0.209 __ipipe_restore_head+0x4d (<00000000>)
: + func -22 0.153 rtdm_fd_unlock+0x0
(rt_ip_rcv+0x15a [rtipv4])
:|+ begin 0x80000000 -22 0.189 rtdm_fd_unlock+0x22 (<00000000>)
:|# func -22 0.160 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_unlock+0x54)
:|# func -22 0.193 xnlock_dbg_acquired+0x0
(rtdm_fd_unlock+0x92)
:|# func -22 0.169 __put_fd+0x0 (rtdm_fd_unlock+0xa4)
:|# func -22 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -21 0.158 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -21 0.169 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -21 0.191 rt_stack_deliver+0x293 [rtnet]
(<00000000>)
:|# func -21 0.267 xnsched_lock+0x0
(rt_stack_deliver+0x2c8 [rtnet])
:|# func -21 0.313 module_put+0x0
(rt_stack_deliver+0x2d4 [rtnet])
:|# func -20 0.225 xnsched_unlock+0x0
(rt_stack_deliver+0x2e8 [rtnet])
:|# func -20 0.153 __ipipe_restore_head+0x0
(rt_stack_mgr_task+0x6b [rtnet])
:|+ end 0x80000000 -20 0.184 __ipipe_restore_head+0x4d (<00000000>)
: + func -20 0.162 rtdm_event_wait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
: + func -20 0.236 rtdm_event_timedwait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
:|+ begin 0x80000000 -19 0.194 rtdm_event_timedwait+0xb1 (<00000000>)
:|# func -19 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_event_timedwait+0xed)
:|# func -19 0.200 xnlock_dbg_acquired+0x0
(rtdm_event_timedwait+0x131)
:|# func -19 0.344 xnsynch_sleep_on+0x0
(rtdm_event_timedwait+0x316)
:|# func -18 0.315 xnthread_suspend+0x0
(xnsynch_sleep_on+0x221)
:|# func -18 0.185 ___xnsched_run+0x0
(xnthread_suspend+0x4cc)
:|# func -18 0.169 ___xnsched_run.part.63+0x0
(xnthread_suspend+0x4cc)
:|# [ 100] rtnet-s 98 -18 0.154 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -18 0.184 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -17 0.156 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -17 0.300 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -17 0.153 xnarch_switch_to+0x0
(___xnsched_run.part.63+0x22b)
:|# func -17 0.395 switch_mm_irqs_off+0x0
(xnarch_switch_to+0x2a)
:|# func -16+ 1.268 __phys_addr+0x0
(switch_mm_irqs_off+0x1c7)
:|# func -15 0.149 xnthread_switch_fpu+0x0
(___xnsched_run.part.63+0x290)
:|# func -15 0.209 xnarch_switch_fpu+0x0
(xnthread_switch_fpu+0x26)
:|# [ 121] rtt-res 81 -15 0.517 ___xnsched_run.part.63+0x2ad
(<00000000>)
:|# func -14 0.182 xnlock_dbg_release+0x0
(rtdm_sem_timeddown+0x239)
:|# func -14 0.154 __ipipe_restore_head+0x0
(rtdm_sem_timeddown+0x1ab)
:|+ end 0x80000000 -14 0.242 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -14 0.193 rt_udp_recvmsg+0x105 [rtudp]
(<00000000>)
:|# func -14 0.165 xnsched_lock+0x0
(rt_udp_recvmsg+0x14b [rtudp])
:|# func -13 0.222 xnsched_unlock+0x0
(rt_udp_recvmsg+0x178 [rtudp])
:|# func -13 0.164 __ipipe_restore_head+0x0
(rt_udp_recvmsg+0x1ad [rtudp])
:|+ end 0x80000000 -13 0.151 __ipipe_restore_head+0x4d (<00000000>)
: + func -13 0.874 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x200 [rtudp])
: + func -12 0.278 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x330 [rtudp])
: + func -12 0.291 rtdm_get_iov_flatlen+0x0
(rt_udp_recvmsg+0x37e [rtudp])
: + func -11 0.171 rtnet_write_to_iov+0x0 [rtnet]
(rt_udp_recvmsg+0x414 [rtudp])
: + func -11 0.335 rtnet_put_arg+0x0 [rtnet]
(rtnet_write_to_iov+0x86 [rtnet])
: + func -11 0.147 kfree_rtskb+0x0 [rtnet]
(rt_udp_recvmsg+0x21e [rtudp])
:|+ begin 0x80000000 -11 0.193 kfree_rtskb+0xb2 [rtnet] (<00000000>)
:|# func -11 0.180 xnsched_lock+0x0
(kfree_rtskb+0xe2 [rtnet])
:|# func -10 0.196 xnsched_unlock+0x0
(kfree_rtskb+0xfc [rtnet])
:|# func -10 0.169 __ipipe_restore_head+0x0
(kfree_rtskb+0x12f [rtnet])
:|+ end 0x80000000 -10 0.162 __ipipe_restore_head+0x4d (<00000000>)
: + func -10 0.153 rtskb_pool_queue_tail+0x0
[rtnet] (kfree_rtskb+0x13f [rtnet])
:|+ begin 0x80000000 -10 0.191 rtskb_pool_queue_tail+0x23
[rtnet] (<00000000>)
:|# func -9 0.209 xnsched_lock+0x0
(rtskb_pool_queue_tail+0x5c [rtnet])
:|# func -9 0.149 rtskb_nop_pool_unlock+0x0
[rtnet] (rtskb_pool_queue_tail+0x89 [rtnet])
:|# func -9 0.209 xnsched_unlock+0x0
(rtskb_pool_queue_tail+0x92 [rtnet])
:|# func -9 0.154 __ipipe_restore_head+0x0
(kfree_rtskb+0x13f [rtnet])
:|+ end 0x80000000 -9 0.278 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -8 0.184 rtdm_fd_recvmsg+0x174 (<00000000>)
:|+ end 0x80000001 -8 0.174 rtdm_fd_recvmsg+0x18d (<00000000>)
: + func -8 0.164 rtdm_fd_put+0x0 (rtdm_fd_recvmsg+0x147)
:|+ begin 0x80000000 -8 0.184 rtdm_fd_put+0x22 (<00000000>)
:|# func -8 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_put+0x54)
:|# func -8 0.153 xnlock_dbg_acquired+0x0
(rtdm_fd_put+0x92)
:|# func -7 0.154 __put_fd+0x0 (rtdm_fd_put+0x9d)
:|# func -7 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -7 0.156 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -7 0.284 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -7 0.173 CoBaLt_recvmsg+0x172 (<00000000>)
:|+ end 0x80000001 -6+ 1.188 CoBaLt_recvmsg+0x18d (<00000000>)
:|+ begin 0x80000000 -5+ 3.917 do_syscall_64+0x57 (<00000000>)
:|+ func -1 0.471 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
:|+ end 0x80000000 -1 0.171 do_syscall_64+0x14f (<00000000>)
: + func -1 0.238 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
: + func -1 0.194 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
: + func 0 0.553 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
: + func 0 0.258 CoBaLt_trace+0x0
(handle_head_syscall+0x100)
< + freeze 0x0000000f 0 0.404 CoBaLt_trace+0xdd (<00000000>)
|+ begin 0x80000000 0 1.275 do_syscall_64+0x57 (<00000000>)
|+ func 1 0.377 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
|+ end 0x80000000 2 0.162 do_syscall_64+0x14f (<00000000>)
+ func 2 0.158 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
+ func 2 0.151 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
+ func 2 0.240 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
+ func 2 0.156 CoBaLt_sendmsg+0x0
(handle_head_syscall+0x100)
|+ begin 0x80000001 2 0.162 CoBaLt_sendmsg+0x9b (<00000000>)
|+ end 0x80000001 3 0.293 CoBaLt_sendmsg+0xb5 (<00000000>)
+ func 3 0.000 rtdm_fd_sendmsg+0x0
(CoBaLt_sendmsg+0x7c)
On 8/28/19, Jan Kiszka <jan.kis...@siemens.com> wrote:
> On 28.08.19 10:11, Laurentiu-Cristian Duca via Xenomai wrote:
>> Hello there,
>>
>> I want to use ipipe tracer for tracing RTNet drivers.
>> In the tutorial
>> https://gitlab.denx.de/Xenomai/xenomai/wikis/Using_The_I_Pipe_Tracer
>> it does not specify which file to "cat" in order to view the function
>> traces
>> so if anybody used it please provide this info.
>> How to view the traced data?
>>
>
> cat .../frozen or .../max
>
> Jan
>
> --
> Siemens AG, Corporate Technology, CT RDA IOT SES-DE
> Corporate Competence Center Embedded Linux
>
-------------- next part --------------
Here is a test of rtt-responder on qemu.
I use the ipipe-trace api to freeze trancing from C code.
I see that rtdm_fd_recvmsg and rtdm_fd_sendmsg are called
(and I wanted to see that).
I have some questions (I have some ideas but just want to be sure).
Please answer to those that have relevance.
1. On Hard IRQs column, I see only ':' and space; what do they mean?
What does mean Hard IRQs ('|': locked) ?
2. On Xenomai column I see only '|' and space; what do they mean?
3. What does the following column mean:
Linux ('*': domain stalled, '+': current, '#': current+stalled)
4. Type 'func' I think it means a function is called; correct?
What do 'begin' and 'end' mean on the Type column? Are they important?
5. NMI noise 'N' ?
I-pipe frozen back-tracing service on 4.14.71/ipipe release #2112
------------------------------------------------------------
CPU: 0, Freeze: 1176197529135 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.074 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 -27 0.574 xnsynch_wakeup_one_sleeper+0x0
(rtdm_sem_up+0xed)
:|# func -26 0.406 xnthread_resume+0x0
(xnsynch_wakeup_one_sleeper+0x14a)
:|# [ 121] rtt-res 81 -26 0.184 xnthread_resume+0x113 (<00000000>)
:|# func -26 0.149 xnsched_rt_enqueue+0x0
(xnthread_resume+0x14f)
:|# func -26 0.335 xnsched_addq_tail+0x0
(xnthread_resume+0x14f)
:|# func -25 0.185 ___xnsched_run+0x0 (rtdm_sem_up+0x18d)
:|# func -25 0.202 ___xnsched_run.part.63+0x0
(rtdm_sem_up+0x18d)
:|# [ 100] rtnet-s 98 -25 0.165 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -25 0.207 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -25 0.160 xnsched_rt_requeue+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.193 xnsched_addq+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.165 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -24 0.200 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -24 0.198 xnlock_dbg_release+0x0
(rtdm_sem_up+0x1b2)
:|# func -24 0.156 __ipipe_restore_head+0x0
(rtdm_sem_up+0x14c)
:|+ end 0x80000000 -23 0.142 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -23 0.193 rt_udp_rcv+0xe4 [rtudp] (<00000000>)
:|# func -23 0.156 xnsched_lock+0x0 (rt_udp_rcv+0x11c
[rtudp])
:|# func -23 0.185 xnsched_unlock+0x0 (rt_udp_rcv+0x136
[rtudp])
:|# func -23 0.156 __ipipe_restore_head+0x0
(rt_udp_rcv+0x15a [rtudp])
:|+ end 0x80000000 -23 0.209 __ipipe_restore_head+0x4d (<00000000>)
: + func -22 0.153 rtdm_fd_unlock+0x0 (rt_ip_rcv+0x15a
[rtipv4])
:|+ begin 0x80000000 -22 0.189 rtdm_fd_unlock+0x22 (<00000000>)
:|# func -22 0.160 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_unlock+0x54)
:|# func -22 0.193 xnlock_dbg_acquired+0x0
(rtdm_fd_unlock+0x92)
:|# func -22 0.169 __put_fd+0x0 (rtdm_fd_unlock+0xa4)
:|# func -22 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -21 0.158 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -21 0.169 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -21 0.191 rt_stack_deliver+0x293 [rtnet]
(<00000000>)
:|# func -21 0.267 xnsched_lock+0x0
(rt_stack_deliver+0x2c8 [rtnet])
:|# func -21 0.313 module_put+0x0 (rt_stack_deliver+0x2d4
[rtnet])
:|# func -20 0.225 xnsched_unlock+0x0
(rt_stack_deliver+0x2e8 [rtnet])
:|# func -20 0.153 __ipipe_restore_head+0x0
(rt_stack_mgr_task+0x6b [rtnet])
:|+ end 0x80000000 -20 0.184 __ipipe_restore_head+0x4d (<00000000>)
: + func -20 0.162 rtdm_event_wait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
: + func -20 0.236 rtdm_event_timedwait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
:|+ begin 0x80000000 -19 0.194 rtdm_event_timedwait+0xb1 (<00000000>)
:|# func -19 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_event_timedwait+0xed)
:|# func -19 0.200 xnlock_dbg_acquired+0x0
(rtdm_event_timedwait+0x131)
:|# func -19 0.344 xnsynch_sleep_on+0x0
(rtdm_event_timedwait+0x316)
:|# func -18 0.315 xnthread_suspend+0x0
(xnsynch_sleep_on+0x221)
:|# func -18 0.185 ___xnsched_run+0x0
(xnthread_suspend+0x4cc)
:|# func -18 0.169 ___xnsched_run.part.63+0x0
(xnthread_suspend+0x4cc)
:|# [ 100] rtnet-s 98 -18 0.154 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -18 0.184 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -17 0.156 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -17 0.300 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -17 0.153 xnarch_switch_to+0x0
(___xnsched_run.part.63+0x22b)
:|# func -17 0.395 switch_mm_irqs_off+0x0
(xnarch_switch_to+0x2a)
:|# func -16+ 1.268 __phys_addr+0x0
(switch_mm_irqs_off+0x1c7)
:|# func -15 0.149 xnthread_switch_fpu+0x0
(___xnsched_run.part.63+0x290)
:|# func -15 0.209 xnarch_switch_fpu+0x0
(xnthread_switch_fpu+0x26)
:|# [ 121] rtt-res 81 -15 0.517 ___xnsched_run.part.63+0x2ad
(<00000000>)
:|# func -14 0.182 xnlock_dbg_release+0x0
(rtdm_sem_timeddown+0x239)
:|# func -14 0.154 __ipipe_restore_head+0x0
(rtdm_sem_timeddown+0x1ab)
:|+ end 0x80000000 -14 0.242 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -14 0.193 rt_udp_recvmsg+0x105 [rtudp]
(<00000000>)
:|# func -14 0.165 xnsched_lock+0x0 (rt_udp_recvmsg+0x14b
[rtudp])
:|# func -13 0.222 xnsched_unlock+0x0
(rt_udp_recvmsg+0x178 [rtudp])
:|# func -13 0.164 __ipipe_restore_head+0x0
(rt_udp_recvmsg+0x1ad [rtudp])
:|+ end 0x80000000 -13 0.151 __ipipe_restore_head+0x4d (<00000000>)
: + func -13 0.874 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x200 [rtudp])
: + func -12 0.278 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x330 [rtudp])
: + func -12 0.291 rtdm_get_iov_flatlen+0x0
(rt_udp_recvmsg+0x37e [rtudp])
: + func -11 0.171 rtnet_write_to_iov+0x0 [rtnet]
(rt_udp_recvmsg+0x414 [rtudp])
: + func -11 0.335 rtnet_put_arg+0x0 [rtnet]
(rtnet_write_to_iov+0x86 [rtnet])
: + func -11 0.147 kfree_rtskb+0x0 [rtnet]
(rt_udp_recvmsg+0x21e [rtudp])
:|+ begin 0x80000000 -11 0.193 kfree_rtskb+0xb2 [rtnet] (<00000000>)
:|# func -11 0.180 xnsched_lock+0x0 (kfree_rtskb+0xe2
[rtnet])
:|# func -10 0.196 xnsched_unlock+0x0 (kfree_rtskb+0xfc
[rtnet])
:|# func -10 0.169 __ipipe_restore_head+0x0
(kfree_rtskb+0x12f [rtnet])
:|+ end 0x80000000 -10 0.162 __ipipe_restore_head+0x4d (<00000000>)
: + func -10 0.153 rtskb_pool_queue_tail+0x0 [rtnet]
(kfree_rtskb+0x13f [rtnet])
:|+ begin 0x80000000 -10 0.191 rtskb_pool_queue_tail+0x23 [rtnet]
(<00000000>)
:|# func -9 0.209 xnsched_lock+0x0
(rtskb_pool_queue_tail+0x5c [rtnet])
:|# func -9 0.149 rtskb_nop_pool_unlock+0x0 [rtnet]
(rtskb_pool_queue_tail+0x89 [rtnet])
:|# func -9 0.209 xnsched_unlock+0x0
(rtskb_pool_queue_tail+0x92 [rtnet])
:|# func -9 0.154 __ipipe_restore_head+0x0
(kfree_rtskb+0x13f [rtnet])
:|+ end 0x80000000 -9 0.278 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -8 0.184 rtdm_fd_recvmsg+0x174 (<00000000>)
:|+ end 0x80000001 -8 0.174 rtdm_fd_recvmsg+0x18d (<00000000>)
: + func -8 0.164 rtdm_fd_put+0x0 (rtdm_fd_recvmsg+0x147)
:|+ begin 0x80000000 -8 0.184 rtdm_fd_put+0x22 (<00000000>)
:|# func -8 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_put+0x54)
:|# func -8 0.153 xnlock_dbg_acquired+0x0
(rtdm_fd_put+0x92)
:|# func -7 0.154 __put_fd+0x0 (rtdm_fd_put+0x9d)
:|# func -7 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -7 0.156 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -7 0.284 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -7 0.173 CoBaLt_recvmsg+0x172 (<00000000>)
:|+ end 0x80000001 -6+ 1.188 CoBaLt_recvmsg+0x18d (<00000000>)
:|+ begin 0x80000000 -5+ 3.917 do_syscall_64+0x57 (<00000000>)
:|+ func -1 0.471 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
:|+ end 0x80000000 -1 0.171 do_syscall_64+0x14f (<00000000>)
: + func -1 0.238 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
: + func -1 0.194 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
: + func 0 0.553 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
: + func 0 0.258 CoBaLt_trace+0x0
(handle_head_syscall+0x100)
< + freeze 0x0000000f 0 0.404 CoBaLt_trace+0xdd (<00000000>)
|+ begin 0x80000000 0 1.275 do_syscall_64+0x57 (<00000000>)
|+ func 1 0.377 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
|+ end 0x80000000 2 0.162 do_syscall_64+0x14f (<00000000>)
+ func 2 0.158 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
+ func 2 0.151 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
+ func 2 0.240 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
+ func 2 0.156 CoBaLt_sendmsg+0x0
(handle_head_syscall+0x100)
|+ begin 0x80000001 2 0.162 CoBaLt_sendmsg+0x9b (<00000000>)
|+ end 0x80000001 3 0.293 CoBaLt_sendmsg+0xb5 (<00000000>)
+ func 3 0.000 rtdm_fd_sendmsg+0x0
(CoBaLt_sendmsg+0x7c)
-------------- next part --------------
Here is a test of rtt-responder on qemu.
I use the ipipe-trace api to freeze trancing from C code.
I see that rtdm_fd_recvmsg and rtdm_fd_sendmsg are called
(and I wanted to see that).
I have some questions (I have some ideas but just want to be sure).
Please answer to those that have relevance.
1. On Hard IRQs column, I see only ':' and space; what do they mean?
What does mean ('|': locked) from Hard IRQs?
2. On Xenomai column I see only '|' and space; what do they mean?
3. What does the following column mean:
Linux ('*': domain stalled, '+': current, '#': current+stalled)
4. Type 'func' I think it means a function is called; correct?
What do 'begin' and 'end' mean on the Type column? Are they important?
5. NMI noise 'N' ?
I-pipe frozen back-tracing service on 4.14.71/ipipe release #2112
------------------------------------------------------------
CPU: 0, Freeze: 1176197529135 cycles, Trace Points: 100 (+10)
Calibrated minimum trace-point overhead: 0.074 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 -27 0.574 xnsynch_wakeup_one_sleeper+0x0
(rtdm_sem_up+0xed)
:|# func -26 0.406 xnthread_resume+0x0
(xnsynch_wakeup_one_sleeper+0x14a)
:|# [ 121] rtt-res 81 -26 0.184 xnthread_resume+0x113 (<00000000>)
:|# func -26 0.149 xnsched_rt_enqueue+0x0
(xnthread_resume+0x14f)
:|# func -26 0.335 xnsched_addq_tail+0x0
(xnthread_resume+0x14f)
:|# func -25 0.185 ___xnsched_run+0x0 (rtdm_sem_up+0x18d)
:|# func -25 0.202 ___xnsched_run.part.63+0x0
(rtdm_sem_up+0x18d)
:|# [ 100] rtnet-s 98 -25 0.165 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -25 0.207 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -25 0.160 xnsched_rt_requeue+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.193 xnsched_addq+0x0
(xnsched_pick_next+0x56)
:|# func -24 0.165 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -24 0.200 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -24 0.198 xnlock_dbg_release+0x0
(rtdm_sem_up+0x1b2)
:|# func -24 0.156 __ipipe_restore_head+0x0
(rtdm_sem_up+0x14c)
:|+ end 0x80000000 -23 0.142 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -23 0.193 rt_udp_rcv+0xe4 [rtudp] (<00000000>)
:|# func -23 0.156 xnsched_lock+0x0 (rt_udp_rcv+0x11c
[rtudp])
:|# func -23 0.185 xnsched_unlock+0x0 (rt_udp_rcv+0x136
[rtudp])
:|# func -23 0.156 __ipipe_restore_head+0x0
(rt_udp_rcv+0x15a [rtudp])
:|+ end 0x80000000 -23 0.209 __ipipe_restore_head+0x4d (<00000000>)
: + func -22 0.153 rtdm_fd_unlock+0x0 (rt_ip_rcv+0x15a
[rtipv4])
:|+ begin 0x80000000 -22 0.189 rtdm_fd_unlock+0x22 (<00000000>)
:|# func -22 0.160 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_unlock+0x54)
:|# func -22 0.193 xnlock_dbg_acquired+0x0
(rtdm_fd_unlock+0x92)
:|# func -22 0.169 __put_fd+0x0 (rtdm_fd_unlock+0xa4)
:|# func -22 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -21 0.158 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -21 0.169 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -21 0.191 rt_stack_deliver+0x293 [rtnet]
(<00000000>)
:|# func -21 0.267 xnsched_lock+0x0
(rt_stack_deliver+0x2c8 [rtnet])
:|# func -21 0.313 module_put+0x0 (rt_stack_deliver+0x2d4
[rtnet])
:|# func -20 0.225 xnsched_unlock+0x0
(rt_stack_deliver+0x2e8 [rtnet])
:|# func -20 0.153 __ipipe_restore_head+0x0
(rt_stack_mgr_task+0x6b [rtnet])
:|+ end 0x80000000 -20 0.184 __ipipe_restore_head+0x4d (<00000000>)
: + func -20 0.162 rtdm_event_wait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
: + func -20 0.236 rtdm_event_timedwait+0x0
(rt_stack_mgr_task+0x2c [rtnet])
:|+ begin 0x80000000 -19 0.194 rtdm_event_timedwait+0xb1 (<00000000>)
:|# func -19 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_event_timedwait+0xed)
:|# func -19 0.200 xnlock_dbg_acquired+0x0
(rtdm_event_timedwait+0x131)
:|# func -19 0.344 xnsynch_sleep_on+0x0
(rtdm_event_timedwait+0x316)
:|# func -18 0.315 xnthread_suspend+0x0
(xnsynch_sleep_on+0x221)
:|# func -18 0.185 ___xnsched_run+0x0
(xnthread_suspend+0x4cc)
:|# func -18 0.169 ___xnsched_run.part.63+0x0
(xnthread_suspend+0x4cc)
:|# [ 100] rtnet-s 98 -18 0.154 ___xnsched_run.part.63+0x102
(<00000000>)
:|# func -18 0.184 xnsched_pick_next+0x0
(___xnsched_run.part.63+0x137)
:|# func -17 0.156 xnsched_rt_pick+0x0
(xnsched_pick_next+0x8b)
:|# func -17 0.300 del_q+0x0 (xnsched_rt_pick+0x5a)
:|# func -17 0.153 xnarch_switch_to+0x0
(___xnsched_run.part.63+0x22b)
:|# func -17 0.395 switch_mm_irqs_off+0x0
(xnarch_switch_to+0x2a)
:|# func -16+ 1.268 __phys_addr+0x0
(switch_mm_irqs_off+0x1c7)
:|# func -15 0.149 xnthread_switch_fpu+0x0
(___xnsched_run.part.63+0x290)
:|# func -15 0.209 xnarch_switch_fpu+0x0
(xnthread_switch_fpu+0x26)
:|# [ 121] rtt-res 81 -15 0.517 ___xnsched_run.part.63+0x2ad
(<00000000>)
:|# func -14 0.182 xnlock_dbg_release+0x0
(rtdm_sem_timeddown+0x239)
:|# func -14 0.154 __ipipe_restore_head+0x0
(rtdm_sem_timeddown+0x1ab)
:|+ end 0x80000000 -14 0.242 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000000 -14 0.193 rt_udp_recvmsg+0x105 [rtudp]
(<00000000>)
:|# func -14 0.165 xnsched_lock+0x0 (rt_udp_recvmsg+0x14b
[rtudp])
:|# func -13 0.222 xnsched_unlock+0x0
(rt_udp_recvmsg+0x178 [rtudp])
:|# func -13 0.164 __ipipe_restore_head+0x0
(rt_udp_recvmsg+0x1ad [rtudp])
:|+ end 0x80000000 -13 0.151 __ipipe_restore_head+0x4d (<00000000>)
: + func -13 0.874 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x200 [rtudp])
: + func -12 0.278 rtnet_put_arg+0x0 [rtnet]
(rt_udp_recvmsg+0x330 [rtudp])
: + func -12 0.291 rtdm_get_iov_flatlen+0x0
(rt_udp_recvmsg+0x37e [rtudp])
: + func -11 0.171 rtnet_write_to_iov+0x0 [rtnet]
(rt_udp_recvmsg+0x414 [rtudp])
: + func -11 0.335 rtnet_put_arg+0x0 [rtnet]
(rtnet_write_to_iov+0x86 [rtnet])
: + func -11 0.147 kfree_rtskb+0x0 [rtnet]
(rt_udp_recvmsg+0x21e [rtudp])
:|+ begin 0x80000000 -11 0.193 kfree_rtskb+0xb2 [rtnet] (<00000000>)
:|# func -11 0.180 xnsched_lock+0x0 (kfree_rtskb+0xe2
[rtnet])
:|# func -10 0.196 xnsched_unlock+0x0 (kfree_rtskb+0xfc
[rtnet])
:|# func -10 0.169 __ipipe_restore_head+0x0
(kfree_rtskb+0x12f [rtnet])
:|+ end 0x80000000 -10 0.162 __ipipe_restore_head+0x4d (<00000000>)
: + func -10 0.153 rtskb_pool_queue_tail+0x0 [rtnet]
(kfree_rtskb+0x13f [rtnet])
:|+ begin 0x80000000 -10 0.191 rtskb_pool_queue_tail+0x23 [rtnet]
(<00000000>)
:|# func -9 0.209 xnsched_lock+0x0
(rtskb_pool_queue_tail+0x5c [rtnet])
:|# func -9 0.149 rtskb_nop_pool_unlock+0x0 [rtnet]
(rtskb_pool_queue_tail+0x89 [rtnet])
:|# func -9 0.209 xnsched_unlock+0x0
(rtskb_pool_queue_tail+0x92 [rtnet])
:|# func -9 0.154 __ipipe_restore_head+0x0
(kfree_rtskb+0x13f [rtnet])
:|+ end 0x80000000 -9 0.278 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -8 0.184 rtdm_fd_recvmsg+0x174 (<00000000>)
:|+ end 0x80000001 -8 0.174 rtdm_fd_recvmsg+0x18d (<00000000>)
: + func -8 0.164 rtdm_fd_put+0x0 (rtdm_fd_recvmsg+0x147)
:|+ begin 0x80000000 -8 0.184 rtdm_fd_put+0x22 (<00000000>)
:|# func -8 0.154 xnlock_dbg_prepare_acquire+0x0
(rtdm_fd_put+0x54)
:|# func -8 0.153 xnlock_dbg_acquired+0x0
(rtdm_fd_put+0x92)
:|# func -7 0.154 __put_fd+0x0 (rtdm_fd_put+0x9d)
:|# func -7 0.180 xnlock_dbg_release+0x0 (__put_fd+0xa8)
:|# func -7 0.156 __ipipe_restore_head+0x0
(__put_fd+0x6f)
:|+ end 0x80000000 -7 0.284 __ipipe_restore_head+0x4d (<00000000>)
:|+ begin 0x80000001 -7 0.173 CoBaLt_recvmsg+0x172 (<00000000>)
:|+ end 0x80000001 -6+ 1.188 CoBaLt_recvmsg+0x18d (<00000000>)
:|+ begin 0x80000000 -5+ 3.917 do_syscall_64+0x57 (<00000000>)
:|+ func -1 0.471 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
:|+ end 0x80000000 -1 0.171 do_syscall_64+0x14f (<00000000>)
: + func -1 0.238 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
: + func -1 0.194 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
: + func 0 0.553 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
: + func 0 0.258 CoBaLt_trace+0x0
(handle_head_syscall+0x100)
< + freeze 0x0000000f 0 0.404 CoBaLt_trace+0xdd (<00000000>)
|+ begin 0x80000000 0 1.275 do_syscall_64+0x57 (<00000000>)
|+ func 1 0.377 do_syscall_64+0x0
(entry_SYSCALL_64_after_hwframe+0x42)
|+ end 0x80000000 2 0.162 do_syscall_64+0x14f (<00000000>)
+ func 2 0.158 ipipe_handle_syscall+0x0
(do_syscall_64+0x37)
+ func 2 0.151 ipipe_fastcall_hook+0x0
(ipipe_handle_syscall+0x5a)
+ func 2 0.240 handle_head_syscall+0x0
(ipipe_fastcall_hook+0x14)
+ func 2 0.156 CoBaLt_sendmsg+0x0
(handle_head_syscall+0x100)
|+ begin 0x80000001 2 0.162 CoBaLt_sendmsg+0x9b (<00000000>)
|+ end 0x80000001 3 0.293 CoBaLt_sendmsg+0xb5 (<00000000>)
+ func 3 0.000 rtdm_fd_sendmsg+0x0
(CoBaLt_sendmsg+0x7c)
