Closed Bug 1389983 Opened 3 years ago Closed 1 year ago

Intermittent dom/media/tests/mochitest/test_getUserMedia_addtrack_removetrack_events.html | assertion count 1 is more than expected 0 assertions

Categories

(Core :: WebRTC, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla69
Tracking Status
firefox57 --- disabled
firefox58 --- disabled
firefox68 --- fixed
firefox69 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: pehrsons)

References

Details

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

Attachments

(1 file)

Filed by: archaeopteryx [at] coole-files.de

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

https://queue.taskcluster.net/v1/task/cFIo0NvlQqqNUCE8PoKHZw/runs/0/artifacts/public/test_info//mochitest-media_errorsummary.log

[task 2017-08-13T19:11:43.461029Z] 19:11:43     INFO - GECKO(3156) | TEST DEVICES: Using media devices:
[task 2017-08-13T19:11:43.461121Z] 19:11:43     INFO - GECKO(3156) | audio: Sine source at 440 Hz
[task 2017-08-13T19:11:43.461171Z] 19:11:43     INFO - GECKO(3156) | video: Dummy video device (0x0000)
[task 2017-08-13T19:11:43.779696Z] 19:11:43     INFO - GECKO(3156) | --DOMWINDOW == 6 (0xce01b800) [pid = 3203] [serial = 42] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_enumerateDevices.html]
[task 2017-08-13T19:11:44.046219Z] 19:11:44     INFO - GECKO(3156) | --DOMWINDOW == 5 (0xce6ee800) [pid = 3203] [serial = 50] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
[task 2017-08-13T19:11:44.514056Z] 19:11:44     INFO - GECKO(3156) | [Child 3203] WARNING: Cannot query channel count on a AudioSegment with no chunks.: '!mChunks.IsEmpty()', file /home/worker/workspace/build/src/dom/media/AudioSegment.h, line 370
[task 2017-08-13T19:11:44.530764Z] 19:11:44     INFO - GECKO(3156) | ++DOCSHELL 0xcd4ed000 == 4 [pid = 3156] [id = {0bbdd25b-8229-451e-960a-ed636278ab2d}]
[task 2017-08-13T19:11:44.530849Z] 19:11:44     INFO - GECKO(3156) | ++DOMWINDOW == 13 (0xcfe07c00) [pid = 3156] [serial = 24] [outer = (nil)]
[task 2017-08-13T19:11:44.531720Z] 19:11:44     INFO - GECKO(3156) | ++DOMWINDOW == 14 (0xd333dc00) [pid = 3156] [serial = 25] [outer = 0xcfe07c00]
[task 2017-08-13T19:11:44.579463Z] 19:11:44     INFO - GECKO(3156) | [Child 3203] WARNING: Cannot query channel count on a AudioSegment with no chunks.: '!mChunks.IsEmpty()', file /home/worker/workspace/build/src/dom/media/AudioSegment.h, line 370
[task 2017-08-13T19:11:44.946816Z] 19:11:44     INFO - GECKO(3156) | [Child 3203] ###!!! ASSERTION: Track not found: 'Error', file /home/worker/workspace/build/src/dom/media/MediaStreamGraph.cpp, line 3060
[task 2017-08-13T19:11:44.947881Z] 19:11:44     INFO - GECKO(3156) | #01: mozilla::SourceMediaStream::GetEndOfAppendedData [dom/media/MediaStreamGraph.cpp:3061]
[task 2017-08-13T19:11:44.948824Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.950192Z] 19:11:44     INFO - GECKO(3156) | #02: mozilla::MediaEngineRemoteVideoSource::NotifyPull [dom/media/webrtc/MediaEngineRemoteVideoSource.cpp:351]
[task 2017-08-13T19:11:44.951467Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.953328Z] 19:11:44     INFO - GECKO(3156) | #03: mozilla::SourceListener::NotifyPull [dom/media/MediaManager.cpp:3772]
[task 2017-08-13T19:11:44.954978Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.956883Z] 19:11:44     INFO - GECKO(3156) | #04: mozilla::MediaStreamGraphImpl::ExtractPendingInput [xpcom/threads/Mutex.h:219]
[task 2017-08-13T19:11:44.958059Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.959390Z] 19:11:44     INFO - GECKO(3156) | #05: mozilla::MediaStreamGraphImpl::UpdateGraph [dom/media/MediaStreamGraph.cpp:1302]
[task 2017-08-13T19:11:44.960185Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.961127Z] 19:11:44     INFO - GECKO(3156) | #06: mozilla::MediaStreamGraphImpl::OneIteration [dom/media/MediaStreamGraph.cpp:1455]
[task 2017-08-13T19:11:44.962170Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.968732Z] 19:11:44     INFO - GECKO(3156) | #07: mozilla::AudioCallbackDriver::DataCallback [dom/media/GraphDriver.cpp:997]
[task 2017-08-13T19:11:44.970477Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.972490Z] 19:11:44     INFO - GECKO(3156) | #08: cubeb_pulse::backend::stream::Stream::trigger_user_callback [media/libcubeb/cubeb-pulse-rs/src/backend/stream.rs:722]
[task 2017-08-13T19:11:44.974465Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.976618Z] 19:11:44     INFO - GECKO(3156) | #09: cubeb_pulse::backend::stream::{{impl}}::new::read_data [media/libcubeb/cubeb-pulse-rs/src/backend/stream.rs:144]
[task 2017-08-13T19:11:44.979943Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.981314Z] 19:11:44     INFO - GECKO(3156) | #10: core::ops::Fn::call<fn(&pulse::stream::Stream, usize, *mut std::os::raw::c_void),(&pulse::stream::Stream, usize, *mut std::os::raw::c_void)> [git:github.com/rust-lang/rust:src/libcore/ops.rs:0ade339411587887bf01bcfa2e9ae4414c8900d4:2588]
[task 2017-08-13T19:11:44.982523Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.983890Z] 19:11:44     INFO - GECKO(3156) | #11: pulse::stream::{{impl}}::set_read_callback::wrapped<fn(&pulse::stream::Stream, usize, *mut std::os::raw::c_void)> [media/libcubeb/cubeb-pulse-rs/pulse-rs/src/stream.rs:290]
[task 2017-08-13T19:11:44.988939Z] 19:11:44     INFO - 
[task 2017-08-13T19:11:44.990839Z] 19:11:44     INFO - GECKO(3156) | [Child 3203] WARNING: Audio Buffer is not full by the end of the callback.: 'Available() == 0 || mSampleWriteOffset == 0', file /home/worker/workspace/build/src/dom/media/AudioBufferUtils.h, line 88
[task 2017-08-13T19:11:45.048713Z] 19:11:45     INFO - GECKO(3156) | --DOCSHELL 0xcd4ed000 == 3 [pid = 3156] [id = {0bbdd25b-8229-451e-960a-ed636278ab2d}]
[task 2017-08-13T19:11:45.105363Z] 19:11:45     INFO - GECKO(3156) | MEMORY STAT | vsize 962MB | residentFast 99MB | heapAllocated 15MB
[task 2017-08-13T19:11:45.121578Z] 19:11:45     INFO - TEST-OK | dom/media/tests/mochitest/test_getUserMedia_addtrack_removetrack_events.html | took 1858ms
[task 2017-08-13T19:11:45.157904Z] 19:11:45     INFO - GECKO(3156) | ++DOMWINDOW == 6 (0xce6e9c00) [pid = 3203] [serial = 52] [outer = 0xd9a09400]
[task 2017-08-13T19:11:45.214899Z] 19:11:45     INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_getUserMedia_addtrack_removetrack_events.html | assertion count 1 is more than expected 0 assertions
This frequent intermittent occurs in the same job as bug 1374164, which may have masked reporting.
See Also: → 1377450
This is the same assertion as bug 1377450. These failures began when bug 1377450 disabled dom/media/tests/mochitest/test_getUserMedia_addTrackRemoveTrack.html, the previous test in the manifest.
Whiteboard: [stockwell needswork]
:pehrsons, I see you are looking into bug 1377450, this one is failing quite often and is sort of the same bug- can you work make sure the work you do fixes this bug as well?
Flags: needinfo?(apehrson)
Will do.
Assignee: nobody → apehrson
Rank: 25
Flags: needinfo?(apehrson)
Priority: P5 → P2
this failure continues at a high rate:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1389983

