Closed Bug 1407497 Opened 7 years ago Closed 2 years ago

Intermittent dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out.

Categories

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

x86_64
Windows 10
defect

Tracking

()

RESOLVED DUPLICATE of bug 1781571

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug, Blocks 1 open bug)

Details

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

(In reply to OrangeFactor Robot from comment #1)
> 1 failures in 947 pushes (0.001 failures/push) were associated with this bug
> in the last 7 days.    
> 
> Repository breakdown:
> * autoland: 1
> 
> Platform breakdown:
> * windows10-64: 1
> 
> For more details, see:
> https://brasstacks.mozilla.com/orangefactor/
> ?display=Bug&bugid=1407497&startday=2017-10-09&endday=2017-10-15&tree=all

Windows 10 timeout.
Depends on: 1407553
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → INCOMPLETE
This is still happening.

Recent log: https://treeherder.mozilla.org/logviewer.html#?job_id=187705900&repo=autoland

00:01:17     INFO -  19 INFO TEST-START | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html
00:06:18     INFO -  TEST-INFO | started process screenshot
00:06:18     INFO -  TEST-INFO | screenshot: exit 0
00:06:18     INFO -  Buffered messages logged at 00:01:17
00:06:18     INFO -  20 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Receive a sourceopen event
00:06:18     INFO -  21 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-videoinit.mp4' status=200
00:06:18     INFO -  22 INFO Loading buffer: [0, 1410)
00:06:18     INFO -  23 INFO SourceBuffer buffered ranges grew from TimeRanges:  to TimeRanges:
00:06:18     INFO -  Buffered messages logged at 00:01:18
00:06:18     INFO -  24 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video1.m4s' status=200
00:06:18     INFO -  25 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video2.m4s' status=200
00:06:18     INFO -  26 INFO Loading buffer: [0, 66806)
00:06:18     INFO -  27 INFO SourceBuffer buffered ranges grew from TimeRanges:  to TimeRanges: [0.095, 0.835918)
00:06:18     INFO -  28 INFO Loading buffer: [0, 65292)
00:06:18     INFO -  29 INFO SourceBuffer buffered ranges grew from TimeRanges: [0.095, 0.835918) to TimeRanges: [0.095, 1.625396)
00:06:18     INFO -  30 INFO seek completed
00:06:18     INFO -  31 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbopinit.mp4' status=200
00:06:18     INFO -  32 INFO Loading buffer: [0, 1395)
00:06:18     INFO -  33 INFO SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
00:06:18     INFO -  34 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop1.m4s' status=200
00:06:18     INFO -  35 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop2.m4s' status=200
00:06:18     INFO -  36 INFO TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop3.m4s' status=200
00:06:18     INFO -  37 INFO Loading buffer: [0, 24424)
00:06:18     INFO -  38 INFO SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
00:06:18     INFO -  39 INFO Loading buffer: [0, 22205)
00:06:18     INFO -  40 INFO SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
00:06:18     INFO -  41 INFO Loading buffer: [0, 24013)
00:06:18     INFO -  42 INFO SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 2.414875)
00:06:18     INFO -  Buffered messages finished
00:06:18    ERROR -  43 INFO TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out.
00:06:18     INFO -      reportError@SimpleTest/TestRunner.js:121:7
00:06:18     INFO -      TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
00:06:18     INFO -      TestRunner.runTests/<@SimpleTest/TestRunner.js:381:9
00:06:18     INFO -      promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:368:5
00:06:18     INFO -      RunSet.runtests@SimpleTest/setup.js:194:3
00:06:18     INFO -      RunSet.runall@SimpleTest/setup.js:173:5
00:06:18     INFO -      hookupTests@SimpleTest/setup.js:266:5
00:06:18     INFO -  parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
00:06:18     INFO -  getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
00:06:18     INFO -  EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
00:06:18     INFO -      hookup@SimpleTest/setup.js:246:5
00:06:18     INFO -  EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=c%3A%5Cusers%5Ctask_1531353213%5Cappdata%5Clocal%5Ctemp&cleanupCrashes=true:11:1
00:06:19     INFO -  GECKO(8428) | MEMORY STAT | vsize 1518MB | vsizeMaxContiguous 132562497MB | residentFast 83MB | heapAllocated 11MB
00:06:19     INFO -  GECKO(8428) | MediaDecoder=18ba816d660: channels=2 rate=22050 hasAudio=1 hasVideo=1 mPlayState=PLAYING
00:06:19     INFO -  GECKO(8428) | reader data:
00:06:19     INFO -  GECKO(8428) | Container Type: MediaSource
00:06:19     INFO -  GECKO(8428) | Audio Decoder(audio/mp4a-latm, 2 channels @ 22.0kHz): wmf audio decoder
00:06:19     INFO -  GECKO(8428) | Audio Frames Decoded: 22
00:06:19     INFO -  GECKO(8428) | Audio State: ni=0 no=0 wp=0 demuxr=0 demuxq=0 decoder=0 tt=-1.0 tths=-1 in=21 out=21 qs=0 pending=0 wfd=0 eos=1 ds=0 wfk=0 sid=12
00:06:19     INFO -  GECKO(8428) | Video Decoder(video/avc, 400x300 @ 29.97): wmf hardware video decoder - nv12 (remote)
00:06:19     INFO -  GECKO(8428) | Hardware Video Decoding: enabled
00:06:19     INFO -  GECKO(8428) | Video Frames Decoded: 39 (skipped=0)
00:06:19     INFO -  GECKO(8428) | Video State: ni=0 no=0 wp=0 demuxr=0 demuxq=0 decoder=0 tt=-1.0 tths=-1 in=48 out=18 qs=31 pending:1 wfd=0 eos=1 ds=3 wfk=0 sid=12
00:06:19     INFO -  GECKO(8428) | Dumping Data for Demuxer: 18ba97d1c00
00:06:19     INFO -  GECKO(8428) | 	Dumping Audio Track Buffer(video/mp4): mLastAudioTime=2.414875
00:06:19     INFO -  GECKO(8428) | 		Audio Track Buffer Details: NumSamples=52 Size=17894 Evictable=17570 NextGetSampleIndex=52 NextInsertionIndex=52
00:06:19     INFO -  GECKO(8428) | 		Audio Track Buffered: ranges=[(0.000000, 2.414875)]
00:06:19     INFO -  GECKO(8428) | 	Dumping Video Track Buffer(video/mp4): mLastVideoTime=2.498333
00:06:19     INFO -  GECKO(8428) | 		Video Track Buffer Details: NumSamples=72 Size=90424 Evictable=59815 NextGetSampleIndex=72 NextInsertionIndex=72
00:06:19     INFO -  GECKO(8428) | 		Video Track Buffered: ranges=[(0.095000, 2.498333)]
00:06:19     INFO -  GECKO(8428) | MDSM: duration=1800029000 GetMediaTime=2093954 GetClock=2093954 mMediaSink=18ba970e7a0 state=DECODING mPlayState=3 mSentFirstFrameLoadedEvent=1 IsPlaying=1 mAudioStatus=idle mVideoStatus=idle mDecodedAudioEndTime=2414874 mDecodedVideoEndTime=2198323 mAudioCompleted=0 mVideoCompleted=0 mIsPrerolling=0
00:06:19     INFO -  GECKO(8428) | VideoSink: IsStarted=1 IsPlaying=1 VideoQueue(finished=0 size=4) mVideoFrameEndTime=2098333 mHasVideo=1 mVideoSinkEndRequest.Exists()=0 mEndPromiseHolder.IsEmpty()=0
00:06:19     INFO -  GECKO(8428) | AudioSinkWrapper: IsStarted=1 IsPlaying=1 AudioEnded=0
00:06:19     INFO -  GECKO(8428) | AudioSink: StartTime=1532517 LastGoodPosition=561437 Playing=1  OutputRate=48000 Written=31749 Errored=0 PlaybackComplete=0
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
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=195150897&repo=mozilla-inbound&lineNumber=1326

