We have detected an awsy regression from push: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?changeset=43a95f0f47256ac54ce6bb2044216de7a9406574 As author of one of the patches included in that push, we need your help to address this regression. Regressions: 9% Heap Unclassified windows10-64 opt stylo 36,892,554.12 -> 40,140,708.21 9% Heap Unclassified windows10-64 pgo stylo 36,865,815.53 -> 40,004,513.82 7% Heap Unclassified windows7-32 pgo stylo 28,986,104.53 -> 31,015,126.35 7% Heap Unclassified windows7-32 opt stylo 29,098,938.99 -> 31,051,457.64 3% Heap Unclassified osx-10-10 opt stylo 66,237,545.71 -> 68,440,557.46 3% Heap Unclassified linux64-stylo-sequential opt stylo-sequential 60,132,963.51 -> 62,078,396.85 3% Heap Unclassified linux64 opt stylo 60,987,423.01 -> 62,650,406.41 You can find links to graphs and comparison views for each of the above tests at: https://treeherder.mozilla.org/perf.html#/alerts?id=15801 On the page above you can see an alert for each affected platform as well as a link to a graph showing the history of scores for this test. There is also a link to a treeherder page showing the jobs in a pushlog format. To learn more about the regressing test(s), please see: https://wiki.mozilla.org/AWSY/Tests

:jonco, I see you authored the patches in bug 1490055, can you take a look at these regressions and determine if we can do anything to fix this?

Bug 1490055 made us use the JSContext's LifoAlloc for helper threads rather than a temporary LifoAlloc that was created and destroyed per parse task. There's two issues here: firstly, the size of these may build up over time since they are never freed, and secondly JSContext memory is not reported.

Patch to free helper thread LifoAlloc memory when the main thread runtime does a GC.

I'm not sure about this patch. This moves the JSContext to be part of the HelperThread class so we can report memory use for for it, but only for idle helper threads. It's not safe to do this for active threads. What do you think, is this better it to report memory where we can or to be consistent and never report this memory for helper threads?

Comment on attachment 9009159 [details] [diff] [review] bug1490055-free-helper-lifo Review of attachment 9009159 [details] [diff] [review]: ----------------------------------------------------------------- ::: js/src/vm/HelperThreads.cpp @@ +2577,5 @@ > // block occurs. > mozilla::recordreplay::NotifyUnrecordedWait(WakeupAll); > } > > + maybeFreeUnusedMemory(&cx); nit: As there is no guarantee on how the LifoAlloc are going to be used. Iterating over multiple task might leave unused memory in allocated chunks. "freeAll()" will deallocate everything, still think we should ensure that at the end of any task, all the LifoAlloc space is reclaimed by calling "cx->tempLifoAlloc().releaseAll();"

Comment on attachment 9009163 [details] [diff] [review] bug1491037-report-helper-context Review of attachment 9009163 [details] [diff] [review]: ----------------------------------------------------------------- This patch looks good to me.

:jonco, is there more work to do in order to land this patch?

Pushed by jcoppeard@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/9a1cfe1a7bee Periodically free helper thread LifoAlloc memory r=nbp https://hg.mozilla.org/integration/mozilla-inbound/rev/a1502c0643fc Report JSContext memory for idle helper threads r=nbp

Backed out for failing sy at awsy\test_memory_usage.py Push that started the failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&group_state=expanded&searchStr=windows,sy-e10s(sy)&selectedJob=200048548&revision=a1502c0643fc8b88c5ae61977333c3deef46b2e2 Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=200048484&repo=mozilla-inbound&lineNumber=2277 Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/8e628cef959cdc5a28a7cb4a5f686ad5fc2da53c

Note that bug 1491395 was inadvertently backed out for these failures, so I did a try push with some logging around those test failures. Posting them here [1] in case they're useful. [1] https://treeherder.mozilla.org/#/jobs?repo=try&revision=9e822258aa61d864da8886e1731b9cb78a5d3dd3

