Closed Bug 949720 Opened 7 years ago Closed 7 years ago

Intermittent Shutdown | Exited with code 11 during test run | application crashed [@ mozilla::places::AsyncGetFaviconURLForPage::Run()] after "Assertion failure: ((bool)(__builtin_expect(!!(!NS_FAILED_impl(rv)), 1)))"

Categories

(Firefox :: Bookmarks & History, defect)

Product:
Firefox
Component:
Bookmarks & History
Platform:
x86_64
Linux
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 30
Tracking Flags:
Tracking Status
firefox28 --- wontfix
firefox29 --- fixed
firefox30 --- fixed
firefox-esr24 --- unaffected
b2g-v1.3 --- wontfix
b2g-v1.4 --- fixed

People

(Reporter: RyanVM, Assigned: mak)

Details

(Keywords: assertion, crash, intermittent-failure)

Attachments

(1 file)

patch v1
3.66 KB, patch
Yoric
: review+
Sylvestre
: approval-mozilla-aurora+
Details | Diff | Splinter Review 
Interesting that it hit twice on two different trees within ~30m of each other when we haven't seen it before nor have I seen it since. Some sort of infra blip that we handled badly?

https://tbpl.mozilla.org/php/getParsedLog.php?id=31884574&tree=Fx-Team

Ubuntu VM 12.04 x64 fx-team debug test reftest on 2013-12-12 10:13:39 PST for push defc9b99115f
slave: tst-linux64-spot-463