20:55:57     INFO - Loading buffer: [0, 24013)
20:55:57     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 2.414875)
20:55:57     INFO - Buffered messages finished
20:55:57     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out. 
20:55:57     INFO -     reportError@SimpleTest/TestRunner.js:121:7
20:55:57     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:55:57     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:381:9
20:55:57     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:368:50
20:55:57     INFO -     RunSet.runtests@SimpleTest/setup.js:194:3
20:55:57     INFO -     RunSet.runall@SimpleTest/setup.js:173:5
20:55:57     INFO -     hookupTests@SimpleTest/setup.js:266:5
20:55:57     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
20:55:57     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
20:55:57     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
20:55:57     INFO -     hookup@SimpleTest/setup.js:246:5
20:55:57     INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=c%3A%5Cusers%5Ctask_1534883398%5Cappdata%5Clocal%5Ctemp&cleanupCrashes=true:11:1
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
Recent failure log : 
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=217514198&repo=mozilla-inbound&lineNumber=1200

20:02:19     INFO - runtests.py | Running with e10s: True
20:02:19     INFO - runtests.py | Running with serviceworker_e10s: False
20:02:19     INFO - runtests.py | Running tests: start.
20:02:19     INFO - 
20:02:19     INFO - Application command: Z:\task_1545076112\build\application\firefox\firefox.exe -marionette --wait-for-browser -foreground -profile c:\users\task_1545076112\appdata\local\temp\tmpnusxpf.mozrunner
20:02:19     INFO - runtests.py | Application pid: 7316
20:02:19     INFO - TEST-INFO | started process GECKO(7316)
20:02:19     INFO - GECKO(7316) | 1545076939621	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: resource://pdf.js/
20:02:19     INFO - GECKO(7316) | 1545076939622	addons.webextension.screenshots@mozilla.org	WARN	Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid host permission: about:reader*
20:02:19     INFO - GECKO(7316) | 1545076939756	Marionette	TRACE	Received observer notification profile-after-change
20:02:19     INFO - GECKO(7316) | 1545076939844	Marionette	TRACE	Received observer notification toplevel-window-ready
20:02:19     INFO - GECKO(7316) | 1545076939873	Marionette	TRACE	Received observer notification command-line-startup
20:02:19     INFO - GECKO(7316) | 1545076939873	Marionette	TRACE	Received observer notification nsPref:changed
20:02:19     INFO - GECKO(7316) | 1545076939873	Marionette	DEBUG	Init aborted (running=false, enabled=true, finalUIStartup=false)
20:02:20     INFO - GECKO(7316) | 1545076940026	Marionette	TRACE	Received observer notification toplevel-window-ready
20:02:20     INFO - GECKO(7316) | 1545076940798	Marionette	TRACE	Received observer notification sessionstore-windows-restored
20:02:20     INFO - GECKO(7316) | 1545076940799	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
20:02:21     INFO - GECKO(7316) | 1545076941101	Marionette	TRACE	All scripts recorded.
20:02:21     INFO - GECKO(7316) | 1545076941149	Marionette	INFO	Listening on port 2828
20:02:21     INFO - GECKO(7316) | 1545076941149	Marionette	DEBUG	Remote service is active
20:02:21     INFO - GECKO(7316) | 1545076941423	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:49985
20:02:21     INFO - GECKO(7316) | 1545076941519	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:49988
20:02:21     INFO - GECKO(7316) | 1545076941520	Marionette	DEBUG	Closed connection 1
20:02:21     INFO - GECKO(7316) | 1545076941521	Marionette	DEBUG	Closed connection 0
20:02:21     INFO - GECKO(7316) | 1545076941521	Marionette	DEBUG	Accepted connection 2 from 127.0.0.1:49989
20:02:21     INFO - GECKO(7316) | 1545076941522	Marionette	DEBUG	2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
20:02:21     INFO - GECKO(7316) | 1545076941553	Marionette	TRACE	[6442450945] Frame script loaded
20:02:21     INFO - GECKO(7316) | 1545076941554	Marionette	TRACE	[6442450945] Frame script registered
20:02:21     INFO - GECKO(7316) | 1545076941560	Marionette	DEBUG	2 <- [1,1,null,{"sessionId":"0bb77afa-6c89-448b-bf03-54d7118f03b4","capabilities":{"browserName":"firefox","browserVersion":"66.0a ... p\\tmpnusxpf.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true}}]
20:02:21     INFO - GECKO(7316) | 1545076941576	Marionette	DEBUG	2 -> [0,2,"Addon:Install",{"path":"c:\\users\\task_1545076112\\appdata\\local\\temp\\tmpe_sv31.zip","temporary":false}]
20:02:21     INFO - GECKO(7316) | 1545076941619	Marionette	DEBUG	2 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
20:02:21     INFO - GECKO(7316) | 1545076941648	Marionette	DEBUG	2 -> [0,3,"Addon:Install",{"path":"c:\\users\\task_1545076112\\appdata\\local\\temp\\tmp3_pgwc.zip","temporary":false}]
20:02:21     INFO - GECKO(7316) | 1545076941683	Marionette	DEBUG	2 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
20:02:21     INFO - GECKO(7316) | 1545076941685	Marionette	DEBUG	2 -> [0,4,"Marionette:GetContext",{}]
20:02:21     INFO - GECKO(7316) | 1545076941685	Marionette	DEBUG	2 <- [1,4,null,{"value":"content"}]
20:02:21     INFO - GECKO(7316) | 1545076941687	Marionette	DEBUG	2 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
20:02:21     INFO - GECKO(7316) | 1545076941687	Marionette	DEBUG	2 <- [1,5,null,{"value":null}]
20:02:21     INFO - GECKO(7316) | 1545076941689	Marionette	DEBUG	2 -> [0,6,"WebDriver:ExecuteScript",{"scriptTimeout":null,"newSandbox":true,"args":[{"testUrl":"http://mochi.test:8888/tests?autor ...  new CustomEvent(\"mochitest-load\", {\"detail\": [flavor, url]});\nwin.dispatchEvent(ev);","sandbox":"default","line":1714}]
20:02:21     INFO - GECKO(7316) | 1545076941695	Marionette	DEBUG	2 <- [1,6,null,{"value":null}]
20:02:21     INFO - GECKO(7316) | 1545076941702	Marionette	DEBUG	2 -> [0,7,"Marionette:SetContext",{"value":"content"}]
20:02:21     INFO - GECKO(7316) | 1545076941703	Marionette	DEBUG	2 <- [1,7,null,{"value":null}]
20:02:21     INFO - GECKO(7316) | 1545076941704	Marionette	DEBUG	2 -> [0,8,"WebDriver:DeleteSession",{}]
20:02:21     INFO - runtests.py | Waiting for browser...
20:02:21     INFO - GECKO(7316) | 1545076941705	Marionette	DEBUG	2 <- [1,8,null,{"value":null}]
20:02:21     INFO - GECKO(7316) | 1545076941707	Marionette	DEBUG	Closed connection 2
20:02:21     INFO - SimpleTest START
20:02:21     INFO - TEST-START | dom/media/mediasource/test/test_AVC3_mp4.html
20:02:27     INFO - GECKO(7316) | MEMORY STAT | vsize 1424MB | vsizeMaxContiguous 131922764MB | residentFast 76MB | heapAllocated 9MB
20:02:27     INFO - TEST-OK | dom/media/mediasource/test/test_AVC3_mp4.html | took 5164ms
20:02:27     INFO - TEST-START | dom/media/mediasource/test/test_AppendPartialInitSegment.html
20:02:27     INFO - GECKO(7316) | MEMORY STAT | vsize 1425MB | vsizeMaxContiguous 131922764MB | residentFast 78MB | heapAllocated 9MB
20:02:27     INFO - TEST-OK | dom/media/mediasource/test/test_AppendPartialInitSegment.html | took 106ms
20:02:27     INFO - TEST-START | dom/media/mediasource/test/test_AudioChange_mp4.html
20:02:33     INFO - GECKO(7316) | MEMORY STAT | vsize 1431MB | vsizeMaxContiguous 131922764MB | residentFast 84MB | heapAllocated 10MB
20:02:33     INFO - TEST-OK | dom/media/mediasource/test/test_AudioChange_mp4.html | took 6246ms
20:02:33     INFO - TEST-START | dom/media/mediasource/test/test_AutoRevocation.html
20:02:33     INFO - GECKO(7316) | MEMORY STAT | vsize 1431MB | vsizeMaxContiguous 131922764MB | residentFast 84MB | heapAllocated 11MB
20:02:33     INFO - TEST-OK | dom/media/mediasource/test/test_AutoRevocation.html | took 50ms
20:02:33     INFO - TEST-START | dom/media/mediasource/test/test_BufferedSeek.html
20:02:33     INFO - GECKO(7316) | MEMORY STAT | vsize 1434MB | vsizeMaxContiguous 131922764MB | residentFast 86MB | heapAllocated 11MB
20:02:33     INFO - TEST-OK | dom/media/mediasource/test/test_BufferedSeek.html | took 114ms
20:02:33     INFO - TEST-START | dom/media/mediasource/test/test_BufferedSeek_mp4.html
20:02:33     INFO - GECKO(7316) | MEMORY STAT | vsize 1434MB | vsizeMaxContiguous 131922764MB | residentFast 86MB | heapAllocated 11MB
20:02:33     INFO - TEST-OK | dom/media/mediasource/test/test_BufferedSeek_mp4.html | took 78ms
20:02:33     INFO - TEST-START | dom/media/mediasource/test/test_BufferingWait.html
20:02:37     INFO - GECKO(7316) | MEMORY STAT | vsize 1437MB | vsizeMaxContiguous 131922764MB | residentFast 87MB | heapAllocated 12MB
20:02:37     INFO - TEST-OK | dom/media/mediasource/test/test_BufferingWait.html | took 4096ms
20:02:37     INFO - TEST-START | dom/media/mediasource/test/test_BufferingWait_mp4.html
20:02:42     INFO - GECKO(7316) | MEMORY STAT | vsize 1436MB | vsizeMaxContiguous 131922764MB | residentFast 89MB | heapAllocated 12MB
20:02:42     INFO - TEST-OK | dom/media/mediasource/test/test_BufferingWait_mp4.html | took 4621ms
20:02:42     INFO - TEST-START | dom/media/mediasource/test/test_ChangeType.html
20:02:48     INFO - GECKO(7316) | MEMORY STAT | vsize 1454MB | vsizeMaxContiguous 131922764MB | residentFast 92MB | heapAllocated 13MB
20:02:48     INFO - TEST-OK | dom/media/mediasource/test/test_ChangeType.html | took 6073ms
20:02:48     INFO - TEST-START | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html
20:07:52     INFO - TEST-INFO | started process screenshot
20:07:52     INFO - TEST-INFO | screenshot: exit 0
20:07:52     INFO - Buffered messages logged at 20:02:48
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Receive a sourceopen event 
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-videoinit.mp4' status=200 
20:07:52     INFO - Loading buffer: [0, 1410)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges:  to TimeRanges: 
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video1.m4s' status=200 
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video2.m4s' status=200 
20:07:52     INFO - Loading buffer: [0, 66806)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges:  to TimeRanges: [0.095, 0.835918)
20:07:52     INFO - Loading buffer: [0, 65292)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 0.835918) to TimeRanges: [0.095, 1.625396)
20:07:52     INFO - seek completed
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbopinit.mp4' status=200 
20:07:52     INFO - Loading buffer: [0, 1395)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop1.m4s' status=200 
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop2.m4s' status=200 
20:07:52     INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop3.m4s' status=200 
20:07:52     INFO - Loading buffer: [0, 24424)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
20:07:52     INFO - Loading buffer: [0, 22205)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
20:07:52     INFO - Loading buffer: [0, 24013)
20:07:52     INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 2.414875)
20:07:52     INFO - Buffered messages finished
20:07:52     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out. 
20:07:52     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:275:7
20:07:52     INFO -     reportError@SimpleTest/TestRunner.js:121:7
20:07:52     INFO -     TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     setTimeout handler*TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
20:07:52     INFO -     TestRunner.runTests/<@SimpleTest/TestRunner.js:381:9
20:07:52     INFO -     promise callback*TestRunner.runTests@SimpleTest/TestRunner.js:368:50
20:07:52     INFO -     RunSet.runtests@SimpleTest/setup.js:201:3
20:07:52     INFO -     RunSet.runall@SimpleTest/setup.js:180:5
20:07:52     INFO -     hookupTests@SimpleTest/setup.js:273:5
20:07:52     INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
20:07:52     INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
20:07:52     INFO - EventHandlerNonNull*getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE

This is still happening.

Recent failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=237697902&repo=autoland&lineNumber=1206

21:09:00 INFO - TEST-START | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html
21:14:29 INFO - TEST-INFO | started process screenshot
21:14:29 INFO - TEST-INFO | screenshot: exit 0
21:14:29 INFO - Buffered messages logged at 21:09:00
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Receive a sourceopen event
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-videoinit.mp4' status=200
21:14:29 INFO - Loading buffer: [0, 1410)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: to TimeRanges:
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video1.m4s' status=200
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop_480_624kbps-video2.m4s' status=200
21:14:29 INFO - Loading buffer: [0, 66806)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: to TimeRanges: [0.095, 0.835918)
21:14:29 INFO - Loading buffer: [0, 65292)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 0.835918) to TimeRanges: [0.095, 1.625396)
21:14:29 INFO - seek completed
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbopinit.mp4' status=200
21:14:29 INFO - Loading buffer: [0, 1395)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop1.m4s' status=200
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop2.m4s' status=200
21:14:29 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop3.m4s' status=200
21:14:29 INFO - Loading buffer: [0, 24424)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
21:14:29 INFO - Loading buffer: [0, 22205)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
21:14:29 INFO - Loading buffer: [0, 24013)
21:14:29 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 2.414875)
21:14:29 INFO - Buffered messages finished
21:14:29 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out.
21:14:29 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
21:14:29 INFO - reportError@SimpleTest/TestRunner.js:121:22
21:14:29 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:14:29 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:381:20
21:14:29 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:368:50
21:14:29 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
21:14:29 INFO - RunSet.runall@SimpleTest/setup.js:180:12
21:14:29 INFO - hookupTests@SimpleTest/setup.js:273:12
21:14:29 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:36:5
21:14:29 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:49:11
21:14:29 INFO - EventHandlerNonNull
getTestManifest@http://mochi.test:8888/manifestLibrary.js:45:3

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

There are 22 total failures in the last 7 days on:

*debug: windows7-32, windows10-64-qr
*opt: windows7-32-shippable, windows10-64-shippable-qr, windows10-64-qr

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=257729602&repo=autoland&lineNumber=1403

21:12:20 INFO - TEST-START | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html
21:12:20 INFO - [3412, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
21:12:20 INFO - GECKO(3168) | ++DOMWINDOW == 9 (08808C00) [pid = 3820] [serial = 28] [outer = 08B3FA60]
21:12:20 INFO - GECKO(3168) | --DOMWINDOW == 8 (08806800) [pid = 3820] [serial = 25] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
21:12:24 INFO - GECKO(3168) | [Child 3820, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6814
21:12:24 INFO - GECKO(3168) | [Child 3820, Main Thread] WARNING: Wrong inner/outer window combination!: file z:/build/build/src/dom/base/Document.cpp, line 6814
21:12:28 INFO - GECKO(3168) | --DOMWINDOW == 7 (0880F000) [pid = 3820] [serial = 27] [outer = 00000000] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
21:12:59 INFO - GECKO(3168) | --DOMWINDOW == 6 (08807000) [pid = 3820] [serial = 24] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/media/mediasource/test/test_BufferingWait_mp4.html]
21:12:59 INFO - GECKO(3168) | --DOMWINDOW == 5 (08808800) [pid = 3820] [serial = 26] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/media/mediasource/test/test_ChangeType.html]
21:12:59 INFO - GECKO(3168) | --DOMWINDOW == 4 (08809800) [pid = 3820] [serial = 22] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/media/mediasource/test/test_BufferingWait.html]
21:13:48 INFO - GECKO(3168) | [Parent 888, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils.cpp, line 1346
21:15:48 INFO - GECKO(3168) | [Parent 888, Jump List] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file z:/build/build/src/widget/windows/WinUtils

21:17:49 INFO - TEST-PASS | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | fetchWithXHR load uri='bipbop/bipbop3.m4s' status=200
21:17:49 INFO - Loading buffer: [0, 24424)
21:17:49 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
21:17:49 INFO - Loading buffer: [0, 22205)
21:17:49 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 1.625396)
21:17:49 INFO - Loading buffer: [0, 24013)
21:17:49 INFO - SourceBuffer buffered ranges grew from TimeRanges: [0.095, 1.625396) to TimeRanges: [0.095, 2.414875)
21:17:49 INFO - Buffered messages finished
21:17:49 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out.
21:17:49 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:275:18
21:17:49 INFO - reportError@SimpleTest/TestRunner.js:121:22
21:17:49 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:142:7
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handlerTestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - setTimeout handler
TestRunner._checkForHangs@SimpleTest/TestRunner.js:163:5
21:17:49 INFO - TestRunner.runTests/<@SimpleTest/TestRunner.js:381:20
21:17:49 INFO - promise callbackTestRunner.runTests@SimpleTest/TestRunner.js:368:50
21:17:49 INFO - RunSet.runtests@SimpleTest/setup.js:201:14
21:17:49 INFO - RunSet.runall@SimpleTest/setup.js:180:12
21:17:49 INFO - hookupTests@SimpleTest/setup.js:273:12
21:17:49 INFO - parseTestManifest@http://mochi.test:8888/manifestLibrary.js:48:5
21:17:49 INFO - getTestManifest/req.onload@http://mochi.test:8888/manifestLibrary.js:61:11
21:17:49 INFO - EventHandlerNonNull
getTestManifest@http://mochi.test:8888/manifestLibrary.js:57:3
21:17:49 INFO - hookup@SimpleTest/setup.js:253:5
21:17:49 INFO - EventHandlerNonNull*@http://mochi.test:8888/tests?autorun=1&closeWhenDone=1&consoleLevel=INFO&manifestFile=tests.json&dumpOutputDirectory=c%3A%5Cusers%5Ctask_1563828872%5Cappdata%5Clocal%5Ctemp&cleanupCrashes=true:11:1
21:17:50 INFO - GECKO(3168) | JavaScript error: http://mochi.test:8888/tests/dom/media/mediasource/test/mediasource.js, line 188: TypeError: v.mozDumpDebugInfo is not a function
21:18:19 INFO - Not taking screenshot here: see the one that was previously logged
21:18:19 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_ChangeWhileWaitingOnMissingData_mp4.html | Test timed out.

Nils can you take a look?

Flags: needinfo?(drno)
Whiteboard: [stockwell needswork:owner]
Status: REOPENED → RESOLVED
Closed: 5 years ago2 years ago
Resolution: --- → DUPLICATE

Declaring NI bankruptcy.

Flags: needinfo?(drno)
You need to log in before you can comment on or make changes to this bug.