On 20/01/2023 17:12, Arnaldo Carvalho de Melo wrote:
Em Fri, Jan 20, 2023 at 02:37:01PM +0000, James Clark escreveu:
There are some edge cases around estimated timestamps that can result in them going backwards.
One is that after a discontinuity, the last used timestamp is set to 0. The duration of the next range is then subtracted which could result in an earlier timestamp than the last instruction. Fix this by not resetting the last timestamp used on a discontinuity, and make sure that new estimated timestamps are clamped to be later than that.
Another case is that estimated timestamps could compound over time to end up being more than the next real timestamp in the trace. Fix this by clamping the estimates in cs_etm_decoder__do_soft_timestamp() to be no later than it.
cs_etm_decoder__do_soft_timestamp() also updated next_cs_timestamp, which meant that the next real timestamp was lost and not stored anywhere. Fix that by only updating cs_timestamp for estimates and keep next_cs_timestamp untouched.
Finally, use next_cs_timestamp to signify if a timestamp has been received previously. Because cs_timestamp has the first range subtracted, it could technically go to 0 which would break the logic.
Testing
It can be verified that timestamps don't go backwards when tracing on a single core with the following commands. Across multiple cores it's expected that timestamps are interleaved:
$ perf record -e cs_etm/@tmc_etr0/k -C 4 taskset -c 4 sleep 1 $ perf script --itrace=i1ns --ns -Fcomm,tid,pid,time,cpu,event,ip,sym,addr,symoff,flags,callindent > itrace $ sed 's/://g' itrace | awk -F ' ' ' { print $4 } ' | awk '{ if ($1 < prev) { print "line:" NR " " $0 } {prev=$1}}'
Trying:
root@roc-rk3399-pc:~# uname -a Linux roc-rk3399-pc 6.1.0-rc5-00123-g4dd7ff4a0311 #2 SMP PREEMPT Wed Nov 16 19:55:11 UTC 2022 aarch64 aarch64 aarch64 GNU/Linux root@roc-rk3399-pc:~# root@roc-rk3399-pc:~# perf record -e cs_etm/@tmc_etr0/k -C 4 taskset -c 4 sleep 1 failed to set sink "tmc_etr0" on event cs_etm/@tmc_etr0/k with 2 (No such file or directory) root@roc-rk3399-pc:~#
We could have a better message at some point, right? :-)
Something like:
root@roc-rk3399-pc:~# perf record -e cs_etm/@tmc_etr0/k -C 4 taskset -c 4 sleep 1 This system lacks the CoreSight component. root@roc-rk3399-pc:~#
Should be possible, I'm having a look now