Closed Bug 1383579 Opened 7 years ago Closed 7 years ago

Intermittent Assertion failure: mState != WAITING (Did we get a spurious wakeup somehow?), at /home/worker/workspace/build/src/image/SourceBuffer.h:248

Categories

(Core :: Graphics: ImageLib, defect, P3)

defect

Tracking

()

RESOLVED FIXED
mozilla56
Tracking Status
firefox-esr52 --- unaffected
firefox54 --- unaffected
firefox55 --- unaffected
firefox56 --- fixed

People

(Reporter: aryx, Assigned: aosmond)

References

Details

(Keywords: intermittent-failure, regression, Whiteboard: [gfx-noted])

Attachments

(1 file)

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

[task 2017-07-23T18:18:57.677054Z] 18:18:57     INFO - REFTEST TEST-START | file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px.html?-bmp-in.ico == file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px-ref.html
[task 2017-07-23T18:18:57.678794Z] 18:18:57     INFO - REFTEST TEST-LOAD | file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px.html?-bmp-in.ico | 646 / 1926 (33%)
[task 2017-07-23T18:18:57.697455Z] 18:18:57     INFO - ++DOMWINDOW == 34 (0x7f4d4a878000) [pid = 1115] [serial = 1723] [outer = 0x7f4d4f66d800]
[task 2017-07-23T18:18:57.738398Z] 18:18:57     INFO - Assertion failure: mState != WAITING (Did we get a spurious wakeup somehow?), at /home/worker/workspace/build/src/image/SourceBuffer.h:248
[task 2017-07-23T18:19:17.481454Z] 18:19:17     INFO - #01: mozilla::image::SourceBuffer::AdvanceIteratorOrScheduleResume [image/SourceBuffer.cpp:662]
[task 2017-07-23T18:19:17.482937Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.484131Z] 18:19:17     INFO - #02: mozilla::image::nsBMPDecoder::DoDecode [image/StreamingLexer.h:477]
[task 2017-07-23T18:19:17.485131Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.486303Z] 18:19:17     INFO - #03: mozilla::image::Decoder::Decode [mfbt/Variant.h:614]
[task 2017-07-23T18:19:17.487317Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.488477Z] 18:19:17     INFO - #04: mozilla::image::nsICODecoder::FlushContainedDecoder [image/decoders/nsICODecoder.cpp:701]
[task 2017-07-23T18:19:17.489478Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.490634Z] 18:19:17     INFO - #05: mozilla::image::nsICODecoder::ReadResource [image/decoders/nsICODecoder.cpp:376]
[task 2017-07-23T18:19:17.491600Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.492829Z] 18:19:17     INFO - #06: mozilla::image::nsICODecoder::DoDecode(mozilla::image::SourceBufferIterator&, mozilla::image::IResumable*)::{lambda(mozilla::image::ICOState, char const*, unsigned long)#1}::operator()(mozilla::image::ICOState, char const*, unsigned long) const [clone .isra.396]
[task 2017-07-23T18:19:17.493800Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.494990Z] 18:19:17     INFO - #07: mozilla::image::StreamingLexer<mozilla::image::ICOState, 32ul>::ContinueUnbufferedRead<mozilla::image::nsICODecoder::DoDecode(mozilla::image::SourceBufferIterator&, mozilla::image::IResumable*)::<lambda(mozilla::image::ICOState, char const*, size_t)> > [image/StreamingLexer.h:590]
[task 2017-07-23T18:19:17.495962Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.497038Z] 18:19:17     INFO - #08: mozilla::image::nsICODecoder::DoDecode [image/StreamingLexer.h:532]
[task 2017-07-23T18:19:17.497950Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.499002Z] 18:19:17     INFO - #09: mozilla::image::Decoder::Decode [mfbt/Variant.h:614]
[task 2017-07-23T18:19:17.499914Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.500973Z] 18:19:17     INFO - #10: mozilla::image::DecodedSurfaceProvider::Run [image/DecodedSurfaceProvider.cpp:142]
[task 2017-07-23T18:19:17.501892Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.502963Z] 18:19:17     INFO - #11: mozilla::image::DecodePoolWorker::Run [image/DecodePool.cpp:42]
[task 2017-07-23T18:19:17.503890Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.504986Z] 18:19:17     INFO - #12: nsThread::ProcessNextEvent [mfbt/Maybe.h:445]
[task 2017-07-23T18:19:17.505907Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.506997Z] 18:19:17     INFO - #13: NS_ProcessNextEvent [xpcom/threads/nsThreadUtils.cpp:530]
[task 2017-07-23T18:19:17.507932Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.508993Z] 18:19:17     INFO - #14: mozilla::ipc::MessagePumpForNonMainThreads::Run [ipc/glue/MessagePump.cpp:340]
[task 2017-07-23T18:19:17.509906Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.510997Z] 18:19:17     INFO - #15: MessageLoop::RunInternal [ipc/chromium/src/base/message_loop.cc:322]
[task 2017-07-23T18:19:17.511914Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.512989Z] 18:19:17     INFO - #16: MessageLoop::Run [ipc/chromium/src/base/message_loop.cc:294]
[task 2017-07-23T18:19:17.513897Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.515002Z] 18:19:17     INFO - #17: nsThread::ThreadFunc [xpcom/threads/nsThread.cpp:509]
[task 2017-07-23T18:19:17.515912Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.552900Z] 18:19:17     INFO - #18: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:219]
[task 2017-07-23T18:19:17.553570Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.554627Z] 18:19:17     INFO - #19: libpthread.so.0 + 0x76ba
[task 2017-07-23T18:19:17.559118Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.560297Z] 18:19:17     INFO - #20: libc.so.6 + 0x10682d
[task 2017-07-23T18:19:17.560785Z] 18:19:17     INFO - 
[task 2017-07-23T18:19:17.560940Z] 18:19:17     INFO - #21: ??? (???:???)
[task 2017-07-23T18:19:17.561422Z] 18:19:17     INFO - [Parent 1017] WARNING: pipe error (89): Connection reset by peer: file /home/worker/workspace/build/src/ipc/chromium/src/chrome/common/ipc_channel_posix.cc, line 353
[task 2017-07-23T18:19:17.562180Z] 18:19:17     INFO - [Parent 1017] WARNING: bad Shmem: file /home/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 527
[task 2017-07-23T18:19:17.562325Z] 18:19:17     INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x280079,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2017-07-23T18:19:17.562770Z] 18:19:17     INFO - [Parent 1017] WARNING: waitpid failed pid:1115 errno:10: file /home/worker/workspace/build/src/ipc/chromium/src/base/process_util_posix.cc, line 276
[task 2017-07-23T18:24:47.571812Z] 18:24:47    ERROR - REFTEST ERROR | file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px.html?-bmp-in.ico | application timed out after 330 seconds with no output
[task 2017-07-23T18:24:47.574916Z] 18:24:47    ERROR - REFTEST ERROR | Force-terminating active process(es).
[task 2017-07-23T18:24:47.576256Z] 18:24:47     INFO - REFTEST TEST-INFO | started process screentopng
[task 2017-07-23T18:24:47.989579Z] 18:24:47     INFO - REFTEST TEST-INFO | screentopng: exit 0
[task 2017-07-23T18:24:48.168408Z] 18:24:48    ERROR - TEST-UNEXPECTED-FAIL | file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px.html?-bmp-in.ico | application terminated with exit code 6
[task 2017-07-23T18:24:48.170344Z] 18:24:48     INFO - REFTEST INFO | Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpt3UarH.mozrunner/minidumps/74d7fe58-1a9a-f4e2-52ef-1836af766a04.dmp /home/worker/workspace/build/symbols
[task 2017-07-23T18:24:57.436174Z] 18:24:57     INFO - REFTEST INFO | Saved minidump as /home/worker/workspace/build/blobber_upload_dir/74d7fe58-1a9a-f4e2-52ef-1836af766a04.dmp
[task 2017-07-23T18:24:57.437949Z] 18:24:57     INFO - REFTEST INFO | Saved app info as /home/worker/workspace/build/blobber_upload_dir/74d7fe58-1a9a-f4e2-52ef-1836af766a04.extra
[task 2017-07-23T18:24:57.500213Z] 18:24:57     INFO - REFTEST PROCESS-CRASH | file:///home/worker/workspace/build/tests/reftest/tests/image/test/reftest/downscaling/downscale-32px.html?-bmp-in.ico | application crashed [@ libc-2.23.so + 0xfab5d]
[task 2017-07-23T18:24:57.500624Z] 18:24:57     INFO - Crash dump filename: /tmp/tmpt3UarH.mozrunner/minidumps/74d7fe58-1a9a-f4e2-52ef-1836af766a04.dmp
[task 2017-07-23T18:24:57.501029Z] 18:24:57     INFO - Operating system: Linux
[task 2017-07-23T18:24:57.501666Z] 18:24:57     INFO -                   0.0.0 Linux 3.13.0-112-generic #159-Ubuntu SMP Fri Mar 3 15:26:07 UTC 2017 x86_64
[task 2017-07-23T18:24:57.502226Z] 18:24:57     INFO - CPU: amd64
[task 2017-07-23T18:24:57.502779Z] 18:24:57     INFO -      family 6 model 62 stepping 4
[task 2017-07-23T18:24:57.503352Z] 18:24:57     INFO -      2 CPUs
[task 2017-07-23T18:24:57.503858Z] 18:24:57     INFO - 
[task 2017-07-23T18:24:57.504387Z] 18:24:57     INFO - GPU: UNKNOWN
[task 2017-07-23T18:24:57.504935Z] 18:24:57     INFO - 
[task 2017-07-23T18:24:57.505494Z] 18:24:57     INFO - Crash reason:  SIGABRT
[task 2017-07-23T18:24:57.506029Z] 18:24:57     INFO - Crash address: 0x3e8000003e3
[task 2017-07-23T18:24:57.506571Z] 18:24:57     INFO - Process uptime: not available
[task 2017-07-23T18:24:57.506891Z] 18:24:57     INFO - 
[task 2017-07-23T18:24:57.507439Z] 18:24:57     INFO - Thread 0 (crashed)
[task 2017-07-23T18:24:57.508017Z] 18:24:57     INFO -  0  libc-2.23.so + 0xfab5d
[task 2017-07-23T18:24:57.508536Z] 18:24:57     INFO -     rax = 0xfffffffffffffffc   rdx = 0x00000000ffffffff
[task 2017-07-23T18:24:57.509075Z] 18:24:57     INFO -     rcx = 0xffffffffffffffff   rbx = 0x00007efdd7fd7530
[task 2017-07-23T18:24:57.510036Z] 18:24:57     INFO -     rsi = 0x0000000000000005   rdi = 0x00007efda33866d0
[task 2017-07-23T18:24:57.510725Z] 18:24:57     INFO -     rbp = 0x00007ffc37cef110   rsp = 0x00007ffc37cef0f0
[task 2017-07-23T18:24:57.511521Z] 18:24:57     INFO -      r8 = 0x0000000000000042    r9 = 0x0000000000000001
[task 2017-07-23T18:24:57.512223Z] 18:24:57     INFO -     r10 = 0x00007efdd966b050   r11 = 0x0000000000000293
[task 2017-07-23T18:24:57.512579Z] 18:24:57     INFO -     r12 = 0x00007efda33866d0   r13 = 0x00000000ffffffff
[task 2017-07-23T18:24:57.512976Z] 18:24:57     INFO -     r14 = 0x00007efdc903936b   r15 = 0x0000000000000005
[task 2017-07-23T18:24:57.514288Z] 18:24:57     INFO -     rip = 0x00007efdd82d6b5d
[task 2017-07-23T18:24:57.514986Z] 18:24:57     INFO -     Found by: given as instruction pointer in context
[task 2017-07-23T18:24:57.515657Z] 18:24:57     INFO -  1  libxul.so!PollWrapper [nsAppShell.cpp:46b12a5d51b8 : 50 + 0x10]
[task 2017-07-23T18:24:57.516218Z] 18:24:57     INFO -     rbp = 0x00007ffc37cef110   rsp = 0x00007ffc37cef100
[task 2017-07-23T18:24:57.516568Z] 18:24:57     INFO -     rip = 0x00007efdc9039397
[task 2017-07-23T18:24:57.517359Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.517783Z] 18:24:57     INFO -  2  libglib-2.0.so.0.4800.2 + 0x4a38c
[task 2017-07-23T18:24:57.518551Z] 18:24:57     INFO -     rbp = 0x0000000000000005   rsp = 0x00007ffc37cef120
[task 2017-07-23T18:24:57.519099Z] 18:24:57     INFO -     rip = 0x00007efdd30b638c
[task 2017-07-23T18:24:57.519670Z] 18:24:57     INFO -     Found by: call frame info
[task 2017-07-23T18:24:57.520238Z] 18:24:57     INFO -  3  libglib-2.0.so.0.4800.2 + 0x4a49c
[task 2017-07-23T18:24:57.520604Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef180   rip = 0x00007efdd30b649c
[task 2017-07-23T18:24:57.520989Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.521421Z] 18:24:57     INFO -  4  libxul.so!nsAppShell::ProcessNextNativeEvent [nsAppShell.cpp:46b12a5d51b8 : 280 + 0x5]
[task 2017-07-23T18:24:57.521849Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef1a0   rip = 0x00007efdc90393dd
[task 2017-07-23T18:24:57.522280Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.522718Z] 18:24:57     INFO -  5  libxul.so!nsBaseAppShell::DoProcessNextNativeEvent [nsBaseAppShell.cpp:46b12a5d51b8 : 138 + 0x10]
[task 2017-07-23T18:24:57.523142Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef1b0   rip = 0x00007efdc900bbbf
[task 2017-07-23T18:24:57.523537Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.523950Z] 18:24:57     INFO -  6  libxul.so!nsBaseAppShell::OnProcessNextEvent [nsBaseAppShell.cpp:46b12a5d51b8 : 289 + 0x8]
[task 2017-07-23T18:24:57.524816Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef1f0   rip = 0x00007efdc900f080
[task 2017-07-23T18:24:57.525220Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.526172Z] 18:24:57     INFO -  7  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:46b12a5d51b8 : 1492 + 0xf]
[task 2017-07-23T18:24:57.526527Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef240   rip = 0x00007efdc750d1bc
[task 2017-07-23T18:24:57.527362Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.527791Z] 18:24:57     INFO -  8  libxul.so!nsACString::ReplacePrep [nsTSubstring.cpp:46b12a5d51b8 : 203 + 0x8]
[task 2017-07-23T18:24:57.528414Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef280   rip = 0x00007efdc7481bc0
[task 2017-07-23T18:24:57.529240Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.529871Z] 18:24:57     INFO -  9  firefox!arena_chunk_comp [mozjemalloc.cpp:46b12a5d51b8 : 2285 + 0x17]
[task 2017-07-23T18:24:57.530516Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef2a0   rip = 0x0000000000417201
[task 2017-07-23T18:24:57.531156Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.531560Z] 18:24:57     INFO - 10  firefox!arena_run_alloc [mozjemalloc.cpp:46b12a5d51b8 : 2666 + 0x2]
[task 2017-07-23T18:24:57.532376Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef330   rip = 0x000000000041b301
[task 2017-07-23T18:24:57.533064Z] 18:24:57     INFO -     Found by: stack scanning
[task 2017-07-23T18:24:57.533975Z] 18:24:57     INFO - 11  firefox!_fini + 0xc28
[task 2017-07-23T18:24:57.534893Z] 18:24:57     INFO -     rsp = 0x00007ffc37cef338   rip = 0x000000000041db00
[task 2017-07-23T18:24:57.535607Z] 18:24:57     INFO -     Found by: stack scanning
This must be a regression from bug 1315554.
Assignee: nobody → aosmond
Blocks: 1315554
Status: NEW → ASSIGNED
Keywords: crash
Priority: -- → P3
Whiteboard: [gfx-noted]
Keywords: crash
I think I see the problem. The iterator for the child BMP decoder is in some state, waiting for N bytes. The iterator for the ICO decoder got M bytes, where N > M, so that when it calls nsICODecoder::FlushContainedDecoder, it is indeed a spurious wakeup for the child decoder.
Keywords: regression
Attachment #8889438 - Flags: review?(tnikkel)
Attachment #8889438 - Flags: review?(tnikkel) → review+
(In reply to Andrew Osmond [:aosmond] from comment #4)
> Created attachment 8889438 [details] [diff] [review]
> SourceBufferIterator::SetWaiting should not assert for spurious wakeups if
> no consumer was given., v1
> 
> Not able to reproduce locally, but I think this should do it...
> 
> try:
> https://treeherder.mozilla.org/#/
> jobs?repo=try&revision=3a846fb32e437c92d59b3b33558608729fea54cb

its reproducible - crash on load - on https://collaborate.avaya.com/aacpa/ - found via bughunter
Pushed by aosmond@gmail.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/277525fcf888
SourceBufferIterator::SetWaiting should not assert for spurious wakeups if no consumer was given. r=tnikkel
https://hg.mozilla.org/mozilla-central/rev/277525fcf888
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla56
Version: unspecified → Trunk
You need to log in before you can comment on or make changes to this bug.