How to debug memory leaks/refcnt leaks

Last update: October 8th, 1999

How to build xpcom with refcnt/memory logging

Built into xpcom is the ability to support the debugging of memory leaks. By default, an optimized build of xpcom has this disabled. Also by default, the debug builds have the logging facilities enabled. You can control either of these options by changing environment variables before you build mozilla:

FORCE_BUILD_REFCNT_LOGGING

If this is defined then regardless of the type of build, refcnt logging (and related memory debugging) will be enabled in the build.
NO_BUILD_REFCNT_LOGGING
If this is defined then regardless of the type of build or of the setting of the FORCE_BUILD_REFCNT_LOGGING, no refcnt logging will be enabled and no memory debugging will be enabled. This variable overrides FORCE_BUILD_REFCNT_LOGGING.
The remaining discussion assumes that one way or another that xpcom has been built with refcnt/memory logging enabled.

How to instrument your objects for refcnt/memory logging

First, if your object is an xpcom object and you use the NS_IMPL_ADDREF and NS_IMPL_RELEASE (or a variation thereof) macro to implement your AddRef and Release methods, then there is nothing you need do. By default, those macros support refcnt logging directly.

If your object is not an xpcom object then some manual editing is in order. The following sample code shows what must be done:

MOZ_DECL_CTOR_COUNTER(MyType);

MyType::MyType()
{
  MOZ_COUNT_CTOR(MyType);
}

MyType::~MyType()
{
  MOZ_COUNT_DTOR(MyType);
}

Now currently the MOZ_DECL_CTOR_COUNTER expands to nothing so your code will compile if you forget to add it; however, we reserve the right to change that so please put it in.

What are those macros doing for me anyway?


NS_IMPL_ADDREF has this additional line in it:

