If you think a bug might affect users in the 57 release, please set the correct tracking and status flags for Release Management.

High results on mozmill endurance test on Mac 10.7.4_x64 since Jul 5

RESOLVED INVALID

Status

Mozilla QA
Mozmill Tests
RESOLVED INVALID
5 years ago
5 years ago

People

(Reporter: mihaelav, Unassigned)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [mozmill-endurance][MemShrink:P2])

(Reporter)

Description

5 years ago
Increased memory consumption (with ~50MB) on Mac OS X 10.7.4 since July 5:
* Explicit memory: from 150-160MB to ~210MB
* Resident memory: from ~250MB to ~300MB

Chart: http://mozmill-ci.blargon7.com/#/endurance/charts?branch=16.0&platform=Mac&from=2012-06-30&to=2012-07-13

Reports: 
July 3: http://mozmill-ci.blargon7.com/#/endurance/report/4c461f9adf1253771fc6455667083579
July 5: http://mozmill-ci.blargon7.com/#/endurance/report/4c461f9adf1253771fc645566715d167

Pushlog: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=1d370ca5bb8d&tochange=675f55c4310c
Thanks for raising this Mihaela. Could you investigate and see if you can reduce the regression window? You can use the nightly builds, and tinderbox builds, which are available here: https://ftp.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds
Whiteboard: [mozmill-endurance][MemShrink]
(Reporter)

Comment 2

5 years ago
I reproduced the issue locally. It seems that there is a regression between July 3 and July 4 builds: 
Maximum Explicit memory (MB): 177 -> 194
Maximum Resident memory (MB): 223 -> 242

Reports:
* July 3 build: http://mozmill-crowd.blargon7.com/#/endurance/report/89726f6b98208a209e7ce2df100e194d
* July 4 build: http://mozmill-crowd.blargon7.com/#/endurance/report/89726f6b98208a209e7ce2df100e6c69

Pushlog: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=1d370ca5bb8d&tochange=87db9617a885

Currently I'm working on reducing more the regression window.
Thanks Mihaela. Let me know if you need any assistance.
Whiteboard: [mozmill-endurance][MemShrink] → [mozmill-endurance][MemShrink:P2]
Summary: High results on Mac 10.7.4_x64 since Jul 5 → High results on mozmill endurance test on Mac 10.7.4_x64 since Jul 5
There's a pretty big change in our memory telemetry around this date [1], which is worrying.  Please keep us up-to-date with your bisection!

I'm leaving this untriaged for MemShrink so we look at it at our next meeting.

[1] http://bit.ly/memorytelemetry
Dave, would you mind to run tests for builds around this date in our CI again? I would be interested in how the numbers for builds before July 5th look like.
I have run the builds from July 3rd and July 4th on Mozmill CI and found much the same as Mihaela reported in comment 2:

Build ID: 20120703110846
Average Explicit: 90MB
Average Resident: 165MB
Report: http://mozmill-crowd.blargon7.com/#/endurance/report/27072cb61461b83e1447b1979b148262

Build ID: 20120704030538
Average Explicit: 97MB
Average Resident: 182MB
Report: http://mozmill-crowd.blargon7.com/#/endurance/report/27072cb61461b83e1447b1979b1491b3

Mihaela: Any progress on narrowing this down? I notice that the Tinderbox builds are still available from this time so it should be fairly easy to reduce the regression range before needing to bisect. See https://ftp.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds/mozilla-central-macosx64/
Virgil & Ioana: As Mihaela is on PTO for the next two weeks, could one of you please pick this up? Thanks.
http://mozmill-ci.blargon7.com/#/endurance/charts?branch=16.0&platform=Mac&from=2012-06-30&to=2012-08-01

Seems this has gone down again (around July the 16th). Last results: 
Explicit memory (MB):	Minimum: 66 / Maximum: 141 / Average: 87
Resident memory (MB):	Minimum: 121 / Maximum: 212 / Average: 163

Attempted to find the culprit for this change, but builds from the 2nd,3rd,4th snd 5th  don't show a reasonable difference between memory usage on our Mac 10.7.4 machine (less than 10 MB per build).

http://mozmill-crowd.blargon7.com/#/endurance/report/c77cfb8878087b850538b93cf20309f3
July the 4th build - 178/231 maximum explicit/resident memory

