Closed Bug 1374441 Opened 3 years ago Closed 3 years ago

Intermittent test_mozHasAudio.html | Assertion count 1 is greater than expected range 0-0 assertions.

Categories

(Core :: Audio/Video: Playback, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla56
Tracking Status
firefox56 --- fixed

People

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

References

Details

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

Attachments

(1 file, 1 obsolete file)

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

[1352] ###!!! ASSERTION: Played block after the current stream position?: 'static_cast<int64_t>(bo->mStreamBlock)*BLOCK_SIZE < bo->mStream->mStreamOffset', file z:/build/build/src/dom/media/MediaCache.cpp, line 1042

#01: mozilla::MediaCache::FindReusableBlock(mozilla::TimeStamp,mozilla::MediaCacheStream *,int,int) [dom/media/MediaCache.cpp:875]
#02: mozilla::MediaCache::FindBlockForIncomingData(mozilla::TimeStamp,mozilla::MediaCacheStream *) [dom/media/MediaCache.cpp:757]
#03: mozilla::MediaCache::AllocateAndWriteBlock(mozilla::MediaCacheStream *,mozilla::MediaCacheStream::ReadMode,mozilla::Span<unsigned char const ,4294967295>,mozilla::Span<unsigned char const ,4294967295>) [dom/media/MediaCache.cpp:1574]
#04: mozilla::MediaCacheStream::NotifyDataReceived(__int64,char const *,nsIPrincipal *) [dom/media/MediaCache.cpp:1883]
#05: mozilla::ChannelMediaResource::CopySegmentToCache(nsIPrincipal *,char const *,unsigned int,unsigned int *) [dom/media/MediaResource.cpp:473]
#06: mozilla::ChannelMediaResource::CopySegmentToCache(nsIInputStream *,void *,char const *,unsigned int,unsigned int,unsigned int *) [dom/media/MediaResource.cpp:494]
#07: nsInputStreamTee::WriteSegmentFun(nsIInputStream *,void *,char const *,unsigned int,unsigned int,unsigned int *) [xpcom/io/nsInputStreamTee.cpp:199]
#08: nsPipeInputStream::ReadSegments(nsresult (*)(nsIInputStream *,void *,char const *,unsigned int,unsigned int,unsigned int *),void *,unsigned int,unsigned int *) [xpcom/io/nsPipe3.cpp:1439]
#09: nsInputStreamTee::ReadSegments(nsresult (*)(nsIInputStream *,void *,char const *,unsigned int,unsigned int,unsigned int *),void *,unsigned int,unsigned int *) [xpcom/io/nsInputStreamTee.cpp:262]
#10: mozilla::ChannelMediaResource::OnDataAvailable(nsIRequest *,nsIInputStream *,unsigned int) [dom/media/MediaResource.cpp:518]
#11: mozilla::ChannelMediaResource::Listener::OnDataAvailable(nsIRequest *,nsISupports *,nsIInputStream *,unsigned __int64,unsigned int) [dom/media/MediaResource.cpp:163]
#12: mozilla::dom::HTMLMediaElement::MediaLoadListener::OnDataAvailable(nsIRequest *,nsISupports *,nsIInputStream *,unsigned __int64,unsigned int) [dom/html/HTMLMediaElement.cpp:583]
#13: mozilla::net::nsStreamListenerTee::OnDataAvailable(nsIRequest *,nsISupports *,nsIInputStream *,unsigned __int64,unsigned int) [netwerk/base/nsStreamListenerTee.cpp:91]
#14: mozilla::net::nsHttpChannel::OnDataAvailable(nsIRequest *,nsISupports *,nsIInputStream *,unsigned __int64,unsigned int) [netwerk/protocol/http/nsHttpChannel.cpp:7564]
#15: nsInputStreamPump::OnStateTransfer() [netwerk/base/nsInputStreamPump.cpp:622]
#16: nsInputStreamPump::OnInputStreamReady(nsIAsyncInputStream *) [netwerk/base/nsInputStreamPump.cpp:445]
#17: nsInputStreamReadyEvent::Run() [xpcom/io/nsStreamUtils.cpp:99]
#18: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1429]
#19: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:475]

Fallout from recent changes to MediaCache?
Flags: needinfo?(gsquelart)
Duplicate of this bug: 1374404
Yes JW, most probably due to bug 1368837, which I'm about to fix in bug 1374180 -- which was based on a hunch, so it's "good" that we have an actual example of failure. And it means we will want to uplift the fix to 55 if possible.
Assignee: nobody → gsquelart
Blocks: 1361625, 1368837
Depends on: 1374180
Flags: needinfo?(gsquelart)
Good hunch!
Duplicate of this bug: 1374532
Duplicate of this bug: 1374897
Duplicate of this bug: 1374904
Duplicate of this bug: 1374910
Duplicate of this bug: 1374993
Duplicate of this bug: 1375312
Whiteboard: [stockwell needswork]
Sadface.

Alright, I'll just turn it off completely, so it doesn't impact builds anymore, and I'll see if I can fix it later on...
(In reply to Gerald Squelart [:gerald] from comment #13)
> Alright, I'll just turn it off completely, so it doesn't impact builds
> anymore, and I'll see if I can fix it later on...

To clarify:
"it" is the MediaResourceIndex cache introduced in bug 1368837, which is the main suspect, as it changes the way MediaResourceIndex reads are translated into different MediaCache reads.
Setting the media.cache.resource-index pref to 0 turns this caching off, and will make MediaResourceIndex reads correspond 1:1 with MediaCache reads, as it was before.
Duplicate of this bug: 1375646
Duplicate of this bug: 1375647
Duplicate of this bug: 1375652
Duplicate of this bug: 1375653
Comment on attachment 8880589 [details]
Bug 1374441 - Disable MediaResourceIndex caching because of intermittent MediaCache assertions -

https://reviewboard.mozilla.org/r/151924/#review156952

Will need to uplift this to beta.
Attachment #8880589 - Flags: review?(cpearce) → review+
Lucky I did my customary minimal Try push and glanced at the results before landing:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=46f71145e440bb2d7d7fa6a116e78d2f765e6555

We're still getting assertions! E.g.:
https://treeherder.mozilla.org/logviewer.html#?job_id=109402613&repo=try&lineNumber=1772
> [3352] ###!!! ASSERTION: Played block after the current stream position?: 'static_cast<int64_t>(bo->mStreamBlock)*BLOCK_SIZE < bo->mStream->mStreamOffset', file z:/build/build/src/dom/media/MediaCache.cpp, line 1042
> #01: mozilla::MediaCache::FindReusableBlock(mozilla::TimeStamp,mozilla::MediaCacheStream *,int,int) [dom/media/MediaCache.cpp:875]
> #02: mozilla::MediaCache::Update() [dom/media/MediaCache.cpp:1208]

I'll triple-check that my patch here does what it's supposed to. But assuming it's correct, it means the issue comes from another bug touching MediaCache or something around it...
Duplicate of this bug: 1374771
Duplicate of this bug: 1374772
After some detective work, I think bug 1374173 is where the intermittent started.

Its very first push to Autoland shows a few assertions (I've repeated 'mda' tests there to reveal the failures) :
https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=1bfb595e6629f8c7f0dd9394d2d5de5893e4c83b
And the push just before doesn't have any such failure, even with heaps of repeated 'mda' tests:
https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=aa9171b8437a9842bec13aea0ff2569a15086f2d

As further proof, just backing-out the 2nd part of bug 1374173 (simplifying MediaCacheStream::Seek) still shows failures:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=d63e56d826679698a4dea658beb3fcc8c946de3d
But backing-out both parts (refactoring MediaCacheStream::Seek and Read) does *not* show failures anymore:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=a7f90750fe2f782204bd9e1846d5d67a8a3c93eb

So the first part of bug 1374173 seems to be the root cause. (As the 2nd part depends on it, I'm going to back-out the whole bug.)

I don't understand (yet) why this bug could cause such issues, as it was "just" a refactoring and shouldn't have changed any actual behavior!
But it's late in the week, and I'm traveling soon, so I would prefer to just land this back-out, to both remove oranges from the trees, and verify that it does remove all MediaCache intermittent assertion failures.
Also bug 1374173 is not that important, so it's fine to back-out, and we can wait to get it done right.
Blocks: 1374173
No longer blocks: 1368837
No longer depends on: 1374180
Attachment #8880589 - Attachment is obsolete: true
Comment on attachment 8880709 [details]
Bug 1374441 - Backed out bug 1374173 (MediaCacheStream Seek&Read refactoring) -

https://reviewboard.mozilla.org/r/152056/#review157018
Attachment #8880709 - Flags: review?(jwwang) → review+
Pushed by gsquelart@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a1ef8b483090
Backed out bug 1374173 (MediaCacheStream Seek&Read refactoring) - r=jwwang
Bug 1374173 landed in 56, so if this fix works, there is no need to uplift to beta 55.
https://hg.mozilla.org/mozilla-central/rev/a1ef8b483090
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla56
Looking at central, I can see plenty of these failures *before* this back-out landed, and none since then, so I am declaring victory.
Whiteboard: [stockwell needswork] → [stockwell fixed:product]
You need to log in before you can comment on or make changes to this bug.