NS_LOG_ADDREF(this, mRefCnt, #_class, sizeof(*this));
What this is doing is logging the addref call using xpcom's nsTraceRefcnt class. The implementation of that macro is:
 
#define NS_LOG_ADDREF(_p, _rc, _type, _size) \
  nsTraceRefcnt::LogAddRef((_p), (_rc), (_type), (PRUint32) (_size))
Which as you can see just passes the buck to nsTraceRefcnt. nsTraceRefcnt implements the logging support and will track addref/release/ctor/dtor calls in a database that it builds up as the program is executing. In a similar manner, NS_IMPL_RELEASE uses NS_LOG_RELEASE which uses nsTraceRefcnt::LogRelease.

For the MOZ_DECL_CTOR_COUNTER, MOZ_COUNT_CTOR and MOZ_COUNT_DTOR macros the expansion boils down to calls to nsTraceRefcnt::LogCtor and nsTraceRefcnt::LogDtor calls. Again, the type of the object is passed in as well as the sizeof of all the data type.

#define MOZ_COUNT_CTOR(_type)                                 \
PR_BEGIN_MACRO                                                \
  nsTraceRefcnt::LogCtor((void*)this, #_type, sizeof(*this)); \
PR_END_MACRO

#define MOZ_COUNT_DTOR(_type)                                 \
PR_BEGIN_MACRO                                                \
  nsTraceRefcnt::LogDtor((void*)this, #_type, sizeof(*this)); \
PR_END_MACRO

What's it good for?

Once you have an instrumented build, you have a fair amount of control over what xpcom will do with the logging calls. Here are the options that you can set using NSPR_LOG_MODULES. The log variable we use is "xpcomrefcnt" and unlike other nspr log variables, it's setting value is a bitfield that controls a set of independent options:
XPCOM_REFCNT_TRACK_BLOAT (0x1)
If this bit is set then xpcom will use the "bloat" trackers. The bloat trackers gather data for the mega turbo bloat vision output that occurs when the program exits or a call to nsTraceRefcnt::DumpStatistics is done.

When an addref/release/ctor/dtor call is made, the data is logged and attributed to the particular data type.

By default enabling this bit will cause the mega turbo bloat vision software to dump out the entire database of collected data. If all you want to see is that data for objects that leaked, set the environment variable MOZ_DUMP_LEAKS.

XPCOM_REFCNT_LOG_ALL (0x2)
Only enable this for severe pain (unless you are using leaky, see below). What this does is to enable logging (to stdout) of each and every call to addref/release without discrimination to the types involved. The output includes mapping the call-stacks at the time of the call to symbolic forms (on platforms that support this) and thus will be *very* *VERY* *VERY* slow. Did I say slow?
 
XPCOM_REFCNT_LOG_SOME (0x4)
Instead of slowing to a useless, instead you can slow to a meer crawl by using this option. When enabled, the xpcom logging software will look for the MOZ_TRACE_REFCNT_TYPES environment variable (for platforms that support getenv). The variable contains a comma seperated list of names which will be used to compare against the type's of the objects being logged. For example:

env MOZ_TRACE_REFCNT_TYPES="nsWebShell" NSPR_LOG_MODULES="xpcomrefcnt:4" ./apprunner

will show you just the addref/release calls to instances of nsWebShell while running apprunner.

XPCOM_REFCNT_LOG_TO_LEAKY (0x8)
For platforms that support leaky, xpcom will endeavor to find at run time the symbols "__log_addref" and "__log_release" and if found, instead of doing the slow painful stack crawls at program execution time instead it will pass the buck to the leaky software. This will allow your program to actually run in user friendly real time, but does require that your platform support leaky. Currently only linux supports leaky.
XPCOM_REFCNT_LOG_CALLS (0x10)
XPCOM_REFCNT_LOG_NEW (0x20)
For losing architectures (those that don't have stack-crawl software written for them), xpcom supports logging at the *call site* to AddRef/Release using the usual cpp __FILE__ and __LINE__ number macro expansion hackery. This results in slower code, but at least you get *some* data about where the leaks might be occurring from.

Using this stuff with leaky

First, setup these environment variables:
setenv LD_PRELOAD ../lib/libleaky.so (assumes you execute apprunner/viewer in the dist/bin directory)
setenv LIBMALLOC_LOG 8 (tells leaky to log addref/release calls)
setenv NSPR_LOG_MODULES "xpcomrefcnt:12" (some logging, use leaky)
setenv MOZ_TRACE_REFCNT_TYPES "a,b,c" (the list of types you care about)
Then run the viewer or the apprunner and run your test. Then exit it. The result will be some large file in your current directory called "malloc-log" and a small file called "malloc-map". If these aren't there then somethings wrong.

If it works properly, then you now have the tracing data for the problem you are chasing in malloc-log. Use leaky to convert it to human readable form and debug away:

leaky -dRq <viewer|apprunner> malloc-log > /tmp/log
Leaky used to require c++filt, but now it does it itself. With the -R option, leaky will only log the refcnts that actually leaked (those that didn't go to zero).

List of environment variables

NSPR_LOG_MODULES
Set this to include "xpcomrefcnt:<value>"
MOZ_TRACE_REFCNT_TYPES
Set this to the list of types that you want traced. Only used when bit 4 is set in xpcomrefcnt

LD_PRELOAD
Set this to the pathname to libleaky.so if you are using leaky to track memory operations.
LIBMALLOC_LOG
Set this to "8" to enable leaky to track addref/release calls that are logged by xpcom. Note that you must set bit 8 in xpcomrefcnt to connect xpcom's tracing to leakys tracing.
MOZ_DUMP_LEAKS
Set this to anything to change the output from turbo mega bloat vision from dumping everything to just dumping the objects that actually leaked.

Sample output

Here is what you get out of turbo mega bloat vision:
                                           Bloaty: Refcounting and Memory Bloat Statistics
     |<-------Name------>|<--------------References-------------->|<----------------Objects---------------->|<------Size----->|
                               Rem    Total      Mean       StdDev       Rem    Total      Mean       StdDev Per-Class      Rem
   1 nsAttributeContent          3       25 (    5.70 +/-     5.14)        3        3 (    2.00 +/-     1.29)       44      132
   4 NameSpaceURIKey             0        0 (     nan +/-      nan)        8      153 (    0.00 +/-      nan)        8       64
   5 nsSupportsArray            25    11690 (  674.48 +/-   673.88)       25     2572 (  492.72 +/-   492.07)       36      900
   9 nsXPCWrappedJS              1        4 (    1.71 +/-     0.97)        1        1 (    1.00 +/-     0.00)       28       28


Here is what you see when you enable some logging with MOZ_TRACE_REFCNT_TYPES set to something:

nsWebShell      0x81189f8       Release 5       nsWebShell::Release(void)+0x59  nsCOMPtr<nsIContentViewerContainer>::~nsCOMPtr(void)+0x34       nsChannelListener::OnStartRequest(nsIChannel *, nsISupports *)+0x550        nsFileChannel::OnStartRequest(nsIChannel *, nsISupports *)+0x7b nsOnStartRequestEvent::HandleEvent(void)+0x46       nsStreamListenerEvent::HandlePLEvent(PLEvent *)+0x62    PL_HandleEvent+0x57     PL_ProcessPendingEvents+0x90    nsEventQueueImpl::ProcessPendingEvents(void)+0x1d   nsAppShell::SetDispatchListener(nsDispatchListener *)+0x3e      gdk_get_show_events+0xbb        g_io_add_watch+0xaa     g_get_current_time+0x136    g_get_current_time+0x6f1        g_main_run+0x81 gtk_main+0xb9   nsAppShell::Run(void)+0x245     nsAppShell::Run(void)+0xc7a92ede   nsAppShell::Run(void)+0xc7a9317c __libc_start_main+0xeb

Here is what you see when you use the leaky tool to dump out addref/release leaks:

addref     082cccc8     0 00000001 --> CViewSourceHTML::AddRef(void) CViewSourceHTML::QueryInterface(nsID &, void **) NS_NewViewSourceHTML(nsIDTD **) .LM708
 GetSharedObjects(void) nsParser::RegisterDTD(nsIDTD *) RDFXMLDataSourceImpl::Refresh(int) nsChromeRegistry::InitRegistry(void) nsChromeProtocolHandler::New
Channel(char *, nsIURI *, nsILoadGroup *, nsIEventSinkGetter *, nsIChannel **) nsIOService::NewChannelFromURI(char *, nsIURI *, nsILoadGroup *, nsIEventSink
Getter *, nsIChannel **) NS_OpenURI(nsIChannel **, nsIURI *, nsILoadGroup *, nsIEventSinkGetter *) NS_OpenURI(nsIInputStream **, nsIURI *) CSSLoaderImpl::Lo
adSheet(URLKey &, SheetLoadData *) CSSLoaderImpl::LoadChildSheet(nsICSSStyleSheet *, nsIURI *, nsString &, int, int) CSSParserImpl::ProcessImport(int &, nsS
tring &, nsString &) CSSParserImpl::ParseImportRule(int &) CSSParserImpl::ParseAtRule(int &) CSSParserImpl::Parse(nsIUnicharInputStream *, nsIURI *, nsICSSS
tyleSheet *&) CSSLoaderImpl::ParseSheet(nsIUnicharInputStream *, SheetLoadData *, int &, nsICSSStyleSheet *&) CSSLoaderImpl::LoadAgentSheet(nsIURI *, nsICSS
StyleSheet *&, int &, void (*)(nsICSSStyleSheet *, void *), void *) nsLayoutModule::Initialize(void) nsLayoutModule::GetClassObject(nsIComponentManager *, n
sID &, nsID &, void **) nsNativeComponentLoader::GetFactoryFromModule(nsDll *, nsID &, nsIFactory **) nsNativeComponentLoader::GetFactory(nsID &, char *, ch
ar *, nsIFactory **) .LM1381 nsComponentManagerImpl::FindFactory(nsID &, nsIFactory **) nsComponentManagerImpl::CreateInstance(nsID &, nsISupports *, nsID &
, void **) nsComponentManager::CreateInstance(nsID &, nsISupports *, nsID &, void **) RDFXMLDataSourceImpl::Refresh(int) nsChromeRegistry::InitRegistry(void
) nsChromeProtocolHandler::NewChannel(char *, nsIURI *, nsILoadGroup *, nsIEventSinkGetter *, nsIChannel **) nsIOService::NewChannelFromURI(char *, nsIURI *
, nsILoadGroup *, nsIEventSinkGetter *, nsIChannel **) NS_OpenURI(nsIChannel **, nsIURI *, nsILoadGroup *, nsIEventSinkGetter *) nsDocumentBindInfo::Bind(ns
IURI *, nsILoadGroup *, nsIInputStream *, unsigned short *) nsDocLoaderImpl::LoadDocument(nsIURI *, char *, nsIContentViewerContainer *, nsIInputStream *, n
sISupports *, unsigned int, unsigned int, unsigned short *) nsWebShell::DoLoadURL(nsIURI *, char *, nsIInputStream *, unsigned int, unsigned int, unsigned s
hort *) nsWebShell::LoadURI(nsIURI *, char *, nsIInputStream *, int, unsigned int, unsigned int, nsISupports *, unsigned short *) nsWebShell::LoadURL(unsign
ed short *, char *, nsIInputStream *, int, unsigned int, unsigned int, nsISupports *, unsigned short *) nsWebShell::LoadURL(unsigned short *, nsIInputStream
 *, int, unsigned int, unsigned int, nsISupports *, unsigned short *) nsWebShellWindow::Initialize(nsIWebShellWindow *, nsIAppShell *, nsIURI *, int, int, n
sIXULWindowCallbacks *, int, int, nsWidgetInitData &) nsAppShellService::JustCreateTopWindow(nsIWebShellWindow *, nsIURI *, int, int, unsigned int, nsIXULWi
ndowCallbacks *, int, int, nsIWebShellWindow **) nsAppShellService::CreateTopLevelWindow(nsIWebShellWindow *, nsIURI *, int, int, unsigned int, nsIXULWindow
Callbacks *, int, int, nsIWebShellWindow **) OpenChromURL(char *, int, int) HandleBrowserStartup(nsICmdLineService *, nsIPref *, int) DoCommandLines(nsICmdL
ineService *, int) main1(int, char **) main __libc_start_main