Intermittent TestAudioInputSource.ErrorCallback |
Categories
(Testing :: GTest, defect, P5)
Tracking
(firefox-esr91 unaffected, firefox99 unaffected, firefox100 unaffected, firefox101 fixed)
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox99 | --- | unaffected |
firefox100 | --- | unaffected |
firefox101 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: chunmin)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])
Attachments
(1 file)
Filed by: csabou [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=374956034&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FLoAjdZCR5GtDTpT7WHk_Q/runs/0/artifacts/public/logs/live_backing.log
[task 2022-04-19T10:51:17.746Z] 10:51:17 INFO - TEST-PASS | TestAudioInputSource.DataOutputBeforeStartAndAfterStop | test completed (time: 29ms)
[task 2022-04-19T10:51:17.748Z] 10:51:17 INFO - TEST-START | TestAudioInputSource.ErrorCallback
[task 2022-04-19T10:51:17.792Z] 10:51:17 WARNING - TEST-UNEXPECTED-FAIL | TestAudioInputSource.ErrorCallback |
[task 2022-04-19T10:51:17.793Z] 10:51:17 INFO - Unexpected mock function call - returning directly.
[task 2022-04-19T10:51:17.793Z] 10:51:17 INFO - Function call: AudioStateCallback(1, 4-byte object <01-00 00-00>)
[task 2022-04-19T10:51:17.793Z] 10:51:17 INFO - Google Mock tried the following 2 expectations, but none matched:
[task 2022-04-19T10:51:17.794Z] 10:51:17 INFO - /builds/worker/checkouts/gecko/dom/media/gtest/TestAudioInputSource.cpp(197): tried expectation #0: EXPECT_CALL(*listener, AudioStateCallback( sourceId, AudioInputSource::EventListener::State::Started))...
[task 2022-04-19T10:51:17.795Z] 10:51:17 INFO - Expected arg #1: is equal to 4-byte object <00-00 00-00>
[task 2022-04-19T10:51:17.795Z] 10:51:17 INFO - Actual: 4-byte object <01-00 00-00>
[task 2022-04-19T10:51:17.795Z] 10:51:17 INFO - Expected: to be called once
[task 2022-04-19T10:51:17.795Z] 10:51:17 INFO - Actual: called once - saturated and active
[task 2022-04-19T10:51:17.796Z] 10:51:17 INFO - /builds/worker/checkouts/gecko/dom/media/gtest/TestAudioInputSource.cpp(200): tried expectation #1: EXPECT_CALL(*listener, AudioStateCallback( sourceId, AudioInputSource::EventListener::State::Error))...
[task 2022-04-19T10:51:17.797Z] 10:51:17 INFO - Expected arg #1: is equal to 4-byte object <03-00 00-00>
[task 2022-04-19T10:51:17.797Z] 10:51:17 INFO - Actual: 4-byte object <01-00 00-00>
[task 2022-04-19T10:51:17.797Z] 10:51:17 INFO - Expected: to be called once
[task 2022-04-19T10:51:17.797Z] 10:51:17 INFO - Actual: called once - saturated and active @ (null):-1
[task 2022-04-19T10:51:17.797Z] 10:51:17 WARNING - TEST-UNEXPECTED-FAIL | TestAudioInputSource.ErrorCallback | test completed (time: 47ms)
[task 2022-04-19T10:51:17.798Z] 10:51:17 INFO - TEST-START | TestAudioInputSource.DeviceChangedCallback
[task 2022-04-19T10:51:17.826Z] 10:51:17 INFO - TEST-PASS | TestAudioInputSource.DeviceChangedCallback | test completed (time: 30ms)
Comment 1•2 years ago
|
||
R+B range: https://treeherder.mozilla.org/jobs?repo=autoland&searchStr=Windows%2C10%2Cx64%2C2004%2CWebRender%2Cdebug%2Ctest-windows10-64-2004-qr%2Fdebug-gtest-1proc%2CGTest-1proc&tochange=aa30bc1b369b2a35843f7d71f05a9d43b6aa305c&fromchange=2b2de9f71e7f917e1732bc12a2ddd4cc64d663cf
Chang, could this somehow be related to changes in Bug 1238038?
Updated•2 years ago
|
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 3•2 years ago
|
||
Yes, this test is landed in bug 1238038
Assignee | ||
Comment 4•2 years ago
•
|
||
It seems we receive a "stop" callback before the expected one. The error should not affect the product code since the problem should be in the test itself or the simulated audio backend.
Comment 5•2 years ago
|
||
Set release status flags based on info from the regressing bug 1238038
Assignee | ||
Comment 6•2 years ago
|
||
We need to wait for the stream stop called by the forced error
before calling AudioInputSource::Stop
to ensure the callback order in
the test. Otherwise, the stream stop called by the forced error on the
background thread will race with the stream stop called by the
AudioInputSource::Stop
in its task thread.
The problem of the intermittently unexpected callbacks can be reproduced
by adding a delay/thread-sleep in the forced-error's background thread
task. When MockCubeb runs into the error state by ForceError()
, it
will create a background-thread task to stop the cubeb stream. On the
other hand, when AuidioInputSource::Stop
is called, it will create a
task to stop the cubeb stream first and then destroy the cubeb stream,
on its own task thread. Most of time, when AudioInputSource::Stop
is
called, the underlying cubeb stream has been stopped by the brackground
task, so the MockCubebStream
won't fire the stopped-state callback.
MockCubeb::StopStream
in MockCubebStream::Stop()
called by
AudioInputSource::Stop()
will return a CUBEB_ERROR
in this case
since no stream needs to be stopped, and so no callback need to be
fired.
However, in rare cases, the stream stop on the AudioInputSource's task
thread finishes before the one in the background thread. Hence, the
MockCubebStream::Stop()
called by AudioInputSource::Stop()
can stop
the stream successfully and then fire a stopped state callback.
We don't care what thread stop the stream in
TestAudioInputSource.ErrorCallback
test, as long as the error-state
cabllback can be forwarded correctly and the stream can be destroyed in
the end. To avoid the racy stream stop calls between the background
thread and the task thread, we don't call AudioInputSource::Stop()
until stream is stopped in background thread.
Updated•2 years ago
|
Assignee | ||
Updated•2 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Pushed by cchang@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8d2934632295 Wait for error stop before AudioInputSource::Stop() r=padenot
Comment 8•2 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Description
•