Closed Bug 1493196 Opened 6 years ago Closed 6 years ago

Nightly doesnt release memory after visiting and closing the francine page

Categories

(Core :: Graphics: WebRender, defect, P1)

defect

Tracking

()

VERIFIED FIXED
mozilla64
Tracking Status
firefox-esr60 --- unaffected
firefox62 --- disabled
firefox63 --- disabled
firefox64 --- verified

People

(Reporter: mayankleoboy1, Assigned: bholley)

References

()

Details

(Keywords: regression, Whiteboard: [MemShrink])

Attachments

(10 files, 1 obsolete file)

Attached file memory-report.json.gz (obsolete) —
User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:64.0) Gecko/20100101 Firefox/64.0
Build ID: 20180921100113

Steps to reproduce:

1. Use nightly. Enable WR
2. Go to http://diana-adrianne.com/purecss-francine/
3. Memory goes up to 1.3GB . 
4. Close the tab
5. Memory is still around 900Mb-1GB
6. Go to about:memory, and click on minimise memory
7. Memory is still high


Actual results:

nightly doesnt release memory even after closin the tab, and minimizing memory


Expected results:

not so
you seem to be looking into WR memory
Flags: needinfo?(bobbyholley)
Attached file before
While the francine page is open and visible
Attachment #9010979 - Attachment is obsolete: true
Attached file after
afer i closed the tab, and clicked on minimize memory 2 times
these new memory reports are after bug 1492263 landed
I can't really reproduce an excessive use of memory on my system.
I have Windows 10 64 and Nightly v64.0a1 from 2018-09-24.
This is the STR I use:
1. Open Nightly with a new profile;
2. Go to "about:config" and set pref "gfx.webrender.enabled" as true;
3. Open Task Manager to observe the memory used by the Nightly browser.
4. Go to http://diana-adrianne.com/purecss-francine/;
Notice the Task Manager: The memory goes up from about 250mb to about 375mb;
5. Go to "about:memory" and click the "Minimize memory usage" button;
Notice the Task Manager: The memory goes down from about 250mb to about 350mb;
6. Close the "http://diana-adrianne.com/purecss-francine/" tab.
Notice the Task Manager: The memory goes down from about 350mb to about 250mb;
7. Go to "about:memory" and click the "Minimize memory usage" button;
Notice the Task Manager: The memory goes down from about 250mb to about 230mb;

NOTICE: I cannot reproduce an excessive use of memory with this page/site.
@Can you provide better reproduction steps? Does this issue still occur for you?
Flags: needinfo?(mayankleoboy1)
Did you restart teh browser after setting gfx.webrender.enabled as true ? That is a necessary step.
So:
1. Start new profile
2. Open about:config. Set gfx.webrender.enabled as true . 
3. Restart.
4. Open http://diana-adrianne.com/purecss-francine/ . in a new tab
5. Observer the memory use in task manager. 
6. Close the tab.
7. Go to "about:memory" and click the "Minimize memory usage" button;
8. Observer teh memory use
Flags: needinfo?(mayankleoboy1) → needinfo?(daniel.bodea)
Attachment #9011206 - Attachment filename: before → before.gz
Attachment #9011206 - Attachment mime type: application/octet-stream → application/x-gzip
Attachment #9011207 - Attachment filename: after → after.gz
Attachment #9011207 - Attachment mime type: application/octet-stream → application/x-gzip
This does sound similar to bug 1378528. I don't think there are a lot of images in Francine though, so we may not be on the right track there.

If I understand correctly, the 'before' attachment is once francine has already been loaded. Can you post a memory report from a clean start of your browser?

If Bodea is still unable to reproduce it after a restart, it may indicate that this is hardware- or driver-specific. Can you post your hardware information from about:support?
Flags: needinfo?(mayankleoboy1)
See Also: → 1378528
Attached file after_startup.json.gz
after startup. Let it stabilize for 10-20 seconds
Flags: needinfo?(mayankleoboy1)
while francine is loaded, and about:memory is loaded in a new tab-window
close francine
open about:memry in a tab in the same window. 
Minimize a couple of times
save report
Priority: -- → P3
this is where things get interesting, and which i just discovered: 

1. Open francine in window1+tab1
2. Open a new tab, tab2 . Open about:memory in to it
3. Detach the tab2 to create a new window2+tab2
4. Close the original francine tab1+window1
5. minimize memory in tab2+window2
 BOOM: low memory

