New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 736714 link

Starred by 2 users

Issue metadata

Status: WontFix
Owner:
Last visit 15 days ago
Closed: May 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 1
Type: Bug



Sign in to add a comment

heap profiler: new trace format freeze the renderer

Project Member Reported by primiano@chromium.org, Jun 26 2017

Issue description

nainar@ just grabbed heap profiler trace on Linux with native heap profiling.
The trace is big (170 MB) but in all honesty doesn't look too scary. there is one renderer and 6 snapshots in total (I used to see traces from 30 renderers with native heap profiling).

I can load the trace in Mac canary but as soon as I start doing things like diffing two points, trace viewer really chokes and eventually the full renderer goes unresponsive.

I fear this might have been introduced by https://crrev.com/2650863003 .
By looking at the trace metadata, the trace has been captured in 61.0.3142.0, and crrev.com/2650863003 is  61.0.3136.0.

dskiba do we have a plan here? 
 
Data point: I have never managed to successfully load a native-heap-profiling trace with compressed size > 25MB in chrome://tracing UI.

I have many examples [old format] that I can pass along if you want something that won't load in the UI [macOS].
TIL about this awesome hjd's doc go/heap-dump-viewer-perf which explains the problems and the possible solutions on the UI side.

Also copy-pasting hjd@ comment from an internal email, it seems too useful to be lost in an email thread:
-----
I think we can improve the situation dramatically with changes just to the TraceViewer UI.

The heap dump viewer does two things. First it crunches the data for a component to produce a graph then it walks this graph to produce two tables (one broken down by ‘stack frame’ and one by ‘type’).

This is a DevTools timeline for opening a diff of one the malloc heap dumps from the trace_weather_new.json file:

[screenshot.png]

The red 13s square surrounds one example of graph materialization phase (the table rendering phase is not visible in the above screen shot).
We materialize the complete graph which has O(N * M) nodes where N = number of stack frames, M = number of types. 
Note in the screenshot above that this allocates 750mb of JS heap to opening a single (small) heap dump.

It is difficult to see how to process the old format without materializing the full graph, in comparison the new format is easy to process without materializing the full graph. This is one of the killer features of the new format.

Currently however we still materialize the whole graph even when processing the new format. This combined with the fact that the new format records more stack frames causes OOMs.

Prototyping processing the new format without materializing the full graph is maybe ~2-3 days work. 
There is some more detail about why the heap dump viewer is slow in this doc.

