Investigating Memory Leaks with Dtrace

Authors: Pascal Danek, Reuters Financial Software, France - Claude Teissedre, Oracle France


Introduction

This article shows a real case of DTrace framework usage to detect undeleted objects in a C++ application running on Solaris 10. In this case context, undeleted objects refer to temporary business objects that are explicitly created, with the new() operator, but never destroyed. This behavior, comparable in its effects to the so-called memory leak1, may lead to a significant unwanted increase in memory usage and cause paging activity on the system, or even generate new objects creation failures with applications which create objects iteratively.

Since the non-deletion of these business objects is not the result of bad pointers but rather of an incorrect cache management in the application, specialized memory-leaks tracking tools which look after allocated memory chunks-pointers inconsistencies do not detect this type of undeleted objects. For instance, Oracle Solaris Discovery tool2 or Oracle Solaris libumem audit facility3, as well as Rational Purify or gdb are ineffective in this situation4.

A new tool based on DTrace and perl scripts was developed to address this specific need and is usable with all programs that have iterative objects creation and deletion patterns similar to our case described below. The tool requires no binary change and is easy to use. It has demonstrated its efficiency at a customer site on a pre-production system in finding the leak in a couple of minutes, where the traditional methods failed after days of investigations.


The principle

Rather than building a fully automatized tool that would be highly dependent on the application and complex to write, we choose a more simple implementation that allowed to get results quickly. The choice was so to write generic scripts (independent of the application) with part of the program logic passed as arguments and a final manual analysis of the selected user stacks.

The principle of our method is to record the objects creation and deletion within the program into a file5 and then post-process this file to detect the mis-undeleted objects based on specific program logic data.

- The program itself implements the following iterative process:

  • The program is launched

  • An action (A1) (import or whatever process) is started. This initial action allocates temporary memory for itself and permanent memory for object that will exist all along the process life (the cache initialization for ex.). As those latter objects could appear as false positive, A1 is discarded from the scope of the analysis.

  • A second action (A2) is started. It is identical to A1 except that it allocated memory for itself only and free the temporary objects created in A1.

  • A third action (A3) , identical to A2, is started and, similarly to A2, it allocated memory for itself and free the temporary objects of the previous step (A2 so).

Since A2 and A3 actions are identical and use the same iterative object’s creation-deletion mechanism, objects created in A2 but not freed after A3 are the potential memory leaks we are looking for. This is illustrated in the fig. below where the letters 'b' and 'e' indicate the area where to search the memory leaks.


- The recording step is based on a dtrace script (watch-memory-usage.d) and contains no business logic, it merely traces the new() and delete() operators, records the user stack a timestamp and tags (iterator ids) at the time the probes are fired as described in the next section.

- The detection step is a postmortem process based on a perl script (findleaks.pl), also independent of the application, which analyzes the output file of the dtrace script and looks for objects (allocated in A2 and not freed after A3) in a given search area.

The full sequence of commands writes:

  • % a.out & // start the program

  • % sudo watch-memory-usage.d pid > leaks.txt

  • Launch action 1, then 2, then 3. Wait for a while between actions and note the launching time for each

  • Stop the dtrace with CTRL-C after 3

  • % cat leaks.txt | c++filt > leaks-dem.txt // demangle the output file

  • Locate in the file the time range between 1 and 2 and retrieve the appropriate sequence ids (tags)

  • % findleaks.pl -f leaks-dem.txt -b begin_id -e end_id

As noted before, the business logic is introduced manually into the perl script through the arguments -b and -e that delimit the search area. The actual implementation somewhat differ slightly from this sequence whose main interest is to detail the necessary steps of the process.

The dtrace script

The DTrace framework6 provides a set of kernel modules called providers, each of which performs dynamically a particular kind of instrumentation of the kernel or the application. The pid provider which allows to trace functions entry and return in user programs is the most appropriate provider to trace the new() and delete() operators7. Since DTrace instruments the excutable program in which the C++ function names are mangled, those mangled names must be used in the probes specifications, that is:

__1c2n6FI_pv_ for new() and 1c2k6Fpv_v_ for delete().

The mangled names can be obtained from the executable program by

# dem `nm a.out | awk -F\| '{ print $NF; }'` | egrep "new|delete"
__1c2k6Fpv_v_ == void operator delete(void*)
__1c2n6FI_pv_ == void*operator new(unsigned)

