Closed Bug 1011401 Opened 12 years ago Closed 11 years ago

Memory increase in endurance testrun on Mac OS X since May 13

Categories

(Mozilla QA Graveyard :: Mozmill Tests, defect)

x86_64
macOS
defect
Not set
normal

Tracking

(Not tracked)

RESOLVED WORKSFORME

People

(Reporter: mihaelav, Assigned: mihaelav)

Details

Mac OS X results show higher memory consumption on Nightly branch since May the 13th: ~7MB explicit memory and ~10 resident memory. The regression appeared between builds 20140512030202 (https://hg.mozilla.org/mozilla-central/rev/20ca234fd62b) and 20140513030201 (https://hg.mozilla.org/mozilla-central/rev/4b6d63b05a0a). Reports: * http://mozmill-daily.blargon7.com/#/endurance/reports?app=All&branch=32.0&platform=Mac&from=2014-05-12&to=2014-05-13 Charts: * http://mozmill-daily.blargon7.com/#/endurance/charts?app=All&branch=32.0&platform=Mac&from=2014-05-10&to=2014-05-15 Pushlog: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=20ca234fd62b&tochange=4b6d63b05a0a Note: I reproduced the regression locally (on Mac OS X 10.9.2) and currently I'm working on narrowing the regression range on inbound builds.
I finished bisecting on inbound and found that the memory regression was caused by https://hg.mozilla.org/integration/mozilla-inbound/rev/443b60f30115: 443b60f30115 Neil Rashbrook — Bug 1003894 Followup to switch from Text to nsIContent so that we can safely use do_QueryInterface r=ehsan Results: * https://hg.mozilla.org/integration/mozilla-inbound/rev/443b60f30115 - first bad: Explicit memory (MB): Minimum: 93 / Maximum: 253 / Average: 134 Resident memory (MB): Minimum: 220 / Maximum: 404 / Average: 288 (Report: http://mozmill-crowd.blargon7.com/#/endurance/report/7a69d3e8424ecf8642bb6566e481e35e) * https://hg.mozilla.org/integration/mozilla-inbound/rev/120d830b89e2 - last good Explicit memory (MB): Minimum: 91 / Maximum: 193 / Average: 126 Resident memory (MB): Minimum: 220 / Maximum: 349 / Average: 278 (Report: http://mozmill-crowd.blargon7.com/#/endurance/report/7a69d3e8424ecf8642bb6566e477e7b4)
Flags: needinfo?(neil)
Three variables were changed from concrete classes to interfaces because they were used with do_QueryInterface (at the time, do_QueryInterface did not actually check for an interface), and this propagated to affect the types of eight other variables. However this should not have changed any functionality...
Flags: needinfo?(neil)
FWIW, I plan to revert the changes in a few months (bug 1010761), but it seems extremely unlikely that this commit is responsible. Are you absolutely sure this is the one at fault?
Flags: needinfo?(mihaela.velimiroviciu)
I'm investigating this again as it appears that some new builds from that period appeared in the builds location.
Flags: needinfo?(mihaela.velimiroviciu)
I ran the endurance tests again and the first (if the alphabetical order of containing folders on inbound is the same as the historical one) relevant (does not contain only tests) revision is https://hg.mozilla.org/integration/mozilla-inbound/rev/ec7113f437f3. What I find strange Note: the explicit memory dropped back since may the 24th, but the resident memory remains increased.
Flags: needinfo?(nfroyd)
(In reply to Mihaela Velimiroviciu [QA] (:mihaelav) from comment #5) > I ran the endurance tests again and the first (if the alphabetical order of > containing folders on inbound is the same as the historical one) relevant > (does not contain only tests) revision is > https://hg.mozilla.org/integration/mozilla-inbound/rev/ec7113f437f3. > What I find strange That seems just as incorrect as the revision identified in comment 1. If the regression range is actually 120d830b89e2 to 443b60f30115, there's a bit of stuff that landed in the middle: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=120d830b89e2&tochange=443b60f30115 In particular, https://hg.mozilla.org/integration/mozilla-inbound/rev/d8eb7fe67883 seems very relevant here, since it lies in the regression range you identified in comment 1, and it's Mac-only.
Flags: needinfo?(nfroyd)
(In reply to Nathan Froyd (:froydnj) from comment #6) > https://hg.mozilla.org/integration/mozilla-inbound/ > pushloghtml?fromchange=120d830b89e2&tochange=443b60f30115 > > In particular, > https://hg.mozilla.org/integration/mozilla-inbound/rev/d8eb7fe67883 seems > very relevant here, since it lies in the regression range you identified in > comment 1, and it's Mac-only. Asking Steven for more info.
Flags: needinfo?(smichaud)
I strongly suspect that, as with bug 1008978, this change isn't truly a regression. Instead the current behavior on this test is probably correct, and the previous behavior was an artifact of nsIRunnable event starvation that my patch for bug 996848 fixed. The only way we can know for sure, though, is for someone to tell me (in detail) how to run this test locally, so I can run it inside the Gecko profiler -- and perform the same tests as I performed at bug 1008978.
Flags: needinfo?(smichaud)
Sure Steven, I can do. Here the steps: 1. Get the latest mozmill-env for mac from https://mozqa.com/mozmill-env/ 2. Unzip it und source into the venv by running 'source mozmill-env/run' 3. Clone the mozmill-tests repository: https://hg.mozilla.org/qa/mozmill-tests 4. You might want to disable other tests by modifying the manifest file under firefox/tests/endurance/manifest.ini (don't forget to commit this change) 5. Execute 'testrun_endurance /Applications/Firefox.app --repository %path_to_mozmill_tests% --report file://report.json After step 5 you will also find a json report file in the same folder, which contains the collected data.
Thanks, Henrik! But I'm really busy right now, so if you don't mind I'll put this off til next week. I assume this bug isn't particularly urgent.
I'm going to wait to test this until my patch for bug 1013852 appears in a mozilla-central nightly. But in the meantime I have a question about one of your steps from comment #9, Henrik: In step #4 you say "you might want to disable other tests", but I don't know what tests you mean. Please let me know which tests in firefox/tests/endurance/manifest.ini I might want to disable, and how I should do it (comment them out with a '#' character, or something else?).
(In reply to Steven Michaud from comment #11) > In step #4 you say "you might want to disable other tests", but I don't know > what tests you mean. Please let me know which tests in > firefox/tests/endurance/manifest.ini I might want to disable, and how I > should do it (comment them out with a '#' character, or something else?). That's one possibility, yes. Otherwise simply remove the lines from the manifest. Mihaela, which test in detail has to be run to see this memory increase?
Flags: needinfo?(mihaela.velimiroviciu)
I ran the entire testrun, but the tests that show the greatest increase are (increased explicit/resident memory in MB): testOpenNewTab - 7/16 testOpenNewTab - 8/12 testPinAndUnpinAppTab - 13/19 testOpenAndCloseMultipleWindows - 9/14 Other tests that had increased memory usage are (increased explicit/resident memory in MB): testFlashIframe - 7/9 testFlashObject - 7/5 testFlashURL - 6/9 testFlashViaEmbedTag - 7/8 testVideo_OGVBuffering - 7/6 testOpenAndCloseAllBookmarks - 5/4
Flags: needinfo?(mihaela.velimiroviciu)
Unfortunately I wasn't able to do what I originally planned, which may turn out to be impossible. The default browser profile doesn't include the Gecko profiler, and I don't know how to add it (or whether this is possible). And even once it's present, I'd need a way to pause every test just at the end so that I can press the profiler's Analyze button. So I was reduced to testing the m-c tree just before and just after my patches for bug 996848 landed. Here I found that only the first test (whatever that was) showed significantly increased memory usage (greater than 10%), and then only for "explicit : max". So this increase is at least partly due to the mozmill test harness itself (to how it runs the first test in a series). This may also have something to do with my patches for bug 996848 -- due to their fixes for nsIRunnable event starvation, they may have allowed whatever mozmill does during the first test to reach a higher level of maximum memory usage. But the end result is that those patches have uncovered a bug in mozmill -- if it *is* a bug.
(In reply to Steven Michaud from comment #14) > The default browser profile doesn't include the Gecko profiler, and I don't > know how to add it (or whether this is possible). And even once it's > present, I'd need a way to pause every test just at the end so that I can > press the profiler's Analyze button. You can use the --addon option for the testrun command and specify the path to the profiler XPI file. Then it will be installed into that profile. To pause the test at the end, you would have to add a 'controller.sleep(%ms%)' where you want to have it. Given that by default the testrun clones the mozmill-tests repository by default, you have to create a local clone yourself. Then add the sleep and do a commit. By running the testrun script use the --repository option with the path to your local mozmill-tests clone. It will clone it from there. > So I was reduced to testing the m-c tree just before and just after my > patches for bug 996848 landed. Here I found that only the first test > (whatever that was) showed significantly increased memory usage (greater > than 10%), and then only for "explicit : max". So this increase is at least > partly due to the mozmill test harness itself (to how it runs the first test > in a series). We don't do anything special. We start httpd.js, attach listeners to the DOM windows, and retrieve add-on related information to send it to the Python side. Maybe the latter could have an influence? https://github.com/mozilla/mozmill/blob/master/mozmill/mozmill/extension/resource/driver/mozmill.js#L73 > This may also have something to do with my patches for bug 996848 -- due to > their fixes for nsIRunnable event starvation, they may have allowed whatever > mozmill does during the first test to reach a higher level of maximum memory > usage. But the end result is that those patches have uncovered a bug in > mozmill -- if it *is* a bug. Whatever it is I would be interested to find that out. Steven, it would be great if you could run the endurance tests directly with mozmill, without the testruns. You can do that with 'mozmill -b %path/to/firefox% -m %path/to/manifest%. That will make lots of things easier to run. Can you tell me how you measured? Maybe I can have a look myself, given that I can better tweak the behavior of Mozmill.
> Can you tell me how you measured? I just followed your instructions from comment #9. I ran all the mozill endurance tests on an m-c custom build made from code just before my patch, and then on another m-c custom build made from code as of my patch. Then I swapped the order of the first two tests and did the same again. Try that yourself, and you'll see.
My custom builds were 64-bit only, and made to be as close as possible to m-c nightlies (aside from not being universal builds).
Mihaela, can you please follow-up here? I was assuming you will do it. Thanks.
(In reply to Henrik Skupin (:whimboo) from comment #18) > Mihaela, can you please follow-up here? I was assuming you will do it. > Thanks. From your comment 15, I also understood that you will look into it :) Anyway, I looked into it these days: built the changesets from https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=120d830b89e2&tochange=443b60f30115 (except ac7542838773, for which I got errors at building) and ran mozmill tests on those builds. Indeed, it seems that Steven's changes from d8eb7fe67883 didn't cause the regression (I got the same memory usage as with the previous changeset). I couldn't build the following changeset(ac7542838773) - that's only tests updates so it wouldn't matter anyway, but the next one after that (ec7113f437f3) shows some more MB of used memory, so that's may be the actual cause.
Flags: needinfo?(nfroyd)
Flags: needinfo?(bjacob)
(In reply to Mihaela Velimiroviciu [QA] (:mihaelav) from comment #19) > Anyway, I looked into it these days: built the changesets from > https://hg.mozilla.org/integration/mozilla-inbound/ > pushloghtml?fromchange=120d830b89e2&tochange=443b60f30115 (except > ac7542838773, for which I got errors at building) and ran mozmill tests on > those builds. Indeed, it seems that Steven's changes from d8eb7fe67883 > didn't cause the regression (I got the same memory usage as with the > previous changeset). I couldn't build the following changeset(ac7542838773) > - that's only tests updates so it wouldn't matter anyway, but the next one > after that (ec7113f437f3) shows some more MB of used memory, so that's may > be the actual cause. If ec7113f437f3 shows more used memory, then there ought to be some point later on, when bug 984783 re-landed, that shows a corresponding drop in used memory.
Flags: needinfo?(nfroyd)
When did bug 984783 re-land? I don't see any activity there after May the 12th. If it's on bug 1008717, there is a possible related resident memory drop in our tests since May the 29th (after patch from 1008717 landed), but nothing notable on the explicit side. May it be that that patch only affects the resident memory?
It re-landed on May 10, see bug 984783 comment 36, https://hg.mozilla.org/integration/mozilla-inbound/rev/24ff9dbc3f20 and as you saw, was followed by bug 1008717. My limited understanding would be that 'explicit' means 'regular memory allocations going through the memory allocator' as opposed to 'other things like direct mmap calls'. Is that correct? If that is correct, then these patches can only significantly affect explicit allocations. The only non-explicit allocation that could be affected is, I guess, growing the stack (???) but my patches shouldn't have a significant impact on stack usage.
Flags: needinfo?(bjacob)
(In reply to Benoit Jacob [:bjacob] from comment #22) > My limited understanding would be that 'explicit' means 'regular memory > allocations going through the memory allocator' as opposed to 'other things > like direct mmap calls'. Is that correct? If that is correct, then these > patches can only significantly affect explicit allocations. The only > non-explicit allocation that could be affected is, I guess, growing the > stack (???) but my patches shouldn't have a significant impact on stack > usage. It's better asking Nicholas here...
Flags: needinfo?(n.nethercote)
Load about:memory, hit "measure", and then hover the cursor over the "explicit" line near the top. The tool-tip explains what it measures.
Flags: needinfo?(n.nethercote)
The memory came back (and even lower) since May 24 2014. Closing this bug since there isn't anything else left to do.
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → WORKSFORME
Product: Mozilla QA → Mozilla QA Graveyard
You need to log in before you can comment on or make changes to this bug.