1283462 - Intermittent test_bug472986.html,browser_bug594131.js | application crashed [@ mozilla::image::IDecodingTask::NotifyProgress(mozilla::NotNull<mozilla::image::Decoder*>)] Assertion failure: aDecoder->HasProgress() && !aDecoder->IsMetadataDecode()

Status: RESOLVED FIXED

(Core :: Graphics: ImageLib, defect)

Description

[Carsten Book [:Tomcat]]

https://treeherder.mozilla.org/logviewer.html#?job_id=30980398&repo=mozilla-inbound#L19088 

05:38:58 WARNING - TEST-UNEXPECTED-FAIL | security/manager/ssl/tests/mochitest/mixedcontent/test_bug472986.html | application terminated with exit code 1

PROCESS-CRASH | security/manager/ssl/tests/mochitest/mixedcontent/test_bug472986.html | application crashed [@ mozilla::image::IDecodingTask::NotifyProgress(mozilla::NotNull<mozilla::image::Decoder*>)]
 05:39:10     INFO -  Crash dump filename: /var/folders/x7/246bjm1d2c1fylzrbln074gc00000w/T/tmpX_1zdF.mozrunner/minidumps/067537A0-1F11-4145-8F69-176494107807.dmp
 05:39:10     INFO -  Operating system: Mac OS X
 05:39:10     INFO -                    10.10.5 14F27
 05:39:10     INFO -  CPU: amd64
 05:39:10     INFO -       family 6 model 69 stepping 1
 05:39:10     INFO -       4 CPUs
 05:39:10     INFO -  Crash reason:  EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
 05:39:10     INFO -  Crash address: 0x0
 05:39:10     INFO -  Process uptime: 15 seconds
 05:39:10     INFO -  Thread 42 (crashed)
 05:39:10     INFO -   0  XUL!mozilla::image::IDecodingTask::NotifyProgress(mozilla::NotNull<mozilla::image::Decoder*>) [IDecodingTask.cpp:732d517ac438 : 25 + 0x0]
 05:39:10     INFO -      rax = 0x0000000000000000   rdx = 0x00007fff740b01f8
 05:39:10     INFO -      rcx = 0x0000000000000000   rbx = 0x00007fff740b0c50
 05:39:10     INFO -      rsi = 0x0000690000006900   rdi = 0x000000010750fbbf
 05:39:10     INFO -      rbp = 0x000000012455bcc0   rsp = 0x000000012455bc90
 05:39:10     INFO -       r8 = 0x000000012455bc40    r9 = 0x000000012455c000
 05:39:10     INFO -      r10 = 0x00007fff8c84a3ef   r11 = 0x00007fff8c84a3c0
 05:39:10     INFO -      r12 = 0x000000011de3a210   r13 = 0x000000011de3a258
 05:39:10     INFO -      r14 = 0x000000011316dc00   r15 = 0x000000011de3a230
 05:39:10     INFO -      rip = 0x0000000103779154
 05:39:10     INFO -      Found by: given as instruction pointer in context
 05:39:10     INFO -   1  XUL!mozilla::image::DecodePoolWorker::Run() [DecodePool.cpp:732d517ac438 : 187 + 0x9]
 05:39:10     INFO -      rbx = 0x0000000114277740   rbp = 0x000000012455bd20
 05:39:10     INFO -      rsp = 0x000000012455bcd0   r12 = 0x000000011de3a210
 05:39:10     INFO -      r13 = 0x000000011de3a258   r14 = 0x000000011deae3e0
 05:39:10     INFO -      r15 = 0x000000011de3a230   rip = 0x00000001037850d9
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   2  XUL!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:732d517ac438 : 1073 + 0x6]
 05:39:10     INFO -      rbx = 0x000000011dbcec00   rbp = 0x000000012455bdd0
 05:39:10     INFO -      rsp = 0x000000012455bd30   r12 = 0x0000000000000000
 05:39:10     INFO -      r13 = 0x0000000000000000   r14 = 0x000000011dbcec20
 05:39:10     INFO -      r15 = 0x000000012455bd60   rip = 0x00000001027537f0
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   3  XUL!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:732d517ac438 : 290 + 0xd]
 05:39:10     INFO -      rbx = 0x0000000000000000   rbp = 0x000000012455bdf0
 05:39:10     INFO -      rsp = 0x000000012455bde0   r12 = 0x000000012455be20
 05:39:10     INFO -      r13 = 0x000000011de988b0   r14 = 0x000000011de98880
 05:39:10     INFO -      r15 = 0x000000011dbcec00   rip = 0x0000000102793ed3
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   4  XUL!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:732d517ac438 : 354 + 0xa]
 05:39:10     INFO -      rbx = 0x0000000119981cc0   rbp = 0x000000012455be50
 05:39:10     INFO -      rsp = 0x000000012455be00   r12 = 0x000000012455be20
 05:39:10     INFO -      r13 = 0x000000011de988b0   r14 = 0x000000011de98880
 05:39:10     INFO -      r15 = 0x000000011dbcec00   rip = 0x0000000102cc838b
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   5  XUL!MessageLoop::Run() [message_loop.cc:732d517ac438 : 228 + 0x5]
 05:39:10     INFO -      rbx = 0x000000011dbcec00   rbp = 0x000000012455be80
 05:39:10     INFO -      rsp = 0x000000012455be60   r12 = 0x000000000000d203
 05:39:10     INFO -      r13 = 0x00000000000008ff   r14 = 0x000000011dbcec20
 05:39:10     INFO -      r15 = 0x0000000119981cc0   rip = 0x0000000102c87d8c
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   6  XUL!nsThread::ThreadFunc(void*) [nsThread.cpp:732d517ac438 : 468 + 0x8]
 05:39:10     INFO -      rbx = 0x000000011dbcec00   rbp = 0x000000012455bec0
 05:39:10     INFO -      rsp = 0x000000012455be90   r12 = 0x000000000000d203
 05:39:10     INFO -      r13 = 0x00000000000008ff   r14 = 0x000000011dbcec20
 05:39:10     INFO -      r15 = 0x0000000119981cc0   rip = 0x0000000102751026
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   7  libnss3.dylib!_pt_root [ptthread.c:732d517ac438 : 216 + 0x3]
 05:39:10     INFO -      rbx = 0x000000011ce2c240   rbp = 0x000000012455bef0
 05:39:10     INFO -      rsp = 0x000000012455bed0   r12 = 0x000000000000d203
 05:39:10     INFO -      r13 = 0x00000000000008ff   r14 = 0x000000012455c000
 05:39:10     INFO -      r15 = 0x0000000000000000   rip = 0x00000001024f6910
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   8  libsystem_pthread.dylib!_pthread_body + 0x83
 05:39:10     INFO -      rbx = 0x000000012455c000   rbp = 0x000000012455bf10
 05:39:10     INFO -      rsp = 0x000000012455bf00   r12 = 0x000000000000d203
 05:39:10     INFO -      r13 = 0x00000000000008ff   r14 = 0x000000011ce2c240
 05:39:10     INFO -      r15 = 0x00000001024f67f0   rip = 0x00007fff8c84d05a
 05:39:10     INFO -      Found by: call frame info
 05:39:10     INFO -   9  libsystem_pthread.dylib!_pthread_start + 0xb0
 05:39:10     INFO -      rbp = 0x000000012455bf50   rsp = 0x000000012455bf20
 05:39:10     INFO -      rip = 0x00007fff8c84cfd7
 05:39:10     INFO -      Found by: previous frame's frame pointer