11:08:48     INFO -  REFTEST TEST-START | Shutdown
11:08:48     INFO -  --DOCSHELL 0x1879620 == 3 [pid = 2387] [id = 2]
11:08:49     INFO -  --DOCSHELL 0x1a67490 == 2 [pid = 2387] [id = 3]
11:08:49     INFO -  --DOCSHELL 0x12d5c00 == 1 [pid = 2387] [id = 1]
11:08:49     INFO -  --DOMWINDOW == 161 (0xa9a9fa8) [pid = 2387] [serial = 28605] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/338427-3-ref.html]
11:08:49     INFO -  --DOMWINDOW == 160 (0x844c998) [pid = 2387] [serial = 28598] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/674212-spellcheck.html]
11:08:49     INFO -  --DOMWINDOW == 159 (0x6937fc8) [pid = 2387] [serial = 28601] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/338427-2.html]
11:08:49     INFO -  --DOMWINDOW == 158 (0x3fed878) [pid = 2387] [serial = 28604] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/338427-3.html]
11:08:49     INFO -  --DOMWINDOW == 157 (0x5536c28) [pid = 2387] [serial = 28599] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/674212-spellcheck-ref.html]
11:08:49     INFO -  --DOMWINDOW == 156 (0x89869c8) [pid = 2387] [serial = 28602] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/338427-2-ref.html]
11:08:49     INFO -  --DOMWINDOW == 155 (0xb9128f8) [pid = 2387] [serial = 28547] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-space-valid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 154 (0x9405e58) [pid = 2387] [serial = 28552] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-multiple-valid.html]
11:08:49     INFO -  --DOMWINDOW == 153 (0x8246088) [pid = 2387] [serial = 28544] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-period-valid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 152 (0xeb445d8) [pid = 2387] [serial = 28549] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-comma-valid.html]
11:08:49     INFO -  --DOMWINDOW == 151 (0x4134308) [pid = 2387] [serial = 28541] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-slash-valid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 150 (0x5ec5928) [pid = 2387] [serial = 28538] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-invalid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 149 (0x3fac988) [pid = 2387] [serial = 28546] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-space-valid.html]
11:08:49     INFO -  --DOMWINDOW == 148 (0x1607a48) [pid = 2387] [serial = 28543] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-period-valid.html]
11:08:49     INFO -  --DOMWINDOW == 147 (0x3edc368) [pid = 2387] [serial = 28556] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-multiple-invalid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 146 (0x41323d8) [pid = 2387] [serial = 28540] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-slash-valid.html]
11:08:49     INFO -  --DOMWINDOW == 145 (0x3fd2e18) [pid = 2387] [serial = 28553] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-multiple-valid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 144 (0x8e2ceb8) [pid = 2387] [serial = 28558] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-dotafterquote-valid.html]
11:08:49     INFO -  --DOMWINDOW == 143 (0x8c73348) [pid = 2387] [serial = 28537] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-invalid.html]
11:08:49     INFO -  --DOMWINDOW == 142 (0x3c89bf8) [pid = 2387] [serial = 28550] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-comma-valid-ref.html]
11:08:49     INFO -  --DOMWINDOW == 141 (0x973c638) [pid = 2387] [serial = 28555] [outer = (nil)] [url = file:///builds/slave/test/build/tests/reftest/tests/editor/reftests/spellcheck-hyphen-multiple-invalid.html]
11:08:49     INFO -  [2387] WARNING: 1 sort operation has occurred for the SQL statement '0x7f25e0044470'.  See https://developer.mozilla.org/En/Storage/Warnings details.: file ../../../storage/src/mozStoragePrivateHelpers.cpp, line 109
11:08:50     INFO -  [2387] WARNING: NS_ENSURE_TRUE(stmt) failed: file ../../../../toolkit/components/places/History.cpp, line 2135
11:08:50     INFO -  [2387] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x8000FFFF: file ../../../../toolkit/components/places/History.cpp, line 1365

The above NS_ENSURE_TRUE & NS_ENSURE_SUCCESS get spammed repeatedly, then...

11:08:50     INFO -  Assertion failure: ((bool)(__builtin_expect(!!(!NS_FAILED_impl(rv)), 1))), at ../../../../toolkit/components/places/AsyncFaviconHelpers.cpp:809
11:08:51     INFO -  [2450] WARNING: shutting down early because of crash!: file ../../../../dom/plugins/ipc/PluginModuleChild.cpp, line 697
11:08:51     INFO -  [2450] WARNING: plugin process _exit()ing: file ../../../../dom/plugins/ipc/PluginModuleChild.cpp, line 662
11:08:51  WARNING -  TEST-UNEXPECTED-FAIL | Shutdown | Exited with code 11 during test run
11:08:51     INFO -  INFO | automation.py | Application ran for: 0:46:06.104645
11:08:51     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpIA9zMipidlog
11:08:51     INFO -  ==> process 2387 launched child process 2450
11:08:51     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2450
11:08:59  WARNING -  PROCESS-CRASH | Shutdown | application crashed [@ mozilla::places::AsyncGetFaviconURLForPage::Run()]
11:08:59     INFO -  Crash dump filename: /tmp/tmpwet9hA.mozrunner/minidumps/21693e78-14e4-262e-3b9f7a27-543b88fd.dmp
11:08:59     INFO -  Operating system: Linux
11:08:59     INFO -                    0.0.0 Linux 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012 x86_64
11:08:59     INFO -  CPU: amd64
11:08:59     INFO -       family 6 model 45 stepping 7
11:08:59     INFO -       1 CPU
11:08:59     INFO -  Crash reason:  SIGSEGV
11:08:59     INFO -  Crash address: 0x0
11:08:59     INFO -  Thread 12 (crashed)
11:08:59     INFO -   0  libxul.so!mozilla::places::AsyncGetFaviconURLForPage::Run() [AsyncFaviconHelpers.cpp:defc9b99115f : 809 + 0x18]
11:08:59     INFO -      rbx = 0x0000000008cdb710   r12 = 0x0000000008cdb738
11:08:59     INFO -      r13 = 0x00007f25c13fed1f   r14 = 0x00007f25c13feca8
11:08:59     INFO -      r15 = 0x0000000000000000   rip = 0x00007f25f8584e56
11:08:59     INFO -      rsp = 0x00007f25c13feb60   rbp = 0x00007f25c13fec90
11:08:59     INFO -      Found by: given as instruction pointer in context
11:08:59     INFO -   1  libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:defc9b99115f : 634 + 0x11]
11:08:59     INFO -      rbx = 0x000000000144fff0   r12 = 0x00007f25e0001100
11:08:59     INFO -      r13 = 0x00007f25c13fed1f   r14 = 0x00007f25c13feca8
11:08:59     INFO -      r15 = 0x0000000000000000   rip = 0x00007f25f7059bdc
11:08:59     INFO -      rsp = 0x00007f25c13feca0   rbp = 0x00007f25c13fed00
11:08:59     INFO -      Found by: call frame info
11:08:59     INFO -   2  libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:defc9b99115f : 263 + 0xc]
11:08:59     INFO -      rbx = 0x00007f25e0001100   r12 = 0x00007f25e00011c0
11:08:59     INFO -      r13 = 0x00007f25e00044e0   r14 = 0x0000000000000901
11:08:59     INFO -      r15 = 0x00007f25e00011b8   rip = 0x00007f25f6ff9bf3
11:08:59     INFO -      rsp = 0x00007f25c13fed10   rbp = 0x00007f25c13fed30
11:08:59     INFO -      Found by: call frame info
11:08:59     INFO -   3  libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:defc9b99115f : 301 + 0xa]
11:08:59     INFO -      rbx = 0x00007f25e00011a0   r12 = 0x00007f25e00011c0
11:08:59     INFO -      r13 = 0x00007f25e00044e0   r14 = 0x0000000000000901
11:08:59     INFO -      r15 = 0x00007f25e00011b8   rip = 0x00007f25f726f0c1
11:08:59     INFO -      rsp = 0x00007f25c13fed40   rbp = 0x00007f25c13fed90
11:08:59     INFO -      Found by: call frame info
11:08:59     INFO -   4  libxul.so!MessageLoop::RunInternal() [message_loop.cc:defc9b99115f : 226 + 0x8]
11:08:59     INFO -      rbx = 0x00007f25e00044e0   r12 = 0x00007f25e00044e0
11:08:59     INFO -      r13 = 0x0000000001450010   r14 = 0x000000000000096a
11:08:59     INFO -      r15 = 0x000000000000096a   rip = 0x00007f25f725c620
11:08:59     INFO -      rsp = 0x00007f25c13feda0   rbp = 0x00007f25c13fedd0
11:08:59     INFO -      Found by: call frame info
11:08:59     INFO -   5  libxul.so!MessageLoop::Run() [message_loop.cc:defc9b99115f : 219 + 0x7]
11:08:59     INFO -      rbx = 0x00007f25e00044e0   r12 = 0x00007f25e00044e0
11:08:59     INFO -      r13 = 0x0000000001450010   r14 = 0x000000000000096a
11:08:59     INFO -      r15 = 0x000000000000096a   rip = 0x00007f25f725c648
11:08:59     INFO -      rsp = 0x00007f25c13fede0   rbp = 0x00007f25c13fee10
11:08:59     INFO -      Found by: call frame info
11:08:59     INFO -   6  libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:defc9b99115f : 258 + 0x7]
11:08:59     INFO -      rbx = 0x000000000144fff0   r12 = 0x00007f25e00044e0
11:08:59     INFO -      r13 = 0x0000000001450010   r14 = 0x000000000000096a
11:08:59     INFO -      r15 = 0x000000000000096a   rip = 0x00007f25f705aae0
11:08:59     INFO -      rsp = 0x00007f25c13fee20   rbp = 0x00007f25c13fee60
11:08:59     INFO -      Found by: call frame info
I think this is the assert that is failing
http://mxr.mozilla.org/mozilla-central/source/toolkit/components/places/AsyncFaviconHelpers.cpp#816
We should check first why we are running so late, and if it's unavoidable we should not assert like this
Assignee: nobody → mak77
Status: NEW → ASSIGNED
Attached patch patch v1 — — Splinter Review 
FetchIconInfo can only fail if it can't get a valid statement, that may happen on shutdown since the connection is closed and we won't reopen it, thus that should just be handled as a common error. Other parts of FetchIconInfo can only fail due to OOM (for which we'd crash regardless) or coding errors, so they make more sense as asserts.
Attachment #8382191 - Flags: review?(dteller)
Comment on attachment 8382191 [details] [diff] [review]
patch v1

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

::: toolkit/components/places/AsyncFaviconHelpers.cpp
@@ +812,5 @@
>                    "This should not be called on the main thread.");
>  
>    nsAutoCString iconSpec;
>    nsresult rv = FetchIconURL(mDB, mPageSpec, iconSpec);
> +  NS_ENSURE_SUCCESS(rv, rv);

