path: root/docs/performance/memory/heap_scan_mode.md

# DMD heap scan mode

Firefox's DMD heap scan mode tracks the set of all live blocks of
malloc-allocated memory and their allocation stacks, and allows you to
log these blocks, and the values stored in them, to a file. When
combined with cycle collector logging, this can be used to investigate
leaks of refcounted cycle collected objects, by figuring out what holds
a strong reference to a leaked object.

**When should you use this?** DMD heap scan mode is intended to be used
to investigate leaks of cycle collected (CCed) objects. DMD heap scan
mode is a "tool of last resort" that should only be used when all
other avenues have been tried and failed, except possibly [ref count
logging](refcount_tracing_and_balancing.md).
It is particularly useful if you have no idea what is causing the leak.
If you have a patch that introduces a leak, you are probably better off
auditing all of the strong references that your patch creates before
trying this.

The particular steps given below are intended for the case where the
leaked object is alive all the way through shutdown. You could modify
these steps for leaks that go away in shutdown by collecting a CC and
DMD log prior to shutdown. However, in that case it may be easier to use
refcount logging, or rr with a conditional breakpoint set on calls to
`Release()` for the leaking object, to see what object actually does the
release that causes the leaked object to go away.

## Prerequisites

-   A debug DMD build of Firefox. [This
    page](dmd.md)
    describes how to do that. This should probably be an optimized
    build. Non-optimized DMD builds will generate better stack traces,
    but they can be so slow as to be useless.
-   The build is going to be very slow, so you may need to disable some
    shutdown checks. First, in
    `toolkit/components/terminator/nsTerminator.cpp`, delete everything
    in `RunWatchDog` but the call to `NS_SetCurrentThreadName`. This
    will keep the watch dog from killing the browser when shut down
    takes multiple minutes. Secondly, you may need to comment out the
    call to `MOZ_CRASH("NSS_Shutdown failed");` in
    `xpcom/build/XPCOMInit.cpp`, as this also seems to trigger when
    shutdown is extremely slow.
