note: d0 here is the timestamp in clockcycles

Yes this can happen. which version of the libtraceparser are you using? 
1. You would be advised to use the version in 700 as that has some fixes for this sort of issue. 
2. To improve this is to import the kev into momentics and let it fix it then used the fixed version. 

Also when you are using the newer libtraceparser, you would be advised to use the litraceparser to get the 64bit 
timestamp. 

e.g.
static const char*
psf_clk_cycles(char * const sbuf, size_t sbuf_len, tp_state_t tp_state, unsigned h, int min, int max){
	const uint64_t * const clk=traceparser_get_info(tp_state, _TRACEPARSER_INFO_CLK, NULL);
	return ulltoa(*clk, sbuf, 16);
}


________________________________________
From: Claudio Fontana [community-noreply@qnx.com]
Sent: Monday, September 17, 2018 13:13
To: ostech-core_os
Subject: TraceEvent event generation order

Hello all,

are there any guarantees with regards to the timestamp (data[0]) of traceevent_t entries in the tracebuffer?

On a Rcar-M3 starter kit development board I am seeing two events generated on the same CPU (0),
both Simple events (non-combined), with timestamps that are not ordered.
Is this expected?

Here are the events in question in the sequence they are entered in the ring buffer.
s: STRUCT (0 = simple 1=CB, 2=CC, 3=CE)
f: flags
c: class (3 = INT, 4 = PR_TH)
e: event
INT: 5 = INT_ENTRY_64, 2 = INT_EXIT
PR_TH: 1 = RUNNING, 2 = READY, 5 = RECEIVE.

tb_log_event: s:0 cpu:00 f:00 c:04 e:0002 d0:1d27a182 d1:00022018 d2:00000001
tb_log_event: s:0 cpu:00 f:00 c:04 e:0001 d0:1d27a186 d1:00000006 d2:00000001
tb_log_event: s:1 cpu:00 f:00 c:03 e:0005 d0:1d27a1f3 d1:0000001b d2:00000000
tb_log_event: s:3 cpu:00 f:00 c:03 e:0005 d0:1d27a1f3 d1:0104f090 d2:00000000
tb_log_event: s:0 cpu:00 f:00 c:03 e:0002 d0:1d27a208 d1:0000001b d2:00001c01
tb_log_event: s:0 cpu:00 f:00 c:04 e:0005 d0:1d27a1ee d1:00000006 d2:00000001

buffer is in ring mode.

Note that the last event in the buffer does not follow a monotonic timestamp increasing order,
it has a timestamp that fits just after the first two simple events.

Is this to be expected?

Thank you,

Claudio



_______________________________________________

OSTech
http://community.qnx.com/sf/go/post119113
To cancel your subscription to this discussion, please e-mail ostech-core_os-unsubscribe@community.qnx.com