The arguments to entry probes are the values of the arguments to the traced function. The arguments to return probes are the offset in the function of the return instruction (arg0) and the return value (arg1).

The full sript watch-memory-usage.d is

#!/usr/sbin/dtrace -s
#pragma D option quiet
/*
   __1c2n6FI_pv_ == void*operator new(unsigned)
   __1c2k6Fpv_v_ == void operator delete(void*)
*/

pid$1::__1c2n6FI_pv_:entry
{
   self->size = arg0;
}

pid$1::__1c2n6FI_pv_:return
/self->size/
{
   addresses[arg1] = 1;
   /* print details of the allocation */
   /* seq_id;event;tid;address;size;datetime */
printf("<__%i;%Y;%d;new;0x%x;%d;\n",
   i++, walltimestamp, tid, arg1, self->size);
   ustack(50);
   printf("__>\n\n");
   @mem[arg1] = sum(1);
   self->size=0;
}

pid$1::__1c2k6Fpv_v_:entry
/addresses[arg0]/
{
   @mem[arg0] = sum(-1);
   /* print details of the deallocation */
   /* seq_id;event;tid;address;datetime */
   printf("<__%i;%Y;%d;delete;0x%x__>\n",
   i++, walltimestamp, tid, arg0);
}

END
{
   printf("== REPORT ==\n\n");
   printa("0x%x => %@u\n",@mem);
}

Whenever an object is created, the script records it's size (arg0 on entry) and address (arg1 on return), the user stack (ustack()), a timestamp and an iterator id. When the object is deleted, the script records it's address (arg0 on entry) and other parameters. Finally, the aggregating array8 @mem[object's address] set to 1 when the object is created, and set to 0 when it is deleted, is printed when the script ends. This array will be used to find the undeleted objects in the postmortem analysis.

Finally, the output file must be demangled for the post-processing phase as shown above. 

The perl script

The leaks-dem.txt file records demangled raw data from the dtrace script. It contains all the necessary info to sort out the memory leaks but contains no program logic info, such as the timestamps corresponding to the beginning of the 3 actions executed. Parsing the file (this is the main function of the perl script9) and using the hand-noted times when the actions were started allow to retrieve the appropriate sequence ids of these actions (the id is the first field of each new record in leaks-dem.txt). In our case, ids 2968 and 3511 correspond to the boundaries of action A2. The search object's satisfy the following conditions:

       @mem[object_address] = 1
        2968 ≤ object_id ≤ 3511

The perl script command line writes:

% findleaks.pl -f leaks-dem.txt -b 2968 -e 3511

and outputs a list of aggregated stack sorted by memory consumption, with the number of occurrences, corresponding to the potential leaks. That is:

Suspicious addresses are: // @mem[object_address] = 1
- 0xf0ed28
- 0xf0edc8
- 0xf0efa8
- 0xf0f048
- 0x20dc968
- 0x20ea9c8

Addresses in specified range are: / 2968 object_id 3511
- 0xf0ed28
- 0xf0f048
- 0xf0efa8
- 0xf0edc8

Found 2 stacks

Saw 2 times:
It consumed 256 bytes
Addresses with this stack: 0xf0ed28,0xf0f048,
Stack:

libCrun.so.1`void*operator new(unsigned)+0x68
libinfracpptools27c.so`void std::deque<ITH_Notifier::Client*>::__allocate_at_end()+0x84
libinfracpptools27c.so`bool ITH_Notifier::ClientMgr::dispatch(ITH_NotifyQueue*,ITH_Notifier&,unsigned long)+0x300
libinfracpptools27c.so`bool ITH_NTFPipe::dispatch()+0x34
libKNETAdapter.so`void*listeningThread(void*)+0x148
libinfracpptools27c.so`ITH_TreadFuncWrapper+0x8
libc.so.1`_lwp_start

Saw 2 times:
It consumed 256 bytes
Addresses with this stack: 0xf0efa8,0xf0edc8,
Stack:

libCrun.so.1`void*operator new(unsigned)+0x68
libinfracpptools27c.so`void std::deque<ITH_Notifier::Client*>::__allocate_at_end()+0x24
libinfracpptools27c.so`bool ITH_Notifier::ClientMgr::dispatch(ITH_NotifyQueue*,ITH_Notifier&,unsigned long)+0x300
libinfracpptools27c.so`bool ITH_NTFPipe::dispatch()+0x34
libKNETAdapter.so`void*listeningThread(void*)+0x148
libinfracpptools27c.so`ITH_TreadFuncWrapper+0x8
libc.so.1`_lwp_start

Footnotes

1 A memory leak occurs when a computer program consumes memory but is unable to release it back to the operating system or to the application. However, many people refer to any unwanted increase in memory usage, because for instance of a wrong cache management, as a memory leak, though this is not strictly accurate.

2 Oracle Discovery tool is a new tool for memory checking, available in Solaris Studio 12 update 2.

3 Libumem is a library, first introduced in Solaris 9 Update 3, used to detect memory management bugs in applications. See http://blogs.sun.com/dlutz/entry/memory_leak_detection_with_libumem

4 Actually, Discovery reports memory blocks allocated on the heap but not released at program exit.

5 Recording into a file allows to overcome the memory size limit of the script

6 DTrace is a comprehensive dynamic tracing facility built into Solaris which enables administrators and developers to examine the behavior of user programs as well as the behavior of the operating system.
Documentation: Solaris Dynamic Tracing Guide, Part No: 817–6223–12, September 2008, http://download.oracle.com/docs/cd/E19253-01/817-6223/817-6223.pdf. Community: http://hub.opensolaris.org/bin/view/Community+Group+dtrace/WebHome

7 The method was initially developed in 2005 in the paper “Using DTrace to Profile and Debug A C++ Program” by Jay Danielsen, published at http://developers.sun.com/solaris/articles/dtrace_cc.html

8 Implementation notes: a) Although it is indexed by an integer value, addresses[] is an associative array. b) Using an aggregation is the only way to be able to print the full array at once.

9 The perl script main function is to parse the output of the dtrace script. It is not included in this paper since it has no educational content related to our topic. It will be provided on demand.

Comments:

Hello,

Please email me a copy of the source for the findleaks.pl script.

Thanks,
Tony

Posted by Tony Saramosing on December 05, 2012 at 04:52 PM CET #

Hello

please send me findleaks.pl script too

Thanks
Danny

Posted by Danny on January 17, 2013 at 06:12 PM CET #

Hello

please send me findleaks.pl script too

Thanks
Mauro

Posted by guest on March 21, 2013 at 12:34 PM CET #

Hello

please send me findleaks.pl script too

Thanks
Mauro

Posted by guest on March 21, 2013 at 12:36 PM CET #

Hello

please send me findleaks.pl script too

Thanks
Mauro

Posted by guest on March 21, 2013 at 12:38 PM CET #

Hello

Please send me findleaks.pl script

Thanks
David

Posted by guest on June 13, 2013 at 07:16 AM CEST #

Please send me the findleaks.pl

Posted by guest on July 01, 2013 at 11:11 PM CEST #

I am getting the following REPORT while running the d script in a production environment.
0x7fade398dc30 => 18446744073709549605
0x7fade5571d60 => 18446744073709550104
0x7fade4e8ef20 => 18446744073709550106
0x7fade31304f0 => 18446744073709550801
0x7fade31c1170 => 18446744073709550839
0x7fade25ef480 => 0
0x7fade25ef4b0 => 0
0x7fade25ef4f0 => 0
0x7fade25ef520 => 0
0x7fade25ef570 => 0
0x7fade25ef580 => 1
0x7fade25ef5c0 => 1
0x7fade25ef610 => 1
0x7fade25ef620 => 1
....

If you see the first few lines of the report it is showing some arbitrary values instead of 0 or 1. Why so?

Posted by guest on July 03, 2013 at 11:36 PM CEST #

The scripts provided have been developed for the Solaris10 OS and might not work another platform (sol11 or Mac OS X for ex.). They are however easily adaptable by looking at the system calls probes and their arguments, and ustack().

Posted by user13343174 on September 17, 2013 at 04:27 PM CEST #

Please send me findleaks.pl script.

Thank you

Posted by Zozos on September 25, 2013 at 11:56 PM CEST #

Please send me findleaks.pl script.

Thank you

Posted by guest on September 25, 2013 at 11:57 PM CEST #

Please send me findleaks.pl script.

Thank you

Posted by guest on September 25, 2013 at 11:58 PM CEST #

Hello,

Please send me findleaks.pl script.

Thanking you,
Salar

Posted by guest on September 26, 2013 at 12:00 AM CEST #

Hi,

Very good script I fasted found two memory leaks.

Note that it is not possible to probe by dtrace the return of new in x86 architecture.
So the procedure work only on sparc.

THANKS!

Posted by guest on October 09, 2013 at 12:30 PM CEST #

Hello,

Please send me findleaks.pl script.

Thanks,

Marc

Posted by guest on October 25, 2013 at 05:49 PM CEST #

This is a nice and useful one.
Could you please send me the perl script findleaks.pl.
Thanks a lot in advance.

Posted by Jai on November 19, 2013 at 06:55 AM CET #

This is a nice and useful one.
Could you please send me the perl script findleaks.pl.
Thanks a lot in advance.

Posted by guest on November 19, 2013 at 07:30 AM CET #

Hello again,
This is is Vijay.
Thanks for the findleaks script anyway. It was really good to know.
I thought of changing this this so that we have all the memory leaks instead of leaks between a range.
So I thought of introducing one more perl script which will give the complete leaks in a simpler manner.

The logic is store the addresses as keys and the complete callstack as the value. If there is an address already existing then simply replace the callstack.This will make sure the callstack of last allocation is preserved for any address.

SO after the report is encountered I will take only the callstacks of those addresses where the counter is not 0(=> 0).
This way i can output only those memory address and their corresponding stacks whereever leaks are occured.
Below is the script i have written.

#!usr/bin/perl -w

use strict;
use Data::Dumper;

open(FILE,"memleaks.txt");
my $start=0;
my $collect=0;
my @callstack;
my %leaks;
my @addresses_leaked;
my $address;
while(<FILE>)
{
if($collect==1)
{
if(/(.*?) => / && $_!~m/=> 0/)
{
push @addresses_leaked,$1;
}
}
if(/^\<__/ && /\;new\;([^\;]*);/)
{
$address=$1;
$start=1;
}
if($start==1)
{
push @callstack,$_;
}
if(/^__>$/)
{
@{$leaks{$address}}=@callstack;
undef @callstack;
$start=0;
}
if(/== REPORT ==/)
{
$collect=1;
}
}

print $_."\n"."@{$leaks{$_}}" for(keys %leaks)

Posted by guest on November 21, 2013 at 10:23 AM CET #

Sounds interesting, what about new[] and older malloc/realloc/free, can these be traced in the same way?

Could you please send me the perl script findleaks.pl.

Thanks a lot in advance.

Posted by guest on November 26, 2013 at 09:31 AM CET #

The findleaks.pl script

#!/usr/bin/perl -w

use strict;

# Modules
use Getopt::Std;
use Fatal(qw/open close/);
use Data::Dumper;

my %opts;
getopts('b:e:f:', \%opts);

&check_opts;

# Non-freed addresses list
my @addresses;

# Report boundary
my $report_boundary = "== REPORT ==";
my $in_report=0;

# open file
open my $fh, '<', $opts{f};

# Get the non freed addresses
while(my $line = <$fh>){
chomp $line;

if( $line eq $report_boundary ){
$in_report=1;
next;
}

# Waiting for the report section
next if !$in_report;

# Not an address
next unless my ($addr, $state) = $line =~ /^(0x\w+) => (\d+)$/;

# Freed address
next if $state==0;
push @addresses, $addr;
}

print "Suspicious addresses are:\n";
print "\t- $_\n" for @addresses;
print "\n\n";

# Reparse the file for events (delete and news)
# only for suspicious addresses
seek($fh,0,0);
my(@fields, $in_element, $stack, %event_at, %new_event_for);
while(my $line = <$fh>){
# Line without markers
my $escaped_line;
$escaped_line = $line;
$escaped_line =~ s/<__//;
$escaped_line =~ s/__>//;

# start element
if( $line =~ /^<__/ ){
@fields = split ';', $escaped_line;
map chomp $_, @fields;
# We skip the entry if the address is not any of the suspicious ones
next if !grep /^\Q$fields[4]\E$/, @addresses;
$in_element=1;
}
else{
# Keeping element content (stack)
$stack .= $escaped_line if $in_element;
}

# End of element
if( $line =~ /__>$/ and $in_element ){
# We have details in @fields
# We have stack in $stack if it's a new
# We log the chronological event in a clean data structure
my $seq_id = $fields[0];
$event_at{$seq_id} = {
nanots => $fields[1],
tid => $fields[2],
event => $fields[3],
address => $fields[4],
# Optionnal (only for new)
size => $fields[5],
stack => $stack,
seq_id => $seq_id,
};

# Cleaning state and close element
$stack = '';
@fields = ();
$in_element=0;
}
}

# We don't need the file anymore
close $fh;

# Here we have all interesting events
# We have to sort new, and then to keep only the last for each address
# We store for each address the new() informations
my %last_new_at;
for my $seq_id (sort {$a<=>$b} keys %event_at){
my $address = $event_at{$seq_id}->{address};
$last_new_at{$address} = $event_at{$seq_id};
}

# Here we have in %last_new_at the latest allocations
# We can get the stacks and report statistics (count and sizes)
my %leaks_for;
for my $address (keys %last_new_at){
next if $last_new_at{$address}->{seq_id} < $opts{b}
or $last_new_at{$address}->{seq_id} > $opts{e};

my $stack = $last_new_at{$address}->{stack};
$leaks_for{ $stack } = []
if !defined $leaks_for{ $stack };
push @{ $leaks_for{ $stack } }, {
address => $address,
size => $last_new_at{$address}->{size},
tid => $last_new_at{$address}->{tid},
};
}

# Now we compute and display the user report
my( %leak_size_for, %leak_addresses_for, %leak_tid_for, %leak_count_for );
for my $stack (keys %leaks_for){
for my $hash_ref ( @{ $leaks_for{$stack} } ){
# No size==no leak.
# Allow to filter the allocations outside the user specified range
next if !$hash_ref->{size};
# We compute the size for a given stack
# This will allow developer to adress the issues by priority
$leak_size_for{ $stack } += $hash_ref->{size};
# Number of occurrences
$leak_count_for{$stack}++;
# THen we keep informations useful to check from the original file
# Addresses
$leak_addresses_for{$stack} = [] if !defined $leak_addresses_for{$stack};
push @{ $leak_addresses_for{$stack} }, $hash_ref->{address};
# Thread ids
$leak_tid_for{$stack} = [] if !defined $leak_tid_for{$stack};
push @{ $leak_tid_for{$stack} }, $hash_ref->{tid};
}
}

# Display report
if(!keys %leak_size_for){
print "No leaks found in specified range\n";
exit;
}
print 'Addresses in specified range are:', "\n";

for my $stack ( keys %leak_addresses_for ){
print "\t - $_\n" for @{ $leak_addresses_for{$stack} };
}
print "\n";

print 'Found ', scalar keys %leak_size_for, " stacks\n\n";
for my $stack ( sort {$leak_size_for{$b} <=> $leak_size_for{$a}} keys %leak_size_for ){
print 'Saw ', $leak_count_for{$stack}, " times:\n";
print 'It consumed ', $leak_size_for{$stack}, " bytes\n";
print 'Addresses with this stack: ';
print join ',', @{ $leak_addresses_for{$stack} }, "\n";
print "Stack:\n";
print $stack, "\n";
}

############
# ROUTINES #
############

sub check_opts{
die "Please specify a begin sequence id (-b)\n" if !defined $opts{b};
die "Please specify a end sequence id (-e)\n" if !defined $opts{e};
die "-e must be greater than -b" if $opts{b}>=$opts{e};
die "Please specify an input memory file (-f)\n" if !defined $opts{f};
}

Posted by guest on December 04, 2013 at 04:19 PM CET #

Mangled C++ symbols can be traced in the same way as the new() and delete() operators in the article. See this ref. paper:

Using DTrace to Profile and Debug A C++ Program:
http://www.oracle.com/technetwork/server-storage/solaris/dtrace-cc-138561.html

Note: On Mac OS X (V10.9), by default, dtrace uses the demangled names of C++ symbols. You can tell dtrace to use the mangled symbol names by passing -xmangled to the command.

Claude

Posted by guest on December 04, 2013 at 04:21 PM CET #

Post a Comment:
  • HTML Syntax: NOT allowed
About

How open innovation and technology adoption translates to business value, with stories from our developer support work at Oracle's ISV Engineering.

Subscribe

Search

Categories
Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
5
6
8
9
10
11
12
13
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today
Feeds