Re: longest path through a task

[Patrick Noffke <patrick.noffke@gmail.com>]

On Friday, May 29, 2015 at 11:31:27 AM UTC-5, Simon Wright wrote:
> Simon Wright writes:
> 
> > Just did some measurements (clumsily) using the Cortex-M4 counter as
> > in [1], and from entering the Ada handler to the triggered task
> > starting to execute averaged at 1200 cycles (6.7 us) with -Og, 1070
> > cycles (5.9 us) with -O2. There is some code in the C handler to
> > redirect to the Ada handler: see [2], starting at line 236.
> 
> The code in the C handler takes 150 cycles.
> 
> So, for my FreeRTOS-based RTS, interrupt to Ada handler is 150 cycles,
> Ada handler to task is 1200 cycles, grand total 1350 cycles or 7.5
> microseconds (core clock 180 MHz).
> 

I am able to instrument the TRACESWO pin on my Cortex-M4 (Atmel SAM4S) and capture the ITM trace information, which includes when the processor enters or exits an exception, and user trace information.  I can neatly capture this on my Saleae Logic Pro 16 analyzer and export it for use by PulseView/sigrok, which has recently added decoding of ITU/ITM/ETM (see http://essentialscrap.com/tips/arm_trace/ and http://www.sigrok.org/blog/new-protocol-decoders-arm-tpiu-itm-etmv3).

I have turned on timestamps (since the ITU baud rate is 8 Mbits/sec, and it can take a while to serialize the ITM information when things get busy), but I'm not sure what the values represent.  From what I read, the timestamps are based on the AHB clock, but I'm not sure what that is for this processor (processor clock of 120 MHz).

On one capture, I have the following ITM exception trace events:

Exit: IRQ 31
Enter: PendSV
Timestamp: 904 (exact)
Exit: PendSV
Timestamp: 906 (exact)
Resume: Thread
Timestamp: 907 (exact)

The actual time from Exit: IRQ 31 to the end of the last timestamp is about 19 us, but the ITU data stream is going continuous that entire time (no gaps), which leads me to suspect the ITU can't quite keep up (indeed, when I was experimenting with faster ITU baud rates, the total actual time for this sequence was less, but I can't recall the exact number).

Do you have some idea how to correlate these timestamps to real time?

Regards,
Patrick