1329079 - Massive shmem leak of textures in e10s (from canvas.captureStream()?)

Status: RESOLVED WORKSFORME

(Core :: Audio/Video: MediaStreamGraph, defect, P1)

Description

[Randell Jesup [:jesup] (needinfo me)]

Found by pehrsons

We're leaking massive amounts of shmem when this page ends the MediaRecorder use and puts up the save requester.  This continues so long as the page is open.

The leak is in shmem-mapped. It's allocated in mozilla::ipc::CreateSegment().  We are continually allocating 2 frames; one from mozilla::layers::TextureClient::CreateForDrawing() (which leaks), one from mozilla::layers::TexClientFactory::Create() (which is freed).  Before the recording finishes, both allocations are freed (Create, Create, Unmap, Destroy, Unmap, Destroy).

I suspect the problem isn't really MediaRecorder, but perhaps might be that the MediaStream is no longer consuming the canvas.captureStream(). 

Note: requires e10s.

Go to the URL.  Try the "demo" song.  Hit "Export and Download", choose "Basic".  When the recording finishes, and the save requester pops up, the leak starts.  Dismissing the save dialog doesn't stop the leak.  reloading the page does, but the leaked shmems are still leaked.

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

You can watch this using a separate window with about:memory, and check the shmem-mapped entry once the recording ends.  I was testing on local linux64 debug.  Note that a small fix is needed or this page tends to crash in an assert when loading it.  See bug 1329082 for the patch.  

On Win10 running Aurora 52 (Nightly opt build), I see a one-time leak, not a continuing one -- but in my test, it leaked 1.5GB.  However a second run within the same browser didn't appear to leak any more.  Not sure what's going on with that.  And not sure it's the same leak.

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

Attachment: GDB dumps of Create(), Create(), (Unmap(), Destroy())*2 before leak started

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

Attachment: GDB dumps of Create(), Create(), Unmap(), Destroy() after leak started

Comment 4

[Jerry Shih[:jerry] (UTC+8) (inactive)]

I'm not sure whether you know the problem.

Comment 5

[Andreas Pehrson [:pehrsons]]

I do, thanks. Haven't had time to dig in yet. I'm guessing the canvas is producing frames, but in some circumstance something is not consuming them properly - probably MediaRecorder, perhaps the compositor. The circumstance seems to be that main thread is completely occupied by the RefreshDriver.

Comment 6

[Andreas Pehrson [:pehrsons]]

Here's a jsfiddle that reproduces the problem (I feel pretty confident the leaking is for the same reason - though this also reveals a starvation issue).

STR
1. Click "Start". This starts drawing into the webgl canvas, which is already captured to a MediaStream.
2. Click "Remove Elements". This removes both the canvas and the video element from the dom, so no transaction to the compositor will now be made.

Expected: Main thread should be at least as responsive as before since we're doing less work.

Actual: Main thread is starved out by RefreshDriver ticks. This can be observed in DevTools' performance recorder - JS Flame Chart, with gecko platform data enabled.

When testing this, beware that if you run out of available RAM your computer might freeze, that has happened to me a couple of times now. I can reproduce this at a 100% rate with Firefox 52 and 53 on Ubuntu. Could be hardware and platform dependent since it's using WebGL.

Comment 7

[Andreas Pehrson [:pehrsons]]

It does appear to be e10s-only.

Comment 8

[Andreas Pehrson [:pehrsons]]

I think the starvation issue comes from bug 1306591. Smaug, could you take a look?

Comment 9

[Andreas Pehrson [:pehrsons]]

Attachment: Main thread is only running the refresh driver (with canvas capture being the slowest thing)

Here's a screenshot showing the issue in devtools. See comment 6 to repro.

Comment 10

[Andreas Pehrson [:pehrsons]]

