Hi Mike,
On 2020-09-25 21:28, Mike Leach wrote:
Hi,
On Fri, 25 Sep 2020 at 16:38, Suzuki K Poulose suzuki.poulose@arm.com wrote:
On 09/25/2020 03:48 PM, Sai Prakash Ranjan wrote:
On 2020-09-25 16:44, Sai Prakash Ranjan wrote:
Hello guys,
There was an issue reported where the ETM timestamp values would freeze or be 0 sometimes when using perf mode of tracing. This was observed only with perf mode and not sysfs but was reproducible with both ETR and ETF as sinks.
After some debugging, I found that it's mostly to do with CPU idle states. For perf mode, I never see entering CPU_PM_ENTER or EXIT(since the check is mode) and so etm4_cpu_save() and restore() are not called and I believe the contexts are not properly saved and restored across low power states leading to these bad timestamp values. For sysfs tracing, I see save and restore called for respective ETMs when CPUs enter low power states.
For testing, I would run perf record and report commands in a loop.
perf record -e cs_etm/@tmc_etf0/ -N -o perf.data -- some_test perf report -D -i perf.data | grep Timestamp | head
On other shell, I would try to suspend the system:
echo freeze/mem > /sys/power/state
After waking up from suspend, perf commands would continue to run and reports would continue to show either 0 or same timestamps for some period of time.
Even the above test does not always reproduce the issue but the observation that save and restore is not called is always consistent with perf cs mode.
Any idea as to what might be missing for perf mode or if it is expected or some limitation?
I understand different perf trace sessions like how I am trying in a loop shouldn't actually be affected by ETM context save and restore but on same SoC without CPU idle support, the issue is never encountered.
What is your perf command line ? Do you specify "timestamp" config ?
i.e,
$ perf record -e cs_etm/timestamp,@tmc_etr0/u ..
?
By default the time stamp is not enabled.
In system wide mode we do automatically enable timestamps to allow perf to correlate the trace streams from different cores.
Yes it is enabled by default as you mentioned even without specifying timestamp config for system wide mode.
In the past, 0 or fixed timestamps have been caused by the clock used to drive the timestamp counters not being enabled.
Yes this was the first suspect and so I tried setting CLK_IS_CRITICAL flag so that the clock is not gated ever. So after this, we don't see 0 timestamps but the timestamp freeze (fixed) was still observed. Only thing making a difference was the CPU idle.
Thanks, Sai