Closed Bug 1453805 Opened Last year Closed 9 months ago

Intermittent GECKO(2347) | Assertion failure: aStream->GraphImpl()->IterationEnd() > mAllocations[i].mLastCallbackAppendTime, at /builds/worker/workspace/build/src/dom/media/webrtc/MediaEngineWebRTCAudio.cpp:837

Categories

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

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Filed by: ncsoregi [at] mozilla.com

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

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

[task 2018-04-12T21:00:28.843Z] 21:00:28     INFO - TEST-START | dom/media/tests/mochitest/test_getUserMedia_audioConstraints.html
[task 2018-04-12T21:00:29.090Z] 21:00:29     INFO - GECKO(2347) | ++DOMWINDOW == 6 (0x7f717ef04000) [pid = 2404] [serial = 12] [outer = 0x7f7187f46000]
[task 2018-04-12T21:00:29.232Z] 21:00:29     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:29.234Z] 21:00:29     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:29.824Z] 21:00:29     INFO - GECKO(2347) | --DOMWINDOW == 10 (0x7fa8bc391c00) [pid = 2347] [serial = 8] [outer = (nil)] [url = about:blank]
[task 2018-04-12T21:00:29.987Z] 21:00:29     INFO - GECKO(2347) | --DOMWINDOW == 5 (0x7f717ff72000) [pid = 2404] [serial = 11] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2018-04-12T21:00:30.209Z] 21:00:30     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:30.211Z] 21:00:30     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:30.211Z] 21:00:30     INFO - GECKO(2347) | --DOMWINDOW == 9 (0x7fa8af62bc00) [pid = 2347] [serial = 10] [outer = (nil)] [url = chrome://browser/content/webrtcIndicator.xul]
[task 2018-04-12T21:00:30.269Z] 21:00:30     INFO - GECKO(2347) | ++DOCSHELL 0x7fa8b5269800 == 4 [pid = 2347] [id = {9cba64b7-742d-4cf1-872a-744cb40c0516}]
[task 2018-04-12T21:00:30.269Z] 21:00:30     INFO - GECKO(2347) | ++DOMWINDOW == 10 (0x7fa8af860000) [pid = 2347] [serial = 14] [outer = (nil)]
[task 2018-04-12T21:00:30.269Z] 21:00:30     INFO - GECKO(2347) | ++DOMWINDOW == 11 (0x7fa8af9ec400) [pid = 2347] [serial = 15] [outer = 0x7fa8af860000]
[task 2018-04-12T21:00:30.370Z] 21:00:30     INFO - GECKO(2347) | [Parent 2347, Main Thread] WARNING: NS_ENSURE_TRUE(root) failed: file /builds/worker/workspace/build/src/layout/base/nsDocumentViewer.cpp, line 3443
[task 2018-04-12T21:00:30.499Z] 21:00:30     INFO - GECKO(2347) | [GLX] window 200003e has VisualID 0x18c
[task 2018-04-12T21:00:30.508Z] 21:00:30     INFO - GECKO(2347) | [Parent 2347, Renderer] WARNING: robust_buffer_access_behavior marked as unsupported: file /builds/worker/workspace/build/src/gfx/gl/GLContextFeatures.cpp, line 915
[task 2018-04-12T21:00:30.509Z] 21:00:30     INFO - GECKO(2347) | [Parent 2347, Renderer] WARNING: Robustness supported, strategy is not LOSE_CONTEXT_ON_RESET!: file /builds/worker/workspace/build/src/gfx/gl/GLContext.cpp, line 1024
[task 2018-04-12T21:00:30.510Z] 21:00:30     INFO - GECKO(2347) | [Parent 2347, Renderer] WARNING: robustness marked as unsupported: file /builds/worker/workspace/build/src/gfx/gl/GLContextFeatures.cpp, line 915
[task 2018-04-12T21:00:30.511Z] 21:00:30     INFO - GECKO(2347) | WebRender - OpenGL version new 3.3 (Core Profile) Mesa 17.2.8
[task 2018-04-12T21:00:32.291Z] 21:00:32     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:32.293Z] 21:00:32     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:34.048Z] 21:00:34     INFO - GECKO(2347) | --DOMWINDOW == 4 (0x7f717efe1c00) [pid = 2404] [serial = 10] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_audioConstraints.html]
[task 2018-04-12T21:00:34.602Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:34.604Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:34.722Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:34.723Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:34.782Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:34.787Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:34.869Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:34.871Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:34.952Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:34.954Z] 21:00:34     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:35.091Z] 21:00:35     INFO - GECKO(2347) | TEST DEVICES: Got loopback audio: Monitor of Null Output
[task 2018-04-12T21:00:35.093Z] 21:00:35     INFO - GECKO(2347) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
[task 2018-04-12T21:00:35.122Z] 21:00:35     INFO - GECKO(2347) | Assertion failure: aStream->GraphImpl()->IterationEnd() > mAllocations[i].mLastCallbackAppendTime, at /builds/worker/workspace/build/src/dom/media/webrtc/MediaEngineWebRTCAudio.cpp:837
[task 2018-04-12T21:01:06.022Z] 21:01:06     INFO - GECKO(2347) | #01: mozilla::MediaDevice::Pull [dom/media/MediaManager.cpp:1032]
[task 2018-04-12T21:01:06.030Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.031Z] 21:01:06     INFO - GECKO(2347) | #02: mozilla::SourceListener::NotifyPull [dom/media/MediaManager.cpp:4425]
[task 2018-04-12T21:01:06.031Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.032Z] 21:01:06     INFO - GECKO(2347) | #03: mozilla::MediaStreamListener::AsyncNotifyPull [dom/media/MediaStreamListener.h:70]
[task 2018-04-12T21:01:06.032Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.033Z] 21:01:06     INFO - GECKO(2347) | #04: mozilla::SourceMediaStream::PullNewData [xpcom/ds/nsTArray.h:369]
[task 2018-04-12T21:01:06.034Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.035Z] 21:01:06     INFO - GECKO(2347) | #05: mozilla::MediaStreamGraphImpl::UpdateGraph [dom/media/MediaStreamGraph.cpp:1157]
[task 2018-04-12T21:01:06.036Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.036Z] 21:01:06     INFO - GECKO(2347) | #06: mozilla::MediaStreamGraphImpl::OneIteration [dom/media/MediaStreamGraph.cpp:1357]
[task 2018-04-12T21:01:06.037Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.038Z] 21:01:06     INFO - GECKO(2347) | #07: mozilla::AudioCallbackDriver::DataCallback [dom/media/GraphDriver.cpp:979]
[task 2018-04-12T21:01:06.039Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.040Z] 21:01:06     INFO - GECKO(2347) | #08: futures::future::lazy::{{impl}}::poll<closure,core::result::Result<audioipc::messages::CallbackResp, ()>> [git:github.com/rust-lang/rust:src/libcore/option.rs:84203cac67e65ca8640b8392348411098c856985:6140]
[task 2018-04-12T21:01:06.040Z] 21:01:06     INFO - 
[task 2018-04-12T21:01:06.040Z] 21:01:06     INFO - GECKO(2347) | ###!!! [Parent][RunMessage] Error: Channel error: cannot send/recv
[task 2018-04-12T21:01:06.041Z] 21:01:06     INFO - GECKO(2347) | ###!!! [Parent][RunMessage] Error: Channel error: cannot send/recv
[task 2018-04-12T21:01:06.041Z] 21:01:06     INFO - GECKO(2347) | ###!!! [Parent][RunMessage] Error: Channel error: cannot send/recv
[task 2018-04-12T21:01:06.042Z] 21:01:06     INFO - GECKO(2347) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x16007F,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
pehrsons, this is your new assert. Let's wait for multiple failures before investigating, there is enough weirdness with the loopback devices to not waste too much time here.
Flags: needinfo?(apehrson)
Agree. This is the new test from bug 1447982, though that's likely not a direct cause. It does a lot of gUM() and stop() h parallel to one gUM track being continuously live. It's probably that track that's hitting the assert.

I'll keep an eye on this.
Flags: needinfo?(apehrson)
For what it's worth, I just hit this assertion a bunch of times on meet.google.com on a Windows 10 laptop, so this isn't just a test issue.
Component: Audio/Video → WebRTC: Audio/Video
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: Last year
Resolution: --- → INCOMPLETE
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: Last year9 months ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.