Performance/MemShrink/DMD: Difference between revisions

From MozillaWiki
Jump to navigation Jump to search
Line 72: Line 72:
The number in the parentheses is the process ID.
The number in the parentheses is the process ID.


=== B2G (targeting devices) ===
=== B2G for devices ===


If you built B2G with <tt>export MOZ_DMD=1</tt>, your build will automagically run with DMD enabled.  (The <tt>b2g.sh</tt> script figures out whether to enable DMD by checking for the presence of </tt>libdmd.so</tt> in <tt>/system/b2g</tt>)
If you built B2G with <tt>export MOZ_DMD=1</tt>, your build will automagically run with DMD enabled.  (The <tt>b2g.sh</tt> script figures out whether to enable DMD by checking for the presence of </tt>libdmd.so</tt> in <tt>/system/b2g</tt>)

Revision as of 03:26, 20 December 2012

DMD (short for "dark matter detector") is a tool for that tracks which heap blocks have been reported by memory reporters. It's designed to help us reduce the "heap-unclassified" value in Firefox's about:memory page. It also detects if any heap blocks are reported twice.

Build

Everything other than B2G-device builds

If you're not building for a B2G device, add this line to the mozconfig file of your choice:

 ac_add_options --enable-dmd

Build with that mozconfig. Optimized builds should work fine.

B2G device builds

For B2G device builds, we don't usually modify the mozconfig (although you can; it's hiding under gonk-misc/default-gecko-config).

Instead, modify your .userconfig and add

  export MOZ_DMD=1