(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #9)
> Here's a screenshot showing the issue in devtools. See comment 6 to repro.

Note that I clicked start after ~1.6s and stop immediately after. It took ~10s for stop to get processed, which was just before I would have run out of memory.

Comment 11

[Olli Pettay [:smaug][[e-mail]]]

bug 1306591 doesn't starve main thread. Normal events are processed too.
Sure, if refresh driver processing is slow, then we don't end up processing too many normal runnables.
Why we're so slow? That is the real bug.

Comment 12

[Olli Pettay [:smaug][[e-mail]]]

(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #6)
> Here's a jsfiddle that reproduces the problem 
Where?

Comment 13

[Ryan VanderMeulen [:RyanVM]]

[Tracking Requested - why for this release]: large memory leaks when using canvas.captureStream()

Comment 14

[Andreas Pehrson [:pehrsons]]

Sorry, forgot the link. https://jsfiddle.net/pehrsons/o5xbu31o/

Comment 15

[Andreas Pehrson [:pehrsons]]

(In reply to Olli Pettay [:smaug] (review request backlog because of a work week) from comment #11)
> Why we're so slow? That is the real bug.

Canvas captureStream's frame capture happens in the refresh driver, and with webgl this does a synchronous readback from the gpu. That can be very slow depending on the gpu bandwidth and canvas size.

The synchronous readback can be improved to be async, but that would need support from gfx and be a fairly large chunk of work I think. Though it would improve perf of canvas capture greatly too.

Comment 16

[Olli Pettay [:smaug][[e-mail]]]

ok, so that is slow. Why are we then not releasing memory, that is another bug. main event loop doesn't starve totally, so it should be able to release whatever is needed.

Comment 17

[Olli Pettay [:smaug][[e-mail]]]

Not knowing about the setup at all, but I'd expect memory to be released before the next frame is captured.

Comment 18

[Andreas Pehrson [:pehrsons]]

Yeah, I'll look into that next. Frames are handled off the main thread but here it seems to only clean the allocations up during GC which is not what we want.

I can easily get main thread to not process anything else than vsync events for 10 seconds or more. It is completely oblivious to user input during this time. That doesn't seem ideal either.

Is there no generic solution to this? I imagine cases where drawing into a canvas is slow, thus causing the same issue, since the requestAnimationFrame handler runs in the refresh driver. Though it seems to be less of a problem when said canvas is visible for some reason.

Comment 19

[Marcia Knous [:marcia]]

Tracking 52/53+ to address these large memory leaks.

Comment 20

[Olli Pettay [:smaug][[e-mail]]]

(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #18)
> I can easily get main thread to not process anything else than vsync events
> for 10 seconds or more. 
I don't understand how that is possible, since in thread level we always try to process one non-prioritized runnable after a prioritized runnable (assuming there is something in the normal queue)

http://searchfox.org/mozilla-central/rev/30fcf167af036aeddf322de44a2fadd370acfd2f/xpcom/threads/nsThread.cpp#804,808-809,816,818-819

Perhaps we could process more normal events, like have also some timestamp of the end time of the high priority runnable handling and try to process normal events until x ms has elapsed.
That is a bit hacky solution, since one really shouldn't do super heavy stuff during refreshdriver tick. It should be moved to idle queue when possible, or some background thread or so.

Comment 21

[Andreas Pehrson [:pehrsons]]

(In reply to Olli Pettay [:smaug] (review request backlog because of a work week) from comment #20)
> (In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #18)
> > I can easily get main thread to not process anything else than vsync events
> > for 10 seconds or more. 
> I don't understand how that is possible, since in thread level we always try
> to process one non-prioritized runnable after a prioritized runnable
> (assuming there is something in the normal queue)

I don't know, but see the screenshot. During that whole time I was waiting for a mouse event that took 10+ seconds to run.

Comment 22

[Olli Pettay [:smaug][[e-mail]]]

sure, because there are other things in the main event loop too.

Comment 23

[Olli Pettay [:smaug][[e-mail]]]

I'm writing a hacky patch to let us process more normal events, but I still think 
'Canvas captureStream's frame capture happens in the refresh driver' is a real issue to fix, at least in webgl case. Isn't that close to as bad as sync I/O. Not sure how to fix it though? Can we readback in some background thread?

Comment 24

[Andreas Pehrson [:pehrsons]]

(In reply to Olli Pettay [:smaug] (review request backlog because of a work week) from comment #23)
> I'm writing a hacky patch to let us process more normal events, but I still
> think 
> 'Canvas captureStream's frame capture happens in the refresh driver' is a
> real issue to fix, at least in webgl case. Isn't that close to as bad as
> sync I/O. Not sure how to fix it though? Can we readback in some background
> thread?

There's async readback, but I don't think our graphics backend is up for it yet.

Comment 25

[Pierre Brochard]

bug 1326311 seems to solve also the bug from the test in comment 0. A big leak was visible without the patches and disappear with it.

It is connected with the MediaRecorder and it seems to me logical that this bug 1326311 impact also the test in comment 0 here.

See the bug 1326311 for more information.

Comment 26

[Andreas Pehrson [:pehrsons]]

(In reply to Olli Pettay [:smaug] from comment #16)
> ok, so that is slow. Why are we then not releasing memory, that is another
> bug. main event loop doesn't starve totally, so it should be able to release
> whatever is needed.

The producer is in the refresh driver tick -- prioritized.

The last consumer (looking at the stack trace of the destructor) is nsOwningThreadSourceSurfaceRef at [1] which dispatches a runnable to destroy the SourceSurface on the owner thread (main) if Release() happened on another thread. 

This could explain why I don't see the same problems when the canvas is visible in the DOM -- CompositorChild might be the last consumer, releasing it on main thread, not causing any extra runnables in the regular queue.

[1] http://searchfox.org/mozilla-central/rev/bf98cd4315b5efa1b28831001ad27d54df7bbb68/gfx/layers/ImageContainer.h#90

Comment 27

[Andreas Pehrson [:pehrsons]]

The thing calling nsOwningThreadSourceSurfaceRef::Release() is StreamTracks::Track::ForgetUpTo(), so that bit seems to work. It just takes a long time for the SurfaceReleaser to run on main thread.

Smaug, what would take to dispatch the SurfaceReleaser with high priority?
I tried to look through your code but it only seems supported for IPC messages for now?

Comment 28

[Olli Pettay [:smaug][[e-mail]]]

high priority runnables must not be used for random things.
(but using them is simple, just implementing nsIRunnablePriority)

Comment 29

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1329079 - Move SurfaceReleaser to cpp file.

Review commit: https://reviewboard.mozilla.org/r/107436/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/107436/

Comment 30

[Andreas Pehrson [:pehrsons]]

Attachment: Bug 1329079 - Make the SurfaceReleaser runnable HIGH priority.

This avoids ever-growing memory allocations caused by SourceSurfaces allocated
in a high priority runnable (like vsync) and a busy main thread that cannot
process the SurfaceReleasers fast enough.

Review commit: https://reviewboard.mozilla.org/r/107438/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/107438/

Comment 31

[Andreas Pehrson [:pehrsons]]

A quick manual test confirms that this works.

Comment 32

[Olli Pettay [:smaug][[e-mail]]]

Comment on attachment 8830696 [details]
Bug 1329079 - Make the SurfaceReleaser runnable HIGH priority.

https://reviewboard.mozilla.org/r/107438/#review108540

No. We should not start to use high priority events for random things.

I'm in process to slowing down vsync processing when processing refresh driver ticks takes too much time, like here.

Comment 33

[Andreas Pehrson [:pehrsons]]

Ok, I'll wait for a more general fix in bug 1332226.

Comment 34

[Olli Pettay [:smaug][[e-mail]]]

I think comment 23 is still valid. We're blocking refresh driver for too long.

Comment 35

[Ryan VanderMeulen [:RyanVM]]

IIUC, bug 1331706 should have fixed this for the time-being. Can you please confirm? We'll presumably want to leave this bug open for tracking future work needed after bug 1332226 lands, but hopefully we can at least get it off the immediate radar.

Comment 36

[Randell Jesup [:jesup] (needinfo me)]

andreas - forwarding to you; do you still see this?  We'll need to leave this open in any case

Comment 37

[Andreas Pehrson [:pehrsons]]

I don't see the issue per comment 0, but there's still the issue of allocating frames faster than they can be consumed in 53 and 54. Those should be fixed by bug 1332226, and we can revisit when a fix for that has landed.

Comment 38

[Andreas Pehrson [:pehrsons]]

Actually this was fixed by bug 1331706 in both 52 and 53.

Comment 39

[Ryan VanderMeulen [:RyanVM]]

That fix landed on 53 when it was still trunk, so this should be fixed across all versions at the moment. But yeah, we'll want to keep this open and keep an eye on things once bug 1332226 lands.

Comment 40

[Olli Pettay [:smaug][[e-mail]]]

(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #15)
> The synchronous readback can be improved to be async, but that would need
> support from gfx and be a fairly large chunk of work I think. Though it
> would improve perf of canvas capture greatly too.
Who would be the right person to look at that? We really must not block main thread longer than needed
(which is why we for example are removing all the sync IPC we can).
Blocking main thread mean nothing else there gets to run, so the thread is just idle for too long.

Comment 41

[Randell Jesup [:jesup] (needinfo me)]

(In reply to Olli Pettay [:smaug] from comment #40)
> (In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #15)
> > The synchronous readback can be improved to be async, but that would need
> > support from gfx and be a fairly large chunk of work I think. Though it
> > would improve perf of canvas capture greatly too.
> Who would be the right person to look at that? We really must not block main
> thread longer than needed
> (which is why we for example are removing all the sync IPC we can).
> Blocking main thread mean nothing else there gets to run, so the thread is
> just idle for too long.

Milan?  This is talking about a canvas readback,  From Comment 15:
> Canvas captureStream's frame capture happens in the refresh driver, and with webgl this does a 
> synchronous readback from the gpu. That can be very slow depending on the gpu bandwidth and canvas 
> size.

> The synchronous readback can be improved to be async, but that would need support from gfx and be a 
> fairly large chunk of work I think. Though it would improve perf of canvas capture greatly too.

Comment 42

[Andreas Pehrson [:pehrsons]]

(In reply to Olli Pettay [:smaug] from comment #40)
> Who would be the right person to look at that? We really must not block main
> thread longer than needed
> (which is why we for example are removing all the sync IPC we can).
> Blocking main thread mean nothing else there gets to run, so the thread is
> just idle for too long.

I reached out to Jeff Gilbert (WebGL peer) a week or two ago but haven't heard back yet.

Comment 43

[Milan Sreckovic [:milan] (needinfo for best results)]

We're now talking about the performance aspect of captureStream, rather than a memory leak, right?  Perhaps another bug for that, and we can link it to the WebGL performance meta bug 1207170, as we're currently evaluating the relative priority of different aspects of WebGL performance.

Comment 44

[Eric Rahm [:erahm]]

It looks like the memory portion has been fixed and we have bug 1340142 for the perf discussion. Lets go ahead and close this.