Closed Bug 1483259 Opened 4 years ago Closed 2 months ago

Intermittent dom/media/test/test_playback.html | ambisonics.mp4 should not fire 'error' event NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004) - virtual mozilla::MediaResult mozilla::FFmpegAudioDecoder<55>::DoDecod

Categories

(Core :: Audio/Video: Playback, defect, P3)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1776941

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])

Attachments

(1 file)

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=193864431&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/CvsRgm2ZQ8eqhhtaXVniBw/runs/0/artifacts/public/logs/live_backing.log

[task 2018-08-14T13:34:40.694Z] 13:34:40     INFO - [finished opus-sample.mp4-60] remaining= ambisonics.mp4-59
[task 2018-08-14T13:34:40.694Z] 13:34:40     INFO - TEST-PASS | dom/media/test/test_playback.html | [finished opus-sample.mp4-60 t=110.404] Length of array should match number of running tests 
[task 2018-08-14T13:34:40.698Z] 13:34:40     INFO - TEST-PASS | dom/media/test/test_playback.html | [started opus-mapping2.mp4-61 t=110.407] Length of array should match number of running tests 
[task 2018-08-14T13:34:40.709Z] 13:34:40     INFO - Buffered messages finished
[task 2018-08-14T13:34:40.718Z] 13:34:40     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_playback.html | ambisonics.mp4 should not fire 'error' event NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004) - virtual mozilla::MediaResult mozilla::FFmpegAudioDecoder<55>::DoDecode(mozilla::MediaRawData*, uint8_t*, int, bool*, mozilla::MediaDataDecoder::DecodedData&): FFmpeg audio error:-1094995529 
[task 2018-08-14T13:34:40.722Z] 13:34:40     INFO -     startTest/noError</<@dom/media/test/test_playback.html:43:5
[task 2018-08-14T13:34:40.723Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:91:3
[task 2018-08-14T13:34:40.725Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.729Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.731Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.732Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.734Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.737Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.738Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.739Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.741Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.742Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.745Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.746Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.747Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.749Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.749Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.751Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.753Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.753Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.754Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.755Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.755Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.755Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.756Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.756Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.756Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.757Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.757Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.759Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.760Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.761Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.761Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.761Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.762Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.763Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.763Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.764Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.765Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.767Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.767Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.773Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.774Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.775Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.775Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.775Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.775Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.776Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.777Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.777Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.777Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.777Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     EventListener.handleEvent*startTest@dom/media/test/test_playback.html:96:3
[task 2018-08-14T13:34:40.778Z] 13:34:40     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:1779:7
[task 2018-08-14T13:34:40.779Z] 13:34:40     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:1758:7
[task 2018-08-14T13:34:40.779Z] 13:34:40     INFO -     finish@dom/media/test/test_playback.html:50:5
[task 2018-08-14T13:34:40.779Z] 13:34:40     INFO -     mayFinish@dom/media/test/test_playback.html:56:7
[task 2018-08-14T13:34:40.779Z] 13:34:40     INFO -     startTest/checkEnded</<@dom/media/test/test_playback.html:69:5
Directly before the failure this gets printed:
> [started opus-mapping2.mp4-61 t=110.407]
That test got added in bug 1482605 - the push for which the failure occurred the first time.
Blocks: 1482605
It's ambisonic.mp4 that cause a decoding error. Not he one recently added
See Also: → 1546655
See Also: → 1554808

There have been 37 total failures in the last 7 days:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-02-01&endday=2021-02-08&tree=trunk&bug=1483259

Only affects linux1804-64-tsan.
Bryce, could you redirect this to someone who can take a look?

Flags: needinfo?(bvandyk)

Looking at the errors it looks like ffmpeg is giving a couple of different errors

Looks like we could audit the audio decode path and the ffmpeg API and try and figure out where this is going wrong. If this is reproducible locally it would be great to catch an rr recording. I'll hold NI and see if I can find an owner.

[0] http://ffmpeg.org/doxygen/trunk/error_8h_source.html

Is there a way to check if the file format is correct? We have a similar bug 1484451 on Mac OS. It's also a decoding error. Not sure why this file causes the same problem on different platforms

Whiteboard: [stockwell needswork:owner]

(In reply to C.M.Chang[:chunmin] from comment #64)

Is there a way to check if the file format is correct? We have a similar bug 1484451 on Mac OS. It's also a decoding error. Not sure why this file causes the same problem on different platforms

We could audit the mp4 structure against the ISO specs that govern them. Beyond that we could audit the samples against whatever spec governs those, but I'm less familiar with that.

:kinetik, do you have any thoughts on auditing the file or debugging this further?

Flags: needinfo?(bvandyk) → needinfo?(kinetik)

In the last 7 days there have been 30 occurrences, all on linux1804-64-tsan opt.

Recent failure: https://treeherder.mozilla.org/logviewer?job_id=330538000&repo=autoland&lineNumber=3494

Flags: needinfo?(kinetik)

Matthew did you get a chance to take a look at this?

Flags: needinfo?(kinetik)
Assignee: nobody → abutkovits
Status: NEW → ASSIGNED
Assignee: abutkovits → nobody
Status: ASSIGNED → NEW
Keywords: leave-open
Whiteboard: [stockwell needswork:owner] → [stockwell disabled][leave-open]
Pushed by abutkovits@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/e71b7bf786d8
disable test_playback.html for frequent failures. r=intermittent-reviewers,jmaher
Whiteboard: [stockwell disabled][leave-open] → [stockwell disabled]

I'm re-enabling the test in bug 1699509, but skipping the problematic file, I'm not sure how this should be reflected in the whiteboard (if at all), so please update as appropriate.

Severity: normal → S4
Priority: P5 → P3
Flags: needinfo?(kinetik)
Status: NEW → RESOLVED
Closed: 2 months ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1776941
You need to log in before you can comment on or make changes to this bug.