There is also the clipboard failure: https://treeherder.mozilla.org/logviewer.html#?job_id=200057123&repo=mozilla-inbound&lineNumber=2333 00:21:12 INFO - TEST-OK | toolkit/components/aboutmemory/tests/test_aboutmemory5.xul | took 2319ms 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 866 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 866 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 866 00:21:12 INFO - GECKO(8156) | [Parent 8156, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 00:21:12 INFO - GECKO(8156) | [Parent 8156, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x80004005: file z:/build/build/src/docshell/shistory/nsSHistory.cpp, line 1291 00:21:12 INFO - GECKO(8156) | [Parent 8156, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, false) failed with result 0x80004005: file z:/build/build/src/docshell/shistory/nsSHistory.cpp, line 1291 00:21:12 INFO - GECKO(8156) | ++DOMWINDOW == 63 (0000025DAC676C00) [pid = 8156] [serial = 63] [outer = 0000025DBB41D800] 00:21:12 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/aboutmemory/tests/test_aboutmemory5.xul | assertion count 6 is more than expected 0 assertions 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!gThread', file z:/build/build/src/xpcom/threads/nsTimerImpl.cpp, line 399 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!gThread', file z:/build/build/src/xpcom/threads/nsTimerImpl.cpp, line 399 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!gThread', file z:/build/build/src/xpcom/threads/nsTimerImpl.cpp, line 399 00:21:12 INFO - TEST-START | Shutdown 00:21:12 INFO - Passed: 24 00:21:12 INFO - Failed: 0 00:21:12 INFO - Todo: 0 00:21:12 INFO - Mode: non-e10s 00:21:12 INFO - Slowest: 2318ms - chrome://mochitests/content/chrome/toolkit/components/aboutmemory/tests/test_aboutmemory5.xul 00:21:12 INFO - SimpleTest FINISHED 00:21:12 INFO - TEST-INFO | Ran 1 Loops 00:21:12 INFO - SimpleTest FINISHED 00:21:12 INFO - GECKO(8156) | --DOCSHELL 0000027604D46800 == 0 [pid = 4564] [id = {6bfd6f9f-add9-45a4-9edc-b84f238376f7}] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 2 (0000027604D13800) [pid = 4564] [serial = 1] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 4564, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 1 (000002760C87EC00) [pid = 4564] [serial = 3] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 0 (000002760A497C00) [pid = 4564] [serial = 2] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 2 (00000230AD677400) [pid = 2992] [serial = 3] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | --DOCSHELL 00000230A5E46800 == 0 [pid = 2992] [id = {16207fb0-b0b2-4179-b4ea-a826528d356c}] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 1 (00000230A5E13A00) [pid = 2992] [serial = 1] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 2992, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 0 (00000230AB498C00) [pid = 2992] [serial = 2] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | --DOCSHELL 0000028926D47800 == 0 [pid = 6552] [id = {ae4b085d-dec9-4f99-acfc-a76ab1496bad}] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 2 (0000028926D14A00) [pid = 6552] [serial = 1] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | [Child 6552, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 564 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 1 (000002892E67FC00) [pid = 6552] [serial = 3] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | --DOMWINDOW == 0 (000002892C49CC00) [pid = 6552] [serial = 2] [outer = 0000000000000000] [url = about:blank] 00:21:12 INFO - GECKO(8156) | nsStringStats 00:21:12 INFO - GECKO(8156) | => mAllocCount: 6968 00:21:12 INFO - GECKO(8156) | => mReallocCount: 0 00:21:12 INFO - GECKO(8156) | => mFreeCount: 6968 00:21:12 INFO - GECKO(8156) | => mShareCount: 4717 00:21:12 INFO - GECKO(8156) | => mAdoptCount: 497 00:21:12 INFO - GECKO(8156) | => mAdoptFreeCount: 497 00:21:12 INFO - GECKO(8156) | => Process ID: 2992, Thread ID: 1160 00:21:12 INFO - GECKO(8156) | nsStringStats 00:21:12 INFO - GECKO(8156) | => mAllocCount: 7044 00:21:12 INFO - GECKO(8156) | => mReallocCount: 0 00:21:12 INFO - GECKO(8156) | => mFreeCount: 7044 00:21:12 INFO - GECKO(8156) | => mShareCount: 4751 00:21:12 INFO - GECKO(8156) | => mAdoptCount: 497 00:21:12 INFO - GECKO(8156) | => mAdoptFreeCount: 497 00:21:12 INFO - GECKO(8156) | => Process ID: 4564, Thread ID: 3172 00:21:12 INFO - GECKO(8156) | nsStringStats 00:21:12 INFO - GECKO(8156) | => mAllocCount: 7006 00:21:12 INFO - GECKO(8156) | => mReallocCount: 0 00:21:12 INFO - GECKO(8156) | => mFreeCount: 7006 00:21:12 INFO - GECKO(8156) | => mShareCount: 4734 00:21:12 INFO - GECKO(8156) | => mAdoptCount: 497 00:21:12 INFO - GECKO(8156) | => mAdoptFreeCount: 497 00:21:12 INFO - GECKO(8156) | => Process ID: 6552, Thread ID: 3644 00:21:12 INFO - GECKO(8156) | ++DOMWINDOW == 64 (0000025DB2FEF000) [pid = 8156] [serial = 64] [outer = 0000025DBB41D800] 00:21:12 INFO - GECKO(8156) | JavaScript error: resource://activity-stream/lib/TopSitesFeed.jsm, line 86: TypeError: setting getter-only property "_currentSearchHostname"

It's failing a sanity assertion that heap-unclassified is > 0 [1]. This implies that the 'explicit/' heap allocated values total more than what was actually heap-allocated. [1] https://searchfox.org/mozilla-central/rev/a0333927deabfe980094a14d0549b589f34cbe49/testing/awsy/awsy/parse_about_memory.py#65-67

it looks like bug 1491395 was relanded- when this was landed we had AWSY improvements, and when this was backed out we had regressions- there is still work to do on this bug.

:jonco, is this something you are still working on?

(In reply to Eric Rahm [:erahm] from comment #12) Thanks for the explanation. I still don't understand why this is happening though. I'm going to reland the first patch only and hope that that is enough to fix the regression.

Pushed by jcoppeard@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/7a9384b6a6c9 Periodically free helper thread LifoAlloc memory r=nbp

Setting leave-open until we know whether this worked.

It looks like the regressions got fixed on all OS platforms. I think we can close this bug as FIXED. Thank you!

This is the new baseline: == Change summary for alert #16079 (as of Fri, 21 Sep 2018 06:26:25 GMT) == Improvements: 9% Heap Unclassified windows7-32 pgo stylo 31,301,884.90 -> 28,571,600.80 9% Heap Unclassified windows10-64 opt stylo 40,516,117.84 -> 37,044,964.57 8% Heap Unclassified windows10-64 pgo stylo 40,499,502.85 -> 37,236,824.55 8% Heap Unclassified windows7-32 opt stylo 31,337,345.55 -> 28,950,840.16 4% Resident Memory linux64-qr opt stylo 1,066,178,465.47 -> 1,020,714,382.72 3% Heap Unclassified linux64-stylo-sequential opt stylo-sequential 61,935,330.26 -> 59,836,683.77 3% Heap Unclassified linux64 opt stylo 62,484,800.96 -> 60,637,899.23 3% Heap Unclassified osx-10-10 opt stylo 68,532,303.37 -> 66,666,514.50 For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=16079