http://mozmill-crowd.blargon7.com/#/endurance/report/c77cfb8878087b850538b93cf2030625
July the 3rd build - 173/222 maximum explicit/resident memory
It's not as much of a difference, but your two reports show an increase:

Build ID: 20120703110846
Resident memory (MB):
Minimum: 120 / Maximum: 222 / Average: 158

Build ID: 20120704030538
Resident memory (MB):
Minimum: 123 / Maximum: 231 / Average: 163

Minimum has increased by 3MB, maximum by 9MB, and average by 5MB. Given this, I think you have replicated the issue. I will admit that it's difficult to investigate unless the spike is more than a few MB as each run will vary. Perhaps try doubling the number of iterations to see if you can make the spike more profound.
> Attempted to find the culprit for this change, but builds from the 2nd,3rd,4th snd 5th  don't show a 
> reasonable difference between memory usage on our Mac 10.7.4 machine (less than 10 MB per build).

Can you please try to replicate using the exact setup Dave used in comment 6?
Actually it was the same setup: same two builds, 10 iterations and 10 entities. Only the machines varied. 

I'll try Dave's suggestion - increasing the iteration number -, but this will take a bit longer. This should make the numbers big enough to spot a difference when running builds between that range.
Used 30 iterations and differences are higher.

Build from the 3rd: max memory: 186, 233
Build from the 4th: max memory: 210, 247

using tinderbox: 
b39f4007be5a -->182, 230
http://mozmill-crowd.blargon7.com/#/endurance/report/c77cfb8878087b850538b93cf209f6ff

477d807660d7 -->221,253
http://mozmill-crowd.blargon7.com/#/endurance/report/c77cfb8878087b850538b93cf2088aca

http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=b39f4007be5a&tochange=477d807660d7

Inbound bisecting following.

The maximum values were recorded for the testEnterAndLeaveWithMutlipleTabsOpen
c36c02221c6a looks suspicious considering that.
There are still too many changesets in this range. Is there any chance to get this reproduced with a local build?
Tried this last week, but hit the branch error which I didn't have the time to look into. Now that is solved, this worked pretty fast:

changeset 14351e2f3937: max 177/228 ---good http://bit.ly/MYKTU8
changeset e29885f8f290: max 201/245 ---bad http://bit.ly/OKVrlT

new changeset: http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=14351e2f3937&tochange=e29885f8f290

I'll have to build again tomorrow (no tinderbox builds for inbound anymore, but that should be fast)
Thanks Virgil! I would tend to say it's related to bug 769048. Given that there are now more processes for Flash it could be the reason. But it's just a vague idea. So yes, it would be great if you can come up with the right changeset with your own builds.
> Given that there are now more processes for Flash it could be the reason.

Is the memory reported here the RSS for firefox.exe, or firefox.exe plus all its child processes?  I thought it was the former.  If so, is it expected that bug 769048 should affect that value?
Well we make use of the internal functions of the MemoryReporter. Not sure how those collect the memory stats in detail:

http://hg.mozilla.org/qa/mozmill-tests/file/29843ea9d97b/lib/performance.js#l88

As mentioned I could be wrong with my assumption, but I don't see another changeset which could have caused this regression.
QA Contact: virgil.dicu
> Well we make use of the internal functions of the MemoryReporter.

These do not count memory used by plugin-container.

> As mentioned I could be wrong with my assumption, but I don't see another changeset which could have 
> caused this regression.

Indeed.  I'm not saying you're wrong to suspect that bug, just that I wouldn't say higher memory usage from it is necessarily expected due to opening more Flash processes.
Blocks: 769048
Something what I would suggest is that we downgrade Flash to 10.x and check if the issue is also present then. Or even better disabling the protected mode of Flash 11.x. That should give us an idea if Flash is really involved here or not.
c36c02221c6a --> good (177/223)
834baebc83f7 --> bad (204/247)

The first bad revision is:changeset:   98187:834baebc83f7
user:        Dão Gottwald <dao@mozilla.com>
date:        Tue Jul 03 17:02:29 2012 +0200
summary:     Bug 767840 - Let middleMousePaste call openUILink instead of whereToOpenLink and openUILinkIn. r=gavin

That would be bug 767840.
And memory reports for the two builds:
http://mozmill-crowd.blargon7.com/#/endurance/report/29fc09ba0c8360d637617903a0264114
http://mozmill-crowd.blargon7.com/#/endurance/report/29fc09ba0c8360d637617903a026eb4f
I have difficulty believing bug 767840 is to blame.  Does this test even do any middle-clicks?

