Improve heap tracking of WebRender

RESOLVED FIXED in Firefox 64

Status

()

enhancement
P1
normal
RESOLVED FIXED
Last year
11 months ago

People

(Reporter: jrmuizel, Assigned: bholley)

Tracking

(Blocks 2 bugs)

63 Branch
mozilla64
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox64 fixed)

Details

Attachments

(3 attachments)

This will help us diagnose leaks. We should be able to use the heapsize crate
I asked njn about this a couple of days ago, actually. He suggested using malloc_size_of, although he didn't have a clear picture of how to integrate it:

==== njn (via email):
malloc_size_of is what you should use. It's used in Stylo and handles even tricky cases like Rc/Arc. There are some comments at the top of servo/components/malloc_size_of/lib.rs on how to use it, and grepping through Stylo for MallocSizeOf and related identifiers should hopefully make its usage clear.

Having said that, I see that alongside all the generic stuff there is some Stylo-specific stuff in that file. Hmm. Also, it's a crate contained only within mozilla-central and WebRender is not, so that may complicate things and I don't have a clear idea how to integrate.

There was a precursor to malloc_size_of, called heap_size_of, which ended up on crates.io. But that wasn't ideal because it was experimental and quite Firefox-specific, and then I had to make some major changes to it because it didn't handle some important cases (like Rc/Arc). A bunch of other crates ended up depending on heap_size_of, so majorly changing the API would have been a huge pain, and I ended up making malloc_size_of as a replacement and heap_size_of is now effectively abandoned :( And malloc_size_of is still very Firefox-specific, so I would prefer to not put it on crates.io to avoid a repeat of all the above.

So... I'm not sure how much that helps you. The current arrangement is definitely Stylo-centric and will likely need some changing to support broader usage. Perhaps it would be possible to use cargo features and only support memory reporting within WebRender when it's vendored into mozilla-central? Not sure.
====
Priority: -- → P3
I'm going to take a look at memory stuff.

I spoke with Emilio, and we agreed that the right way forward with malloc_size_of would be to have a conditionally-compiled gecko-only path dependency from WR to servo/components/heap_size_of. This could lead to accidental breakage when hacking on standalone WR, but the per-commit gecko try run should at least catch it.

That said, It's not 100% clear to me yet whether we'll really need malloc_size_of. For stylo, we had lots of large and complicated data structures, and really needed detailed tracking of every byte in order to get a clear picture. Furthermore, the auto-derived traits were pretty critical for tracing memory usage through the zillions of CSS types.

With WebRender though, we only have a single instance (in the parent/GPU process), and I'd guess that most of the overhead is in a few large cached things in known places. So we may be able to get away with something simpler and more manual. I'm going to start with DMD and see how far I can get with that approach.
Assignee: nobody → bobbyholley
Priority: P3 → P1
Linux numbers were kinda screwy because of nouveau, which didn't seem worth digging into. Mac numbers seem to make more sense. I'm attaching a DMD log for all allocations above 250k.
Posted file Complete DMD report
Complete DMD report, for reference.
So the biggest obvious offenders from the reduced log are:
* webrender::renderer::CacheTexture::update
* webrender::prim_store::PrimitiveStore::add_primitive
* webrender::gpu_cache::Texture::push_data
* gldCreateTexture (in the GL driver, perhaps this is a temporary space for texture upload?)
* gldCreateFramebuffer (similar to the above?)
* webrender::render_task::RenderTaskTree::add
* webrender::clip::ClipStore::add_clip_items

I'll get to work adding memory reports for the non-driver bits.

There's also some Skia stuff up near the top, but that seems orthogonal to WR. There's a decent amount of heap-unclassified in the parent process with WR disabled, so I wouldn't be surprised if that was there in either case. That said, I don't understand why we're calling into that stuff at all (it doesn't look like blob rasterization). Jeff?
Flags: needinfo?(jmuizelaar)
(In reply to Bobby Holley (:bholley) from comment #5)
> There's also some Skia stuff up near the top, but that seems orthogonal to
> WR. There's a decent amount of heap-unclassified in the parent process with
> WR disabled, so I wouldn't be surprised if that was there in either case.
> That said, I don't understand why we're calling into that stuff at all (it
> doesn't look like blob rasterization). Jeff?

Jeff says we still use the old backend for non-top-level OS windows like the awesomebar and context menus. So that explains that.
Flags: needinfo?(jmuizelaar)
(In reply to Bobby Holley (:bholley) from comment #5)
> * gldCreateTexture (in the GL driver, perhaps this is a temporary space for
> texture upload?)
> * gldCreateFramebuffer (similar to the above?)

It might be worth doing a run on Windows to see if the same usage occurs for these. ANGLE+D3D11 might have somewhat different behaviour to a direct OpenGL driver.
(In reply to Matt Woodrow (:mattwoodrow) from comment #7)
> (In reply to Bobby Holley (:bholley) from comment #5)
> > * gldCreateTexture (in the GL driver, perhaps this is a temporary space for
> > texture upload?)
> > * gldCreateFramebuffer (similar to the above?)
> 
> It might be worth doing a run on Windows to see if the same usage occurs for
> these. ANGLE+D3D11 might have somewhat different behaviour to a direct
> OpenGL driver.

Yeah, totally. I wasn't planning to chase down the driver allocations, both because they're hard to integrate with memory reporters and because they'll differ per-platform anyway. My plan is to add reporting for the big chunks I see in the WR code, and then see how things look under ANGLE+D3D11.
Blocks: 1378528
Comment on attachment 9008573 [details]
Basic Memory Reporting for WebRender.

Jeff Muizelaar [:jrmuizel] has approved the revision.
Attachment #9008573 - Flags: review+
Depends on: 1491130
Pushed by bholley@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/9762d76da9b3
Basic Memory Reporting for WebRender. r=jrmuizel
Blocks: 1425756
Backed out changeset 9762d76da9b3 (bug 1480293) for failing at aboutmemory/tests/test_memoryReporters.xul

Backout link: https://hg.mozilla.org/integration/mozilla-inbound/rev/a1d4f580dfbce1b837d65021f5d8841812cb048f

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=9762d76da9b33ab583c4e89b4fb642be6fadb981

Log link: https://treeherder.mozilla.org/logviewer.html#?job_id=199359024&repo=mozilla-inbound&lineNumber=2860

Log snippet: 

[task 2018-09-14T18:30:54.912Z] 18:30:54     INFO - TEST-START | toolkit/components/aboutmemory/tests/test_memoryReporters.xul
[task 2018-09-14T18:30:55.184Z] 18:30:55     INFO - GECKO(3051) | ExceptionHandler::GenerateDump cloned child 3237
[task 2018-09-14T18:30:55.186Z] 18:30:55     INFO - GECKO(3051) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2018-09-14T18:30:55.188Z] 18:30:55     INFO - GECKO(3051) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-INFO | Main app process: exit 11
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - Buffered messages logged at 18:30:54
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: vsize 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: resident 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: residentFast 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: residentPeak 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - Buffered messages logged at 18:30:55
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: residentUnique 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: heapAllocated 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: heapOverheadFraction 
[task 2018-09-14T18:30:55.379Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: JSMainRuntimeGCHeap 
[task 2018-09-14T18:30:55.384Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: JSMainRuntimeTemporaryPeak 
[task 2018-09-14T18:30:55.384Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: JSMainRuntimeRealmsSystem 
[task 2018-09-14T18:30:55.384Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: JSMainRuntimeRealmsUser 
[task 2018-09-14T18:30:55.385Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: imagesContentUsedUncompressed 
[task 2018-09-14T18:30:55.385Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: storageSQLite 
[task 2018-09-14T18:30:55.385Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: ghostWindows 
[task 2018-09-14T18:30:55.386Z] 18:30:55     INFO - TEST-PASS | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | accessed an unknown distinguished amount: pageFaultsHard 
[task 2018-09-14T18:30:55.386Z] 18:30:55     INFO - Buffered messages finished
[task 2018-09-14T18:30:55.386Z] 18:30:55    ERROR - TEST-UNEXPECTED-FAIL | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | application terminated with exit code 11
[task 2018-09-14T18:30:55.387Z] 18:30:55     INFO - runtests.py | Application ran for: 0:00:10.417061
[task 2018-09-14T18:30:55.389Z] 18:30:55     INFO - zombiecheck | Reading PID log: /tmp/tmpsMii72pidlog
[task 2018-09-14T18:30:55.389Z] 18:30:55     INFO - ==> process 3051 launched child process 3075
[task 2018-09-14T18:30:55.390Z] 18:30:55     INFO - ==> process 3051 launched child process 3166
[task 2018-09-14T18:30:55.391Z] 18:30:55     INFO - ==> process 3051 launched child process 3178
[task 2018-09-14T18:30:55.391Z] 18:30:55     INFO - ==> process 3051 launched child process 3193
[task 2018-09-14T18:30:55.393Z] 18:30:55     INFO - zombiecheck | Checking for orphan process with PID: 3193
[task 2018-09-14T18:30:55.394Z] 18:30:55     INFO - zombiecheck | Checking for orphan process with PID: 3178
[task 2018-09-14T18:30:55.395Z] 18:30:55     INFO - zombiecheck | Checking for orphan process with PID: 3075
[task 2018-09-14T18:30:55.396Z] 18:30:55     INFO - zombiecheck | Checking for orphan process with PID: 3166
[task 2018-09-14T18:30:55.397Z] 18:30:55     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/G_cDWCniQ6SvVPoug7ZYHA/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-09-14T18:31:03.753Z] 18:31:03     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpbX7UYx.mozrunner/minidumps/7f23fe5e-d48f-64c4-01bf-9455fb6bd77b.dmp /tmp/tmpUAq23x
[task 2018-09-14T18:31:13.113Z] 18:31:13     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/7f23fe5e-d48f-64c4-01bf-9455fb6bd77b.dmp
[task 2018-09-14T18:31:13.115Z] 18:31:13     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/7f23fe5e-d48f-64c4-01bf-9455fb6bd77b.extra
[task 2018-09-14T18:31:13.280Z] 18:31:13     INFO - PROCESS-CRASH | toolkit/components/aboutmemory/tests/test_memoryReporters.xul | application crashed [@ MessageLoop::PostTask_Helper(already_AddRefed<nsIRunnable>, int)]
[task 2018-09-14T18:31:13.281Z] 18:31:13     INFO - Crash dump filename: /tmp/tmpbX7UYx.mozrunner/minidumps/7f23fe5e-d48f-64c4-01bf-9455fb6bd77b.dmp
[task 2018-09-14T18:31:13.282Z] 18:31:13     INFO - Operating system: Linux
[task 2018-09-14T18:31:13.283Z] 18:31:13     INFO -                   0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2018-09-14T18:31:13.284Z] 18:31:13     INFO - CPU: amd64
[task 2018-09-14T18:31:13.285Z] 18:31:13     INFO -      family 6 model 62 stepping 4
[task 2018-09-14T18:31:13.286Z] 18:31:13     INFO -      2 CPUs
[task 2018-09-14T18:31:13.287Z] 18:31:13     INFO - 
[task 2018-09-14T18:31:13.288Z] 18:31:13     INFO - GPU: UNKNOWN
[task 2018-09-14T18:31:13.288Z] 18:31:13     INFO - 
[task 2018-09-14T18:31:13.289Z] 18:31:13     INFO - Crash reason:  SIGSEGV
[task 2018-09-14T18:31:13.290Z] 18:31:13     INFO - Crash address: 0xd0
[task 2018-09-14T18:31:13.291Z] 18:31:13     INFO - Process uptime: not available
[task 2018-09-14T18:31:13.292Z] 18:31:13     INFO - 
[task 2018-09-14T18:31:13.293Z] 18:31:13     INFO - Thread 20 (crashed)
[task 2018-09-14T18:31:13.294Z] 18:31:13     INFO -  0  libxul.so!MessageLoop::PostTask_Helper(already_AddRefed<nsIRunnable>, int) [RefPtr.h:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 307 + 0x0]
[task 2018-09-14T18:31:13.295Z] 18:31:13     INFO -     rax = 0x0000000000000001   rdx = 0x0000000000000000
[task 2018-09-14T18:31:13.296Z] 18:31:13     INFO -     rcx = 0x0000000000000003   rbx = 0x0000000000000000
[task 2018-09-14T18:31:13.297Z] 18:31:13     INFO -     rsi = 0x00007fb5c79c9d60   rdi = 0x0000000000000000
[task 2018-09-14T18:31:13.298Z] 18:31:13     INFO -     rbp = 0x00007fb5d5dbd950   rsp = 0x00007fb5d5dbd930
[task 2018-09-14T18:31:13.299Z] 18:31:13     INFO -      r8 = 0x0000000000000000    r9 = 0x0000000000000001
[task 2018-09-14T18:31:13.299Z] 18:31:13     INFO -     r10 = 0x0000000040000000   r11 = 0x0000000000000206
[task 2018-09-14T18:31:13.300Z] 18:31:13     INFO -     r12 = 0x0000000000000000   r13 = 0x0000000000000000
[task 2018-09-14T18:31:13.301Z] 18:31:13     INFO -     r14 = 0x00007fb5c79c9d60   r15 = 0x0000000000000000
[task 2018-09-14T18:31:13.302Z] 18:31:13     INFO -     rip = 0x00007fb5ddb9cd03
[task 2018-09-14T18:31:13.303Z] 18:31:13     INFO -     Found by: given as instruction pointer in context
[task 2018-09-14T18:31:13.304Z] 18:31:13     INFO -  1  libxul.so!mozilla::wr::RenderThread::AccumulateMemoryReport(mozilla::wr::MemoryReport) [RenderThread.cpp:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 162 + 0xb]
[task 2018-09-14T18:31:13.305Z] 18:31:13     INFO -     rbx = 0x00007fb5c79c9d60   rbp = 0x00007fb5d5dbd990
[task 2018-09-14T18:31:13.306Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbd960   r12 = 0x00007fb5c9f7d4c0
[task 2018-09-14T18:31:13.307Z] 18:31:13     INFO -     r13 = 0x0000000000000000   r14 = 0x0000000000000000
[task 2018-09-14T18:31:13.308Z] 18:31:13     INFO -     r15 = 0x0000000000000000   rip = 0x00007fb5de3bdb08
[task 2018-09-14T18:31:13.309Z] 18:31:13     INFO -     Found by: call frame info
[task 2018-09-14T18:31:13.310Z] 18:31:13     INFO -  2  libxul.so!mozilla::layers::CompositorManagerParent::RecvReportMemory(std::function<void (mozilla::wr::MemoryReport const&)>&&) [CompositorManagerParent.cpp:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 322 + 0x26]
[task 2018-09-14T18:31:13.311Z] 18:31:13     INFO -     rbx = 0x0000000000000000   rbp = 0x00007fb5d5dbda80
[task 2018-09-14T18:31:13.312Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbd9a0   r12 = 0x0000000000000000
[task 2018-09-14T18:31:13.313Z] 18:31:13     INFO -     r13 = 0x00007fb5e34eee64   r14 = 0x00007fb5d5dbd9f0
[task 2018-09-14T18:31:13.313Z] 18:31:13     INFO -     r15 = 0x00007fb5d5dbdab8   rip = 0x00007fb5de2e4a93
[task 2018-09-14T18:31:13.314Z] 18:31:13     INFO -     Found by: call frame info
[task 2018-09-14T18:31:13.315Z] 18:31:13     INFO -  3  libxul.so!mozilla::layers::PCompositorManagerParent::OnMessageReceived(IPC::Message const&) [PCompositorManagerParent.cpp: : 303 + 0x10]
[task 2018-09-14T18:31:13.316Z] 18:31:13     INFO -     rbx = 0x00007fb5c5d24900   rbp = 0x00007fb5d5dbdb10
[task 2018-09-14T18:31:13.318Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbda90   r12 = 0xfffffff17fffffff
[task 2018-09-14T18:31:13.318Z] 18:31:13     INFO -     r13 = 0x0000000000000000   r14 = 0x00007fb5c93ad720
[task 2018-09-14T18:31:13.321Z] 18:31:13     INFO -     r15 = 0x00007fb5ccdf4b00   rip = 0x00007fb5ddc34b1b
[task 2018-09-14T18:31:13.322Z] 18:31:13     INFO -     Found by: call frame info
[task 2018-09-14T18:31:13.323Z] 18:31:13     INFO -  4  libxul.so!mozilla::ipc::MessageChannel::DispatchAsyncMessage(IPC::Message const&) [MessageChannel.cpp:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 2248 + 0x9]
[task 2018-09-14T18:31:13.324Z] 18:31:13     INFO -     rbx = 0x00007fb5cccb18e0   rbp = 0x00007fb5d5dbdb50
[task 2018-09-14T18:31:13.324Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbdb20   r12 = 0x00007fb5cccb1800
[task 2018-09-14T18:31:13.325Z] 18:31:13     INFO -     r13 = 0x0000000000000000   r14 = 0x00007fb5cd556c48
[task 2018-09-14T18:31:13.326Z] 18:31:13     INFO -     r15 = 0x0000000000000001   rip = 0x00007fb5ddbca052
[task 2018-09-14T18:31:13.327Z] 18:31:13     INFO -     Found by: call frame info
[task 2018-09-14T18:31:13.328Z] 18:31:13     INFO -  5  libxul.so!mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) [MessageChannel.cpp:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 2175 + 0xb]
[task 2018-09-14T18:31:13.328Z] 18:31:13     INFO -     rbx = 0x00007fb5ccddc6d0   rbp = 0x00007fb5d5dbdbe0
[task 2018-09-14T18:31:13.329Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbdb60   r12 = 0x00007fb5cccb18e0
[task 2018-09-14T18:31:13.330Z] 18:31:13     INFO -     r13 = 0x00007fb5d5dbdc30   r14 = 0x00007fb5cd556c48
[task 2018-09-14T18:31:13.331Z] 18:31:13     INFO -     r15 = 0x00000000ffffffff   rip = 0x00007fb5ddbc9259
[task 2018-09-14T18:31:13.332Z] 18:31:13     INFO -     Found by: call frame info
[task 2018-09-14T18:31:13.332Z] 18:31:13     INFO -  6  libxul.so!mozilla::ipc::MessageChannel::MessageTask::Run() [MessageChannel.cpp:9762d76da9b33ab583c4e89b4fb642be6fadb981 : 2045 + 0x8]
[task 2018-09-14T18:31:13.333Z] 18:31:13     INFO -     rbx = 0x00007fb5cd556bf0   rbp = 0x00007fb5d5dbdc00
[task 2018-09-14T18:31:13.334Z] 18:31:13     INFO -     rsp = 0x00007fb5d5dbdbf0   r12 = 0x00007fb5d5dbdda0
[task 2018-09-14T18:31:13.335Z] 18:31:13     INFO -     r13 = 0x00007fb5d5dbdc30   r14 = 0x00007fb5ccddc6d0
[task 2018-09-14T18:31:13.336Z] 18:31:13     INFO -     r15 = 0x00007fb5d5dbdc38   rip = 0x00007fb5ddbc9b3e
[task 2018-09-14T18:31:13.336Z] 18:31:13     INFO -     Found by: call frame info
Flags: needinfo?(bobbyholley)
Pushed by bholley@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/91c7687d381b
Basic Memory Reporting for WebRender. r=jrmuizel
Blocks: 1491478
https://hg.mozilla.org/mozilla-central/rev/91c7687d381b
Status: NEW → RESOLVED
Closed: 11 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Depends on: 1491546
I see an improvement in AWSY numbers:
== Change summary for alert #15910 (as of Sat, 15 Sep 2018 03:34:06 GMT) ==

Improvements:

  2%  Heap Unclassified linux64-qr opt stylo     315,835,752.91 -> 308,518,836.83

For up to date results, see: https://treeherder.mozilla.org/perf.html#/alerts?id=15910
Depends on: 1491572
You need to log in before you can comment on or make changes to this bug.