Subject: Input latency

From: Daniel van Vugt <[email-masked]>
Date: Fri, 13 Dec 2013 17:31:54 +0800

Here are some fun numbers I've collected about the latency between input 
events sent from the top-level Mir server to a client. All in 
milliseconds...

Desktop (3.12.0-7-generic)
Direct 0.8ms
Nested 1.3ms

Desktop (3.11.0-11-lowlatency)
Direct 1.0ms
Nested 1.7ms

Nexus4 (3.4.0-3-mako)
Direct 0.9ms
Nested 1.5ms with high variance; frequent spikes to 73ms. Sometimes 700ms.

The above numbers are for motion events. Key events appear to be twice 
as fast (half the latency). This suggests we could yet optimize the 
processing of motion events to perform better like key events do.

In summary, we're looking pretty good. Only the Nexus has potential 
usability issues, and even then, only with nested servers.

- Daniel

---

From: Christopher James Halse Rogers <[email-masked]>
Date: Fri, 13 Dec 2013 18:27:22 +0800

> Nested 1.5ms with high variance; frequent spikes to 73ms. Sometimes 700ms.

Do we have any way to get insight into the spikes? Something strange is
obviously happening when the variance is ~3 orders of magnitude.

---

From: Daniel van Vugt <[email-masked]>
Date: Mon, 16 Dec 2013 13:52:37 +0800

If I had a theory, I could test if it correlates with the spikes. At the 
moment I don't even have a theory.

The other weird thing I didn't mention was that the "lowlatency" kernel 
has higher latency :). But it was worth a try. As are different kernel 
schedulers, I haven't tried playing with them yet.

---

From: Andreas Pokorny <[email-masked]>
Date: Mon, 16 Dec 2013 07:27:14 +0100

Hi,
Can we split the times up? .. decoding from evdev until a EV_SYN ..
internal processing in the shell.. transfer to client?

On Mon, Dec 16, 2013 at 6:52 AM, Daniel van Vugt <
[email-masked]> wrote:

> --
> Mir-devel mailing list
> [email-masked]
> Modify settings or unsubscribe at: https://lists.ubuntu.com/
> mailman/listinfo/mir-devel
>

---

From: Daniel van Vugt <[email-masked]>
Date: Mon, 16 Dec 2013 14:30:15 +0800

Yes indeed. I did think about that, but if you look at the merge 
proposal it's all about using the existing reports unmodified right now. 
And my primary task was to assess the feasibility of nesting vs non-nested.

I wasn't going to spend any more time on input latency measurements this 
week but perhaps there is sufficient interest to get more details...

On 16/12/13 14:27, Andreas Pokorny wrote:
> On Mon, Dec 16, 2013 at 6:52 AM, Daniel van Vugt
> <[email-masked] <mailto:[email-masked]>>
> wrote:
>
>     If I had a theory, I could test if it correlates with the spikes. At
>     the moment I don't even have a theory.
>
>     The other weird thing I didn't mention was that the "lowlatency"
>     kernel has higher latency :). But it was worth a try. As are
>     different kernel schedulers, I haven't tried playing with them yet.
>
>
>
>     [email-masked] <mailto:[email-masked]>
>     Modify settings or unsubscribe at:
>     https://lists.ubuntu.com/__mailman/listinfo/mir-devel
>     <https://lists.ubuntu.com/mailman/listinfo/mir-devel>
>
>

---

From: Thomas Voß <[email-masked]>
Date: Mon, 16 Dec 2013 07:44:33 +0100

On Mon, Dec 16, 2013 at 7:30 AM, Daniel van Vugt
<[email-masked]> wrote:
> Yes indeed. I did think about that, but if you look at the merge proposal
> it's all about using the existing reports unmodified right now. And my
> primary task was to assess the feasibility of nesting vs non-nested.
>

Out of curiosity: When you say leveraging existing reports, does that
mean this evaluation is using the lttng traces?

Thanks,

  Thomas

> https://lists.ubuntu.com/mailman/listinfo/mir-devel

---

From: Daniel van Vugt <[email-masked]>
Date: Mon, 16 Dec 2013 14:52:57 +0800

Existing reports, output as logs, collated across the multiple processes 
using awk.

The procedure of collating the data isn't relevant to the accuracy of 
the results. The accuracy hinges on the timestamps in the log reports, 
which seem pretty accurate (I've compared with other timing APIs). 
Perhaps some time in future we could convince LTTNG to correlate the 
data like my script does, but I'm not sure how to make LTTNG gather and 
match data across multiple processes.

P.S. I wanted to attend your LTTNG talk in London but was trapped in a 
meeting at the time :)

---

From: Thomas Voß <[email-masked]>
Date: Mon, 16 Dec 2013 07:55:23 +0100

On Mon, Dec 16, 2013 at 7:52 AM, Daniel van Vugt
<[email-masked]> wrote:
> The procedure of collating the data isn't relevant to the accuracy of the
> results. The accuracy hinges on the timestamps in the log reports, which
> seem pretty accurate (I've compared with other timing APIs). Perhaps some
> time in future we could convince LTTNG to correlate the data like my script
> does, but I'm not sure how to make LTTNG gather and match data across
> multiple processes.
>

Babeltrace (see http://lttng.org/babeltrace) is your friend here, it
allows for iterating and analyzing the traces.
Btw.: Multi-process tracing isn't a problem for LTTNG, you can easily
"tag" entries with the PID they originate from.

HTH,

  Thomas

---

From: Daniel van Vugt <[email-masked]>
Date: Mon, 16 Dec 2013 16:40:36 +0800

Nexus10 (3.4.0-4-manta)
Direct 1.0ms with sporadic spikes to 74ms, sometimes 400ms
Nested 1.2ms with sporadic spikes to 100ms, sometimes 1000ms

I'm not convinced the problem is specifically Android. It could just be 
a common issue visible on the slowest hardware.

On the Nexus10, just running a single server and client (egltriangle) 
occupies almost 100% of one of the cores. So stressing the CPU doesn't 
leave much time for being responsive.

---

From: Kevin Gunn <[email-masked]>
Date: Mon, 16 Dec 2013 17:30:40 -0600

hey Daniel - thanks for the numbers, however the last statement of having a
core 100% loaded with mir_demo_client_egltriangle doesn't seem reasonable.
running on N4 shows ~20% load on cpu at most.

br,kg

On Mon, Dec 16, 2013 at 2:40 AM, Daniel van Vugt <
[email-masked]> wrote:

> I'm not convinced the problem is specifically Android. It could just be a
> common issue visible on the slowest hardware.
>

---

From: Daniel van Vugt <[email-masked]>
Date: Tue, 17 Dec 2013 09:39:26 +0800

I observed egltriangle on the N10 (2 cores):
server 30%
client 20%

I misinterpreted that as 100% of one core, which is true for some tools, 
and "top" on some Unixes. But I just realized top on Linux goes to 100% 
multiple times (for each core).

So my assessment should have been 50% of one core, sorry.

On 17/12/13 07:30, Kevin Gunn wrote:
> hey Daniel - thanks for the numbers, however the last statement of
> having a core 100% loaded with mir_demo_client_egltriangle doesn't seem
> reasonable.
> On Mon, Dec 16, 2013 at 2:40 AM, Daniel van Vugt
>     I'm not convinced the problem is specifically Android. It could just
>     be a common issue visible on the slowest hardware.
>
>     On the Nexus10, just running a single server and client
>     (egltriangle) occupies almost 100% of one of the cores. So stressing
>     the CPU doesn't leave much time for being responsive.
>
>
>