1597227 - Investigate options for not forcing a GC in nsHttpServer._connectionClosed

Status: RESOLVED FIXED

(Core :: Networking, task, P1)

Description

[Henrik Skupin [:whimboo][⌚️UTC+1]]

On bug 1596390 I see a very slow performance for browser chrome tests in remote/tests/browser, which are all related to connecting and disconnecting to the Remote Agent. I recorded a profile via the Gecko Profiler (https://perfht.ml/2QfXvLE) and it turned out that a forced GC in nsHttpServer._connectionClosed() is causing that. It landed about 9 years ago via bug 508128.

As given by Andrew and Jonco options exist given the the code has been substantially changed in all the last 9 years. First thing I should try is to remove that line given that the garbage collector works way better those days. If that's still causing problems, we should move to trigger an incremental GC which runs shorter.

On the other hand an option for a forced GC in nsHttpServer could also be an option.

I will first try to remove this line and compare some perfherder statistics if there is higher memory usage recorded, and also test locally for xpcshell and mochitests for sure.

Comment 1

[Henrik Skupin [:whimboo][⌚️UTC+1]]

As noted in the comment the call to forceGC() cannot be part of xpcshell, because specific GC tests would be affected here.

I wonder when removing the method here would it have any side-effects for those tests? Or do we actually still have those xpcshell tests?

Also the referenced test content/media/test/test_seek.html doesn't exist anymore in the tree. The latest revision I was able to find is [1], which is from June 2014. Then the whole folder was moved to /dom/media [2], but the file was no longer present?

I could try to run some random xpcshell test under /dom/media/test and check if it is causing a memory increase.

[1] https://hg.mozilla.org/mozilla-central/file/5519fd827576219b11440b05a946255a70a65936/content/media/test/test_seek.html
[2] https://hg.mozilla.org/mozilla-central/rev/277005c35f05

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Here a try build:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=04fae348cd1e2ac74edd6d0fa2852dd3238b4a35

Comment 3

[Jon Coppeard (:jonco)]

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #1)
Hopefully nothing depends on the specific timing of GCs, although it is possible. Let's see why try shows us.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Jonco, the tryserver build from comment 2 with the forced GC removed has a couple of failing tests, but not sure if those are related to this change. The tests under toolkit/mozapps/extensions/test/xpcshell/ work just fine for me locally on MacOS. I'm not around tomorrow, so maybe you could also have a quick look?

Comment 5

[Jon Coppeard (:jonco)]

(In reply to Henrik Skupin (:whimboo) [⌚️UTC+2] from comment #4)
So I don't know much about this area of the browser or these tests in particular.

I looked at the try build and it seems there two tests that fail on Windows but pass elsewhere:

• toolkit/mozapps/extensions/test/xpcshell/test_install.js
• toolkit/mozapps/extensions/test/xpcshell/test_system_update_checkSizeHash.js

The first one seems to be failing because it found an unexpected file:

[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  Error: Found unexpected files in temporary directory: generated-extension.xpi at resource://testing-common/AddonTestUtils.jsm:469
[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  init/<@resource://testing-common/AddonTestUtils.jsm:469:15
[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  _execute_test/<@Z:\task_1574083708\build\tests\xpcshell\head.js:636:28
[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  async*_execute_test@Z:\task_1574083708\build\tests\xpcshell\head.js:645:5
[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  @-e:1:1

From elsewhere in the log it has tried to delete this file but failed because the file was locked:

[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "[Exception... "Component returned failure code: 0x8052000e (NS_ERROR_FILE_IS_LOCKED) [nsIFile.remove]"  nsresult: "0x8052000e (NS_ERROR_FILE_IS_LOCKED)"  location: "JS frame :: resource://testing-common/AddonTestUtils.jsm :: cleanupTempXPIs :: line 644"  data: no]"]
[task 2019-11-18T15:10:44.483Z] 15:10:44     INFO -  cleanupTempXPIs@resource://testing-common/AddonTestUtils.jsm:644:16
[task 2019-11-18T15:10:44.484Z] 15:10:44     INFO -  init/<@resource://testing-common/AddonTestUtils.jsm:446:12
[task 2019-11-18T15:10:44.484Z] 15:10:44     INFO -  _execute_test/<@Z:\\task_1574083708\\build\\tests\\xpcshell\\head.js:636:28
[task 2019-11-18T15:10:44.484Z] 15:10:44     INFO -  async*_execute_test@Z:\\task_1574083708\\build\\tests\\xpcshell\\head.js:645:5
[task 2019-11-18T15:10:44.484Z] 15:10:44     INFO -  @-e:1:1

Maybe there is a race condition that is exposed when we remove the time spent doing a GC.

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+1]]

(In reply to Jon Coppeard (:jonco) from comment #5)

I looked at the try build and it seems there two tests that fail on Windows but pass elsewhere:

• toolkit/mozapps/extensions/test/xpcshell/test_install.js
• toolkit/mozapps/extensions/test/xpcshell/test_system_update_checkSizeHash.js

Maybe there is a race condition that is exposed when we remove the time spent doing a GC.

Oh, that could actually be it! Andrew, given that this is your area, could you please have a look at those tests? Thanks

Comment 7

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Noticed that Andrew isn't with us anymore. Jim could you help figuring out why those webextension tests are broken when we stop forcing a GC when stopping httpd.js? Thanks

Comment 8

[Jim Mathies [:jimm]]

Hey Rob, can you offer any insight here? Relevant bits are in comment 5. Something to do with a generated-extension file that can't be delete during xpcshell test runs.

Comment 9

[Rob Wu [:robwu]]

The two referenced tests both use httpd.js (HttpServer) and serve a generated XPI file (AddonTestUtils.createTempWebExtensionFile) from the server. This generated file is removed from a cleanup handler at the end of the test.

We have repeatedly seen failures to remove XPI files in tests on Windows when the file is still somehow open/in use.
In these two tests, I cannot tell with certainty that httpd.js doesn't still keep the file open at the end of the test.

If you want to remove this forceGC without breaking those tests, then you could consider adding a forceGC call to these two tests. If that doesn't help, close the server before calling forceGC.

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+1]]

I had to push a new try build given that for the former one no log files are available anymore:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=7be6913cdb5e6c46e13cf5748b8212add93ace4b

Comment 11

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Attachment: Bug 1597227 - Keep forcing a GC in extension xpcshell tests to prevent deleting a locked XPI file.

Comment 12

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Attachment: Bug 1597227 - Remove forced GC when closing a httpd.js connection.

Depends on D58549

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/95ebf23f4717
Keep forcing a GC in extension xpcshell tests to prevent deleting a locked XPI file. r=robwu
https://hg.mozilla.org/integration/autoland/rev/01d21786d635
Remove forced GC when closing a httpd.js connection. r=froydnj

Comment 14

[Cristina Coroiu [:ccoroiu]]

https://hg.mozilla.org/mozilla-central/rev/95ebf23f4717
https://hg.mozilla.org/mozilla-central/rev/01d21786d635