Intermittent Assertion failure: m_refCount == 1, at /builds/worker/workspace/build/src/js/src/jit/ExecutableAllocator.cpp:51
Categories
(Core :: Networking: HTTP, defect, P2)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr60 | --- | unaffected |
firefox65 | --- | wontfix |
firefox66 | --- | wontfix |
firefox67 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: valentin)
References
Details
(Keywords: intermittent-failure, regression, Whiteboard: [necko-triaged][stockwell disable-recommended])
Attachments
(2 files)
994 bytes,
text/plain
|
Details | |
10.16 KB,
patch
|
Details | Diff | Splinter Review |
Comment hidden (Intermittent Failures Robot) |
![]() |
||
Updated•7 years ago
|
Comment 2•7 years ago
|
||
Comment 3•7 years ago
|
||
Updated•7 years ago
|
Comment 5•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 8•7 years ago
|
||
Comment 9•7 years ago
|
||
Comment 10•7 years ago
|
||
Updated•7 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 13•7 years ago
|
||
Updated•7 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 15•7 years ago
|
||
Comment 16•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 19•7 years ago
|
||
Comment 21•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 28•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 31•7 years ago
|
||
Comment 32•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 35•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 44•7 years ago
|
||
Comment 45•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Comment 48•7 years ago
|
||
Comment 49•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 52•7 years ago
|
||
Comment 53•7 years ago
|
||
Comment 54•7 years ago
|
||
Comment 55•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 57•7 years ago
|
||
Comment 58•7 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 60•7 years ago
|
||
The failure rate here is still high, 30 total failures in the last 7 days and 304 total failures in the last 30 days.
Andrew/Justin do you have an update here?
Updated•7 years ago
|
Updated•7 years ago
|
Comment 61•7 years ago
|
||
I don't know anything about this test suite, and I'm not sure why this leak is hitting an assertion when we usually don't hit it.
Comment 62•7 years ago
|
||
(In reply to Andrew McCreight [:mccr8] from comment #61)
I don't know anything about this test suite, and I'm not sure why this leak is hitting an assertion when we usually don't hit it.
It's not only Firefox ui tests which are causing this assertion and crash. But also lots of mochitests on Linux triggering it. Please see the OrangeFactor history.
06:20:05 INFO - FAILED TESTS
06:20:05 INFO - -------
06:20:05 INFO - test_restore_windows_after_windows_shutdown.py test_restore_windows_after_windows_shutdown.TestWindowsShutdownRegisterRestart.test_manual_restart
06:20:05 INFO - SUITE-END | took 1249s
This test failure is specific for Firefox UI tests and is only failing on Windows 10 64bit and that for ccov debug builds. Maybe something is wrong here with the shutdown for such builds? Marco, is there something you can help with?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 68•7 years ago
|
||
Marco, can you please take a look at the above comment?
Comment 69•7 years ago
|
||
The only thing I can think of is that shutdown for ccov builds is very slow, as the coverage counters are written out on shutdown. So the timing of the shutdown can be different in ccov builds. I wonder if the test fails in test-verify mode too.
Comment 70•7 years ago
|
||
(In reply to Marco Castelluccio [:marco] from comment #69)
The only thing I can think of is that shutdown for ccov builds is very slow, as the coverage counters are written out on shutdown. So the timing of the shutdown can be different in ccov builds. I wonder if the test fails in test-verify mode too.
At least the Marionette and firefox-ui tests aren't supported yet in test-verify mode. I cannot say something for mochitests.
Also the ccov failures are only a small set compared to normal debug builds which fail way more often.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 78•7 years ago
|
||
There are 139 failures associated to this bug in the last 7 days. These are hitting all platforms but only the debug builds.
:Dolske any updates on this?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 82•7 years ago
|
||
There are 118 total failures in the last 7 days, Justin can you assign someone to work on this?
We cannot disable it since this fails in different tests.
Updated•7 years ago
|
Comment 83•7 years ago
|
||
(In reply to Andrew McCreight [:mccr8] from comment #53)
I think the basic problem here is an assertion in the JS engine is causing
leaks that we normally ignore to turn into a failure. Of the 113 failures
that started in the last week, maybe 1/4 are in
firefox-ui-functional-local-e10s, whatever that is, and the rest are in
marionette tests.
firefox-ui tests are also run under marionette. Could this be a webdriver bug?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 86•7 years ago
|
||
So I was able to trace down the problem to create a minimized testcase which can be run with Marionette. It seems to be a situation when in a new tab a page load is started, but it is getting closed before the page load has been finished.
I can reproduce this crash kinda easily on MacOS when running the following command with the testcase as attached:
mach marionette test -vv --gecko-log - %testcase.py% --run-until-failure
Firefox should crash after a couple of iterations of this test. If not, repeat the command or additionally use --repeat 100
or such to run more than 30 iterations.
I hope that helps to nail down this problem. Who could actually investigate that?
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 90•7 years ago
|
||
I hate to keep bouncing this around, but tracking down an ill-defined leak is going to be difficult for the front-end team to assist with.
Andrew, does the reduced test case in comment 86 help? I'm not sure who is best positioned to look at leaks.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 99•7 years ago
|
||
Comment 100•7 years ago
|
||
With this patch, I was able to get a CC log of the case when we leaked. There were 3 non-garbage items in the final CC log. A nsWebBrowser, a nsXPCWrappedJS (nsIStreamListener), and a nsXPCWrappedJS (nsIInterfaceRequestor). The two XPCWJS were in the same object chain. I looked at the JS object being used to implement the WJS and I figured out that it must be a FaviconLoad from FaviconLoader.jsm. It looks like it is being used as some kind of networking listener thing. The bloat log also includes an HttpChannelChild.
On a hunch, I applied the patches from bug 1520062 (which was landed and backed out) and with that I am no longer able to reproduce the leak, so I think the leak is from hitting some error case.
Comment 101•7 years ago
|
||
This bug also seems to have had zero instances on January 23, when bug 1520062 was in the tree, so that's consistent with my theory.
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 104•7 years ago
|
||
Thanks a lot Andrew! That sounds promising.
![]() |
||
Comment 105•7 years ago
|
||
Andrew, thanks. I will duplicate it then to get this off our triage list.
Comment 106•7 years ago
|
||
The test failures are still present and as such we should allow sheriffs to easily classify failures. Otherwise we might also see spreading failures across different bugs. If you don't mind I would like to keep this open, given that it is such a high frequent failure.
Note that we can remove the P1 which should also already help to get it off your triage list.
![]() |
||
Comment 107•7 years ago
|
||
Oh, I didn't realize, sorry for that. Marking as P2 (to actually remove it from our triage list) which is the same priority as the blocker.
Comment 108•7 years ago
|
||
(In reply to Henrik Skupin (:whimboo) [⌚️UTC+1] from comment #104)
Thanks a lot Andrew! That sounds promising.
Thanks for the minimized test case. It would have been much harder to investigate without it.
![]() |
||
Updated•7 years ago
|
Updated•7 years ago
|
Updated•7 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•7 years ago
|
Comment 111•7 years ago
|
||
There are 24 total failures in the last 7 days and 702 total failures in the last 30 days on all platforms, only debug build types.
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=229899897&repo=autoland&lineNumber=14338
[task 2019-02-22T14:18:25.055Z] 14:18:25 INFO - TEST-START | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html
[task 2019-02-22T14:18:25.074Z] 14:18:25 INFO - GECKO(3526) | ERROR: GC found live Cell 0xf74575e7040 of kind FUNCTION at shutdown
[task 2019-02-22T14:18:25.074Z] 14:18:25 INFO - GECKO(3526) | ERROR: GC found live Cell 0xf74575e7080 of kind FUNCTION at shutdown
[task 2019-02-22T14:18:25.074Z] 14:18:25 INFO - GECKO(3526) | ERROR: GC found live Cell 0xf74575e70c0 of kind FUNCTION at shutdown
[task 2019-02-22T14:18:25.074Z] 14:18:25 INFO - GECKO(3526) | ERROR: GC found live Cell 0xf74575e7100 of kind FUNCTION at shutdown
[task 2019-02-22T14:18:26.485Z] 14:18:26 INFO - GECKO(3526) | ERROR: GC found live SharedScriptData 0x7efc2a670900 with ref count 2 at shutdown
[task 2019-02-22T14:18:26.486Z] 14:18:26 INFO - GECKO(3526) | Assertion failure: m_refCount == 1, at /builds/worker/workspace/build/src/js/src/jit/ExecutableAllocator.cpp:49
[task 2019-02-22T14:18:26.487Z] 14:18:26 INFO - GECKO(3526) | [Parent 3526, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4059
[task 2019-02-22T14:18:26.487Z] 14:18:26 INFO - GECKO(3526) | [Parent 3526, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4059
[task 2019-02-22T14:18:26.488Z] 14:18:26 INFO - GECKO(3526) | ++DOMWINDOW == 9 (0x7efc65285000) [pid = 3639] [serial = 128] [outer = 0x7efc7fecf800]
[task 2019-02-22T14:18:26.651Z] 14:18:26 INFO - GECKO(3526) | Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "http://mochi.test:8888/tests/toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html" line: 0}]
[task 2019-02-22T14:18:26.652Z] 14:18:26 INFO - GECKO(3526) | Console message: Warning: attempting to write 5552 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2019-02-22T14:18:26.693Z] 14:18:26 INFO - GECKO(3526) | [Parent 3526, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/protocol/res/SubstitutingProtocolHandler.cpp, line 314
[task 2019-02-22T14:18:26.757Z] 14:18:26 INFO - GECKO(3526) | [Parent 3526, Main Thread] WARNING: Need TabChild to get the nativeWindow from!: file /builds/worker/workspace/build/src/widget/PuppetWidget.cpp, line 1078
[task 2019-02-22T14:18:26.761Z] 14:18:26 INFO - GECKO(3526) | ++DOCSHELL 0x7f98535a5000 == 18 [pid = 3619] [id = {79c099e3-272e-4e07-a27a-fc6c2cf57e7d}]
[task 2019-02-22T14:18:26.763Z] 14:18:26 INFO - GECKO(3526) | ++DOMWINDOW == 55 (0x7f985358e400) [pid = 3619] [serial = 176] [outer = (nil)]
[task 2019-02-22T14:18:26.765Z] 14:18:26 INFO - GECKO(3526) | [Child 3619, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/workspace/build/src/dom/ipc/TabChild.cpp, line 2586
task 2019-02-22T14:18:37.338Z] 14:18:37 INFO - GECKO(3526) | MEMORY STAT | vsize 1497MB | residentFast 139MB | heapAllocated 14MB
[task 2019-02-22T14:18:37.357Z] 14:18:37 INFO - Buffered messages logged at 14:18:26
[task 2019-02-22T14:18:37.357Z] 14:18:37 INFO - AddTask.js | Entering test testWithRealIdleService
[task 2019-02-22T14:18:37.357Z] 14:18:37 INFO - Extension loaded
[task 2019-02-22T14:18:37.357Z] 14:18:37 INFO - Setting interval to 152
[task 2019-02-22T14:18:37.357Z] 14:18:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | Idle status is active - Expected: active, Actual: active
[task 2019-02-22T14:18:37.359Z] 14:18:37 INFO - Buffered messages logged at 14:18:27
[task 2019-02-22T14:18:37.359Z] 14:18:37 INFO - Listener added
[task 2019-02-22T14:18:37.359Z] 14:18:37 INFO - Buffered messages logged at 14:18:37
[task 2019-02-22T14:18:37.360Z] 14:18:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | listener fired with the expected state - Expected: idle, Actual: idle
[task 2019-02-22T14:18:37.360Z] 14:18:37 INFO - Listener fired
[task 2019-02-22T14:18:37.363Z] 14:18:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | Idle status is idle - Expected: idle, Actual: idle
[task 2019-02-22T14:18:37.365Z] 14:18:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | idle
[task 2019-02-22T14:18:37.367Z] 14:18:37 INFO - TEST-PASS | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | test result correct
[task 2019-02-22T14:18:37.373Z] 14:18:37 INFO - AddTask.js | Leaving test testWithRealIdleService
[task 2019-02-22T14:18:37.373Z] 14:18:37 INFO - Buffered messages finished
[task 2019-02-22T14:18:37.374Z] 14:18:37 INFO - TEST-UNEXPECTED-ERROR | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | unexpected-crash-dump-found - This test left crash dumps behind, but we weren't expecting it to!
[task 2019-02-22T14:18:37.376Z] 14:18:37 INFO - Found unexpected crash dump file /tmp/tmp9g3QJx.mozrunner/minidumps/051c3f0d-70e0-f358-553b-891fb40e584a.dmp.
[task 2019-02-22T14:18:37.377Z] 14:18:37 INFO - Found unexpected crash dump file /tmp/tmp9g3QJx.mozrunner/minidumps/051c3f0d-70e0-f358-553b-891fb40e584a.extra.
[task 2019-02-22T14:18:37.377Z] 14:18:37 INFO - TEST-UNEXPECTED-CRASH | toolkit/components/extensions/test/mochitest/test-oop-extensions/test_ext_idle.html | Finished in 12302ms
[task 2019-02-22T14:18:37.378Z] 14:18:37 INFO - {u'runtime': 12302}
[task 2019-02-22T14:18:37.378Z] 14:18:37 INFO - TEST-INFO took 12302ms
[task 2019-02-22T14:18:37.420Z] 14:18:37 INFO - GECKO(3526) | ++DOMWINDOW == 7 (0x7efc65281800) [pid = 3639] [serial = 129] [outer = 0x7efc7fecf800]
[task 2019-02-22T14:18:37.436Z] 14:18:37 INFO - GECKO(3526) | [Parent 3526, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4059
Andrew are there updates here? Failure rate seems to have decreased starting with ~18th of February.
Comment hidden (Intermittent Failures Robot) |
Comment 113•6 years ago
|
||
See comment 100. Bug 1520062 landed and there have been no failures more recently than 2/22.
Comment 114•6 years ago
|
||
(In reply to Andrew McCreight [:mccr8] from comment #113)
See comment 100. Bug 1520062 landed and there have been no failures more recently than 2/22.
Yes, that is correct, I posted the comment on the 22nd.
Comment 115•6 years ago
|
||
Closing as fixed given that no more failures are present in the last 3 days on trunk. Beta is still affected but has a very low number of intermittents, so maybe a wontfix.
Updated•6 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 118•6 years ago
|
||
Fwiw, I still see this assertion fairly often on Try, e.g.:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=83a6688560d512a4095a7497a412cf58c52109e0&selectedJob=243543274
Comment 119•6 years ago
|
||
(In reply to Mats Palmgren (:mats) from comment #118)
Fwiw, I still see this assertion fairly often on Try, e.g.:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=83a6688560d512a4095a7497a412cf58c52109e0&selectedJob=243543274
Can you please file a new bug, and then also classify the failure? That way we could see how often it actually fails on try. Thanks.
Description
•