Closed Bug 1453078 Opened Last year Closed 10 months ago

Intermittent dom/media/test/test_mediarecorder_principals.html | assertion count 1 is more than expected 0 assertions

Categories

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

defect

Tracking

()

RESOLVED FIXED
mozilla65
Tracking Status
firefox-esr60 --- wontfix
firefox63 --- wontfix
firefox64 --- fixed
firefox65 --- fixed

People

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

References

Details

(Keywords: assertion, intermittent-failure)

Attachments

(1 file)

Link to a recent log https://treeherder.mozilla.org/logviewer.html#?job_id=172887790&repo=mozilla-inbound&lineNumber=5415
Part of that log:
15:56:39     INFO -  565 INFO TEST-OK | dom/media/test/test_mediarecorder_principals.html | took 3457ms
15:56:39     INFO -  GECKO(3060) | --DOMWINDOW == 19 (0000016FD2B4F000) [pid = 7660] [serial = 466] [outer = 0000000000000000] [url = about:blank]
15:56:39     INFO -  GECKO(3060) | --DOMWINDOW == 18 (0000016FD264F400) [pid = 7660] [serial = 462] [outer = 0000000000000000] [url = about:blank]
15:56:39     INFO -  GECKO(3060) | ++DOMWINDOW == 19 (0000016FD3229C00) [pid = 7660] [serial = 478] [outer = 0000016FD2B4E800]
15:57:04     INFO -  GECKO(3060) | #01: mozilla::detail::RunnableMethodImpl<RefPtr<mozilla::VideoTrackEncoder>,void ( mozilla::VideoTrackEncoder::*)(__int64),1,0,__int64>::Run() [xpcom/threads/nsThreadUtils.h:1218]
15:57:04     INFO -  GECKO(3060) | #02: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.cpp:244]
15:57:04     INFO -  GECKO(3060) | #03: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:230]
15:57:04     INFO -  GECKO(3060) | #04: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1100]
15:57:04     INFO -  GECKO(3060) | #05: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:519]
15:57:04     INFO -  GECKO(3060) | #06: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:334]
15:57:04     INFO -  GECKO(3060) | #07: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:320]
15:57:04     INFO -  GECKO(3060) | #08: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:300]
15:57:04     INFO -  GECKO(3060) | #09: nsThread::ThreadFunc(void *) [xpcom/threads/nsThread.cpp:427]
15:57:05     INFO -  GECKO(3060) | #10: PR_NativeRunThread [nsprpub/pr/src/threads/combined/pruthr.c:406]
15:57:05     INFO -  GECKO(3060) | #11: static unsigned int pr_root(void *) [nsprpub/pr/src/md/windows/w95thred.c:138]
15:57:05     INFO -  GECKO(3060) | #12: ucrtbase.dll + 0x20369
15:57:05     INFO -  GECKO(3060) | #13: KERNEL32.DLL + 0x12774
15:57:05     INFO -  GECKO(3060) | #14: ntdll.dll + 0x70d51
15:57:05    ERROR -  566 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_mediarecorder_principals.html | assertion count 1 is more than expected 0 assertions
15:57:05     INFO -  567 INFO TEST-START | dom/media/test/test_mediarecorder_record_4ch_audiocontext.html
15:57:05     INFO -  GECKO(3060) | ++DOMWINDOW == 20 (0000016FD322E800) [pid = 7660] [serial = 479] [outer = 0000016FD2B4E800]
15:57:05     INFO -  GECKO(3060) | ++DOCSHELL 0000016FD233B000 == 5 [pid = 7660] [id = {63fdb4b1-9204-4731-aa92-15fdf83d300f}]
15:57:05     INFO -  GECKO(3060) | ++DOMWINDOW == 21 (0000016FD3232400) [pid = 7660] [serial = 480] [outer = 0000000000000000]
15:57:05     INFO -  GECKO(3060) | ++DOMWINDOW == 22 (0000016FD3233400) [pid = 7660] [serial = 481] [outer = 0000016FD3232400]
15:57:05     INFO -  GECKO(3060) | --DOMWINDOW == 21 (0000016FD322A000) [pid = 7660] [serial = 467] [outer = 0000000000000000] [url = about:blank
There are 22 failures in the last 7 days. All of them on windows10-64-qr / debug
I did some retriggers and it seems that the fail started from 
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=db2973e7667c86f991162206506e64fdcd2d18d4&filter-searchStr=test-windows10-64-qr%2Fdebug-mochitest-media-e10s%20M-e10s(mda)

:drno, can you please take a look?
Flags: needinfo?(drno)
I caught this in rr, but I also saw the error from bug 1468831. I think bug 1468831 is the failure mode of this bug in opt builds.
Assignee: nobody → apehrson
Component: Audio/Video: Playback → Audio/Video: Recording
Flags: needinfo?(drno)
See Also: → 1468831
This happens because we naively assume in the track listeners that a MediaSegment is always all-null or all-non-null. But the bug occurs when it's a mix, so our check [1] is fooled and the track encoder advances too far.

[1] https://searchfox.org/mozilla-central/rev/fcfb479e6ff63aea017d063faa17877ff750b4e5/dom/media/encoder/MediaEncoder.cpp#275-285
Status: NEW → ASSIGNED
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/54761b7fd534
Do not assume segments are all non-null when not all null. r=padenot
https://hg.mozilla.org/mozilla-central/rev/54761b7fd534
Status: ASSIGNED → RESOLVED
Closed: 10 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla65
Is there a big risk to taking this on Beta to help lower the noise from intermittents? If not, please nominate for approval.
Flags: needinfo?(apehrson)
Keywords: assertion
I'd say low risk.
Blocks: 1296531
Flags: needinfo?(apehrson)
Comment on attachment 9019399 [details]
Bug 1453078 - Do not assume segments are all non-null when not all null. r?padenot

[Beta/Release Uplift Approval Request]

Feature/Bug causing the regression: Bug 1296531

User impact if declined: Mostly intermittent failures on try in debug builds. There could also be small a/v sync issues in recordings in release builds.

Is this code covered by automated tests?: Yes

Has the fix been verified in Nightly?: No

Needs manual test from QE?: No

If yes, steps to reproduce: 

List of other uplifts needed: None

Risk to taking this patch: Low

Why is the change risky/not risky? (and alternatives if risky): The amount of changed code is non-trivial but it's logically simple; we move to finer-grained checks and aggregate the results manually.

String changes made/needed:
Attachment #9019399 - Flags: approval-mozilla-beta?
Flags: qe-verify-
Comment on attachment 9019399 [details]
Bug 1453078 - Do not assume segments are all non-null when not all null. r?padenot

[Triage Comment]
Low-risk fix which helps reduce intermittent oranges on Beta. Approved for 64.0b6.
Attachment #9019399 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
You need to log in before you can comment on or make changes to this bug.