I see some more recent updates in bug 1377450
Mass change P2->P3 to align with new Mozilla triage process.
Priority: P2 → P3
Bulk priority update of open intermittent test failure bugs. 

P3 => P5

https://bugzilla.mozilla.org/show_bug.cgi?id=1381960
Priority: P3 → P5
disabled the test case:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5e24a3d197808a919011fba8fe4f2f6e6273ffca

apehrson@mozilla.com, while working on this, please re-enable the test so it runs locally and on try
Flags: needinfo?(apehrson)
Keywords: leave-open
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Looks like you missed a '=' after the skip-if. This intermittent is still occurring.
Flags: needinfo?(apehrson) → needinfo?(jmaher)
Priority: P5 → P3
oh, thank you for pointing this out!  I will get a patch landed today.
Flags: needinfo?(jmaher)
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/c879bfc1067e
fix skip syntax for dom/media/tests/mochitest/test_getUserMedia_addtrack_removetrack_events.html. r=me, a=test-only
this is disabled properly now, please remember to enable this when working on a patch to fix the test case.
The leave-open keyword is there and there is no activity for 6 months.
:pehrsons, maybe it's time to close this bug?
Flags: needinfo?(apehrson)
Just because it's been disabled doesn't mean it's fixed. But if you prefer you can close this and we take the fix to bug 1377450.
Flags: needinfo?(apehrson)

This assert no longer exists. Let me try to re-enable this and see what happens.

Status: ASSIGNED → RESOLVED
Closed: 1 year ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla69
You need to log in before you can comment on or make changes to this bug.