(don't forget the export).

You probably need to clobber your objdir (rm -rf objdir-gecko). Then build normally.

Run

Desktop

To run DMD on a desktop build (including Firefox and B2G desktop), you need to precede your usual invocation of Firefox with three environment variable definitions.

On Linux, do this:

 LD_PRELOAD=$OBJDIR/dist/lib/libdmd.so \
 LD_LIBRARY_PATH=$OBJDIR/dist/lib/ \
 DMD=1 \
 <command>

On Mac OS X, do this:

 DYLD_INSERT_LIBRARIES=$OBJDIR/dist/lib/libdmd.dylib \
 LD_LIBRARY_PATH=$OBJDIR/dist/lib/ \
 DMD=1 \
 <command>

On Windows, do this:

 [Doesn't currently work on windows, sorry.  See bug 819839.]

On start-up, you'll see some commentary on stderr, such as:

 DMD[20523] $DMD = '1'
 DMD[20523] DMD is enabled

The number in brackets is the process ID.

The browser will run a little slower than usual.

Fennec

To run DMD on Fennec, run the following commands (be sure to replace "org.mozilla.fennec" with the app identifier as appropriate; this will usually be org.mozilla.fennec_$USERNAME for a local build).

 adb push $OBJDIR/dist/lib/libdmd.so /sdcard/
 adb shell am start -n org.mozilla.fennec/.App --es \
     env0 MOZ_REPLACE_MALLOC_LIB=/sdcard/libdmd.so \
     --es env1 DMD=1

The commentary on Fennec goes to logcat, and looks like this:

 I/DMD  (27314): $DMD = '1'
 I/DMD  (27314): DMD is enabled

The number in the parentheses is the process ID.

B2G for devices

If you built B2G with export MOZ_DMD=1, your build will automagically run with DMD enabled. (The b2g.sh script figures out whether to enable DMD by checking for the presence of libdmd.so in /system/b2g)

If DMD is enabled, you'll see a message in logcat when a process starts up:

  I/DMD     (  305): $DMD = '1'
  I/DMD     (  305): DMD is enabled

The run-gdb.sh script also knows to start DMD builds with DMD enabled, so you don't need to do anything special.

Analyze

DMD doesn't do anything notable until you ask it to.

Desktop

To trigger DMD's analysis phase, enter this URI:

 javascript:DMDReportAndDump(<filename>)

where <filename> is the name of the file that output will be written to.

Note that Firefox doesn't let you do this directly in the address bar, so you must either (a) create a bookmark for it, or (b) run it from the error console. The latter is discouraged because opening the error console allocates a lot of memory that will skew your results.

This command tells DMD to do three things.

  • Run all the memory reporters. While this happens, DMD builds up some state recording which heap blocks have and have not been reported.
  • Analyze the state and produce output.
  • Clear the state.

Because of the third step, you can run DMDReportAndDump multiple times in a single session.

However, it's important that the memory reporters only run once between invocations of DMDReportAndDump, otherwise the state will be inaccurate. For example, if you view about:memory (which runs the memory reporters) and then invoke DMDReportAndDump (which runs them again before analyzing) you'll get _many_ reports about blocks being reported twice. Therefore, there is a second way to invoke DMD, which doesn't run the reporters:

 javascript:DMDDump(<filename>)

When either command is invoked, you'll see some more commentary:

 DMD[20600] Dump 1 {
 DMD[20600]   gathering live block groups...
 DMD[20600]   creating and sorting double-reported block group array...
 DMD[20600]   creating and sorting unreported block group array...
 DMD[20600]   printing unreported block group array...
 DMD[20600]   creating and sorting unreported frame group array...
 DMD[20600]   printing unreported frame group array...
 DMD[20600]   creating and sorting reported block group array...
 DMD[20600]   printing reported block group array...
 DMD[20600]   creating and sorting reported frame group array...
 DMD[20600]   printing reported frame group array...
 DMD[20600] }

On Linux this step is very fast. On Mac it can take 30+ seconds (and it was 5x slower before bug 819817 landed).

Once that's finished printing you can look in <filename> for the output.

Fennec

On Fennec you can use the existing memory-report dumping hook to get a DMD report as well, assuming you have a DMD-enabled build. Run the following command:

 adb shell am broadcast -a org.mozilla.gecko.MEMORY_DUMP

In logcat, you should see output similar to this:

 E/GeckoConsole (27314): nsIMemoryInfoDumper dumped reports to /data/data/org.mozilla.fennec_kats/app_tmp/memory-report-default-27314.json.gz

The path (should always be /data/data/$APPID/app_tmp/) is where the memory reports and DMD reports get dumped to. You can pull them like so:

 adb pull /data/data/org.mozilla.fennec_kats/app_tmp/memory-report-default-27314.json.gz
 adb pull /data/data/org.mozilla.fennec_kats/app_tmp/dmd-default-27314.txt.gz

B2G

[todo]

The output

Pre-processing

DMD's output file contains a lot of stack traces. As printed, many of the stack trace entries will look like this:

 ???[/home/njn/moz/mi2/dmdo64/dist/bin/libxul.so +0x1761BCD] 0x7f845186bbcd

To make them more useful, you need to run them through a "stack-fixing" script.

  • On Linux, use tools/rb/fix-linux-stack.pl.
  • On Mac, use tools/rb/fix_macosx_stack.py.

Both scripts read from stdin and print to stdout. After doing so, these lines should look something more like this:

 nsStringBuffer::Alloc(unsigned long) (/home/njn/moz/mi2/xpcom/string/src/nsSubstring.cpp:177) 0x7f845186bbcd

This shows the function, filename, line number, and PC.

Note that fix-linux-stack.pl is very slow, and can take 2+ minutes to process a DMD output file. (It was almost 10x slower than that before bug 812070 landed.) fix_macosx_stack.py is faster, but can still take 30+ seconds.

Output Sections

DMD's output is broken into multiple sections.

  1. "Invocation". This tells you how DMD was invoked, i.e. what options were used.
  2. "Twice-reported trace records". This tells you which heap blocks were reported twice or more. The presence of any such records indicates bugs in one or more memory reporters.
  3. "Unreported trace records". This tells you which heap blocks were not reported, which indicate where additional memory reporters would be most helpful.
  4. "Unreported frame records". This also presents information about unreported blocks, but in a different way. It can be used to better understand the "Unreported trace records" section.
  5. "Once-reported trace records": like the "Unreported trace records" section, but for blocks reported once.
  6. "Once-reported frame records": like the "Unreported frame records" section, but for blocks reported once.
  7. "Summary": gives measurements of the total heap, and the unreported/once-reported/twice-reported portions of it.
  8. "Execution measurements": gives some statistics about DMD's execution, which are mostly of interest to DMD's developers.

The "Twice-reported trace records" and "Unreported trace records" sections are the most important, because they indicate ways in which the memory reporters can be improved.

Trace records

The trace record sections are the most important ones. Here's an example trace record from the "Unreported trace records" section.

Unreported: 3 blocks in trace record 209 of 1,891
 36,864 bytes (26,184 requested / 10,680 slop)
 0.03% of the heap (64.55% cumulative);  0.04% of unreported (86.78% cumulative)
 Allocated at
   malloc (/home/njn/moz/mi2/memory/build/replace_malloc.c:151) 0x417170
   PR_Malloc (/home/njn/moz/mi2/nsprpub/pr/src/malloc/prmem.c:435) 0x7f68650f423c
   PL_ArenaAllocate (/home/njn/moz/mi2/nsprpub/lib/ds/plarena.c:200) 0x7f68652463e1
   nsFixedSizeAllocator::Alloc(unsigned long) (/home/njn/moz/mi2/xpcom/ds/nsFixedSizeAllocator.cpp:95) 0x7f6860f528dc
   nsNodeInfo::Create(nsIAtom*, nsIAtom*, int, unsigned short, nsIAtom*, nsNodeInfoManager*) (/home/njn/moz/mi2/content/base/src/nsNodeInfo.cpp:64) 0x7f685f640933
   nsNodeInfoManager::GetNodeInfo(nsIAtom*, nsIAtom*, int, unsigned short, nsIAtom*) (/home/njn/moz/mi2/content/base/src/nsNodeInfoManager.cpp:225) 0x7f685f642d05
   mozilla::dom::Element::SetAttrAndNotify(int, nsIAtom*, nsIAtom*, nsAttrValue const&, nsAttrValue&, unsigned char, bool, bool, bool) (/home/njn/moz/mi2/content/base/src/Element.cpp:1862) 0x7f685f60ad87
   mozilla::dom::Element::SetAttr(int, nsIAtom*, nsIAtom*, nsAString_internal const&, bool) (/home/njn/moz/mi2/content/base/src/Element.cpp:1778) 0x7f685f60a9b3
   nsXMLContentSink::AddAttributes(unsigned short const**, nsIContent*) (/home/njn/moz/mi2/content/xml/document/src/nsXMLContentSink.cpp:1464) 0x7f685fa76c5c
   nsXBLContentSink::AddAttributes(unsigned short const**, nsIContent*) (/home/njn/moz/mi2/content/xbl/src/nsXBLContentSink.cpp:882) 0x7f685fb3ad42
   nsXMLContentSink::HandleStartElement(unsigned short const*, unsigned short const**, unsigned int, int, unsigned int, bool) (/home/njn/moz/mi2/content/xml/document/src/nsXMLContentSink.cpp:1018) 0x7f685fa73db5
   nsXMLContentSink::HandleStartElement(unsigned short const*, unsigned short const**, unsigned int, int, unsigned int) (/home/njn/moz/mi2/content/xml/document/src/nsXMLContentSink.cpp:947) 0x7f685fa7370a
   nsXBLContentSink::HandleStartElement(unsigned short const*, unsigned short const**, unsigned int, int, unsigned int) (/home/njn/moz/mi2/content/xbl/src/nsXBLContentSink.cpp:258) 0x7f685fb37cc0

It tells you that there were 3 heap blocks that were allocated from the program point indicated by the "Allocated at" stack trace, that these blocks took up 36,864 bytes, and that 10,680 of those bytes were "slop" (wasted space caused by the heap allocator rounding up request sizes). It also indicates what percentage of the total heap size and the unreported portion of the heap these blocks represent.

Within each section, records are listed from largest to smallest.

Once-reported and twice-reported trace records also have stack traces for the report point(s). For example:

Reported at
  mozilla::dmd::Report(void const*) (/home/njn/moz/mi2/memory/replace/dmd/DMD.cpp:1740) 0x7f68652581ca
  CycleCollectorMallocSizeOf(void const*) (/home/njn/moz/mi2/xpcom/base/nsCycleCollector.cpp:3008) 0x7f6860fdfe02
  nsPurpleBuffer::SizeOfExcludingThis(unsigned long (*)(void const*)) const (/home/njn/moz/mi2/xpcom/base/nsCycleCollector.cpp:933) 0x7f6860fdb7af
  nsCycleCollector::SizeOfIncludingThis(unsigned long (*)(void const*), unsigned long*, unsigned long*, unsigned long*, unsigned long*, unsigned long*) const (/home/njn/moz/mi2/xpcom/base/nsCycleCollector.cpp:3029) 0x7f6860fdb6b1
  CycleCollectorMultiReporter::CollectReports(nsIMemoryMultiReporterCallback*, nsISupports*) (/home/njn/moz/mi2/xpcom/base/nsCycleCollector.cpp:3075) 0x7f6860fde432
  nsMemoryInfoDumper::DumpMemoryReportsToFileImpl(nsAString_internal const&) (/home/njn/moz/mi2/xpcom/base/nsMemoryInfoDumper.cpp:626) 0x7f6860fece79
  nsMemoryInfoDumper::DumpMemoryReportsToFile(nsAString_internal const&, bool, bool) (/home/njn/moz/mi2/xpcom/base/nsMemoryInfoDumper.cpp:344) 0x7f6860febaf9
  mozilla::(anonymous namespace)::DumpMemoryReportsRunnable::Run() (/home/njn/moz/mi2/xpcom/base/nsMemoryInfoDumper.cpp:58) 0x7f6860fefe03

You can tell which memory reporter made the report by the name of the MallocSizeOf function near the top of the stack trace. In this case it was the cycle collector's reporter.

By default, DMD measures heap blocks above a certain size precisely, but uses sampling to measure blocks below that size. Any measurements that involve sampled blocks (even if combined with non-sampled measurements) are approximate, and this is indicated by a preceding '~'. For example:

Unreported: ~273 blocks in block group 17 of 14,611
 ~1,125,590 bytes (~1,117,936 requested / ~7,654 slop)
 0.07% of the heap (2.58% cumulative);  0.43% of unreported (16.36% cumulative)

Frame Records

One shortcoming of trace records is that sometimes there are multiple trace records that have stacks that only vary by a small amount, and this can obscure the fact that a single function is ultimately responsible for all of the blocks covered by these heap allocations. Frame records are an attempt to identify such cases.

Here's an example frame record from the "Unreported frame records" section:

Unreported: ~4,047 blocks from ~979 trace records in frame record 39 of 11,482
 ~16,634,045 bytes (~16,624,445 requested / ~9,600 slop)
 0.99% of the heap;  0.00% of unreported
 PC is
   PL_DHashTableInit (/home/njn/moz/mi2/dmdo64/xpcom/build/pldhash.cpp:231) 0x7f8451816018

A frame record is a merging of every trace record that had an allocation stack trace containing its stack frame. In this example we can see that the initialization of pldhash structures accounted for over 16 MiB of heap allocations, and those are spread over 4,047 heap blocks, which covered approximately 979 trace records.

Options

Setting the DMD environment variable to 1 gives default options. But you can also specify non-default options by setting DMD to a whitespace separated list of --option=val entries.

Valid options are as follows.

  • --sample-below=<1..n> This is the size below which blocks are sampled. The default is 4093, which is a prime number, which helps avoid sampling artifacts that can happen with a rounder number like 4096. Set it to 1 to disable sampling, but note that DMD will run substantially slower if you do so.
  • --mode=<normal|test|stress> This can be used to invoke "test" or "stress" mode, which is only of use to DMD's developers.

For example, if you invoke DMD like this:

 DMD='--mode=normal --sample-below=1' <rest-of-command>

DMD will run in normal mode with sampling off.

Which heap blocks are reported?

At this stage you might wonder how DMD knows which allocations have been reported and which haven't. DMD only knows about heap blocks that are measured via a function created with one of the following two macros:

 NS_MEMORY_REPORTER_MALLOC_SIZEOF_FUN
 NS_MEMORY_REPORTER_MALLOC_SIZEOF_ON_ALLOC_FUN

Fortunately, most of the existing memory reporters do this. See Platform/Memory_Reporting for more details about how memory reporters are written.

Troubleshooting DMD

Contact Nick Nethercote ("njn" on IRC).