05:39:10 INFO - 10 libsystem_pthread.dylib!t

Comment 1

[Intermittent Failures Robot]

6 automation job failures were associated with this bug in the last 7 days.

Repository breakdown:
* mozilla-central: 2
* fx-team: 2
* mozilla-inbound: 1
* autoland: 1

Platform breakdown:
* osx-10-10: 4
* windows7-32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1283462&startday=2016-07-11&endday=2016-07-17&tree=all

Comment 2

[Andrew Osmond [:aosmond] (he/him)]

Attachment: Fix notify progress race condition, v1

I am having trouble reproducing (doesn't seem to be any occurrences on Linux yet) but I believe a possible root cause is a race condition between the lambda runnable posted to the main thread in NotifyProgress and the decoding thread resuming after yielding. If the decoding resumes and yields again before the main thread gets a chance to run, the original lambda runnable has yet to call TakeProgress/TakeInvalidRect, and now we get a second runnable posted to the main thread. The first runs successfully, and the second fails because the state got changed underneath it.

Additionally, TakeProgress/TakeInvalidRect are not threadsafe and really should only be called in the context of the decoding thread anyways.

Comment 5

[Andrew Osmond [:aosmond] (he/him)]

Attachment: Fix notify progress race condition, v2

Comment 6

[Andrew Osmond [:aosmond] (he/him)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=cefdb1a0a517

Comment 7

[Seth Fowler [:seth] [:s2h]]

Comment on attachment 8773795 [details] [diff] [review]
Fix notify progress race condition, v2

Review of attachment 8773795 [details] [diff] [review]:
-----------------------------------------------------------------

Thanks for fixing this, Andrew!

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/343a4eced34b
Fix race condition when notifying on image decoding progress. r=seth

Comment 9

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/343a4eced34b