Intermittent leakcheck | default 296 bytes leaked (xpcAccessibleDocument, xpcAccessibleGeneric, xpcAccessibleHyperText)
Categories
(Core :: Disability Access APIs, defect, P5)
Tracking
()
Tracking | Status | |
---|---|---|
firefox79 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: Jamie)
References
(Blocks 1 open bug, Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [retriggered][stockwell disabled][stockwell needswork:owner])
Attachments
(6 files)
Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=297702975&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/C8_4kK8aQnSVRFt-8zaXVQ/runs/0/artifacts/public/logs/live_backing.log
[task 2020-04-15T09:25:43.396Z] 09:25:43 INFO - TEST-START | accessible/tests/browser/hittest/browser_test_zoom_text.js
[task 2020-04-15T09:25:43.420Z] 09:25:43 INFO - GECKO(1225) | [Child 1313: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f912876a000 == 2 [pid = 1313] [id = {9eb63a55-6e5c-4702-aae3-4fb01b91d089}]
[task 2020-04-15T09:25:43.420Z] 09:25:43 INFO - GECKO(1225) | [Child 1313: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (0x7f912f7a33c0) [pid = 1313] [serial = 21] [outer = (nil)]
[task 2020-04-15T09:25:43.420Z] 09:25:43 INFO - GECKO(1225) | [Child 1313: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f912876a400) [pid = 1313] [serial = 22] [outer = 0x7f912f7a33c0]
[task 2020-04-15T09:25:43.460Z] 09:25:43 INFO - GECKO(1225) | [Child 1727: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7fa4fb3d8000 == 0 [pid = 1727] [id = {4eb0e1b2-6a3e-4fc9-9d9b-d7b480b936fd}] [url = http://example.net/document-builder.sjs?html=%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cp+id%3D%22p1%22%3Epara+1%3C%2Fp%3E%3Cp+id%3D%22p2%22%3Epara+2%3C%2Fp%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2020-04-15T09:25:43.464Z] 09:25:43 INFO - GECKO(1225) | [Parent 1225, Main Thread] WARNING: '!mName', file /builds/worker/checkouts/gecko/editor/libeditor/EditAggregateTransaction.cpp, line 92
[task 2020-04-15T09:25:43.464Z] 09:25:43 INFO - GECKO(1225) | [Parent 1225, Main Thread] WARNING: EditAggregationTransaction::GetName() failed: 'NS_SUCCEEDED(rv)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 217
[task 2020-04-15T09:25:43.465Z] 09:25:43 INFO - GECKO(1225) | [Parent 1225, Main Thread] WARNING: nsIAbsorbingTransaction::GetTxnName() failed, but ignored: 'NS_SUCCEEDED(rvIgnored)', file /builds/worker/checkouts/gecko/editor/libeditor/PlaceholderTransaction.cpp, line 188
[task 2020-04-15T09:25:43.513Z] 09:25:43 INFO - GECKO(1225) | [Child 1727: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7fa510765c80) [pid = 1727] [serial = 1] [outer = (nil)] [url = http://example.net/document-builder.sjs?html=%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cp+id%3D%22p1%22%3Epara+1%3C%2Fp%3E%3Cp+id%3D%22p2%22%3Epara+2%3C%2Fp%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2020-04-15T09:25:43.513Z] 09:25:43 INFO - GECKO(1225) | [Child 1727: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7fa4f542c000) [pid = 1727] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-04-15T09:25:43.514Z] 09:25:43 INFO - GECKO(1225) | [Child 1727: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fa4f5435000) [pid = 1727] [serial = 3] [outer = (nil)] [url = http://example.net/document-builder.sjs?html=%3Chtml%3E%0A++++++++++%3Chead%3E%0A++++++++++++%3Cmeta+charset%3D%22utf-8%22%2F%3E%0A++++++++++++%3Ctitle%3EAccessibility+Fission+Test%3C%2Ftitle%3E%0A++++++++++%3C%2Fhead%3E%0A++++++++++%3Cbody+id%3D%22default-iframe-body-id%22%3E%3Cp+id%3D%22p1%22%3Epara+1%3C%2Fp%3E%3Cp+id%3D%22p2%22%3Epara+2%3C%2Fp%3E%3C%2Fbody%3E%0A++++++++%3C%2Fhtml%3E]
[task 2020-04-15T09:25:43.514Z] 09:25:43 INFO - GECKO(1225) | [Child 1727, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/netwerk/base/nsNetUtil.cpp, line 2307
[task 2020-04-15T09:25:43.514Z] 09:25:43 INFO - GECKO(1225) | [Child 1727, Main Thread] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/caps/ContentPrincipal.cpp, line 398
[task 2020-04-15T09:25:43.514Z] 09:25:43 INFO - GECKO(1225) | [Child 1727, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/caps/ContentPrincipal.cpp, line 423
[task 2020-04-15T09:25:43.531Z] 09:25:43 INFO - GECKO(1225) | [Child 1727, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp, line 3352
[task 2020-04-15T09:25:43.676Z] 09:25:43 INFO - GECKO(1225) | [Child 1313: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (0x7f9128772800) [pid = 1313] [serial = 23] [outer = 0x7f912f7a33c0
[task 2020-04-15T09:25:59.293Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.293Z] 09:25:59 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1516
[task 2020-04-15T09:25:59.294Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.294Z] 09:25:59 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-04-15T09:25:59.294Z] 09:25:59 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-04-15T09:25:59.295Z] 09:25:59 INFO - 0 |TOTAL | 40 0| 32083 0|
[task 2020-04-15T09:25:59.297Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.297Z] 09:25:59 INFO - nsTraceRefcnt::DumpStatistics: 805 entries
[task 2020-04-15T09:25:59.298Z] 09:25:59 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-04-15T09:25:59.298Z] 09:25:59 INFO - leakcheck | Processing leak log file /tmp/tmpwr6hPD.mozrunner/runtests_leaks.log
[task 2020-04-15T09:25:59.298Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.299Z] 09:25:59 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 1225
[task 2020-04-15T09:25:59.299Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.299Z] 09:25:59 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-04-15T09:25:59.300Z] 09:25:59 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-04-15T09:25:59.300Z] 09:25:59 INFO - 0 |TOTAL | 35 296| 9912318 3|
[task 2020-04-15T09:25:59.308Z] 09:25:59 INFO - 2057 |xpcAccessibleDocument | 144 144| 60 1|
[task 2020-04-15T09:25:59.309Z] 09:25:59 INFO - 2058 |xpcAccessibleGeneric | 64 64| 422 1|
[task 2020-04-15T09:25:59.311Z] 09:25:59 INFO - 2059 |xpcAccessibleHyperText | 88 88| 161 1|
[task 2020-04-15T09:25:59.311Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.312Z] 09:25:59 INFO - nsTraceRefcnt::DumpStatistics: 2061 entries
[task 2020-04-15T09:25:59.312Z] 09:25:59 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleDocument
[task 2020-04-15T09:25:59.313Z] 09:25:59 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleGeneric
[task 2020-04-15T09:25:59.313Z] 09:25:59 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleHyperText
[task 2020-04-15T09:25:59.314Z] 09:25:59 INFO - TEST-UNEXPECTED-FAIL | leakcheck | default 296 bytes leaked (xpcAccessibleDocument, xpcAccessibleGeneric, xpcAccessibleHyperText)
[task 2020-04-15T09:25:59.314Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.315Z] 09:25:59 INFO - leakcheck | Processing leak log file /tmp/tmpwr6hPD.mozrunner/runtests_leaks_tab_pid1489.log
[task 2020-04-15T09:25:59.315Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.316Z] 09:25:59 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1489
[task 2020-04-15T09:25:59.316Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.317Z] 09:25:59 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-04-15T09:25:59.317Z] 09:25:59 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-04-15T09:25:59.318Z] 09:25:59 INFO - 0 |TOTAL | 38 0| 46882 0|
[task 2020-04-15T09:25:59.318Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.319Z] 09:25:59 INFO - nsTraceRefcnt::DumpStatistics: 884 entries
[task 2020-04-15T09:25:59.319Z] 09:25:59 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-04-15T09:25:59.320Z] 09:25:59 INFO - leakcheck | Processing leak log file /tmp/tmpwr6hPD.mozrunner/runtests_leaks_tab_pid1600.log
[task 2020-04-15T09:25:59.320Z] 09:25:59 INFO -
[task 2020-04-15T09:25:59.321Z] 09:25:59 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1600
Comment 1•5 years ago
|
||
Comment 2•5 years ago
|
||
The leaks occur for accessible/tests/browser/hittest/browser_test_zoom_text.js test: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=297702975&repo=autoland
Yura, can you please take a look? Thank you
Updated•5 years ago
|
Comment 3•5 years ago
|
||
ill try to resolve it next week.
Comment hidden (Intermittent Failures Robot) |
Comment 5•5 years ago
|
||
It might take me a little longer. this is only happening on linux. Is this an intermittent or a permafail?
Comment hidden (Intermittent Failures Robot) |
Comment 7•5 years ago
|
||
Hi Yura,
This is still intermittent, affecting linux1804-64 platform, debug build type. Already has 57 failures since 14th of April.
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment 9•5 years ago
|
||
The three classes being leaked are all related by inheritance, so I think this is really the leak of a single xpcAccessibleDocument.
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Comment 11•5 years ago
|
||
It is very peculiar to leak a single refcounted object and nothing else. It looks like we don't have leakchecking for hashtables, so it is possible that sRemoteXPCDocumentCache is also leaking, like maybe something gets put in that hashtable but never removed for some reason.
Comment hidden (Intermittent Failures Robot) |
Comment 13•5 years ago
|
||
Yura, Andrew, any updates here? This is now on disable recommended bug list with 157 total failures since it was filed on 15th Apr: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-04-04&endday=2020-05-04&tree=trunk&bug=1630208
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=300599619&repo=autoland&lineNumber=2278
It only fails on linux1804-64 debug with fission. Could the bump of leak threshold on fission be a temporary "fix" until an actual fix is in place?
Comment 14•5 years ago
|
||
I guess we can disable this for now, I just don't have the time to look at it this/next week.
Comment 15•5 years ago
|
||
I don't understand how this code works so I'm not sure how to fix this.
Leak thresholds apply to an entire test suite, and I really don't want to increase it just for one leak in one test directory.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 17•5 years ago
|
||
When does the leak check actually happen? Is it immediately after the test file runs?
I'm wondering whether the PDocAccessible IPC actor is still alive for a short while even after the "tab" has closed. In that case, we won't have received the IPC message to shut down the DocAccessibleParent (and thus remove the xpcAccessibleDocument). Do we necessarily wait for an OOP iframe document to be fully destroyed before we consider the tab closed? But if this were the problem, I'd expect a bunch of other stuff to be considered "leaked".
Assignee | ||
Updated•5 years ago
|
Comment 18•5 years ago
|
||
(In reply to James Teh [:Jamie] from comment #17)
When does the leak check actually happen? Is it immediately after the test file runs?
This check happens extremely late in XPCOM shutdown. IPDL is gone, threads are gone, the JS engine is gone, etc.
Comment hidden (Intermittent Failures Robot) |
Comment 20•5 years ago
|
||
This is still in the [stockwell disable-recommended] list for more than 10 days.
I have checked the logs for the recent 20 failures, and it is still failing for accessible/tests/browser/hittest/browser_test_zoom_text.js test.
I'll create a disable patch for linux1804-64.
Comment 21•5 years ago
|
||
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 24•5 years ago
|
||
Comment 25•5 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
![]() |
||
Comment 30•5 years ago
|
||
Yura, can you look into this? It has had 100 failures last week.
Comment hidden (Intermittent Failures Robot) |
Comment 32•5 years ago
|
||
There are 42 failures in the last 7 days on linux1804-64 debug.
Log link: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=305277036&repo=autoland&lineNumber=2376
TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | forkserver process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | gmplugin process: leak threshold set at 20000 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | gpu process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | rdd process: leak threshold set at 400 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | socket process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | tab process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-INFO | leakcheck | vr process: leak threshold set at 0 bytes
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1937.log
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1937
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - 0 |TOTAL | 35 0| 16352 0|
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 397 entries
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1533.log
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1533
[task 2020-06-05T22:58:58.594Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.596Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.596Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.597Z] 22:58:58 INFO - 0 |TOTAL | 36 0| 156160 0|
[task 2020-06-05T22:58:58.601Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.602Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 1019 entries
[task 2020-06-05T22:58:58.602Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.603Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1909.log
[task 2020-06-05T22:58:58.603Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1909
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - 0 |TOTAL | 35 0| 16432 0|
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 399 entries
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1653.log
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.605Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1653
[task 2020-06-05T22:58:58.606Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.606Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.607Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.607Z] 22:58:58 INFO - 0 |TOTAL | 36 0| 34435 0|
[task 2020-06-05T22:58:58.609Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.610Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 802 entries
[task 2020-06-05T22:58:58.610Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.611Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1422.log
[task 2020-06-05T22:58:58.611Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.612Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1422
[task 2020-06-05T22:58:58.612Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.613Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.613Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.614Z] 22:58:58 INFO - 0 |TOTAL | 37 0| 129829 0|
[task 2020-06-05T22:58:58.616Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.616Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 936 entries
[task 2020-06-05T22:58:58.617Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.617Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks_tab_pid1539.log
[task 2020-06-05T22:58:58.618Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.618Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 1539
[task 2020-06-05T22:58:58.619Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.619Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.620Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.620Z] 22:58:58 INFO - 0 |TOTAL | 38 0| 159392 0|
[task 2020-06-05T22:58:58.623Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.623Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 1018 entries
[task 2020-06-05T22:58:58.624Z] 22:58:58 INFO - TEST-PASS | leakcheck | tab no leaks detected!
[task 2020-06-05T22:58:58.624Z] 22:58:58 INFO - leakcheck | Processing leak log file /tmp/tmpQGZNez.mozrunner/runtests_leaks.log
[task 2020-06-05T22:58:58.625Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.625Z] 22:58:58 INFO - == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 1241
[task 2020-06-05T22:58:58.626Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.626Z] 22:58:58 INFO - |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
[task 2020-06-05T22:58:58.627Z] 22:58:58 INFO - | | Per-Inst Leaked| Total Rem|
[task 2020-06-05T22:58:58.627Z] 22:58:58 INFO - 0 |TOTAL | 36 296| 5719477 3|
[task 2020-06-05T22:58:58.631Z] 22:58:58 INFO - 2047 |xpcAccessibleDocument | 144 144| 51 1|
[task 2020-06-05T22:58:58.632Z] 22:58:58 INFO - 2048 |xpcAccessibleGeneric | 64 64| 391 1|
[task 2020-06-05T22:58:58.632Z] 22:58:58 INFO - 2049 |xpcAccessibleHyperText | 88 88| 155 1|
[task 2020-06-05T22:58:58.634Z] 22:58:58 INFO -
[task 2020-06-05T22:58:58.634Z] 22:58:58 INFO - nsTraceRefcnt::DumpStatistics: 2051 entries
[task 2020-06-05T22:58:58.635Z] 22:58:58 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleDocument
[task 2020-06-05T22:58:58.635Z] 22:58:58 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleGeneric
[task 2020-06-05T22:58:58.635Z] 22:58:58 INFO - TEST-INFO | leakcheck | default leaked 1 xpcAccessibleHyperText
Updated•5 years ago
|
Assignee | ||
Comment 33•5 years ago
|
||
If I understand correctly, this got disabled in the commit in comment 24. So why are we still seeing failures here?
Comment hidden (Intermittent Failures Robot) |
![]() |
||
Comment 35•5 years ago
|
||
One test got disabled but one or more others are leaking - leaks are detected on shutdown after the folder with tests got executed.
Comment 36•5 years ago
|
||
(In reply to James Teh [:Jamie] from comment #33)
If I understand correctly, this got disabled in the commit in comment 24. So why are we still seeing failures here?
What often happens is that the leaks are reported at the end of the run, and the sheriffs look at the logs and disable the last test, but the leak is actually in another test. Maybe running --verify on each individual test could help figure out which test is leaking. There's exactly one object being leaked, so it does feel like there must be just one test that is leaking.
Comment 37•5 years ago
|
||
I don't know how useful this is, but I've attached a file containing the allocation stack of the instance of xpcAccessibleDocument that leaked in a try run.
I got this by adding the option "--setenv=XPCOM_MEM_LOG_CLASSES=xpcAccessibleDocument" to the mochitest options in testing/mozharness/configs/unittests/linux_unittest.py and pushing to try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=b437e6afa3ec7211cce9b3e5b6699a384091e2b8
Comment 38•5 years ago
|
||
A second failure is also inside mozilla::a11y::DocAccessibleParent::RecvScrollingEvent().
Comment 39•5 years ago
|
||
Two more failures with the same stack in a separate try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=87ac315497484da5beeb5b7d6fe036548b3287b2
In that try run, I added some asserts around the tables being recreated after they were shut down, but those did not hit.
I looked at the code that runs in RecvScrollingEvent, and I couldn't find anything wrong. xpcAccessibleDocument::Release is a little concerning. It treats one strong reference like a weak reference, and one weak reference like a strong reference. Also, as far as I can tell, we just always leak sRemoteXPCDocumentCache.
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 41•5 years ago
•
|
||
Aha! Finally worked out what's going on here.
(Try run: https://treeherder.mozilla.org/#/jobs?repo=try&selectedTaskRun=ZGjE9oWKShG8Wd5b5FaPaA.0&revision=654685996f7c4c63a843f592288ff063a3caf026 )
A scrolling event is received after the DocAccessibleParent is shut down, which can happen if the BrowserParent is in the process of being destroyed (probably the tab closed) but there are still events in the IPC queue. Most Recv*Event methods in BrowserParent check mShutdown, but a few don't, including RecvScrollingEvent. This event is for the document, so we successfully get and cache an xpcAccessibleDocument for it. However, that xpcAccessibleDocument will never be removed from the cache because it's already shut down, so NotifyOfRemoteDocShutdown (which would normally remove it from the XPC cache) won't get called.
Assignee | ||
Comment 42•5 years ago
|
||
We really want to know about this because the document will never be removed from the cache, since NotifyOfRemoteDocShutdown (which would normally remove it from the XPC cache) won't get called.
Assignee | ||
Comment 43•5 years ago
|
||
We can receive IPC events after a DocAccessibleParent is shut down if the BrowserParent is in the process of being destroyed (probably the tab closed) but there are still events in the IPC queue.
Most RecvEvent methods in BrowserParent check mShutdown, but a few don't.
For the events that don't, if the event is for a document, we'll successfully fire the platform event, and then successfully get and cache an xpcAccessibleDocument.
However, that xpcAccessibleDocument will never be removed from the cache because it's already shut down, so NotifyOfRemoteDocShutdown (which would normally remove it from the XPC cache) won't get called.
This results in a leaked object.
Thus, it's important that all RecvEvent methods drop the event if mShutdown is true.
This patch adds that check to the methods which didn't have it already.
Assignee | ||
Comment 44•5 years ago
|
||
The cache should already be empty by this point unless there's a bug, but we should still clean up regardless.
Also, the hashtable itself was previously never cleaned up even if it was empty.
Assignee | ||
Comment 45•5 years ago
|
||
The intermittent leak has been fixed, so we can now re-enable this.
Comment 46•5 years ago
|
||
Comment 47•5 years ago
|
||
bugherder |
Comment hidden (typo) |
Assignee | ||
Updated•5 years ago
|
Assignee | ||
Updated•5 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•5 years ago
|
Description
•