-   You need the cycle collector analysis script `find_roots.py`, which
    can be downloaded as part of [this repo on
    Github](https://github.com/amccreight/heapgraph).

## Generating Logs

The next step is to generate a number of log files. You need to get a
shutdown CC log and a DMD log, for a single run.

**Definitions** I'll write `$objdir` for the object directory for your
Firefox DMD build, `$srcdir` for the top level of the Firefox source
directory, and `$heapgraph` for the location of the heapgraph repo, and
`$logdir` for the location you want logs to go to. `$logdir` should end
in a path separator. For instance, `~/logs/leak/`.

The command you need to run Firefox will look something like this:

    XPCOM_MEM_BLOAT_LOG=1 MOZ_CC_LOG_SHUTDOWN=1 MOZ_DISABLE_CONTENT_SANDBOX=t MOZ_CC_LOG_DIRECTORY=$logdir
    MOZ_CC_LOG_PROCESS=content MOZ_CC_LOG_THREAD=main MOZ_DMD_SHUTDOWN_LOG=$logdir MOZ_DMD_LOG_PROCESS=tab ./mach run --dmd --mode=scan

Breaking this down:

-   `XPCOM_MEM_BLOAT_LOG=1`: This reports a list of the counts of every
    object created and destroyed and tracked by the XPCOM leak tracking
    system. From this chart, you can see how many objects of a
    particular type were leaked through shutdown. This can come in handy
    during the manual analysis phase later, to get evidence to support
    your hunches. For instance, if you think that an `nsFoo` object
    might be holding your leaking object alive, you can use this to
    easily see if we leaked an `nsFoo` object.
-   `MOZ_CC_LOG_SHUTDOWN=1`: This generates a cycle collector log during
    shutdown. Creating this log during shutdown is nice because there
    are less things unrelated to the leak in the log, and various cycle
    collector optimizations are disabled. A garbage collector log will
    also be created, which you may not need.
-   `MOZ_DISABLE_CONTENT_SANDBOX=t`: This disables the content process
    sandbox, which is needed because the DMD and CC log files are
    created directly by the child processes.
-   `MOZ_CC_LOG_DIRECTORY=$logdir`: This selects the location for cycle
    collector logs to be saved.
-   `MOZ_CC_LOG_PROCESS=content MOZ_CC_LOG_THREAD=main`: These options
    specify that we only want CC logs for the main thread of content
    processes, to make shutdown less slow. If your leak is happening in
    a different process or thread, change the options, which are listed
    in `xpcom/base/nsCycleCollector.cpp`.
-   `MOZ_DMD_SHUTDOWN_LOG=$logdir`: This option specifies that we want a
    DMD log to be taken very late in XPCOM shutdown, and the location
    for that log to be saved. Like with the CC log, we want this log
    very late to avoid as many non-leaking things as possible.
-   `MOZ_DMD_LOG_PROCESS=tab`: As with the CC, this means that we only
    want these logs in content processes, in order to make shutdown
    faster. The allowed values here are the same as those returned by
    `XRE_GetProcessType()`, so adjust as needed.
-   Finally, the `--dmd` option need to be passed in so that DMD will be
    run. `--mode=scan` is needed so that when we get a DMD log the
    entire contents of each block of memory is saved for later analysis.

With that command line in hand, you can start Firefox. Be aware that
this may take multiple minutes if you have optimization disabled.

Once it has started, go through the steps you need to reproduce your
leak. If your leak is a ghost window, it can be handy to get an
`about:memory` report and write down the PID of the leaking process. You
may want to wait 10 or so seconds after this to make sure as much as
possible is cleaned up.

Next, exit the browser. This will cause a lot of logs to be written out,
so it can take a while.

## Analyzing the Logs

### Getting the PID and address of the leaking object

The first step is to figure out the **PID** of the leaking process. The
second step is to figure out **the address of the leaking object**,
usually a window. Conveniently, you can usually do both at once using
the cycle collector log. If you are investigating a leak of
`www.example.com`, then from `$logdir` you can do
`"grep nsGlobalWindow cc-edges* | grep example.com"`. This looks through
all of the windows in all of the CC logs (which may leaked, this late in
shutdown), and then filters out windows where the URL contains
`example.com`.

The result of that grep will contain output that looks something like
this:

    cc-edges.15873.log:0x7f0897082c00 [rc=1285] nsGlobalWindowInner # 2147483662 inner https://www.example.com/

cc-edges.15873.log: The first part is the file name where it was
found. `15873` is the PID of the process that leaked. You'll want to
write down the name of the file and the PID. Let's call the file
`$cclog` and the pid `$pid`.

0x7f0897082c00: This is the address of the leaking window. You'll
also want to write that down. Let's call this `$winaddr`.

If there are multiple files, you'll end up with one that looks like
`cc-edges.$pid.log` and one or more that look like
`cc-edges.$pid-$n.log` for various values of `$n`. You want the one with
the largest `$n`, as this was recorded the latest, and so it will
contain the least non-garbage.

### Identifying the root in the cycle collector log

The next step is to figure out why the cycle collector could not collect
the window, using the `find_roots.py` script from the heapgraph
repository. The command to invoke this looks like this:

    python $heapgraph/find_roots.py $cclog $winaddr

This may take a few seconds. It will eventually produce some output.
You'll want to save a copy of this output for later.

The output will look something like this, after a message about loading
progress:

    0x7f0882fe3230 [FragmentOrElement (xhtml) script https://www.example.com]
    --[[via hash] mListenerManager]--> 0x7f0899b4e550 [EventListenerManager]
    --[mListeners event=onload listenerType=3 [i]]--> 0x7f0882ff8f80 [CallbackObject]
    --[mIncumbentGlobal]--> 0x7f0897082c00 [nsGlobalWindowInner # 2147483662 inner https://www.example.com]

Root 0x7f0882fe3230 is a ref counted object with 1 unknown edge(s).
    known edges:
    0x7f08975a24c0 [FragmentOrElement (xhtml) head https://www.example.com] --[mAttrsAndChildren[i]]--> 0x7f0882fe3230
    0x7f08967e7b20 [JS Object (HTMLScriptElement)] --[UnwrapDOMObject(obj)]--> 0x7f0882fe3230

The first two lines mean that the script element `0x7f0882fe3230`
contains a strong reference to the EventListenerManager
`0x7f0899b4e550`. "[via hash] mListenerManager" is a description of
that strong reference. Together, these lines show a chain of strong
references from an object the cycle collector thinks needs to be kept
alive, `0x7f0899b4e550`, to the object` 0x7f0897082c00` that you asked
about. Most of the time, the actual chain is not important, because the
cycle collector can only tell us about what went right. Let us call the
address of the leaking object (`0x7f0882fe3230` in this case)
`$leakaddr`.

Besides `$leakaddr`, the other interesting part is the chunk at the
bottom. It tells us that there is 1 unknown edge, and 2 known edges.
What this means is that the leaking object has a refcount of 3, but the
cycle collector was only told about these two references. In this case,
a head element and a JS object (the JS reflector of the script element).
We need to figure out what the unknown reference is from, as that is
where our leak really is.

### Figure out what is holding the leaking object alive.

Now we need to use the DMD heap scan logs. These contain the contents of
every live block of memory.

The first step to using the DMD heap scan logs is to do some
pre-processing for the DMD log. Stacks need to be symbolicated, and we
need to clamp the values contained in the heap. Clamping is the same
kind of analysis that a conservative GC does: if a word-aligned value in
a heap block points to somewhere within another heap block, replace that
value with the address of the block.

Both kinds of preprocessing are done by the `dmd.py` script, which can
be invoked like this:

    $objdir/dist/bin/dmd.py --clamp-contents dmd-$pid.log.gz

This can take a few minutes due to symbolification, but you only need to
run it once on a log file.

You can also locally symbolicate stacks from DMD logs generated on TreeHerder,
but it will [take a few extra steps](/contributing/debugging/local_symbols.rst)
that you need to do before running `dmd.py`.

After that is done, we can finally find out which objects (possibly)
point to other objects, using the block_analyzer script:

    python $srcdir/memory/replace/dmd/block_analyzer.py dmd-$pid.log.gz $leakaddr

This will look through every block of memory in the log, and give some
basic information about any block of memory that (possibly) contains a
pointer to that object. You can pass some additional options to affect
how the results are displayed. "-sfl 10000 -a" is useful. The -sfl 10000
tells it to not truncate stack frames, and -a tells it to not display
generic frames related to the allocator.

Caveat: I think block_analyzer.py does not attempt to clamp the address
you pass into it, so if it is an offset from the start of the block, it
won't find it.

    block_analyzer.py` will return a series of entries that look like this
    with the [...] indicating where I have removed things):
    0x7f089306b000 size = 4096 bytes at byte offset 2168
    nsAttrAndChildArray::GrowBy[...]
    nsAttrAndChildArray::InsertChildAt[...]
    [...]

`0x7f089306b000` is the address of the block that contains `$leakaddr`.
144 bytes is the size of that block. That can be useful for confirming
your guess about what class the block actually is. The byte offset tells
you were in the block the pointer is. This is mostly useful for larger
objects, and you can potentially combine this with debugging information
to figure out exactly what field this is. The rest of the entry is the
stack trace for the allocation of the block, which is the most useful
piece of information.

What you need to do now is to go through every one of these entries and
place it into three categories: strong reference known to the cycle
collector, weak reference, or something else! The goal is to eventually
shrink down the "something else" category until there are only as many
things in it as there are unknown references to the leaking object, and
then you have your leaker.

To place an entry into one of the categories, you must look at the code
locations given in the stack trace, and see if you can tell what the
object is based on that, then compare that to what `find_roots.py` told
you.

For instance, one of the strong references in the CC log is from a head
element to its child via `mAttrsAndChildren`, and that sounds a lot like
this, so we can mark it as being a strong known reference.

This is an iterative process, where you first go through and mark off
the things that are easily categorizable, and repeat until you have a
small list of things to analyze.

### Example analysis of block_analyzer.py results

In one debugging session where I was investigating the leak from bug
1451985, I eventually reduced the list of entries until this was the
most suspicious looking entry:

    0x7f0892f29630 size = 392 bytes at byte offset 56
    mozilla::dom::ScriptLoader::ProcessExternalScript[...]
    [...]

I went to that line of `ScriptLoader::ProcessExternalScript()`, and it
contained a call to ScriptLoader::CreateLoadRequest(). Fortunately, this
method mostly just contains two calls to `new`, one for
`ScriptLoadRequest` and one for `ModuleLoadRequest`. (This is where an
unoptimized build comes in handy, as it would have pointed out the exact
line. Unfortunately, in this particular case, the unoptimized build was
so slow I wasn't getting any logs.) I then looked through the list of
leaked objects generated by `XPCOM_MEM_BLOAT_LOG` and saw that we were
leaking a `ScriptLoadRequest`, so I went and looked at its class
definition, where I noticed that `ScriptLoadRequest` had a strong
reference to an element that it wasn't telling the cycle collector
about, which seemed suspicious.

The first thing I did to try to confirm that this was the source of the
leak was pass the address of this object into the cycle collector
analysis log, `find_roots.py`, that we used at an earlier step. That
gave a result that contained this:

    0x7f0882fe3230 [FragmentOrElement (xhtml) script [...]
    --[mNodeInfo]--> 0x7f0897431f00 [NodeInfo (xhtml) script]
    [...]
    --[mLoadingAsyncRequests]--> 0x7f0892f29630 [ScriptLoadRequest]

This confirms that this block is actually a ScriptLoadRequest. Secondly,
notice that the load request is being held alive by the very same script
element that is causing the window leak! This strongly suggests that
there is a cycle of strong references between the script element and the
load request. I then added the missing field to the traverse and unlink
methods of ScriptLoadRequest, and confirmed that I couldn't reproduce
the leak.

Keep in mind that you may need to run `block_analyzer.py` multiple
times. For instance, if the script element was being held alive by some
container being held alive by a runnable, we'd first need to figure out
that the container was holding the element. If it isn't possible to
figure out what is holding that alive, you'd have to run block_analyzer
again. This isn't too bad, because unlike ref count logging, we have the
full state of memory in our existing log, so we don't need to run the
browser again.