I'm going to run this story locally to get a trace and see if I can repro the slow metric computation. If I can, then I think the next step here is to get a devtools trace of computing the metrics.

My first guess is that since there are 172M trace events, probably the trace file is large, causing the importer to switch to stream processing the trace file (i.e. using the third-party lib oboe.js) instead of JSON.parse(), since it the whole trace file won't fit into a v8 string. If that's the case, stream processing is ~9x slower that JSON.parse() which can describe the slowness.

If that's indeed the case: there was a 20% project to make oboe.js faster, and we had some ideas. But, we don't know how to priorotize that work: does it worth spending time on it or we should just wait for the proto-based perfetto to launch, probably next year? What do you think? Does this happen frequently?

Some results from my investigation:

1. Telemetry said that computing metrics took 125s on my machine for the imgur story.
2. Of that, importing is 30 seconds, which is indeed a pretty long time.
3. EQT metric is really slow, taking 60 seconds. runtimeStatsTotalMetric is also somewhat slow, taking 17 seconds.
4. memoryMetric and the GC metrics take order of a single digit number of seconds to run.

2. and 3. present pretty big opportunities for optimization, and Ehsan already describes a strategy for working on 2., so let me talk about 3.

A devtools profile reveals that both EQT and runtimeStatsTotalMetric call functions in loadingMetric that take a long time because they basically iterate over everything. benjhayden@ mentioned that mythria@ is working on moving some of this work into the import phase so that we only have to do it once. It may also be possible to do something more efficient than iterating over everything.

Mythri, I would suggest running locally and then just opening the trace in the viewer. You can then use the metrics side panel to profile using devtools; as soon as you select a metric the change handler will cause the selected metric to be computed.

By the way, I filed https://github.com/catapult-project/catapult/issues/4234 (credit to benjhayden@ for the idea) to let metric_map_function record histograms for import duration and individual metric computation duration and use them to build breakdowns, so that it'll be easy to account for overhead on any benchmark run.

Thanks for creating this bug. 

Re: comment#3 Yes, I am working on moving computing loading metric to import phase. This would avoid computing it twice, though we still need to compute this once. This is the cl: https://chromium-review.googlesource.com/c/catapult/+/897491. We could also compute the metrics once for the entire trace instead of doing it per renderer. This was suggested by benjhayden@. I will also implement that optimization and see what would be the impact. I will take a closer look at runtimeStatsTotalMetric to see if there are any other optimizations we could do there.

+ulan incase he has any ideas about optimizing EQT.

Thanks, Ethan and Mythri, for looking into this. 

Some time ago I did one optimization here: https://codereview.chromium.org/2769643002/

We do multiple passes over trace (one pass per "contribution to EQT" metric). We could try doing one pass and collect events corresponding to each contribution in a separate array.