694702 - Decode time telemetry doesn't account for synchronous decoding

Status: NEW

(Core :: Graphics: ImageLib, defect)

Description

[Robert Lickenbrock [:rclick]]

Currently the telemetry for total decode time only accounts for time spent decoding asynchronously (in imgDecodeWorker::Run()). This should be expanded to include the other places where we write data to the decoder.

Comment 1

[Joe Drew (not getting mail)]

Robert, did you want to work on this? Jeff can probably give you some pointers if you need them.

Comment 2

[Jeff Muizelaar [:jrmuizel]]

I've known about this for a while. I'd actually hoped that we would switch to only writing data to the decoder in one place.

Comment 3

[Robert Lickenbrock [:rclick]]

Attachment: patch

This stores the decode time as a member of RasterImage, times how long we spend decoding in SyncDecode() and AddSourceData(), and accumulates the decode time and speed in ShutdownDecoder().

This seems to work, although I'm commonly seeing a decode time of zero. I'm still investigating why that's happening.

Comment 4

[Robert Lickenbrock [:rclick]]

Attachment: patch v2

The zero decode times I was seeing seem to be due to TimeStamp not having enough resolution on my Windows box to accurately time decoding of tiny images. The data isn't very useful in that case, so I've opted to just not accumulate the data if we have a zero decode time.

Assuming that's acceptable, this is ready for review. Jeff, can you look at this?

Comment 5

[Robert Lickenbrock [:rclick]]

Attachment: patch v2

Oops, forgot to qref. This is the right patch.

Comment 6

[Jeff Muizelaar [:jrmuizel]]

Comment on attachment 585686 [details] [diff] [review]
patch v2

Review of attachment 585686 [details] [diff] [review]:
-----------------------------------------------------------------

This patch is ok, but it adds more code that's basically doing the same thing in two places. Instead do you think you could look at refactoring the code so that we only write to the decoder in one place and then will only have to do the timing in a single place?

::: image/src/RasterImage.cpp
@@ +2541,5 @@
>    CONTAINER_ENSURE_SUCCESS(rv);
>  
> +  TimeDuration decodeLatency = TimeStamp::Now() - start;
> +  Telemetry::Accumulate(Telemetry::IMAGE_DECODE_LATENCY,
> +                        PRInt32(decodeLatency.ToMicroseconds()));

It looks like this accumulates the DECODE_LATENCY even for size decodes. We don't do this in the other case.

Comment 7

[Robert Lickenbrock [:rclick]]

(In reply to Jeff Muizelaar [:jrmuizel] from comment #6)
> This patch is ok, but it adds more code that's basically doing the same
> thing in two places. Instead do you think you could look at refactoring the
> code so that we only write to the decoder in one place and then will only
> have to do the timing in a single place?
Sure. I filed Bug 718927 for that.

Comment 8

[Jeff Muizelaar [:jrmuizel]]

Comment on attachment 585686 [details] [diff] [review]
patch v2

Dropping review request because of the refactoring needed for bug 718927