Hi, I am trying to understand the origin of the timestamps in the trace output. Here is an example trace of a sample C code.
/> perf sched record -a ./a.out /> perf script [ ... ] a.out 29311 [000] 1746678.549886: sched_stat_runtime: comm=a.out pid=29311 runtime=310028 [ns] vruntime=159246710291986646 [ns] a.out 29311 [000] 1746678.550885: sched_stat_runtime: comm=a.out pid=29311 runtime=998470 [ns] vruntime=159246710292985116 [ns] a.out 29311 [000] 1746678.550895: sched_stat_runtime: comm=a.out pid=29311 runtime=11039 [ns] vruntime=159246710292996155 [ns] [ ... ] My original impression was that this timestamp (eg, 1746678.550895) would align with time reported clk_gettime(MONOTONIC,...) function, but it does not. My C function above prints out timestamps from clk_gettime(MONOTONIC,..) function and there is a delta of >15 mins. Here is the printout on console: CLKTIME (MONOTONIC): 1748132.102228068 This delta has been varying from 5 mins to 15+ mins. My objective is to correlate events in a kernel trace with the execution of our user program. My understanding is that both perf and clk_gettime functions on newer x86 systems use TSC as the clock source and hence I was confused why they do not align. Can someone please help? Regards, Saumil -- To unsubscribe from this list: send the line "unsubscribe linux-perf-users" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
