Closed Bug 1407485 Opened 7 years ago Closed 3 years ago

Intermittent dom/media/test/test_streams_gc.html | Test timed out.

Categories

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

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure)

Component: Audio/Video → Audio/Video: MediaStreamGraph
Windows 10 timeout.
Depends on: 1407553
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=157575495&repo=mozilla-central&lineNumber=23574

20:58:02     INFO -  820 INFO TEST-START | dom/media/test/test_streams_gc.html
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Register: decoder=000001EC9558E000, count=4
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] ShutdownDecoder: decoder: 'vorbis audio decoder' (000001EC96AF2D20) flush:1
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC969E8A90 shutdown=false count=0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] ShutdownDecoder: decoder: 'vorbis audio decoder' (000001EC96A704E0) flush:1
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC969E8A90 shutdown=false count=0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: decoder=000001EC94268400 state machine=000001EC9695C000
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: decoder=000001EC8E793400 state machine=000001EC955D9000
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Enter: state machine=000001EC955C3B70 reader=000001EC955B75E0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Enter: state machine=000001EC9698F6A0 reader=000001EC8E7753A0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: reader=000001EC9608C000 shutdown demuxer=000001EC9698F760
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: pool=000001EC9698BBE0 count=1
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC9698BBE0 shutdown=true count=0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: reader=000001EC955B5000 shutdown demuxer=000001EC96009310
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: pool=000001EC8C6087F0 count=1
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC8C6087F0 shutdown=true count=0
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC9608C000 shut down audio task queue
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC9608C000 shut down video task queue
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC955B5000 shut down audio task queue
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] FinishShutdown: state machine=000001EC9695C000
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC955B5000 shut down video task queue
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] FinishShutdown: state machine=000001EC955D9000
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Unregister: decoder=000001EC94268400, count=3
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Unregister: decoder=000001EC8E793400, count=2
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] ShutdownDecoder: decoder: 'vorbis audio decoder' (000001EC9553C680) flush:1
20:58:02     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC969E8A90 shutdown=false count=0
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: decoder=000001EC98D6E000 state machine=000001EC9A9AB000
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Enter: state machine=000001EC94486600 reader=000001EC97B424C0
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: reader=000001EC9A986000 shutdown demuxer=000001EC97A7DD70
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Shutdown: pool=000001EC985A3C10 count=1
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] operator (): pool=000001EC985A3C10 shutdown=true count=0
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC9A986000 shut down audio task queue
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] TearDownDecoders: reader=000001EC9A986000 shut down video task queue
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] FinishShutdown: state machine=000001EC9A9AB000
20:58:14     INFO -  GECKO(8796) | [DEBUG SHUTDOWN] Unregister: decoder=000001EC98D6E000, count=1
21:03:13     INFO -  TEST-INFO | started process screenshot
21:03:13     INFO -  TEST-INFO | screenshot: exit 0
21:03:13     INFO -  Buffered messages logged at 20:58:02
21:03:13     INFO -  821 INFO TEST-PASS | dom/media/test/test_streams_gc.html | A valid string reason is expected
21:03:13     INFO -  822 INFO TEST-PASS | dom/media/test/test_streams_gc.html | Reason cannot be empty
21:03:13     INFO -  Buffered messages finished
21:03:13    ERROR -  823 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out.
21:03:13     INFO -      reportError@SimpleTest/TestRunner.js:121:7
21:03:13     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:03:13     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:03:13     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:03:13     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:03:13     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=322516463&repo=mozilla-central&lineNumber=6375

