1661368 - Slow testcase impacts AVIF fuzzing performance

Status: NEW

(Core :: Graphics: ImageLib, defect, P4)

Description

[Tyson Smith [:tsmith]]

Attachment: testcase.avif

The attached (relatively small) testcase takes just over 10 seconds to run.

Ideally for this target we would like to get iteration rates of tens of iterations per second (or more if possible) for most inputs (with exceptions such as large images). I think running with a timeout of 5 seconds per test case is reasonable (perhaps higher if the slow cases are infrequent) if not please let me know.

Comment 1

[Sotaro Ikeda [:sotaro]]

:jbauman, can you comment to this bug?

Comment 2

[Jon Bauman [:jbauman:]]

(In reply to Sotaro Ikeda [:sotaro] from comment #1)

:jbauman, can you comment to this bug?

Yes, planning to look at this today.

Comment 3

[Jon Bauman [:jbauman:]]

Adding leave-open, since I want to add some additional logging here

Comment 4

[Jon Bauman [:jbauman:]]

Attachment: Bug 1661368 - Slow testcase impacts AVIF fuzzing performance. r=tsmith

Add finer-grained logging to evaluate where decoding is taking too long.

Comment 5

[Jon Bauman [:jbauman:]]

For reference, the attached test case this file from the Netflix suite of AVIF test images. It hasn't been modified in any way, so we don't expect any sort of pathological performance issues.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b89f24b3eddd
Slow testcase impacts AVIF fuzzing performance. r=tsmith

Comment 7

[Jon Bauman [:jbauman:]]

This issue is proving somewhat mysterious. Running a non-fuzzing build locally, this image takes about 1 second for dav1d do decode on a debug build and ~0.15 seconds on an optimized build. Given that the automated fuzzing runs with optimization setting 02, it's especially confusing why this image would take orders of magnitude longer.

Comment 8

[Tyson Smith [:tsmith]]

Attachment: testcase_2.avif

Here is another one that seem to consistently hang (for about 5 seconds) on my local fuzzing build (44ee384376ce). It seems to load fine in my Nightly opt build.

Comment 9

[Tyson Smith [:tsmith]]

Attachment: hang_2.txt

Comment 10

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/b89f24b3eddd

Comment 11

[Jon Bauman [:jbauman:]]

(In reply to Tyson Smith [:tsmith] from comment #8)

Here is another one that seem to consistently hang (for about 5 seconds) on my local fuzzing build (44ee384376ce). It seems to load fine in my Nightly opt build.

Same. In a local non-fuzzing build, the entire rendering process takes about 295 ms in a release optimized build, but takes ~10,576 ms in your above log. Could you share the mozconfig you're using for your local fuzzing build?

Comment 12

[Jon Bauman [:jbauman:]]

While I can't specifically run the fuzzing build on my macOS machine, I created a build as close to the fuzzing configuration as I could and got some interesting results.

While the first testcase renders in about 1.6 seconds with this fuzzing-like build (considerably slower than the 0.3 seconds it takes on a normal release optimized local build), the second testcase takes nearly 10 seconds with the fuzz-like build, compared to about 0.3 seconds on a normal one. It looks like there's a particular nsAVIFDecoder::ReadSourceReadSource call that is taking a suspiciously long time to complete. This doesn't really explain the behavior on the first testcase, but it does give me something specific to investigate. I'll look into this more on Monday.

Comment 13

[Tyson Smith [:tsmith]]

Attachment: sample_mozconfig

Looks like you got it but just for the record here is the mozconfig.

Comment 14

[BugBot [:suhaib / :marco/ :calixte]]

The leave-open keyword is there and there is no activity for 6 months.
:jbauman, maybe it's time to close this bug?

Comment 15

[Jon Bauman [:jbauman:]]

I'd still intended to come back to track this down. Tyson, is this still impacting our fuzzing, or do you think we should close it?

Comment 16

[Tyson Smith [:tsmith]]

(In reply to Jon Bauman [:jbauman:] from comment #15)

I'd still intended to come back to track this down. Tyson, is this still impacting our fuzzing, or do you think we should close it?

I tested the attached test cases with m-c 20210325-2da6d806f457 and here is what I see:

testcase.avif does still trigger a significant slowdown.

Running: testcase.avif
Executed testcase.avif in 8049 ms

The slowdown triggered by testcase_2.avif may have been slow due to large allocations. Running with ASAN_OPTIONS="max_allocation_size_mb=512" I see:

Running: testcase_2.avif
==358926==WARNING: AddressSanitizer failed to allocate 0x7a8380000 bytes
==358926==WARNING: AddressSanitizer failed to allocate 0x7a8380000 bytes
Executed testcase_2.avif in 75 ms

Comment 17

[BugBot [:suhaib / :marco/ :calixte]]

The leave-open keyword is there and there is no activity for 6 months.
:jbauman, maybe it's time to close this bug?

Comment 18

[Jon Bauman [:jbauman:]]

Still worth addressing, just haven't been able to get to it yet

Comment 19

[BugBot [:suhaib / :marco/ :calixte]]

The leave-open keyword is there and there is no activity for 6 months.
:jbauman, maybe it's time to close this bug?
For more information, please visit auto_nag documentation.

Comment 20

[Jon Bauman [:jbauman:]]

Leave open; I think this may be a good issue for someone new to the AVIF codebase to investigate as a way to learn.

Comment 21

[val.zapod.vz]

This sample is YCbCr, 444, 12 bit and PQ, so PQ means HDR, you really broke support for HDR in last 5 or 6 versions. BTW, other such PQ samples are here: https://github.com/mpv-player/mpv/issues/10247

Comment 22

[BugBot [:suhaib / :marco/ :calixte]]

The leave-open keyword is there and there is no activity for 6 months.
:aosmond, maybe it's time to close this bug?
For more information, please visit auto_nag documentation.