Bug 1693151 Comment 11 Edit History

Note: The actual edited comment in the bug view page will always show the original commenter’s name and original timestamp.

Original comment by
on 
Aside from the mess of which PA server is being used by the tests, [here](https://treeherder.mozilla.org/jobs?repo=try&revision=8cf282a4e5295ca099684f3170e2648df2b8372f&selectedTaskRun=Ea-EhOUJTMGzAG6wh4btYw.0) is an example of a bc7 task that used the test-linux.sh PA server and the mediacontrols tests still failed, so I'm able to look at the PA logs.

In this case, we see the [PA server start](https://firefoxci.taskcluster-artifacts.net/Ea-EhOUJTMGzAG6wh4btYw/0/public/logs/live_backing.log) at 2021-03-08T23:28:33.756Z.  [pulse-a.log](https://firefoxci.taskcluster-artifacts.net/Ea-EhOUJTMGzAG6wh4btYw/0/public/test/public/pulse-a.log) shows the PA server runs for 1067.402 seconds, at the end of which we see some GNOME stuff disconnecting.  This puts the PA server's last log time around 2021-03-08T23:46:21Z, which the main logs reveal is when the tests start failing:
```
[task 2021-03-08T23:46:19.240Z] 23:46:19     INFO - GECKO(9701) | MEMORY STAT | vsize 3100MB | residentFast 312MB | heapAllocated 104MB
[task 2021-03-08T23:46:19.241Z] 23:46:19     INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_media_control_supported_keys.js | took 8356ms
[task 2021-03-08T23:46:19.262Z] 23:46:19     INFO - checking window state
[task 2021-03-08T23:46:19.278Z] 23:46:19     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_nosrc_and_error_media.js
[task 2021-03-08T23:46:19.902Z] 23:46:19     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf309c5400 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:366
[task 2021-03-08T23:46:19.903Z] 23:46:19     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf309c5400 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3476
[task 2021-03-08T23:46:21.549Z] 23:46:21     INFO - GECKO(9701) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 130: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2021-03-08T23:46:21.659Z] 23:46:21     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf340ad000 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:366
[task 2021-03-08T23:46:21.659Z] 23:46:21     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf340ad000 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3476
[task 2021-03-08T23:46:21.921Z] 23:46:21     INFO - GECKO(9701) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 130: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2021-03-08T23:46:21.986Z] 23:46:21     INFO - GECKO(9701) | MEMORY STAT | vsize 2899MB | residentFast 308MB | heapAllocated 104MB
[task 2021-03-08T23:46:21.988Z] 23:46:21     INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_nosrc_and_error_media.js | took 2712ms
[task 2021-03-08T23:46:22.004Z] 23:46:22     INFO - checking window state
[task 2021-03-08T23:46:22.020Z] 23:46:22     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js
[task 2021-03-08T23:46:22.337Z] 23:46:22     INFO - GECKO(9701) | [Child 9762, MediaDecoderStateMachine #1] WARNING: 7f27d1e59120 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:323
```
Revision 1 by
on 
Aside from the mess of which PA server is being used by the tests, [here](https://treeherder.mozilla.org/jobs?repo=try&revision=8cf282a4e5295ca099684f3170e2648df2b8372f&selectedTaskRun=Ea-EhOUJTMGzAG6wh4btYw.0) is an example of a bc7 task that used the test-linux.sh PA server and the mediacontrols tests still failed, so I'm able to look at the PA logs.

In this case, we see the [PA server start](https://firefoxci.taskcluster-artifacts.net/Ea-EhOUJTMGzAG6wh4btYw/0/public/logs/live_backing.log) at 2021-03-08T23:28:33.756Z.  [pulse-a.log](https://firefoxci.taskcluster-artifacts.net/Ea-EhOUJTMGzAG6wh4btYw/0/public/test/public/pulse-a.log) shows the PA server running for at least 1067.402 seconds, at the end of which we see some GNOME stuff disconnecting.  This puts the PA server's last log time around 2021-03-08T23:46:21Z, which the main logs reveal is when the tests start failing:
```
[task 2021-03-08T23:46:19.240Z] 23:46:19     INFO - GECKO(9701) | MEMORY STAT | vsize 3100MB | residentFast 312MB | heapAllocated 104MB
[task 2021-03-08T23:46:19.241Z] 23:46:19     INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_media_control_supported_keys.js | took 8356ms
[task 2021-03-08T23:46:19.262Z] 23:46:19     INFO - checking window state
[task 2021-03-08T23:46:19.278Z] 23:46:19     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_nosrc_and_error_media.js
[task 2021-03-08T23:46:19.902Z] 23:46:19     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf309c5400 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:366
[task 2021-03-08T23:46:19.903Z] 23:46:19     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf309c5400 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3476
[task 2021-03-08T23:46:21.549Z] 23:46:21     INFO - GECKO(9701) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 130: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2021-03-08T23:46:21.659Z] 23:46:21     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf340ad000 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:366
[task 2021-03-08T23:46:21.659Z] 23:46:21     INFO - GECKO(9701) | [Child 9934, MediaDecoderStateMachine #1] WARNING: Decoder=7fbf340ad000 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3476
[task 2021-03-08T23:46:21.921Z] 23:46:21     INFO - GECKO(9701) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 130: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2021-03-08T23:46:21.986Z] 23:46:21     INFO - GECKO(9701) | MEMORY STAT | vsize 2899MB | residentFast 308MB | heapAllocated 104MB
[task 2021-03-08T23:46:21.988Z] 23:46:21     INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_nosrc_and_error_media.js | took 2712ms
[task 2021-03-08T23:46:22.004Z] 23:46:22     INFO - checking window state
[task 2021-03-08T23:46:22.020Z] 23:46:22     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_remove_controllable_media_for_active_controller.js
[task 2021-03-08T23:46:22.337Z] 23:46:22     INFO - GECKO(9701) | [Child 9762, MediaDecoderStateMachine #1] WARNING: 7f27d1e59120 OpenCubeb() failed to init cubeb: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:323
```

Back to Bug 1693151 Comment 11