[task 2020-11-21T10:31:12.206Z] 10:31:12 INFO - TEST-START | dom/media/test/test_streams_gc.html
[task 2020-11-21T10:36:21.056Z] 10:36:21 INFO - TEST-INFO | started process screenshot
[task 2020-11-21T10:36:21.135Z] 10:36:21 INFO - TEST-INFO | screenshot: exit 0
[task 2020-11-21T10:36:21.135Z] 10:36:21 INFO - Buffered messages logged at 10:31:12
[task 2020-11-21T10:36:21.135Z] 10:36:21 INFO - TEST-PASS | dom/media/test/test_streams_gc.html | A valid string reason is expected
[task 2020-11-21T10:36:21.135Z] 10:36:21 INFO - TEST-PASS | dom/media/test/test_streams_gc.html | Reason cannot be empty
[task 2020-11-21T10:36:21.135Z] 10:36:21 INFO - Buffered messages finished
[task 2020-11-21T10:36:21.136Z] 10:36:21 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out.
[task 2020-11-21T10:36:21.136Z] 10:36:21 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:36:21.136Z] 10:36:21 INFO - reportError@SimpleTest/TestRunner.js:143:22
[task 2020-11-21T10:36:21.136Z] 10:36:21 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-11-21T10:36:22.195Z] 10:36:22 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":2,"containerType":"application/ogg","hasAudio":true,"hasVideo":false,"instance":"2a4fc97e000","rate":11127,"reader":{"audioChannels":2,"audioDecoderName":"shutdown","audioFramesDecoded":4,"audioRate":11.126999855041504,"audioState":{"demuxEOS":1,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":0,"numSamplesOutput":0,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"audioType":"audio/vorbis","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"videoDecoderName":"unavailable","videoHardwareAccelerated":false,"videoHeight":0,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":0,"videoState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":0,"needInput":false,"numSamplesInput":0,"numSamplesOutput":0,"pending":0,"queueSize":0,"timeTreshold":0,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"videoType":"none","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":0,"decodedAudioEndTime":276085,"decodedVideoEndTime":0,"duration":276085,"isPlaying":true,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":false,"hasErrored":false,"isPlaying":true,"isStarted":false,"lastGoodPosition":0,"outputRate":48000,"playbackComplete":false,"startTime":0,"written":4800},"isPlaying":true,"isStarted":true},"decodedStream":{"audioQueueFinished":false,"audioQueueSize":0,"data":{"audioFramesWritten":0,"haveSentFinishAudio":false,"haveSentFinishVideo":false,"instance":"","lastVideoEndTime":0,"lastVideoStartTime":0,"nextAudioTime":0,"streamAudioWritten":0,"streamVideoWritten":0},"instance":"","lastAudio":0,"lastOutputTime":0,"playing":0,"startTime":0},"videoSink":{"endPromiseHolderIsEmpty":true,"finished":false,"hasVideo":false,"isPlaying":true,"isStarted":true,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2020-11-21T10:36:22.213Z] 10:36:22 INFO - GECKO(6176) | MEMORY STAT | vsize 2103959MB | vsizeMaxContiguous 67119314MB | residentFast 132MB | heapAllocated 13MB
[task 2020-11-21T10:36:22.232Z] 10:36:22 INFO - TEST-OK | dom/media/test/test_streams_gc.html | took 310018ms
[task 2020-11-21T10:36:22.280Z] 10:36:22 INFO - TEST-START | dom/media/test/test_streams_srcObject.html
[task 2020-11-21T10:36:22.534Z] 10:36:22 INFO - GECKO(6176) | MEMORY STAT | vsize 2103962MB | vsizeMaxContiguous 78713074MB | residentFast 134MB | heapAllocated 15MB
[task 2020-11-21T10:36:22.552Z] 10:36:22 INFO - TEST-OK | dom/media/test/test_streams_srcObject.html | took 272ms
[task 2020-11-21T10:36:22.684Z] 10:36:22 INFO - TEST-START | dom/media/test/test_streams_tracks.html
[task 2020-11-21T10:37:23.428Z] 10:37:23 INFO - GECKO(6176) | [Parent 7508, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp:1391
[task 2020-11-21T10:39:22.889Z] 10:39:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-21T10:39:22.889Z] 10:39:22 INFO - Buffered messages logged at 10:36:22
[task 2020-11-21T10:39:22.889Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | A valid string reason is expected
[task 2020-11-21T10:39:22.889Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Reason cannot be empty
[task 2020-11-21T10:39:22.890Z] 10:39:22 INFO - Started Sat Nov 21 2020 10:36:22 GMT+0000 (Greenwich Mean Time) (1605954982.824s)
[task 2020-11-21T10:39:22.890Z] 10:39:22 INFO - Starting test of big-short.wav
[task 2020-11-21T10:39:22.890Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [started big-short.wav-0 t=0.007] Length of array should match number of running tests
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - Starting test of 320x240.ogv
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [started 320x240.ogv-1 t=0.012] Length of array should match number of running tests
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct audio track count for big-short.wav
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {8990add2-643c-4133-9977-d423ad5d8216} should still be live
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {8990add2-643c-4133-9977-d423ad5d8216} of big-short.wav
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {8990add2-643c-4133-9977-d423ad5d8216} for audio track of big-short.wav has correct form
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct video track count for big-short.wav
[task 2020-11-21T10:39:22.891Z] 10:39:22 INFO - Buffered messages logged at 10:36:23
[task 2020-11-21T10:39:22.892Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct audio track count for 320x240.ogv
[task 2020-11-21T10:39:22.892Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct video track count for 320x240.ogv
[task 2020-11-21T10:39:22.892Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {4f2fc088-a020-4d18-8f20-886083edbfd9} should still be live
[task 2020-11-21T10:39:22.892Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {4f2fc088-a020-4d18-8f20-886083edbfd9} of 320x240.ogv
[task 2020-11-21T10:39:22.892Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {4f2fc088-a020-4d18-8f20-886083edbfd9} for video track of 320x240.ogv has correct form
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - Buffered messages finished
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_tracks.html | Test timed out!
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - big-short.wav-0 timed out!
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - [finished big-short.wav-0] remaining= 320x240.ogv-1
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [finished big-short.wav-0 t=180.061] Length of array should match number of running tests
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - Starting test of short-video.ogv
[task 2020-11-21T10:39:22.893Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [started short-video.ogv-2 t=180.063] Length of array should match number of running tests
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_tracks.html | Test timed out!
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - 320x240.ogv-1 timed out!
[task 2020-11-21T10:39:22.894Z] 10:39:22 INFO - [finished 320x240.ogv-1] remaining= short-video.ogv-2
[task 2020-11-21T10:39:22.895Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [finished 320x240.ogv-1 t=180.066] Length of array should match number of running tests
[task 2020-11-21T10:39:22.895Z] 10:39:22 INFO - Starting test of seek-short.webm
[task 2020-11-21T10:39:22.895Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [started seek-short.webm-3 t=180.067] Length of array should match number of running tests
[task 2020-11-21T10:39:22.973Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct audio track count for short-video.ogv
[task 2020-11-21T10:39:22.973Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {99f50e3a-20ef-4930-b347-30fdc430d555} should still be live
[task 2020-11-21T10:39:22.973Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {99f50e3a-20ef-4930-b347-30fdc430d555} of short-video.ogv
[task 2020-11-21T10:39:22.974Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {99f50e3a-20ef-4930-b347-30fdc430d555} for audio track of short-video.ogv has correct form
[task 2020-11-21T10:39:22.974Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct video track count for short-video.ogv
[task 2020-11-21T10:39:22.974Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {ac8f007e-7ea8-4903-bdec-0648d4ee0715} should still be live
[task 2020-11-21T10:39:22.974Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {ac8f007e-7ea8-4903-bdec-0648d4ee0715} of short-video.ogv
[task 2020-11-21T10:39:22.974Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {ac8f007e-7ea8-4903-bdec-0648d4ee0715} for video track of short-video.ogv has correct form
[task 2020-11-21T10:39:22.993Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct audio track count for seek-short.webm
[task 2020-11-21T10:39:22.994Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct video track count for seek-short.webm
[task 2020-11-21T10:39:22.994Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {3a9e77dc-dcbe-4fd4-afb5-a61dd5b78391} should still be live
[task 2020-11-21T10:39:22.994Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {3a9e77dc-dcbe-4fd4-afb5-a61dd5b78391} of seek-short.webm
[task 2020-11-21T10:39:22.994Z] 10:39:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {3a9e77dc-dcbe-4fd4-afb5-a61dd5b78391} for video track of seek-short.webm has correct form
[task 2020-11-21T10:39:23.459Z] 10:39:23 INFO - GECKO(6176) | [Parent 7508, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012 (NS_ERROR_FILE_NOT_FOUND): file /builds/worker/checkouts/gecko/widget/windows/WinUtils.cpp:1391
[task 2020-11-21T10:42:22.934Z] 10:42:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_tracks.html | Test timed out!
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - short-video.ogv-2 timed out!
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - [finished short-video.ogv-2] remaining= seek-short.webm-3
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [finished short-video.ogv-2 t=360.108] Length of array should match number of running tests
[task 2020-11-21T10:42:22.935Z] 10:42:22 INFO - Starting test of flac-s24.flac
[task 2020-11-21T10:42:22.936Z] 10:42:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [started flac-s24.flac-4 t=360.109] Length of array should match number of running tests
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_tracks.html | Test timed out!
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - seek-short.webm-3 timed out!
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - [finished seek-short.webm-3] remaining= flac-s24.flac-4
[task 2020-11-21T10:42:22.938Z] 10:42:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [finished seek-short.webm-3 t=360.113] Length of array should match number of running tests
[task 2020-11-21T10:42:23.750Z] 10:42:23 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct audio track count for flac-s24.flac
[task 2020-11-21T10:42:23.750Z] 10:42:23 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Track {54c6050e-aaf5-4c41-a958-1d469224a7ee} should still be live
[task 2020-11-21T10:42:23.750Z] 10:42:23 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct track kind for track {54c6050e-aaf5-4c41-a958-1d469224a7ee} of flac-s24.flac
[task 2020-11-21T10:42:23.751Z] 10:42:23 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | id {54c6050e-aaf5-4c41-a958-1d469224a7ee} for audio track of flac-s24.flac has correct form
[task 2020-11-21T10:42:23.751Z] 10:42:23 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | Correct video track count for flac-s24.flac
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_tracks.html | Test timed out!
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - flac-s24.flac-4 timed out!
[task 2020-11-21T10:45:22.984Z] 10:45:22 INFO - [finished flac-s24.flac-4] remaining=
[task 2020-11-21T10:45:22.985Z] 10:45:22 INFO - TEST-PASS | dom/media/test/test_streams_tracks.html | [finished flac-s24.flac-4 t=540.153] Length of array should match number of running tests
[task 2020-11-21T10:45:23.218Z] 10:45:23 INFO - Finished at Sat Nov 21 2020 10:45:23 GMT+0000 (Greenwich Mean Time) (1605955523.211s)
[task 2020-11-21T10:45:23.218Z] 10:45:23 INFO - Running time: 540.388s
[task 2020-11-21T10:45:23.243Z] 10:45:23 INFO - GECKO(6176) | MEMORY STAT | vsize 2103949MB | vsizeMaxContiguous 78713074MB | residentFast 132MB | heapAllocated 18MB
[task 2020-11-21T10:45:23.261Z] 10:45:23 INFO - TEST-OK | dom/media/test/test_streams_tracks.html | took 540580ms

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=336064110&repo=mozilla-central&lineNumber=34480

[task 2021-04-10T10:04:24.888Z] 10:04:24 INFO - TEST-START | dom/media/test/test_streams_gc.html
[task 2021-04-10T10:04:25.477Z] 10:04:25 INFO - GECKO(2901) | [Child 2903, Main Thread] WARNING: No audio stream!: 'mDriver->mAudioStream || aOperation == AsyncCubebOperation::INIT', file /builds/worker/checkouts/gecko/dom/media/GraphDriver.cpp:296
[task 2021-04-10T10:04:40.696Z] 10:04:40 INFO - GECKO(2901) | [Child 2903, Main Thread] ###!!! ASSERTION: MediaTrackGraph took too long to shut down!: '!mShutdownBlocker', file /builds/worker/checkouts/gecko/dom/media/MediaTrackGraph.cpp:1485
[task 2021-04-10T10:04:40.707Z] 10:04:40 INFO - Initializing stack-fixing for the first stack frame, this may take a while...
[task 2021-04-10T10:04:48.919Z] 10:04:48 INFO - GECKO(2901) | #01: {virtual override thunk({offset(-40)}, mozilla::MediaTrackGraphImpl::Notify(nsITimer*))} [/Users/cltbld/tasks/task_1618038085/build/application/Firefox NightlyDebug.app/Contents/MacOS/XUL + 0x34f1325]
[task 2021-04-10T10:04:48.919Z] 10:04:48 INFO - GECKO(2901) | #02: nsTimerImpl::Fire(int) [xpcom/threads/nsTimerImpl.cpp:574]
[task 2021-04-10T10:04:48.919Z] 10:04:48 INFO - GECKO(2901) | #03: nsTimerEvent::Run() [xpcom/threads/TimerThread.cpp:254]
[task 2021-04-10T10:04:48.919Z] 10:04:48 INFO - GECKO(2901) | #04: mozilla::XPCOMThreadWrapper::Runner::Run() [xpcom/threads/AbstractThread.cpp:211]
[task 2021-04-10T10:04:48.920Z] 10:04:48 INFO - GECKO(2901) | #05: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.920Z] 10:04:48 INFO - GECKO(2901) | #06: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.920Z] 10:04:48 INFO - GECKO(2901) | #07: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.920Z] 10:04:48 INFO - GECKO(2901) | #08: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.920Z] 10:04:48 INFO - GECKO(2901) | #09: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.921Z] 10:04:48 INFO - GECKO(2901) | #10: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.921Z] 10:04:48 INFO - GECKO(2901) | #11: nsThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/nsThreadPool.cpp:349]
[task 2021-04-10T10:04:48.921Z] 10:04:48 INFO - GECKO(2901) | #12: mozilla::SharedThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/SharedThreadPool.h:73]
[task 2021-04-10T10:04:48.921Z] 10:04:48 INFO - GECKO(2901) | #13: nsIEventTarget::Dispatch(nsIRunnable*, unsigned int) [s3:gecko-generated-sources:d72bcb61713baa8aa2a5b1e747d00f3902e1243598ecfb27626316992a99323173c809fcd527edf55c1f869ebd41ca32c85b18a314efc99b582036bc6928b48e/dist/include/nsIEventTarget.h::41]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #14: mozilla::AudioCallbackDriver::Shutdown() [dom/media/GraphDriver.cpp:800]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #15: mozilla::(anonymous namespace)::MediaTrackGraphShutDownRunnable::Run() [dom/media/MediaTrackGraph.cpp:1571]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #16: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:230]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #17: mozilla::XPCOMThreadWrapper::Runner::Run() [xpcom/threads/AbstractThread.cpp:211]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #18: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.922Z] 10:04:48 INFO - GECKO(2901) | #19: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.923Z] 10:04:48 INFO - GECKO(2901) | #20: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.923Z] 10:04:48 INFO - GECKO(2901) | #21: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.923Z] 10:04:48 INFO - GECKO(2901) | #22: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.923Z] 10:04:48 INFO - GECKO(2901) | #23: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.923Z] 10:04:48 INFO - GECKO(2901) | #24: nsThread::Shutdown() [xpcom/threads/nsThread.cpp:851]
[task 2021-04-10T10:04:48.924Z] 10:04:48 INFO - GECKO(2901) | #25: mozilla::MediaTrackGraphShutdownThreadRunnable::Run() [dom/media/GraphDriver.cpp:86]
[task 2021-04-10T10:04:48.924Z] 10:04:48 INFO - GECKO(2901) | #26: mozilla::SchedulerGroup::Runnable::Run() [xpcom/threads/SchedulerGroup.cpp:143]
[task 2021-04-10T10:04:48.924Z] 10:04:48 INFO - GECKO(2901) | #27: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.924Z] 10:04:48 INFO - GECKO(2901) | #28: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.924Z] 10:04:48 INFO - GECKO(2901) | #29: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.925Z] 10:04:48 INFO - GECKO(2901) | #30: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.925Z] 10:04:48 INFO - GECKO(2901) | #31: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.925Z] 10:04:48 INFO - GECKO(2901) | #32: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.925Z] 10:04:48 INFO - GECKO(2901) | #33: nsThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/nsThreadPool.cpp:349]
[task 2021-04-10T10:04:48.925Z] 10:04:48 INFO - GECKO(2901) | #34: mozilla::SharedThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/SharedThreadPool.h:73]
[task 2021-04-10T10:04:48.926Z] 10:04:48 INFO - GECKO(2901) | #35: nsIEventTarget::Dispatch(nsIRunnable*, unsigned int) [s3:gecko-generated-sources:d72bcb61713baa8aa2a5b1e747d00f3902e1243598ecfb27626316992a99323173c809fcd527edf55c1f869ebd41ca32c85b18a314efc99b582036bc6928b48e/dist/include/nsIEventTarget.h::41]
[task 2021-04-10T10:04:48.926Z] 10:04:48 INFO - GECKO(2901) | #36: mozilla::AudioCallbackDriver::Shutdown() [dom/media/GraphDriver.cpp:800]
[task 2021-04-10T10:04:48.926Z] 10:04:48 INFO - GECKO(2901) | #37: mozilla::(anonymous namespace)::MediaTrackGraphShutDownRunnable::Run() [dom/media/MediaTrackGraph.cpp:1571]
[task 2021-04-10T10:04:48.926Z] 10:04:48 INFO - GECKO(2901) | #38: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:230]
[task 2021-04-10T10:04:48.926Z] 10:04:48 INFO - GECKO(2901) | #39: mozilla::XPCOMThreadWrapper::Runner::Run() [xpcom/threads/AbstractThread.cpp:211]
[task 2021-04-10T10:04:48.927Z] 10:04:48 INFO - GECKO(2901) | #40: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.927Z] 10:04:48 INFO - GECKO(2901) | #41: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.927Z] 10:04:48 INFO - GECKO(2901) | #42: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.929Z] 10:04:48 INFO - GECKO(2901) | #43: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.930Z] 10:04:48 INFO - GECKO(2901) | #44: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.930Z] 10:04:48 INFO - GECKO(2901) | #45: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.930Z] 10:04:48 INFO - GECKO(2901) | #46: nsThread::Shutdown() [xpcom/threads/nsThread.cpp:851]
[task 2021-04-10T10:04:48.930Z] 10:04:48 INFO - GECKO(2901) | #47: mozilla::MediaTrackGraphShutdownThreadRunnable::Run() [dom/media/GraphDriver.cpp:86]
[task 2021-04-10T10:04:48.931Z] 10:04:48 INFO - GECKO(2901) | #48: mozilla::SchedulerGroup::Runnable::Run() [xpcom/threads/SchedulerGroup.cpp:143]
[task 2021-04-10T10:04:48.931Z] 10:04:48 INFO - GECKO(2901) | #49: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.931Z] 10:04:48 INFO - GECKO(2901) | #50: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.931Z] 10:04:48 INFO - GECKO(2901) | #51: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.931Z] 10:04:48 INFO - GECKO(2901) | #52: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.932Z] 10:04:48 INFO - GECKO(2901) | #53: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.932Z] 10:04:48 INFO - GECKO(2901) | #54: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.932Z] 10:04:48 INFO - GECKO(2901) | #55: nsThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/nsThreadPool.cpp:349]
[task 2021-04-10T10:04:48.932Z] 10:04:48 INFO - GECKO(2901) | #56: mozilla::SharedThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) [xpcom/threads/SharedThreadPool.h:73]
[task 2021-04-10T10:04:48.936Z] 10:04:48 INFO - GECKO(2901) | #57: nsIEventTarget::Dispatch(nsIRunnable*, unsigned int) [s3:gecko-generated-sources:d72bcb61713baa8aa2a5b1e747d00f3902e1243598ecfb27626316992a99323173c809fcd527edf55c1f869ebd41ca32c85b18a314efc99b582036bc6928b48e/dist/include/nsIEventTarget.h::41]
[task 2021-04-10T10:04:48.936Z] 10:04:48 INFO - GECKO(2901) | #58: mozilla::AudioCallbackDriver::Shutdown() [dom/media/GraphDriver.cpp:800]
[task 2021-04-10T10:04:48.936Z] 10:04:48 INFO - GECKO(2901) | #59: mozilla::(anonymous namespace)::MediaTrackGraphShutDownRunnable::Run() [dom/media/MediaTrackGraph.cpp:1571]
[task 2021-04-10T10:04:48.936Z] 10:04:48 INFO - GECKO(2901) | #60: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:230]
[task 2021-04-10T10:04:48.937Z] 10:04:48 INFO - GECKO(2901) | #61: mozilla::XPCOMThreadWrapper::Runner::Run() [xpcom/threads/AbstractThread.cpp:211]
[task 2021-04-10T10:04:48.937Z] 10:04:48 INFO - GECKO(2901) | #62: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.937Z] 10:04:48 INFO - GECKO(2901) | #63: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.937Z] 10:04:48 INFO - GECKO(2901) | #64: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.937Z] 10:04:48 INFO - GECKO(2901) | #65: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.938Z] 10:04:48 INFO - GECKO(2901) | #66: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_1>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.938Z] 10:04:48 INFO - GECKO(2901) | #67: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.938Z] 10:04:48 INFO - GECKO(2901) | #68: nsThread::Shutdown() [xpcom/threads/nsThread.cpp:851]
[task 2021-04-10T10:04:48.938Z] 10:04:48 INFO - GECKO(2901) | #69: mozilla::MediaTrackGraphShutdownThreadRunnable::Run() [dom/media/GraphDriver.cpp:86]
[task 2021-04-10T10:04:48.938Z] 10:04:48 INFO - GECKO(2901) | #70: mozilla::SchedulerGroup::Runnable::Run() [xpcom/threads/SchedulerGroup.cpp:143]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #71: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:471]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #72: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:754]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #73: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:609]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #74: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:393]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #75: mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_0>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-04-10T10:04:48.939Z] 10:04:48 INFO - GECKO(2901) | #76: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1163]
[task 2021-04-10T10:04:48.940Z] 10:04:48 INFO - GECKO(2901) | #77: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:548]
[task 2021-04-10T10:04:48.940Z] 10:04:48 INFO - GECKO(2901) | #78: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:87]
[task 2021-04-10T10:04:48.940Z] 10:04:48 INFO - GECKO(2901) | #79: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:311]
[task 2021-04-10T10:04:48.940Z] 10:04:48 INFO - GECKO(2901) | #80: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:139]
[task 2021-04-10T10:04:48.940Z] 10:04:48 INFO - GECKO(2901) | #81: nsAppShell::Run() [widget/cocoa/nsAppShell.mm:731]
[task 2021-04-10T10:04:48.942Z] 10:04:48 INFO - GECKO(2901) | #82: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:906]
[task 2021-04-10T10:04:48.942Z] 10:04:48 INFO - GECKO(2901) | #83: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:237]
[task 2021-04-10T10:04:48.942Z] 10:04:48 INFO - GECKO(2901) | #84: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:311]
[task 2021-04-10T10:04:48.942Z] 10:04:48 INFO - GECKO(2901) | #85: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:742]
[task 2021-04-10T10:04:48.942Z] 10:04:48 INFO - GECKO(2901) | #86: main [ipc/app/MozillaRuntimeMain.cpp:72]
[task 2021-04-10T10:09:46.385Z] 10:09:46 INFO - TEST-INFO | started process screencapture
[task 2021-04-10T10:09:46.459Z] 10:09:46 INFO - TEST-INFO | screencapture: exit 0
[task 2021-04-10T10:09:46.460Z] 10:09:46 INFO - Buffered messages logged at 10:04:24
[task 2021-04-10T10:09:46.460Z] 10:09:46 INFO - TEST-PASS | dom/media/test/test_streams_gc.html | A valid string reason is expected
[task 2021-04-10T10:09:46.460Z] 10:09:46 INFO - TEST-PASS | dom/media/test/test_streams_gc.html | Reason cannot be empty
[task 2021-04-10T10:09:46.460Z] 10:09:46 INFO - Buffered messages finished
[task 2021-04-10T10:09:46.460Z] 10:09:46 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out. -
[task 2021-04-10T10:10:16.492Z] 10:10:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:10:16.492Z] 10:10:16 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out. -
[task 2021-04-10T10:10:46.626Z] 10:10:46 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:10:46.627Z] 10:10:46 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out. -
[task 2021-04-10T10:11:16.701Z] 10:11:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:11:16.701Z] 10:11:16 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_gc.html | Test timed out. -
[task 2021-04-10T10:11:16.702Z] 10:11:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:11:16.702Z] 10:11:16 INFO - TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | 4 test timeouts, giving up. -
[task 2021-04-10T10:11:16.702Z] 10:11:16 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:11:16.702Z] 10:11:16 INFO - TEST-UNEXPECTED-FAIL | (SimpleTest/TestRunner.js) | Skipping 14 remaining tests. -
[task 2021-04-10T10:17:26.696Z] 10:17:26 INFO - Buffered messages finished
[task 2021-04-10T10:17:26.697Z] 10:17:26 ERROR - TEST-UNEXPECTED-TIMEOUT | dom/media/test/test_streams_gc.html | application timed out after 370 seconds with no output
[task 2021-04-10T10:17:26.697Z] 10:17:26 ERROR - Force-terminating active process(es).
[task 2021-04-10T10:17:26.697Z] 10:17:26 INFO - Determining child pids from psutil...
[task 2021-04-10T10:17:26.697Z] 10:17:26 INFO - [2902, 2903, 2904, 2905, 2906]
[task 2021-04-10T10:17:26.697Z] 10:17:26 INFO - ==> process 2901 launched child process 2902
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - ==> process 2901 launched child process 2903
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - ==> process 2901 launched child process 2904
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - ==> process 2901 launched child process 2905
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - ==> process 2901 launched child process 2906
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - Found child pids: set([2904, 2905, 2906, 2902, 2903])
[task 2021-04-10T10:17:26.698Z] 10:17:26 INFO - Killing process: 2904
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Killing process: 2905
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Killing process: 2906
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:26.699Z] 10:17:26 INFO - Killing process: 2902
[task 2021-04-10T10:17:26.700Z] 10:17:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:26.700Z] 10:17:26 INFO - Killing process: 2903
[task 2021-04-10T10:17:26.700Z] 10:17:26 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:28.925Z] 10:17:28 INFO - psutil found pid 2902 dead
[task 2021-04-10T10:17:28.926Z] 10:17:28 INFO - psutil found pid 2903 dead
[task 2021-04-10T10:17:28.926Z] 10:17:28 INFO - psutil found pid 2904 dead
[task 2021-04-10T10:17:28.926Z] 10:17:28 INFO - psutil found pid 2906 dead
[task 2021-04-10T10:17:28.926Z] 10:17:28 INFO - psutil found pid 2905 dead
[task 2021-04-10T10:17:28.927Z] 10:17:28 INFO - Killing process: 2901
[task 2021-04-10T10:17:28.927Z] 10:17:28 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-10T10:17:28.927Z] 10:17:28 INFO - psutil found pid 2901 dead
[task 2021-04-10T10:17:29.053Z] 10:17:29 WARNING - runtests.py | Failed to get app exit code - running/crashed?
[task 2021-04-10T10:17:29.054Z] 10:17:29 INFO - TEST-INFO | Main app process: exit 0

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.