Tl;dr
If you close the complete window with francine tab, the memory goes down
If you only close the francine tab, memory doesnt go down
I wonder if this is related to keeping render targets around for too long. Though render targets should be GPU memory, so I'm not sure if they're counted in these numbers.
Mayank: Do you notice anything interesting if you run with gfx.webrender.debug.render-targets set to true?
(In reply to Markus Stange [:mstange] from comment #12)
> I wonder if this is related to keeping render targets around for too long.
> Though render targets should be GPU memory, so I'm not sure if they're
> counted in these numbers.
> Mayank: Do you notice anything interesting if you run with
> gfx.webrender.debug.render-targets set to true?


1. If i open francine, then the red/black boxes become small and dense. Then when i close the francine tab, they still persist in another tab of the same window.  Memory remains high.

2. If i open francie in a new window, then the red/black things disappear within a few seconds after I close that window. Memory returns to normal
to write more clearly:

1. If I open francine in a tab of a window, and then close that tab, the red/black boxes remain in other tab of the window. Memory remains high.
2. If I open francine in a new window, and then I close that window, the red/black boxes disappear within a few seconds and dont interfere in tabs of other windows. Memory returns to normal.
Flags: needinfo?(mstange)
Ok, so it sounds like at least superficially, the high memory usage is correlated to having a large number of red/black boxes (number of render targets). That's all I wanted to know. Thanks!
Flags: needinfo?(mstange)
also see this behaviour: 
each time you detach francine tab to create a new window, add a tab, and detach francine again , the memory increases by ~1GB

So:

1. Window1 : francine+ blank tab
2.  Detach fr to create window2
3. Create new tab in window2 : fr+ blank tab2
4. Detach fr to get window3

Each time memory use increases
this also happens on other pages like google. When i repeatedly create new windows by detaching google tab, the memory keeps on growing very quickly
Whiteboard: [MemShrink]
I can reproduce at least some of this, looking into it.
Assignee: nobody → bobbyholley
Flags: needinfo?(daniel.bodea)
A few interesting details:

GPU (pid 15732)

> 134,217,727.94 MB (100.0%) -- address-space
> ├──134,211,829.72 MB (100.0%) ── free(segments=270)
> └────────5,898.21 MB (00.00%) -- (2 tiny)
>          ├──4,246.54 MB (00.00%) -- reserved
>          │  ├──4,224.56 MB (00.00%) ── private(segments=220)
>          │  └─────21.98 MB (00.00%) ── mapped(segments=4)
>          └──1,651.68 MB (00.00%) -- commit
>             ├──1,350.77 MB (00.00%) ++ private
>             ├────206.20 MB (00.00%) ++ image
>             └─────94.72 MB (00.00%) ++ mapped
> 
>          99.37 MB ── heap-allocated
>         112.00 MB ── heap-mapped
>       1,362.15 MB ── private
>       1,358.54 MB ── resident
>       1,333.73 MB ── resident-unique
>           6.37 MB ── system-heap-allocated
>       5,898.21 MB ── vsize

So the GPU process has 4.2GB reserved-private (we expect that in vsize) and 1.35GB committed-private. Very little is "mapped," I'm not totally clear what that means in the address space reporter lingo. resident-unique reflects the commit-private number, but we only see 100MB of heap-allocated. We also only see 6MB from the system-heap (allocations not tracked by us).

The current theory is most of the memory is coming from the graphics driver.

Each of the other processes appear to have ~5GB of reserved memory impacting their vsize (the WebExtension process has 11GB but 6GB of that is from wasm page guards), their resident-unique is reasonable. The large vsize is a bit surprising.
Flags: needinfo?(bobbyholley)
Priority: P3 → P1
Attached file VirtualAlloc Stacks
Stacks extracted using WPR/WPA [1] on NVidia windows desktop.

[1] https://wiki.mozilla.org/Tracing_VirtualAlloc_With_Xperf
Discussed this a bit with gw. It looks like we don't actually have any GC scheme for RenderTargets, and we probably need something like that. However, we're also not quite sure why presumably-large textures generated by Francine don't end up getting reused and resized to something reasonable. I'll debug it.

That said, the first order of business is to add a memory reporter to estimate texture memory usage. I'll try to get started on that tomorrow.
(In reply to Mayank Bansal from comment #6)
> Did you restart teh browser after setting gfx.webrender.enabled as true ? That is a necessary step.

Yes, I have. I have also retested my STR from comment 5 to be sure:
1. Open Nightly with a new profile;
2. Go to "about:config" and set pref "gfx.webrender.enabled" as true (and RESTART, yes, I knew it was necessary);
3. Open Task Manager to observe the memory used by the Nightly browser: 250mb;
4. Go to http://diana-adrianne.com/purecss-francine/: spiked to 400mb and stabilized at 250mb;
5. Go to "about:memory" and click the "Minimize memory usage" button: went down to 330mb and then back to 350mb;
6. Close the "http://diana-adrianne.com/purecss-francine/" tab: went down to 275mb;
7. Go to "about:memory" and click the "Minimize memory usage" button: went down to about 265mb.

Testing your STR from comment 6:
1. Start new profile: 270mb ;
2. Open about:config. Set gfx.webrender.enabled as true: memory went down to 225mb;
3. Restart: 220mb;
4. Open http://diana-adrianne.com/purecss-francine/ . in a new tab: spiked to 300mb, then stabilized to 250mb:
5. Observer the memory use in task manager. (MADE IN EACH STEP);
6. Close the tab: memory went up to 275mb!
7. Go to "about:memory" and click the "Minimize memory usage" button: went down to 265mb and is slowly stabilizing to about 315mb;
8. Observer teh memory use (MADE IN EACH STEP).

Testing your STR from comment 11:
1. Open francine in window1+tab1: spiked at 300mb, then stabilized at 290mb;
2. Open a new tab, tab2 . Open about:memory in to it: went down to 250mb;
3. Detach the tab2 to create a new window2+tab2: memory went up to 315mb;
4. Close the original francine tab1+window1: memory went down to 200mb;
5. minimize memory in tab2+window2: memory went down to 190mb, then stabilized to 200mb.

I have tested on Windows 10 x64 and Nightly v64.0a1 from 2018-09-25.
I've added some memory reporters that confirm the issue reported in this bug is the result of no GC on the render target pool.

I added a bit of logging, and after francine it looks like this:

14: 2048x2048x1 (4194304 bytes), last used @ FrameId(3680)
965: 2048x2048x21 (88080384 bytes), last used @ FrameId(1520)
11: 2048x2048x5 (20971520 bytes), last used @ FrameId(1520)
959: 2048x2048x4 (16777216 bytes), last used @ FrameId(1520)
960: 2048x2048x52 (218103808 bytes), last used @ FrameId(1520)
961: 2048x2048x52 (218103808 bytes), last used @ FrameId(1520)
966: 2048x2048x17 (285212672 bytes), last used @ FrameId(1545)
15: 2488x2048x2 (10190848 bytes), last used @ FrameId(3414)
968: 2048x2048x17 (285212672 bytes), last used @ FrameId(1545)
967: 2048x2048x18 (75497472 bytes), last used @ FrameId(1545)
969: 2048x2048x2 (33554432 bytes), last used @ FrameId(1545)
971: 2048x2048x2 (33554432 bytes), last used @ FrameId(1545)
964: 2048x2048x60 (251658240 bytes), last used @ FrameId(1545)
962: 2048x2048x1 (16777216 bytes), last used @ FrameId(3720)
970: 2048x2048x1 (4194304 bytes), last used @ FrameId(3681)
12: 2048x2048x1 (16777216 bytes), last used @ FrameId(3721)
963: 2048x2048x2 (8388608 bytes), last used @ FrameId(3721)

So what's happening here is that Francine allocates render targets that are both numerous _and_ large. If they were just large it wouldn't be a problem, since we'd recycle them (and then resize them) for subsequent frames. But because no subsequent frames end up using so many render targets, they remain orphaned.

I'll write up some proper eviction now.
Comment on attachment 9011951 [details] [diff] [review]
Part 1 - Add reporting for texture memory. v1

Review of attachment 9011951 [details] [diff] [review]:
-----------------------------------------------------------------

WR parts look good - not sure if you need someone to check the Gecko part.
Attachment #9011951 - Flags: review?(gwatson) → review+
Attachment #9011952 - Flags: review?(gwatson) → review+
Comment on attachment 9011951 [details] [diff] [review]
Part 1 - Add reporting for texture memory. v1

Gecko parts are trivial but might as well get a stamp from Jeff.
Attachment #9011951 - Flags: review?(jmuizelaar)
Attachment #9011951 - Flags: review?(jmuizelaar) → review+
Pushed by bholley@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/2dc1c6e56100
Add reporting for texture memory. r=jrmuizel
(In reply to Pulsebot from comment #30)
> Pushed by bholley@mozilla.com:
> https://hg.mozilla.org/integration/mozilla-inbound/rev/2dc1c6e56100
> Add reporting for texture memory. r=jrmuizel

Note that the actual eviction code landed with the WR update, this part just hooks up the memory reporters.
https://hg.mozilla.org/mozilla-central/rev/2dc1c6e56100
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
I have retried the STRs I have reported in comment 22 to see a comparison and these are my results:

Retesting my STR from comment 5:
1. Open Nightly with a new profile;
2. Go to "about:config" and set pref "gfx.webrender.enabled" as true (and RESTART, yes, I knew it was necessary);
3. Open Task Manager to observe the memory used by the Nightly browser:
 - before fix: 250mb / after fix: 200mb;
4. Go to http://diana-adrianne.com/purecss-francine/:
 - before fix: spiked to 400mb and stabilized at 250mb / after fix spiked to 330mb and stabilized at 265mb;
5. Go to "about:memory" and click the "Minimize memory usage" button:
 - before fix went down to 330mb and then back to 350mb / after fix went up from 265mb to 275mb;
6. Close the "http://diana-adrianne.com/purecss-francine/" tab:
 - before fix went down to 275mb / after fix stabilized at 280mb;
7. Go to "about:memory" and click the "Minimize memory usage" button:
 - before fix went down to about 265mb / after fix went down to 265mb.

Retesting your STR from comment 6:
1. Start new profile:
 - before fix 270mb / after fix 270mb;
2. Open about:config. Set gfx.webrender.enabled as true:
 - before fix memory went down to 225mb / after fix memory went down to 230mb;
3. Restart:
 - before fix 220mb / after fix 220mb, then stabilized at 200mb;
4. Open http://diana-adrianne.com/purecss-francine/, in a new tab:
 - before fix, spiked to 300mb, then stabilized to 250mb / after fix, spiked to 350, then stabilized at 300mb;
5. Observer the memory usage in task manager. (MADE IN EACH STEP);
6. Close the tab:
 - before fix memory went up to 275mb! / after fix memory went down to 200mb;
7. Go to "about:memory" and click the "Minimize memory usage" button:
 - before fix went down to 265mb and is slowly stabilizing to about 315mb / after fix, it went down to 190mb, then stabilized at about 220mb;
8. Observer the memory use (MADE IN EACH STEP).

Testing your STR from comment 11:
1. Open francine in window1+tab1:
- before fix spiked at 300mb, then stabilized at 290mb / after fix spiked to 380mb, then stabilized at 315mb;
2. Open a new tab, tab2. Open about:memory in to it:
 - before fix went down to 250mb / after fix 320mb;
3. Detach the tab2 to create a new window2+tab2:
 - before fix memory went up to 315mb / after fix memory went down to 280mb;
4. Close the original francine tab1+window1:
 - before fix memory went down to 200mb / after fix memory is 175-195mb;
5. minimize memory in tab2+window2:
 - before fix memory went down to 190mb, then stabilized to 200mb / after fix memory was 185, then stabilized at 205mb.


These differences don't make much sense to me and I know that these memory spikes are rarely as expected/reliable, but I have tried to make results are readable as possible so the developer can see some (if any) intended changes after the fix. 
@Bobby Holley, do these results count as an appropriate fix verification?

On the other hand, my system is not necessarily a good comparison as I could not reproduce as much memory usage as the reporter, while attempting to confirm the original issue.

Hope my testing is not done in vain.
Thanks!
Flags: needinfo?(bobbyholley)
Attached file memory-report.json.gz
Memory report after I opened fr, closed the tab, let browser sit idle for 10-20 seconds, opened about:memory and "minimized" memory use.

ni? for bholley, if he thinks this is acceptable reduction of memory.

anecdotally:
fresh start+idle = 120MB
after taking the memory report: 380MB
(In reply to Mayank Bansal from comment #34)
> Created attachment 9012599 [details]
> memory-report.json.gz
> 
> Memory report after I opened fr, closed the tab, let browser sit idle for
> 10-20 seconds, opened about:memory and "minimized" memory use.
> 
> ni? for bholley, if he thinks this is acceptable reduction of memory.
> 
> anecdotally:
> fresh start+idle = 120MB
> after taking the memory report: 380MB

Yes, I think the GPU process memory in this report looks ok. Thanks!

(In reply to Bodea Daniel [:danibodea] from comment #33)
> @Bobby Holley, do these results count as an appropriate fix verification?
> 
> On the other hand, my system is not necessarily a good comparison as I could
> not reproduce as much memory usage as the reporter, while attempting to
> confirm the original issue.

Given that you weren't able to reproduce the original issue, it would be difficult for you to verify that it's fixed. The root problem in this bug is excessive GPU memory usage, which may or may not show up as high CPU memory usage (in the task manager) depending on the driver.

You should be able to monitor GPU memory usage by looking at "GPU memory" under the "Performance" tab in the windows 10 task manager. That said, I'm comfortable with Mayank's verification of this issue.

> Hope my testing is not done in vain.

I think it was a generally useful sanity check. :-)
Flags: needinfo?(bobbyholley)
Marking as verified in firefox64 based on the comment above.

Thank you!
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: