Features

Debugging Component-Based Memory Leaks

Ernesto Guisado

The best place to catch memory leaks is as close to the source as possible.

The Problem — Leaking Objects

It normally goes like this: the GUI department (programming in VB, Java, C++ Builder, Macromedia Director, or whatever) says the server group (using DCOM/CORBA or some such) isn't releasing all the memory they are using. Before firing up specific memory debugging tools, I resort to a little homegrown C++ class. If I'm lucky it will tell me I'm not releasing several objects. If it doesn't, the memory must be going somewhere else. The class I use for debugging is small, about 30 lines of code. I have used it in several server projects; there is nothing about it specific to COM or CORBA. I've used this class both with Microsoft's ATL or when programming bare-to-the-bones COM.

You can use this class to tell how many objects your class hierarchy has created, when each one was created, and the type of the instantiated object. It's particularly useful to track down reference counting errors (AddRef/Release) in COM servers.

In this article I show how this class works and briefly discuss some alternative approaches I tried before coming up with this solution. Finally, I also include a short Perl script that digests the raw info this class generates and transforms it into a report you can show at meetings.

Logger Output Format

I begin by showing what kind of raw output a user can expect from this logging system. Figure 1 shows an easy-to-parse text format I use often. Since it is comma separated it is easy to parse using Awk or Perl (or even MS-Excel if that is what you like). The source code accompanying this article (see p. 3 for downloading instructions) includes a Perl script for parsing this sort of output, which you can adapt to your own needs. This format is a compromise between readability and size. It is nice to be able to understand the output without using anything more sophisticated than a text editor. On the other side, automatically generated output can easily grow to a size that disallows easy editing.

In Figure 1, a '+' signifies object creation (constructor invoked) and '-' means destruction. The next field is the object ID. Each object created gets a unique ID for identification purposes. The next two fields comprise a time stamp (when was the object created or destroyed). Then there is the memory address and the size of the object. The last field is the class name. In my experience this is more than enough for most cases.

Note that there are several fields missing from the destruction trace (address, size, and class name). This saves some space in the output file; you can always look them up (using the object ID) in the creation trace.

The following code produced the output shown in Figure 1:

unsigned next_id = 0;
FILE* fp = NULL;

void log_create
   (
   unsigned id,
   void* self,
   size_t size,
   const char* name
   )
{
   if (fp == NULL) {
      fp = fopen(LOGFILE, "wt");
      if (fp == NULL) {
         fprintf(stderr,
            "Could not open '%s'.\n",
            LOGFILE);
         exit(-1);
      }
   }
   struct timeb tb; ftime(&tb);
   fprintf(fp, "+, %u, %ld, %hd, "
      "0x%lx, %d, %s\n",
      id, tb.time, tb.millitm,
      self, size, name);
   fflush(fp);
}

void log_delete(unsigned id)
{
   struct timeb tb; ftime(&tb);
   fprintf(fp, "-, %u, %ld, %hd\n",
      id, tb.time, tb.millitm);
   fflush(fp);
}

Notice how I use fflush to make sure everything gets written to disk. This is nice if you are using these functions to track down a core dump.

Earlier Approaches

Before I describe the technique used to create the output in Figure 1, I want to mention a few debugging approaches I used earlier. These are commonly used debugging techniques which, for various reasons, I found unsatisfactory.

Wrapping Allocation/Deallocation

If you create all your objects with new and destroy them with delete, you can create wrapper functions around new and delete that send trace output to a file whenever an object is created or destroyed. This approach has the following drawbacks:

Instrumenting the Constructors and Destructors

Another approach is to modify the constructor and the destructor for each object you want to instrument.

The rationale behind this approach is that the objects' contructors will always be invoked. This is true whether you create an object on the stack, as a global, as a static, or using operator new. All end up calling the constructor. This approach works, but there are several catches:

Using a Trace Object Data Member

A handy property of C++ objects is that any data member is constructed before its containing object and is destroyed after its containing object's destructor is run. These rules can be used to advantage by adding a trace object to the classes that need to monitored:

class log_object {
public:
   log_object()
   {
      log_creation(this,
        "log_object");
   }
   ~log_object()
   {
      log_destruction(this,
         "log_object");
   }
};

class my_document {
private:
   log_object log;
  // Whatever ...
};

This is not enough, though. The trace file needs contextual information, such as the name of the surrounding class (my_document in this case). It would be nice to initialize the trace object within the enclosing class's definition:

class log_object {
public:
log_object(const char* n)
{
name = strdup(n);
log_creation(this, name);
}
~log_object()
{
log_destruction(this, name);
free(name);
} private:
char* name; };

class my_document {
private:
   log_object log = "my_document";   // Not allowed in C++.
  // Whatever ...
};

Alas, this is not allowed in C++. The right way to do it is to use the contructor:

class my_document {
private:
   my_document() : log("my_document") {}
   log_object log;
  // Whatever ...
};

But modifying the contructor is just a slight variation on the second approach given above — an approach I've already shown to have drawbacks.

The Final Solution

My final solution is to use nested classes to create an "informed" trace object data member:

class log_object { public:
log_object(const char* n)
{
name = strdup(n);
log_creation(this, name);
}
~log_object()
{
log_destruction(this, name);
free(name);
} private:
char* name; };

class my_document {
private:
   class my_document_logger :
      public log_object {
   public:
      my_document_logger()
      : log_object("my_document")
      {}
   } log;
  // Whatever ...
};

This works, but it is a little long to write, so I wrap it in a preprocessor macro:

class log_object { public:
log_object(const char* n)
{
name = strdup(n);
log_creation(this, name);
}
~log_object()
{
log_destruction(this, name);
free(name);
} private:
char* name; };

#define OBJECT_LOGGER(name)\
   class _##name##_logger :\
      public log_object {  \
   public:                 \
      _##name##_logger()   \
      : log_object(#name)  \
      {}                   \
   } __##name##_log_object;

class my_document {
   OBJECT_LOGGER(my_document)
  // Whatever ...
};

class my_gizmo {
   OBJECT_LOGGER(my_gizmo)
public:
private:
  // Whatever ...
};

The final solution uses nested class declarations. I want to concentrate all the logging related code in one place — inside the class declaration of the logged object. Nested classes allow just that (as long as only inline functions are used). Here is another fine point: declaring the OBJECT_LOGGER first inside the surrounding class guarantees that the log object will be created first and destroyed last among all the surrounding class's data members (C++'s rules again).

The files log_object.h and log_object.cpp (available on the CUJ ftp site) provide the full implementation for the trace class. The full implementation is not much longer than what I've already shown. It uses a few more variables for file I/O and internal record keeping, but the overall structure remains the same.

A Real-Life Example

Instead of coming up with some contrived example of how to instrument an existing class hierarchy, I show here how to instrument a freely available C++ class hierarchy.

VRML (Virtual Reality Modeling Language) is a fairly common 3-D graphics format. It uses plain text, which makes it a nice choice for several types of applications (particularly as an output format for homegrown tools). As an example of how VRML can be used in such a fashion, see [1]. The starting point for most VRML parsers is QV (Quick VRML parser). VRML is based on Silicon Graphics' 3-D text format for the Open Inventor class library. The author of QV is Paul S. Strauss of Silicon Graphics and the README file states (not surprisingly) it is based on the Open Inventor 2.0.1 source.

To test the trace utilities I have modified the QV class library. I execute the modified sample program travTest, which comes with QV, on a few VRML files to generate trace output. The modified version of QV with VC++ 5.0 project files is included on the CUJ ftp site.

Instrumenting QV

A VRML file has a tree-like structure, in which each 3-D object is a node in a tree:

#VRML V1.0 ascii
Separator {
   PerspectiveCamera { }
   DirectionalLight {
      direction 0 0 -1
   }
   Translation {
      translation 0 0 -3 }
   Sphere { radius .3 }
   Translation {
      translation 0 0 2 }
   Sphere { radius .3 }
}

In QV this snippet indicates there is a QvNode base class and a different class (derived from QvNode) for each VRML node type. Here's a code snippet showing the node for the Sphere node class:

class QvSphere : public QvNode {
    QV_NODE_HEADER(QvSphere);
    // .. Ommited for brevity
};

Note that the QV_NODE_HEADER line looks similar to my OBJECT_LOGGER line. This might simplify things — I could just modify the QV_NODE_HEADER macro and all the QvNode-derived classes will be automatically instrumented. Said and done. This is the macro with my modification emphasized:

#define QV_NODE_HEADER(name) \
/* Begin */ \
class _##name##_logger \
: public log_object { \
public: \
_##name##_logger() \
: log_object(#name) \
{} \
} __##name##_log_object; \
/* End */ \
public: \
name::name(); \
virtual ~name(); \
virtual void \
traverse(QvState *state);
// Rest omitted

Now running travTest on the minimal VRML file shown above produces the output shown in Figure 2.

If you now run the log_analyzer.pl Perl script on the output file (by default, c:\temp\log_obj.txt), it will produce three tab-separated reports. The first report shows a list of class names, with object creation count and average lifetime per class. The second report shows a list of class names sorted by object creation count. The final report shows a list of all created objects with class name, ID, lifetime, and a flag indicating whether the object has been released or not.

Wrap Up

With just a little work I've come up with what I believe is a good solution to the problem stated in the beginning. This trace system requires just one line of code for each class whose objects you want to trace, and the code for the two trace functions (creation and destruction) is about 30 lines long.

Reference

[1] Kent Cearley. "Webview II: Network Mapping with VRML," Web Developer, Vol. 2 No.2, May/June 1996.

Ernesto Guisado works as Software Engineer at Amper Programas S.A., where he is developing Command and Control Systems in C++. You can contact him at erngui@acm.org.