Isn't NS_ENSURE_SUCCESS deprecated?
Attachment #8382191 - Flags: review?(dteller) → review+
(In reply to David Rajchenbach Teller [:Yoric] (please use "needinfo?") from comment #43)
> ::: toolkit/components/places/AsyncFaviconHelpers.cpp
> @@ +812,5 @@
> >                    "This should not be called on the main thread.");
> >  
> >    nsAutoCString iconSpec;
> >    nsresult rv = FetchIconURL(mDB, mPageSpec, iconSpec);
> > +  NS_ENSURE_SUCCESS(rv, rv);
> 
> Isn't NS_ENSURE_SUCCESS deprecated?

in this case we want the warning and I don't see a valid reason to use the longest form, that deprecation is one of those cases where misuse by some ends up affecting others code cleanness. As module owner I don't think it gives any value to Places codebase (where it's basically used anywhere, with very rare cases of abuse or misuse). So probably the right answer is yes, but we didn't yet decide whether is worth to apply such rule to Places codebase.
https://hg.mozilla.org/mozilla-central/rev/1320ac79187f
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Please request Aurora approval for this when you get a chance :)
status-firefox28: --- → unaffected
status-firefox29: --- → affected
status-firefox30: --- → fixed
status-firefox-esr24: --- → unaffected
(In reply to Marco Bonardo [:mak] from comment #44)
> in this case we want the warning and I don't see a valid reason to use the
> longest form, that deprecation is one of those cases where misuse by some
> ends up affecting others code cleanness. As module owner I don't think it
> gives any value to Places codebase (where it's basically used anywhere, with
> very rare cases of abuse or misuse). So probably the right answer is yes,
> but we didn't yet decide whether is worth to apply such rule to Places
> codebase.

I think the discussion on dev.platform came to a pretty clear conclusion: module owners don't get to veto this rule :)

Not saying places needs to be changed all at once, but it's probably best going forward to not make the problem worse with new additions.
The fact is that there is no problem that can be made worse in this code, since we never had bad-use-of-warnings issues, I can remember maybe a couple bugs in 5 years (fixed as soon as they were filed). On the other side, changing to the verbose version will make readability and maintainability of our code much worse, since our src files are already very long (e.g. nsNavHistory.cpp, nsNavhistoryResult.cpp and so on) and changing one line to three lines is not going to improve things at all, most of our code is code,error,code,error,code,error. These issues have never been solved by the discussion. Btw, it's not the right place for a discussion and looks like there's no space for a discussion now.
Comment on attachment 8382191 [details] [diff] [review]
patch v1

[Approval Request Comment]
Bug caused by (feature/regressing bug #): async favicons service
User impact if declined: tests can assert at shutdown breaking tbpl results
Testing completed (on m-c, etc.): m-c
Risk to taking this patch (and alternatives if risky): the changed error handling can only happen in very rare cases where we are likely already broken (memory corruption), so the risk is expected to be low
String or IDL/UUID changes made by this patch: none
Attachment #8382191 - Attachment description: patc hv1 → patch v1
Attachment #8382191 - Flags: approval-mozilla-aurora?
Attachment #8382191 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
QA Whiteboard: [qa-]
You need to log in before you can comment on or make changes to this bug.