GSoC Project | Basic Support for Trace Compass

[Sebastian Huber]

On 15/07/2019 18:32, Ravindra Kumar Meena wrote:
>     This is also a global variable:
> 
>     +  static bool ts_recevied[ RTEMS_RECORD_CLIENT_MAXIMUM_CPU_COUNT ] = {
>     false };
> 
>     Please don't modify flush_items(), add everything to print_item().
> 
>     You don't need this extra boolean flag, just use
> 
>     if (timestamp_begin == 0) {
>         timestamp_begin = item->ns;
>     }
> 
>     timestamp_end = item->ns;
> 
> 
> Have made changes.
> 
> https://github.com/rmeena840/rtems-tools/commit/10c17a29a3810cfd2efc96636032d76a0241321a 
> 
> 
> I have also added packet_size and content_size in both client and metadata.
> 
> https://github.com/rmeena840/rtems-tools/commit/88a53f93865fb54f8bcf2afc323baba3feac98c3
> 
> https://github.com/rmeena840/rtems-tools/commit/2e4c130f42352df3333427ebafd7c36b1443f16c
> 
> Since our binary stream files do not have struct padding so both should 
> be equal in values.
> 
> Have a look.

The clock definitions for the timestamps are not right. I loaded the 
trace with Trace Compass and it shows always the same timestamp. For 
example in

102-tracing-wget-critical-path/wget-first-call

I get this:

babeltrace . | grep sched | head
[17:50:44.093074246] (+?.?????????) arnaud-desktop sched_wakeup: { 
cpu_id = 3 }, { comm = "lttng-consumerd", tid = 6854, prio = 20, 
target_cpu = 0 }
[17:50:44.093076317] (+0.000002071) arnaud-desktop sched_switch: { 
cpu_id = 0 }, { prev_comm = "swapper/0", prev_tid = 0, prev_prio = 20, 
prev_state = 0, next_comm = "lttng-consumerd", next_tid = 6854, 
next_prio = 20 }
[17:50:44.093115428] (+0.000017727) arnaud-desktop sched_wakeup: { 
cpu_id = 0 }, { comm = "code", tid = 3906, prio = 20, target_cpu = 2 }
[17:50:44.093116515] (+0.000001087) arnaud-desktop sched_switch: { 
cpu_id = 2 }, { prev_comm = "swapper/2", prev_tid = 0, prev_prio = 20, 
prev_state = 0, next_comm = "code", next_tid = 3906, next_prio = 20 }
[17:50:44.093167902] (+0.000002249) arnaud-desktop sched_switch: { 
cpu_id = 0 }, { prev_comm = "lttng-consumerd", prev_tid = 6854, 
prev_prio = 20, prev_state = 2, next_comm = "swapper/0", next_tid = 0, 
next_prio = 20 }
[17:50:44.093256580] (+0.000003128) arnaud-desktop sched_wakeup: { 
cpu_id = 2 }, { comm = "code", tid = 3915, prio = 20, target_cpu = 0 }
[17:50:44.093257484] (+0.000000267) arnaud-desktop sched_switch: { 
cpu_id = 0 }, { prev_comm = "swapper/0", prev_tid = 0, prev_prio = 20, 
prev_state = 0, next_comm = "code", next_tid = 3915, next_prio = 20 }
[17:50:44.093271009] (+0.000001250) arnaud-desktop sched_switch: { 
cpu_id = 0 }, { prev_comm = "code", prev_tid = 3915, prev_prio = 20, 
prev_state = 1, next_comm = "swapper/0", next_tid = 0, next_prio = 20 }
[17:50:44.093271610] (+0.000000601) arnaud-desktop sched_wakeup: { 
cpu_id = 2 }, { comm = "code", tid = 3916, prio = 20, target_cpu = 2 }
[17:50:44.093272936] (+0.000000887) arnaud-desktop sched_switch: { 
cpu_id = 2 }, { prev_comm = "code", prev_tid = 3906, prev_prio = 20, 
prev_state = 0, next_comm = "code", next_tid = 3916, next_prio = 20 }

In our trace output I get this:

babeltrace . | head
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 986422, events = ( 
"RTEMS_RECORD_THREAD_STACK_CURRENT" : container = 209 ), data = 7392 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 986422, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_IN" : container = 215 ), data = 167837739 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1006753, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_OUT" : container = 216 ), data = 167837739 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1006753, events = ( 
"RTEMS_RECORD_THREAD_STACK_CURRENT" : container = 209 ), data = 5856 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1006753, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_IN" : container = 215 ), data = 151060500 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1044799, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_OUT" : container = 216 ), data = 151060500 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1044799, events = ( 
"RTEMS_RECORD_THREAD_STACK_CURRENT" : container = 209 ), data = 7392 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1044799, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_IN" : container = 215 ), data = 167837739 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1064443, events = ( 
"RTEMS_RECORD_THREAD_SWITCH_OUT" : container = 216 ), data = 167837739 }
0 RTEMS_RECORDING_EVENT: { cpu_id = 17 }, { ns = 1064443, events = ( 
"RTEMS_RECORD_THREAD_STACK_CURRENT" : container = 209 ), data = 5856 }

-- 
Sebastian Huber, embedded brains GmbH

Address : Dornierstr. 4, D-82178 Puchheim, Germany
Phone   : +49 89 189 47 41-16
Fax     : +49 89 189 47 41-09
E-Mail  : sebastian.huber at embedded-brains.de
PGP     : Public key available on request.

Diese Nachricht ist keine geschäftliche Mitteilung im Sinne des EHUG.