[1]: Screenshot.
[2]: Example timeline (not the one from the screenshot, it's too big...) https://chromedevtools.github.io/timeline-viewer/?loadTimelineFromURL=https://gist.github.com/chromy/95630a226f43f33d78e85030028a93ba/raw/6dc5bfcf6556521265fc4eff734ab185cc9690be/HeapDumpViewer-TimelineRawData-20170125T203028
-----
screenshot.png
140 KB View Download
dskiba@ we received another report today * about people not being able to use the heap profiler anymore. Is there any way we could make any cuts from the chrome side (cuts -> coalesce allocation groups < some KB)? We could repurpose that "breakdown_threshold_bytes" of the TraceConfig to drive that.


* internal thread: "Re: Gathering memory data about the StyleEngine"
I'm facing the same problem.
But, I think I've found some stuff to optimize.
I'm gonna take some metrics so see if it's helping.
FYI: https://bugs.chromium.org/p/chromium/issues/detail?id=739378
I was not able to find a quick work-around.
Status: Started (was: Untriaged)
I think this bug describes slightly different problem: too many stack frames (while  issue 739378  is about the speed of dump generation).

I can suggest using third_party/catapult/experimental/tracing/bin/symbolize_trace script with --collapse-threshold of 1024 or more. It can even be used on already symbolized files. That option will cause the script to collapse small branches together, reducing number of stack frames.

primiano@ can you share the trace?
Got the trace from #2, and here is what it contains:

/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 4769 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 556 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 19 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 999 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 1023 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 1024 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 1023 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 1020 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 1019 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 15850 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 950 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 26 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 2910 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 3039 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 3037 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 3029 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 2999 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 3001 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 135026 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 4915 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 723 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12664 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2529 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 2570 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12734 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2372 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 1714 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12734 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2372 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 1714 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12738 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2372 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 1714 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12654 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2372 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 1714 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 12657 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 2372 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 1725 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 538528 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 6212 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 1042 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 18194 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 6713 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 3350 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 31979 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 12239 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 8904 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 31830 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 11836 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 7244 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 31825 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 11849 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 7293 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 31803 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/partition_alloc/nodes has 11855 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/blink_gc/nodes has 7320 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 320849 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 8709 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 387 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 39971 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 50764 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 58362 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 58279 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 57686 objects
/traceEvents[]/args/dumps/heaps_v2/maps/nodes has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/strings has 0 objects
/traceEvents[]/args/dumps/heaps_v2/maps/types has 0 objects
/traceEvents[]/args/dumps/heaps_v2/allocators/malloc/nodes has 57345 objects

Note that there are two humongous "nodes" dicts (i.e. stack frames) with 538528 and 320849 objects.

Most stack frames are collapsible though, here is the output of "third_party/catapult/experimental/tracing/bin/symbolize_trace --collapse-threshold=1024" on that trace:

Collapsing stack branches smaller than 1024...
  Renderer(3218): collapsed 109443 stack frames (out of 144730)
  UnnamedProcess(3207): collapsed 3724 stack frames (out of 5384)
  Renderer(3272): collapsed 428032 stack frames (out of 569128)
  GPU Process(3171): collapsed 10862 stack frames (out of 17730)
  Browser(3073): collapsed 254224 stack frames (out of 351622)
  UnnamedProcess(3179): collapsed 0 stack frames (out of 0)

Resulting trace is openable and doesn't freeze the UI when navigating memory dumps.
Can we just collapse by default until we have a better story? Given that it causes problems on OnMemoryDump I'd collapse them in chrome before serializing.
Project Member

Comment 9 by bugdroid1@chromium.org, Jul 20 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/dd1180754539805af312a7f2ac52f758d543226f

commit dd1180754539805af312a7f2ac52f758d543226f
Author: Dmitry Skiba <dskiba@chromium.org>
Date: Thu Jul 20 10:12:37 2017

Revert "[tracing] Switch to new heap dump format."

This reverts commit d4a5e98235da0cc8c4fb1ae2f67826b0b480ce4c.

Reason for revert: regressed performance ( crbug.com/739378 ,  crbug.com/736714 ).

The main cause is that new heap format produces a lot more stack frames in
an attempt to dump all information in contrast with the old format, where
small stack branches are coalesced together. I'll that functionality to
the new format and reland it.

> [tracing] Switch to new heap dump format.
>
> This CL switches tracing to a new heap dump format, that offers the
> following advantages:
>
> 1. Dumps include all the information collected by Chrome's heap profiler.
>
> 2. The format is simpler and more compact.
>
> 3. The format can easily be extended to include additional per-entry data.
>
> 4. The format allows for post-processing (see recategorization from
>    crrev.com/2906413002 as an example).
>
> BUG= 708930 
>
> Review-Url: https://codereview.chromium.org/2650863003
> Cr-Commit-Position: refs/heads/master@{#480580}

TBR=mark@chromium.org

Bug:  708930 ,  739378 ,  736714 
Change-Id: Ifc2b647aa1f57f4decae6e593ad032d72208b304
Reviewed-on: https://chromium-review.googlesource.com/575682
Commit-Queue: Dmitry Skiba <dskiba@chromium.org>
Reviewed-by: Primiano Tucci <primiano@chromium.org>
Reviewed-by: Dirk Pranke <dpranke@chromium.org>
Cr-Commit-Position: refs/heads/master@{#488186}
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/BUILD.gn
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_event_writer.cc
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_event_writer.h
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_event_writer_unittest.cc
[add] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_heap_dump_writer.cc
[add] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_heap_dump_writer.h
[add] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_heap_dump_writer_unittest.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_serialization_state.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_serialization_state.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_stack_frame_deduplicator.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_stack_frame_deduplicator.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_stack_frame_deduplicator_unittest.cc
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_string_deduplicator.cc
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_string_deduplicator.h
[delete] https://crrev.com/e773fb28d92d781058b58897b4f8638166fc5a45/base/trace_event/heap_profiler_string_deduplicator_unittest.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_type_name_deduplicator.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_type_name_deduplicator.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/heap_profiler_type_name_deduplicator_unittest.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/malloc_dump_provider.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/memory_dump_manager.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/process_memory_dump.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/process_memory_dump.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/process_memory_dump_unittest.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/sharded_allocation_register.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/sharded_allocation_register.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/trace_event_memory_overhead.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/base/trace_event/trace_event_memory_overhead.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/components/tracing/test/heap_profiler_perftest.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/third_party/WebKit/Source/platform/PartitionAllocMemoryDumpProvider.cpp
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/third_party/WebKit/Source/platform/heap/BlinkGCMemoryDumpProvider.cpp
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/third_party/WebKit/Source/platform/instrumentation/tracing/web_process_memory_dump.cc
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/third_party/WebKit/Source/platform/instrumentation/tracing/web_process_memory_dump.h
[modify] https://crrev.com/dd1180754539805af312a7f2ac52f758d543226f/tools/gn/bootstrap/bootstrap.py

Status: WontFix (was: Started)
We switched to memlog for heap profiling.

Sign in to add a comment