1683016 - Intermittent dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | Test timed out -

Status: REOPENED

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

Description

[Treeherder Bug Filer]

Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=324777144&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/PN266-cpSGOteBJByh6Z3w/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-12-17T02:28:06.854Z] 02:28:06     INFO - TEST-INFO | screentopng: exit 0
[task 2020-12-17T02:28:06.855Z] 02:28:06     INFO - Buffered messages logged at 02:26:36
[task 2020-12-17T02:28:06.855Z] 02:28:06     INFO - Entering test bound setupTestingPref
[task 2020-12-17T02:28:06.855Z] 02:28:06     INFO - Leaving test bound setupTestingPref
[task 2020-12-17T02:28:06.855Z] 02:28:06     INFO - Entering test bound testControllerWithActiveMediaSessionShouldStillBeActiveWhenNoControllableMediaPresents
[task 2020-12-17T02:28:06.856Z] 02:28:06     INFO - open media page
[task 2020-12-17T02:28:06.856Z] 02:28:06     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-12-17T02:28:06.856Z] 02:28:06     INFO - play media would activate controller and media session
[task 2020-12-17T02:28:06.857Z] 02:28:06     INFO - Buffered messages logged at 02:26:37
[task 2020-12-17T02:28:06.857Z] 02:28:06     INFO - Console message: [JavaScript Warning: "Cannot play media. No decoders for requested formats: video/ogg" {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_error_media.html" line: 0}]
[task 2020-12-17T02:28:06.857Z] 02:28:06     INFO - Buffered messages finished
[task 2020-12-17T02:28:06.857Z] 02:28:06     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | Test timed out - 
[task 2020-12-17T02:28:06.858Z] 02:28:06     INFO - GECKO(1539) | MEMORY STAT | vsize 20975364MB | residentFast 1250MB
[task 2020-12-17T02:28:06.861Z] 02:28:06     INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | took 90017ms
[task 2020-12-17T02:28:06.862Z] 02:28:06     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-17T02:28:06.862Z] 02:28:06     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | Found a tab after previous test timed out: https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html - 
[task 2020-12-17T02:28:06.863Z] 02:28:06     INFO - checking window state



----------[task 2020-12-17T02:26:36.547Z] 02:26:36     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js--------```

Comment 1

[Intermittent Failures Robot]

17 failures in 3421 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 11
• mozilla-central: 5
• mozilla-beta: 1

Platform breakdown:

• linux1804-64-asan: 2
• linux1804-64-tsan: 5
• linux1804-64: 6
• linux1804-64-ccov: 1
• linux1804-64-shippable: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2020-12-14&endday=2020-12-20&tree=all

Comment 2

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

There are many of these failure lines before the snippet in comment 0.

Bryce, can you spot from the commits before the first failure which one started it?

Comment 3

[Bryce Seager van Dyk [:bryce] (he/him) - Not reading bugmail]

Alastor, does anything stand out to you here? Could you help me take a look?

Looks like our first failure was on 2020-12-16, and many of the same errors in the logs are present before and after that in passing runs. Here's some passing runs for comparison (that has many of the same errors):

• Older https://treeherder.mozilla.org/logviewer?job_id=324720611&repo=autoland&lineNumber=2374
• Recent https://treeherder.mozilla.org/logviewer?job_id=325151210&repo=autoland&lineNumber=3944

One thing that looks suspicious is the MDSM errors in the failing runs. E.g.

[Child 19053, MediaDecoderStateMachine #1] WARNING: 7fe3b68fe040 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334

We're not able to open cubeb and it's breaking our tests? It's not clear to me what recent change would cause this though.

Comment 4

[Alastor Wu [:alwu]]

I'm not sure what happened on the cubeb side, but I think I can try to solve this on the media control side, where I suspect that we miss some events which causes a timeout. If that doesn't work, then we can investigate the cubeb issue.I'm not sure what happened on the cubeb side, but I think I can try to solve this with media control side, which I suspect that we miss some events which causes a timeout. If that doesn't work, then we can investigate the cubeb issue.

Comment 5

[Alastor Wu [:alwu]]

Attachment: Bug 1683016 - listen to display playback change before calling video's `play()`

Call waitUntilDisplayedPlaybackChanged() first to ensure that we won't miss the event. In addition, add more logs in order to help diagnosing issue if timeout happens again.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/89a982fb950b
listen to display playback change before calling video's `play()` r=bryce

Comment 7

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/89a982fb950b

Comment 8

[Cosmin Sabou [:CosminS]]

This doesn't seem to be fixed: https://treeherder.mozilla.org/logviewer?job_id=325258418&repo=mozilla-central
Alastor, could you please have a second go at this?

Comment 9

[Alastor Wu [:alwu]]

My previous patches are used to add more logs which help indentifying if the problem is caused by a certain module. They are not an actual fix and it's expected to see the failure again. I will continue to investigate what's happened on those failures.

Comment 10

[Intermittent Failures Robot]

21 failures in 1450 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #28 most frequent failure this week.

Repository breakdown:

• autoland: 15
• mozilla-central: 5
• mozilla-beta: 1

Platform breakdown:

• linux1804-64: 13
• linux1804-64-tsan: 5
• linux1804-64-ccov: 1
• linux1804-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2020-12-21&endday=2020-12-27&tree=all

Comment 11

[Intermittent Failures Robot]

8 failures in 525 pushes (0.015 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 7
• mozilla-central: 1

Platform breakdown:

• linux1804-64: 3
• linux1804-64-tsan: 4
• linux1804-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2020-12-28&endday=2021-01-03&tree=all

Comment 12

[Intermittent Failures Robot]

35 failures in 2956 pushes (0.012 failures/push) were associated with this bug in the last 7 days.

This is the #24 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 18
• try: 5
• mozilla-central: 6
• mozilla-beta: 6

Platform breakdown:

• linux1804-64: 11
• linux1804-64-asan: 3
• linux1804-64-devedition: 5
• linux1804-64-tsan: 12
• linux1804-64-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-01-04&endday=2021-01-10&tree=all

Comment 13

[Andreea Pavel [:apavel]]

There are 33 total failures in the last 7 days on

• linux1804-64 debug and opt
• linux1804-64-shippable opt
• linux1804-64-tsan opt
  Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=326569611&repo=mozilla-central&lineNumber=3624

[task 2021-01-13T11:12:43.553Z] 11:12:43 INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js
[task 2021-01-13T11:12:43.895Z] 11:12:43 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000b9ff40 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:12:43.897Z] 11:12:43 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:12:49.455Z] 11:12:49 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000c037c0 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:12:49.456Z] 11:12:49 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:12:55.015Z] 11:12:55 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 6110001b4bc0 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:12:55.016Z] 11:12:55 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:00.575Z] 11:13:00 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000845840 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:00.575Z] 11:13:00 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:06.135Z] 11:13:06 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000c4d500 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:06.136Z] 11:13:06 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:11.695Z] 11:13:11 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 6110002e4900 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:11.696Z] 11:13:11 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:17.256Z] 11:13:17 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000398180 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:17.256Z] 11:13:17 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:22.816Z] 11:13:22 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 6110005417c0 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:22.816Z] 11:13:22 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:28.374Z] 11:13:28 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000015a80 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:28.375Z] 11:13:28 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:33.933Z] 11:13:33 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000424400 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:33.934Z] 11:13:33 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:39.492Z] 11:13:39 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 6110004ad200 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:39.493Z] 11:13:39 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:45.052Z] 11:13:45 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000521d80 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:45.052Z] 11:13:45 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:50.612Z] 11:13:50 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000d95840 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:50.613Z] 11:13:50 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:13:56.172Z] 11:13:56 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000de8e00 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:13:56.172Z] 11:13:56 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:14:01.732Z] 11:14:01 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000377840 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:14:01.733Z] 11:14:01 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:14:07.293Z] 11:14:07 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 6110005f5b80 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:14:07.293Z] 11:14:07 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:14:12.847Z] 11:14:12 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: 611000e4ccc0 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:334
[task 2021-01-13T11:14:12.848Z] 11:14:12 INFO - GECKO(2965) | [Child 3023, MediaDecoderStateMachine #1] WARNING: Decoder=6170001c7b00 [OnMediaSinkAudioError]: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3900
[task 2021-01-13T11:14:13.551Z] 11:14:13 INFO - TEST-INFO | started process screentopng
[task 2021-01-13T11:14:13.861Z] 11:14:13 INFO - TEST-INFO | screentopng: exit 0
[task 2021-01-13T11:14:13.861Z] 11:14:13 INFO - Buffered messages logged at 11:12:43
[task 2021-01-13T11:14:13.861Z] 11:14:13 INFO - Entering test bound setupTestingPref
[task 2021-01-13T11:14:13.862Z] 11:14:13 INFO - Leaving test bound setupTestingPref
[task 2021-01-13T11:14:13.862Z] 11:14:13 INFO - Entering test bound testControllerWithActiveMediaSessionShouldStillBeActiveWhenNoControllableMediaPresents
[task 2021-01-13T11:14:13.863Z] 11:14:13 INFO - open media page
[task 2021-01-13T11:14:13.864Z] 11:14:13 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2021-01-13T11:14:13.865Z] 11:14:13 INFO - play media would activate controller and media session
[task 2021-01-13T11:14:13.866Z] 11:14:13 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | video started playing - true == true -
[task 2021-01-13T11:14:13.866Z] 11:14:13 INFO - Buffered messages logged at 11:12:44
[task 2021-01-13T11:14:13.867Z] 11:14:13 INFO - Console message: [JavaScript Warning: "Media resource https://example.com/browser/dom/media/mediacontrol/tests/browser/bogus.ogv could not be decoded, error: Error Code: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006)" {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_error_media.html" line: 0}]
[task 2021-01-13T11:14:13.868Z] 11:14:13 INFO - Buffered messages finished
[task 2021-01-13T11:14:13.869Z] 11:14:13 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | Test timed out -
[task 2021-01-13T11:14:13.870Z] 11:14:13 INFO - GECKO(2965) | MEMORY STAT | vsize 20975342MB | residentFast 1294MB
[task 2021-01-13T11:14:13.870Z] 11:14:13 INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | took 90019ms
[task 2021-01-13T11:14:13.871Z] 11:14:13 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-01-13T11:14:13.872Z] 11:14:13 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js | Found a tab after previous test timed out: https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html -
[task 2021-01-13T11:14:13.872Z] 11:14:13 INFO - checking window state
Alastor are there any updates here? Are you still working on this?

Comment 14

[Alastor Wu [:alwu]]

Paul, these timeout is because those media weren't able to start playing successfully, and I saw a lot of error failed to init cubeb, do you have any idea about that?

This timeout failure only happens on Linux. In addition, I recently found that on my Ubuntu 20.04, I sometime noticed an issue where even if video has started playing, but audio won't start playing (here I mean no sound can be heard, I believe the audio decoding has started). I wonder if they (audio issue and the error on test) are related.

I will file a new bug when next time I encouter that issue.

Comment 15

[Intermittent Failures Robot]

42 failures in 3810 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #10 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 16
• mozilla-central: 11
• mozilla-beta: 11
• try: 4

Platform breakdown:

• linux1804-64-tsan: 15
• linux1804-64: 12
• linux1804-64-shippable: 9
• linux1804-64-asan: 3
• linux1804-64-devedition: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-01-11&endday=2021-01-17&tree=all

Comment 16

[Paul Adenot (:padenot)]

I've never seen that, and I'm also using Ubuntu 20.04, playing music in Firefox all day most days. If cubeb fails to init, then we need to get logs. If you can repro locally, it's easier (MOZ_LOG=cubeb:4).

Comment 17

[Alastor Wu [:alwu]]

No I can't reproduce it locally. I also uses my Firefox playing music on Unbuntu all the time, and didn't encouter this issue. So I think that issue is probably related with the environment used on the try server.

However, when I tried to enable the log module in the test in order to print the log on the try server, I found that when I added ["logging.cubeb", 5] in the test while pushing the testing preferences, or added pref("logging.cubeb", 5) in all.js, none of them could work perfectly, it didn't show much log. I only saw some logs like that.

 0:09.83 GECKO(314544) [Child 314672: MediaDecoderStateMachine #1]: I/cubeb media.cubeb.sandbox: true
 0:09.83 GECKO(314544) [Child 314672: MediaDecoderStateMachine #1]: D/cubeb media.audioipc.pool_size: 1
 0:09.83 GECKO(314544) [Child 314672: MediaDecoderStateMachine #1]: D/cubeb media.audioipc.stack_size: 262144

But if I use MOZ_LOG=cubeb:5 ./mach mochitest XXX, then I can see more logs. eg.

 0:10.59 GECKO(315207) [Parent 315207: Unnamed thread 0x7faa770f5280]: E/cubeb stream.rs:364: Output callback to be written buffer size 24000
 0:10.59 GECKO(315207) [Parent 315207: Unnamed thread 0x7faa770f53a0]: E/cubeb stream.rs:532: Output buffer attributes maxlength 4194304, tlength 24000, prebuf 19204, minreq 4800, fragsize 4294967295
 0:10.59 GECKO(315207) [Parent 315207: Unnamed thread 0x7faa770f5280]: E/cubeb stream.rs:1004: Trigger user callback with output buffer size=24000, read_offset=0

Do you know why enabling log via testing preference didn't work? It seems to me that the logging system for cubeb works differently than other media logging system. Because I can easily enable other logs by simply adding a pref (eg. logging.MediaDecoder, logging.MediaControl ..e.t.c)

Comment 18

[Paul Adenot (:padenot)]

Because this is Linux desktop, with audioipc enabled by default, I think a good try would be to get rust logging, RUST_LOG=audioipc=debug or something like that. What you observe on try would be what I would expect if we're stuck trying to create a cubeb stream, or if audioipc fails to open a stream.

Comment 19

[Alastor Wu [:alwu]]

Got it, thank you. I pushed a patch to try server with RUST_LOG=audioipc=debug and cubeb:5, let's see if we can capture the log when error happens.

Comment 20

[Alastor Wu [:alwu]]

Here is the log. It seems we were failing to create a stream and kept re-registering a new one?

[DEBUG audioipc_server::server] Registering stream 1
...
[DEBUG audioipc_server::server] Registering stream 16

Comment 21

[Paul Adenot (:padenot)]

That seems to happen starting at 2021-01-19T23:22:43.182Z. We need a lot more log to understand why we're getting a nullptr cubeb context.

Comment 22

[Atila Butkovits]

There have been 20 failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-01-13&endday=2021-01-20&tree=trunk&bug=1683016

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=327170015&repo=autoland&lineNumber=2669

Comment 23

[Alastor Wu [:alwu]]

What log would you need? You can reproduce that by pushing task onto the try server as well, just need to select the browser-chrome. In addition, this failure was seen first on 2020-12-16, did you remember any possible change, which might cause this, happening at that time?

Comment 24

[Intermittent Failures Robot]

37 failures in 3488 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

This is the #34 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 30
• mozilla-central: 5
• try: 2

Platform and build breakdown:

• linux1804-64: 25
  • opt: 21
  • debug: 4
• linux1804-64-tsan: 9
  • opt: 9
• linux1804-64-shippable: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-01-18&endday=2021-01-24&tree=all

Comment 25

[Intermittent Failures Robot]

18 failures in 688 pushes (0.026 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 13
• mozilla-central: 2
• try: 2
• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-tsan: 3
  • opt: 3
• linux1804-64: 11
  • debug: 2
  • opt: 9
• linux1804-64-shippable: 3
  • opt: 3
• linux1804-64-devedition: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-01-29&endday=2021-01-29&tree=all

Comment 26

[Natalia Csoregi [:nataliaCs]]

Update:

There have been 58 failures within the last 7 days:

• 9 failures on Linux 18.04 x64 tsan opt
• 8 failures on Linux 18.04 x64 shippable opt
• 2 failures on Linux 18.04 x64 asan opt
• 39 failures on Linux 18.04 x64 opt & debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=328335395&repo=autoland&lineNumber=6982

Comment 27

[Intermittent Failures Robot]

65 failures in 3891 pushes (0.017 failures/push) were associated with this bug in the last 7 days.

This is the #8 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 50
• mozilla-central: 9
• try: 4
• mozilla-beta: 2

Platform and build breakdown:

• linux1804-64: 43
  • opt: 37
  • debug: 6
• linux1804-64-shippable: 11
  • opt: 11
• linux1804-64-tsan: 8
  • opt: 8
• linux1804-64-asan: 2
  • opt: 2
• linux1804-64-devedition: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-01-25&endday=2021-01-31&tree=all

Comment 28

[Andreea Pavel [:apavel]]

Attachment: Bug 1683016 - disable browser_remove_controllable_media_for_active_controller.js on linux 64 not asan r?#intermittent-reviewers

Comment 29

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/325c082b8642
disable browser_remove_controllable_media_for_active_controller.js on linux 64 not asan r=intermittent-reviewers,jmaher DONTBUILD

Comment 30

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/325c082b8642

Comment 31

[Intermittent Failures Robot]

38 failures in 3966 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #28 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 30
• mozilla-central: 5
• mozilla-beta: 3

Platform and build breakdown:

• linux1804-64: 19
  • debug: 2
  • opt: 17
• linux1804-64-shippable: 7
  • opt: 7
• linux1804-64-asan: 11
  • opt: 11
• linux1804-64-tsan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-02-01&endday=2021-02-07&tree=all

Comment 32

[Intermittent Failures Robot]

6 failures in 4322 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 6

Platform and build breakdown:

• linux1804-64-asan: 6
  • opt: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-02-08&endday=2021-02-14&tree=all

Comment 33

[Intermittent Failures Robot]

12 failures in 3737 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• try: 1
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64-asan: 12
  • opt: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-02-15&endday=2021-02-21&tree=all

Comment 34

[Intermittent Failures Robot]

15 failures in 4327 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 14
• mozilla-central: 1

Platform and build breakdown:

• linux1804-64-asan: 15
  • opt: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-02-22&endday=2021-02-28&tree=all

Comment 35

[Intermittent Failures Robot]

2 failures in 3683 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• linux1804-64-asan: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2021-03-01&endday=2021-03-07&tree=all

Comment 36

[Intermittent Failures Robot]

1 failures in 3304 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• macosx1015-64-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-03-14&endday=2022-03-20&tree=all

Comment 37

[Intermittent Failures Robot]

1 failures in 3341 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-03-21&endday=2022-03-27&tree=all

Comment 38

[Intermittent Failures Robot]

1 failures in 2948 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-04-11&endday=2022-04-17&tree=all

Comment 39

[Intermittent Failures Robot]

1 failures in 3159 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-04-18&endday=2022-04-24&tree=all

Comment 40

[Intermittent Failures Robot]

2 failures in 3540 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-05-02&endday=2022-05-08&tree=all

Comment 41

[Intermittent Failures Robot]

1 failures in 2917 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-05-30&endday=2022-06-05&tree=all

Comment 42

[Intermittent Failures Robot]

3 failures in 3336 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 2
• try: 1

Platform and build breakdown:

• macosx1015-64-devedition-qr: 2
  • opt: 2
• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-06-06&endday=2022-06-12&tree=all

Comment 43

[Intermittent Failures Robot]

1 failures in 3170 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1683016&startday=2022-06-13&endday=2022-06-19&tree=all