Intermittent Assertion failure: GetMediaTime() <= clockTime (Clock should go forwards.), at /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3676
Categories
(Core :: Audio/Video, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox99 | --- | unaffected |
firefox100 | --- | unaffected |
firefox101 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: padenot)
References
(Regression)
Details
(Keywords: assertion, intermittent-failure, regression)
Attachments
(1 file)
Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=375153293&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MT5Rjy_uSeCqTc5eRaBmiQ/runs/0/artifacts/public/logs/live_backing.log
[task 2022-04-20T14:44:37.319Z] 14:44:37 INFO - TEST-START | toolkit/components/pictureinpicture/tests/browser_tabIconOverlayPiP.js
[task 2022-04-20T14:44:37.327Z] 14:44:37 INFO - GECKO(8524) | ###!!! [Parent][PImageBridgeParent] Error: Send(msgname=PTexture::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-20T14:44:37.328Z] 14:44:37 INFO - GECKO(8524) | ###!!! [Parent][PImageBridgeParent] Error: RunMessage(msgname=PImageBridge::Msg_WillClose) Channel closing: too late to send/recv, messages will be lost
[task 2022-04-20T14:44:37.332Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL eec0700 == 1 [pid = 6456] [id = 1] [url = about:blank]
[task 2022-04-20T14:44:37.333Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.338Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL a6dcf00 == 1 [pid = 7060] [id = 0]
[task 2022-04-20T14:44:37.338Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (5770b00) [pid = 7060] [serial = 1] [outer = 0]
[task 2022-04-20T14:44:37.340Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (a6dde00) [pid = 7060] [serial = 2] [outer = 5770b00]
[task 2022-04-20T14:44:37.352Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.355Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.367Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.388Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 4d85f00 == 0 [pid = 6456] [id = 0] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
[task 2022-04-20T14:44:37.402Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (c867700) [pid = 7060] [serial = 3] [outer = 5770b00]
[task 2022-04-20T14:44:37.430Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.447Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.455Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (4d70b00) [pid = 6456] [serial = 1] [outer = 0] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
[task 2022-04-20T14:44:37.456Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (ee57700) [pid = 6456] [serial = 5] [outer = 0] [url = about:blank]
[task 2022-04-20T14:44:37.456Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (4d86e00) [pid = 6456] [serial = 2] [outer = 0] [url = about:blank]
[task 2022-04-20T14:44:37.457Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (ee8c600) [pid = 6456] [serial = 4] [outer = 0] [url = about:blank]
[task 2022-04-20T14:44:37.457Z] 14:44:37 INFO - GECKO(8524) | [Child 6456: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (bc0e700) [pid = 6456] [serial = 3] [outer = 0] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
[task 2022-04-20T14:44:37.459Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2022-04-20T14:44:37.463Z] 14:44:37 INFO - GECKO(8524) | [2022-04-20T14:44:37Z WARN audioipc2::ipccore] AudioIPC Server RPC: EventLoop drop - closing connection for Token(9) failed: Custom { kind: NotFound, error: "I/O source not registered with `Registry`" }
[task 2022-04-20T14:44:37.463Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:128
[task 2022-04-20T14:44:37.465Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.468Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.469Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_StartedGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.469Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: IPC message 'PIdleScheduler::Msg_DoneGC' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:468
[task 2022-04-20T14:44:37.474Z] 14:44:37 INFO - GECKO(8524) | [Child 6456, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4464
[task 2022-04-20T14:44:37.627Z] 14:44:37 INFO - GECKO(8524) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to C:\Users\task_165045940919267\AppData\Local\Temp\tmpxiguu8fu.mozrunner\runtests_leaks_tab_pid7196.log
[task 2022-04-20T14:44:37.627Z] 14:44:37 INFO - GECKO(8524) | [7196, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-04-20T14:44:37.664Z] 14:44:37 INFO - GECKO(8524) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to C:\Users\task_165045940919267\AppData\Local\Temp\tmpxiguu8fu.mozrunner\runtests_leaks_tab_pid6724.log
[task 2022-04-20T14:44:37.664Z] 14:44:37 INFO - GECKO(8524) | [6724, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:339
[task 2022-04-20T14:44:37.692Z] 14:44:37 INFO - GECKO(8524) | [Child 7060, MediaDecoderStateMachine #1] WARNING: fae9050 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:320
[task 2022-04-20T14:44:37.693Z] 14:44:37 INFO - GECKO(8524) | [Child 7060, AudioIPC Client Callback] WARNING: Underrun when popping samples from audiosink ring buffer.: file /builds/worker/checkouts/gecko/dom/media/mediasink/AudioSink.cpp:305
[task 2022-04-20T14:44:37.701Z] 14:44:37 INFO - GECKO(8524) | [Child 7060, AudioIPC Client Callback] WARNING: Underrun when popping samples from audiosink ring buffer.: file /builds/worker/checkouts/gecko/dom/media/mediasink/AudioSink.cpp:305
[task 2022-04-20T14:44:37.763Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 1af5aa00 == 8 [pid = 8092] [id = 101]
[task 2022-04-20T14:44:37.764Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 21 (179e2100) [pid = 8092] [serial = 205] [outer = 0]
[task 2022-04-20T14:44:37.765Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 22 (1af84a00) [pid = 8092] [serial = 206] [outer = 179e2100]
[task 2022-04-20T14:44:37.771Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: NS_ENSURE_TRUE(uri) failed: file /builds/worker/checkouts/gecko/caps/BasePrincipal.cpp:1358
[task 2022-04-20T14:44:37.775Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4147
[task 2022-04-20T14:44:37.810Z] 14:44:37 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 9dea700 == 3 [pid = 3252] [id = 55]
[task 2022-04-20T14:44:37.811Z] 14:44:37 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 8 (c028e00) [pid = 3252] [serial = 116] [outer = 0]
[task 2022-04-20T14:44:37.812Z] 14:44:37 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 9 (c057c00) [pid = 3252] [serial = 117] [outer = c028e00]
[task 2022-04-20T14:44:37.838Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 10c62e00 == 2 [pid = 7060] [id = 1]
[task 2022-04-20T14:44:37.839Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (fa40000) [pid = 7060] [serial = 4] [outer = 0]
[task 2022-04-20T14:44:37.840Z] 14:44:37 INFO - GECKO(8524) | [Child 7060: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (10c63d00) [pid = 7060] [serial = 5] [outer = fa40000]
[task 2022-04-20T14:44:37.840Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out!: '!nsContentUtils::IsChromeDoc(window->GetExtantDoc())', file /builds/worker/checkouts/gecko/dom/events/EventListenerManager.cpp:381
[task 2022-04-20T14:44:37.841Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: Please do not use mouseenter/leave events in chrome. They are slower than mouseover/out!: '!nsContentUtils::IsChromeDoc(window->GetExtantDoc())', file /builds/worker/checkouts/gecko/dom/events/EventListenerManager.cpp:381
[task 2022-04-20T14:44:37.858Z] 14:44:37 INFO - GECKO(8524) | must wait for focus
[task 2022-04-20T14:44:37.873Z] 14:44:37 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: WebProgress Ignored: BrowsingContext is null or discarded: file /builds/worker/checkouts/gecko/dom/ipc/BrowserParent.cpp:2986
[task 2022-04-20T14:44:38.005Z] 14:44:38 INFO - GECKO(8524) | [Parent 8092, Main Thread] WARNING: 'aOwner->IsDiscarded()', file /builds/worker/workspace/obj-build/dist/include/mozilla/dom/SyncedContextInlines.h:95
[task 2022-04-20T14:44:38.012Z] 14:44:38 INFO - GECKO(8524) | Assertion failure: GetMediaTime() <= clockTime (Clock should go forwards.), at /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:3676
[task 2022-04-20T14:44:38.017Z] 14:44:38 INFO - GECKO(8524) | JavaScript error: resource://gre/actors/AudioPlaybackParent.jsm, line 24: TypeError: can't access property "audioPlaybackStopped", browser is null
[task 2022-04-20T14:44:38.029Z] 14:44:38 INFO - GECKO(8524) | [GPU 3752, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:365
[task 2022-04-20T14:44:38.062Z] 14:44:38 INFO - GECKO(8524) | MEMORY STAT | vsize 1031MB | vsizeMaxContiguous 1293MB | residentFast 273MB | heapAllocated 91MB
[task 2022-04-20T14:44:38.071Z] 14:44:38 INFO - TEST-OK | toolkit/components/pictureinpicture/tests/browser_tabIconOverlayPiP.js | took 745ms
[task 2022-04-20T14:44:38.078Z] 14:44:38 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL c058200 == 4 [pid = 3252] [id = 56]
[task 2022-04-20T14:44:38.079Z] 14:44:38 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 10 (c029b00) [pid = 3252] [serial = 118] [outer = 0]
[task 2022-04-20T14:44:38.080Z] 14:44:38 INFO - GECKO(8524) | [Child 3252: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (c059100) [pid = 3252] [serial = 119] [outer = c029b00]
[task 2022-04-20T14:44:38.105Z] 14:44:38 INFO - checking window state
[task 2022-04-20T14:44:38.110Z] 14:44:38 INFO - GECKO(8524) | #01: mozilla::MediaDecoderStateMachine::GetClock(mozilla::TimeStamp*) const [dom/media/MediaDecoderStateMachine.cpp:3676]
[task 2022-04-20T14:44:38.111Z] 14:44:38 INFO - GECKO(8524) | #02: mozilla::MediaDecoderStateMachine::DormantState::Enter() [dom/media/MediaDecoderStateMachine.cpp:395]
[task 2022-04-20T14:44:38.112Z] 14:44:38 INFO - GECKO(8524) | #03: mozilla::MediaDecoderStateMachine::StateObject::CallEnterMemberFunction<mozilla::MediaDecoderStateMachine::DormantState>(mozilla::MediaDecoderStateMachine::DormantState*, mozilla::Tuple<>&, std::integer_sequence<unsigned int>) [dom/media/MediaDecoderStateMachine.cpp:259]
[task 2022-04-20T14:44:38.114Z] 14:44:38 INFO - GECKO(8524) | #04: mozilla::MediaDecoderStateMachine::StateObject::SetState<mozilla::MediaDecoderStateMachine::DormantState>() [dom/media/MediaDecoderStateMachine.cpp:299]
[task 2022-04-20T14:44:38.116Z] 14:44:38 INFO - GECKO(8524) | #05: mozilla::MediaDecoderStateMachine::DecodingState::StartDormantTimer() [dom/media/MediaDecoderStateMachine.cpp:753]
[task 2022-04-20T14:44:38.117Z] 14:44:38 INFO - GECKO(8524) | #06: mozilla::MediaDecoderStateMachine::DecodingState::HandlePlayStateChanged(mozilla::MediaDecoder::PlayState) [dom/media/MediaDecoderStateMachine.cpp:670]
[task 2022-04-20T14:44:38.119Z] 14:44:38 INFO - GECKO(8524) | #07: mozilla::MediaDecoderStateMachine::PlayStateChanged() [dom/media/MediaDecoderStateMachine.cpp:3174]
[task 2022-04-20T14:44:38.120Z] 14:44:38 INFO - GECKO(8524) | #08: mozilla::detail::RunnableFunction<`lambda at /builds/worker/workspace/obj-build/dist/include/mozilla/StateWatching.h:248:34'>::Run() [xpcom/threads/nsThreadUtils.h:531]
[task 2022-04-20T14:44:38.121Z] 14:44:38 INFO - GECKO(8524) | #09: mozilla::SimpleTaskQueue::DrainTasks() [xpcom/threads/TaskDispatcher.h:45]
[task 2022-04-20T14:44:38.122Z] 14:44:38 INFO - GECKO(8524) | #10: mozilla::TaskQueue::DrainDirectTasks() [xpcom/threads/TaskQueue.cpp:258]
[task 2022-04-20T14:44:38.122Z] 14:44:38 INFO - GECKO(8524) | #11: mozilla::AutoTaskDispatcher::DrainDirectTasks() [xpcom/threads/TaskDispatcher.h:135]
[task 2022-04-20T14:44:38.123Z] 14:44:38 INFO - GECKO(8524) | #12: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:228]
[task 2022-04-20T14:44:38.125Z] 14:44:38 INFO - GECKO(8524) | #13: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.cpp:203]
[task 2022-04-20T14:44:38.135Z] 14:44:38 INFO - GECKO(8524) | #14: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:312]
[task 2022-04-20T14:44:38.136Z] 14:44:38 INFO - GECKO(8524) | #15: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1174]
[task 2022-04-20T14:44:38.137Z] 14:44:38 INFO - GECKO(8524) | #16: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:465]
[task 2022-04-20T14:44:38.137Z] 14:44:38 INFO - GECKO(8524) | #17: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:300]
Updated•3 years ago
|
Comment 1•3 years ago
|
||
:padenot, since you are the author of the regressor, bug 1743834, could you take a look?
For more information, please visit auto_nag documentation.
Assignee | ||
Comment 2•3 years ago
|
||
We're going to backout the last patch of the series while I investigate.
Assignee | ||
Updated•3 years ago
|
Assignee | ||
Comment 3•3 years ago
|
||
Updated•3 years ago
|
Updated•3 years ago
|
Comment 5•3 years ago
|
||
(In reply to Pulsebot from comment #4)
Back out changeset e1c85e8a23b1 for investigation on Windows 32-bits.
I think this^ was a typo -- e1c85e8a23b1 doesn't seem to be an actual commit ID. At least, these are both error pages:
https://hg.mozilla.org/integration/autoland/rev/e1c85e8a23b1
https://hg.mozilla.org/mozilla-central/rev/e1c85e8a23b1
I think you maybe meant to point at e2e3a95faccd (i.e. https://hg.mozilla.org/integration/autoland/rev/e2e3a95faccd ) -- that seems to be what this commit is conditionally reverting.
Comment 6•3 years ago
|
||
Backed out for causing conflicts with backout of Bug 1743834(https://hg.mozilla.org/integration/autoland/rev/59ca4d757f293cb5c3ba5b690ad6f59b4605d5fe)
Assignee | ||
Updated•3 years ago
|
Assignee | ||
Updated•3 years ago
|
Updated•3 years ago
|
Updated•3 years ago
|
Comment 7•3 years ago
|
||
Fixed by backout of bug 1743834
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment 10•2 years ago
|
||
Comment 11•2 years ago
|
||
Also:
R1 <--> Failure Log
bc4 Failure Log
Assignee | ||
Updated•2 years ago
|
Comment 12•2 years ago
|
||
Comment 13•2 years ago
|
||
bugherder |
Description
•