Comment 23

5 years ago
I'm confused: this bug was originally filed and most of the comments are against mac, where there are not additional Flash processes and bug 769048 is almost a no-op hidden behind ifdefs. Are you saying that this memory regression was also present on Windows?
Virgil: I'm also not convinced by your results. The average memory only differs by ~2MB between those two builds. As you can see from comment 6, this regression showed much larger discrepancies (7MB for explicit and 17MB for resident). Can you rerun your tests but please focus on average memory metrics. If you need to, you can increase the iterations and entities to highlight the regression.

I think we may need to investigate running tinderbox builds on the Mozmill CI so that we have a consistent hardware for reducing regression ranges. Attempting to replicate these locally often consumes a lot of time and can be difficult.
Virgil: Any updates on this? We now have the ability to run tinderbox builds on Mozmill CI, however the builds of interest are no longer available.
I'll build on inbound again and see where that leads, but sincerely I'm a bit skeptical. The focus on maximum memory seemed a good lead at the time (bigger differences between values) and it hit a dead end.

It will take some time until I narrow the regression range through the original changeset, so I'll report back tomorrow once I'll have a couple of results.
Thanks Virgil, the problem with using maximum is that there may be extreme one-off values there that skew the results. We should really focus on average, and perhaps even improve the value of the average by excluding the max and min values. Let us know how you go with replicating this.
http://mozmill-crowd.blargon7.com/#/endurance/report/671677a5d9d5ca25f3cf5ae1c4a90eb1
http://mozmill-crowd.blargon7.com/#/endurance/report/671677a5d9d5ca25f3cf5ae1c4ab46fe
http://mozmill-crowd.blargon7.com/#/endurance/report/671677a5d9d5ca25f3cf5ae1c4ad353e
http://mozmill-crowd.blargon7.com/#/endurance/report/671677a5d9d5ca25f3cf5ae1c4aa2c6e

I've started from the beginning to make sure I don't miss anything. The results listed above are from the 2nd, 3rd, 4th and 5th of July. In that order. 
As can be seen above, the average memory goes up from the July 2nd to the July 3rd (13 MB average memory), goes down starting with July the 4th (over 20 MB less) and rises once again with the July 5th build ()

Used 30 iterations. These results aren't very encouraging. There should have been a spike in memory between the 3rd and the 4th, instead of the reduction which I'm seeing currently.

This needs more investigation. I'll be on PTO for 2 weeks (returning 1st of October) so I'll leave this to Mihaela until then.

Dave, is there something I'm missing here? I've also ran a build of inbound from the 3rd, but it pretty much confirms the other results.
http://mozmill-crowd.blargon7.com/#/endurance/report/671677a5d9d5ca25f3cf5ae1c4a76e1b
QA Contact: virgil.dicu → mihaela.velimiroviciu
It looks like the open new window test is skewing the results. Could you try again, but skip this test?
(Reporter)

Comment 30

5 years ago
I skipped the open new window test from the run and built form inbound changesets, but finding the changeset that caused this was hard because I was often getting contradictory results. 

What I found is the following regression:
834baebc83f7--> last good (155/229)
d17fc82f43ed--> first bad (187/265)
Reports: 
* d17fc82f43ed - http://mozmill-crowd.blargon7.com/#/endurance/report/190d57cf64e3c5c3996c0c10593b046b
* 834baebc83f7 - http://mozmill-crowd.blargon7.com/#/endurance/report/190d57cf64e3c5c3996c0c105936f5c4

The first bad revision is:
d17fc82f43ed	Ehsan Akhgari — Merge mozilla-central into moizilla-inbound

Using a patch which disabled the dom.ipc.plugins.flash.subprocess.crashreporter preference, the numbers got better: 159/238
Report: http://mozmill-crowd.blargon7.com/#/endurance/report/190d57cf64e3c5c3996c0c10593d969a
As mentioned in comment 27, we should focus on average and not max. The numbers quoted in comment 30 appear to be max values. Please also be explicit in the values you mention in bugs.

Given the original report of this bug was based on a spike in maximum memory, and that the increase in average memory was less concerning (almost non-existent in the reports in comment 2) I'm going to close this issue as invalid.

The endurance reports have recently been switched to track the average memory, and any significant and persistent increases in this should be reported and investigated.

Updated

5 years ago
Status: NEW → RESOLVED
Last Resolved: 5 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.