How to capture real input latency time - in user timespace perspective

[Ravi Kasibhatla]

Hi,

We can record the input latency for each input event executed using tracing. However, the recorded latency time is from the point the input event was received by the chromium widget (from the system framework) till the frame (updated by the event) has been swapped.

I was wondering is there a way we can measure the actual latency for the input event i.e. the time taken when the user clicks on the screen to the final execution point (i.e. including the time taken to receive the event by Chromium browser framework).

In order to get the real user time, I took input category system traces along with chromium traces (for Android platform). My idea was to check for the time android system received the input event (probably from driver) and when it was received by the chromium framework. THe difference between these two timestamps when added with the latency benchmark time, we can get very close to the actual event latency (in user timespace).

However, to my surprise I found that the first log in system trace for input (deliverInputEvent) is already under the timestamp label of the event whose latency is being marked in trace. So, I was wondering about following queries:

1. What is the timestamp that is present in android system traces.

2. How can we correlate the timestamp present in system trace with the timestamps of chromium browser?

3. If the data captured through android systraces is not enough to do the complete latency calculation (as I tried earlier), how can we best capture this information? Through logs or some other mechanism.

4. From adb logcat, I observed certain InputDispatcher logs, which recorded the timestamp of the received event. Can we use that timestamp for our calculation.

Can somebody guide me about the path to follow to get the real latency time?

Regards,

Ravi Kasibhatla (kphanee)

[Yufeng Shen]

I think for chrome on android the starting point of input event latency is already the timestamp when the input event is received

by the android, not the timestamp when the input event is received by chrome (not considering the android system event batching

and timestamp interpolation). 

[Jared Duke]

Right, we forward the timestamps provided by Android events to the generated Chrome input events (and from there to telemetry), so your findings seem consistent.

As Yufeng mentioned, it's possible that the Android MotionEvent timestamps (those you see in the systrace) are lossy due to event batching/interpolation. If you're really motivated, you can try probing |MotionEvent.getHistoricalEventTime()| to get the raw kernel timestamps. I'm not aware of any existing wiring for capturing such values via systrace, so you may have to extract them manually.

[Rick Byers]

Note that "real latency time" is always going to be impossible to track exactly from software.  Eg. the LCD panel takes some time to update.  We rely on high-speed camera based testing (robot drives a touch on a device, camera captures a video which we process in software) to act as our absolute gold standard for input latency.  We periodically cross-check that the mean_input_event_latency metrics we get out of telemetry are consistent with the true end-to-end latency measurements we get out of our camera testing.

So what we find most useful to track in telemetry/tracing is the portion of the latency that we can control (and are likely to regress with our changes).  The rest is considered fixed overhead whose changes (hardware, drivers, OS, etc.) we track only via our camera testing.

Rick