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

RESOLVED FIXED in Firefox 68

Status

()

defect
P3
normal
Rank:
25
RESOLVED FIXED
2 years ago
3 months ago

People

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

Tracking

({intermittent-failure})

unspecified
mozilla69
Points:
---
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox57 disabled, firefox58 disabled, firefox68 fixed, firefox69 fixed)

Details

(Whiteboard: [stockwell disabled])

Attachments

(1 attachment)

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.
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: NEW → ASSIGNED
Keywords: leave-open
Status: ASSIGNED → RESOLVED
Closed: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla69
You need to log in before you can comment on or make changes to this bug.