1509511 - Investigate performance impact of prioEncode

Status: NEW

(Toolkit :: Telemetry, enhancement, P3)

Description

[Florian Quèze [:florian]]

In this shutdown profile captured on the 2018 reference hardware, it takes 70ms twice: https://perfht.ml/2R6YGKZ

Comment 1

[Chris H-C :chutten]

Most notably to my eyes is that prioEncode seems to take about the same length of time as the entire rest of assemblePayload combined.

(The twice is because it's a startup&shutdown profile where shutdown is triggering delayedInit which is saving an aborted-session ping. Then a short time later shutdown actually happens and we save and send our "main"/shutdown and "first-shutdown" pings using a single payload... maybe we need a separate bug for not saving "aborted-session" during shutdown?)

Comment 2

[Florian Quèze [:florian]]

Here is a profile with symbols that shows where the time is spent: https://perfht.ml/2RgcMd2

Comment 3

[Jan-Erik Rediger [:janerik]]

There seem to be some inefficiencies in Prio, e.g. doing to much: https://searchfox.org/mozilla-central/rev/f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/config.c#29-31

There's also a lot of time spent in `toupper`, upcasing data from this array: https://searchfox.org/mozilla-central/rev/f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/params.h#32

Comment 4

[Robert Helmer [:rhelmer]]

Thanks for investigating!

(In reply to Jan-Erik Rediger [:janerik] from comment #3)
> There seem to be some inefficiencies in Prio, e.g. doing to much:
> https://searchfox.org/mozilla-central/rev/
> f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/config.c#29-31
> 
> There's also a lot of time spent in `toupper`, upcasing data from this
> array:
> https://searchfox.org/mozilla-central/rev/
> f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/params.h#32

Before we dig too far into the specifics here, one thing I've been concerned about as we prio-encode more data is that even with optimization there's always going to be some jank if we run this on the main thread. We could make `PrioEncoder.encode()` async, but since Telemetry blocks shutdown that will only help so much.

(In reply to Chris H-C :chutten from comment #1)
> Most notably to my eyes is that prioEncode seems to take about the same
> length of time as the entire rest of assemblePayload combined.
> 
> (The twice is because it's a startup&shutdown profile where shutdown is
> triggering delayedInit which is saving an aborted-session ping. Then a short
> time later shutdown actually happens and we save and send our
> "main"/shutdown and "first-shutdown" pings using a single payload... maybe
> we need a separate bug for not saving "aborted-session" during shutdown?)

The current state of Prio is that it is only enabled by default on Nightly, and it's encoding three non-sensitive values for testing.

It's possible that in the near future we might want to encode a lot more data, say a few thousand values instead of the three. I think that even if libprio implements Prio in a completely optimal way, this will still cause unacceptable jank and slow down shutdown too much.

A better use of everyone's time is probably to make prio-encoding async, and to not run the encoding during shutdown.

Any thoughts?

Comment 5

[Chris H-C :chutten]

That seems fine by me, though I'm not sure how we'd be able to decouple prioEncode from shutdown if it will be using "main" pings as its transport.

Comment 6

[Georg Fritzsche [:gfritzsche]]

From what i understand, the prio data does not correlate to main ping data anyway.
Moving the Prio data to a separate ping would probably be good for the next phase of Prio.
That would also clear up the shutdown coupling concern.

Comment 7

[Robert Helmer [:rhelmer]]

(In reply to Georg Fritzsche [:gfritzsche] from comment #6)
> From what i understand, the prio data does not correlate to main ping data
> anyway.
> Moving the Prio data to a separate ping would probably be good for the next
> phase of Prio.
> That would also clear up the shutdown coupling concern.

This is a good point. Anthony and I were discussing this recently and the idea of having a prio-specific ping came up, it would probably simplify things overall especially given that we need to coordinate with another org at some point and this gives us more flexibility.

Comment 8

[Jan-Erik Rediger [:janerik]]

P3, going to be tackled by upcoming usage of Prio (proposal in 2019)

Comment 9

[Florian Quèze [:florian]]

Any progress on this? It's still pretty visible when profiling Nightly: https://perfht.ml/2DeDqgJ

Comment 10

[Robert Helmer [:rhelmer]]

I think that this will be moved out of the main ping soon as part of bug 1522657 - chutten is that correct?

As mentioned in comment 4 Prio is currently only enabled for the main ping on Nightly so I wouldn't expect this to show up in profiles of Release or Beta users (but do correct me if that's wrong)

Comment 11

[Chris H-C :chutten]

That is the plan. I just now added a "Performance" section under "Details" in the proposal to ensure we remember to not call libprio on the main thread.

Comment 12

[Robert Helmer [:rhelmer]]

(In reply to Chris H-C :chutten from comment #11)

That is the plan. I just now added a "Performance" section under "Details" in the proposal to ensure we remember to not call libprio on the main thread.

Cool. Just FYI we haven't explicitly tested but do expect libprio to be thread-safe, and the current PrioEncoder.encode() is synchronous but should therefore be fine to run in a worker (assuming the webidl is modified to allow it to be exposed to workers, right now it is Chrome-only.) Running in a separate process would be safe and easy too although probably not worth the overhead.

It'd be pretty easy to make .encode() return a promise and handle threading internally too, a bit more work than the above but if you wanted to be able to call it seamlessly from JS on the main thread this would be a nice approach.

Comment 13

[Robert Helmer [:rhelmer]]

(In reply to Jan-Erik Rediger [:janerik] from comment #3)

There seem to be some inefficiencies in Prio, e.g. doing to much:
https://searchfox.org/mozilla-central/rev/
f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/config.c#29-31

There's also a lot of time spent in toupper, upcasing data from this
array:
https://searchfox.org/mozilla-central/rev/
f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/params.h#32

FYI Henry opened a PR which should fix this in https://github.com/mozilla/libprio/pull/69

If anyone wants to help review please do!

Comment 14

[Robert Helmer [:rhelmer]]

(In reply to Robert Helmer [:rhelmer] from comment #13)

(In reply to Jan-Erik Rediger [:janerik] from comment #3)

There seem to be some inefficiencies in Prio, e.g. doing to much:
https://searchfox.org/mozilla-central/rev/
f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/config.c#29-31

There's also a lot of time spent in toupper, upcasing data from this
array:
https://searchfox.org/mozilla-central/rev/
f997bd6bbfc4773e774fdb6cd010142370d186f9/third_party/prio/prio/params.h#32

FYI Henry opened a PR which should fix this in https://github.com/mozilla/libprio/pull/69

If anyone wants to help review please do!

This has been merged upstream, it'll be vendored into Firefox by bug 1539715.