Changeset 2d9e75d

Timestamp:

07/22/15 14:18:06 (9 years ago)

Author:

Hal Finkel <hfinkel@…>

Branches:

master

Children:

96927c5

Parents:

09f3093 (diff), 3c9fc94 (diff)
Note: this is a merge changeset, the changes displayed below correspond to the merge itself.
Use the (diff) links above to see all the changes relative to each parent.

git-author:

Hal Finkel <hfinkel@…> (07/22/15 14:18:06)

git-committer:

Hal Finkel <hfinkel@…> (07/22/15 14:18:06)

Message:

Merge branch 'master' of git.mcs.anl.gov:memlog

Files:

• Makefile (modified) (2 diffs)
• README (modified) (3 diffs)
• memlog.cpp (modified) (16 diffs)
• memlog_analyze (moved) (moved from memlog2dot) (11 diffs)
• COPYING (added)

Makefile

@@ -2 +2 @@
 CXXFLAGS = -std=gnu++0x -O3 -g
 
-CPPFLAGS =
+# When compiling with CXX=powerpc64-bgq-linux-g++, we need these:
+CPPFLAGS = -I/bgsys/drivers/ppcfloor -I/bgsys/drivers/ppcfloor/spi/include/kernel/cnk
+
 LDFLAGS = -lpthread -ldl
 
@@ -16 +18 @@
         $(CXX) $(CPPFLAGS) $(CXXFLAGS) $(LDFLAGS) -fPIC -shared -o libmemlog.so memlog.cpp
 
-install: all memlog2dot README
-        cp -a libmemlog.so memlog_s.o memlog2dot README $(DESTDIR)/
+install: all memlog_analyze README
+        cp -a libmemlog.so memlog_s.o memlog_analyze README $(DESTDIR)/
+        echo '-Wl,--wrap,malloc,--wrap,valloc,--wrap,realloc,--wrap,calloc,--wrap,memalign,--wrap,free,--wrap,posix_memalign,--wrap,mmap,--wrap,mmap64,--wrap,munmap $(DESTDIR)/memlog_s.o -lpthread -ldl' > $(DESTDIR)/memlog_s_ld_cmds
 
 clean:

README

@@ -16 +16 @@
       -L/path/to/memlog -Wl,-rpath,/path/to/memlog -lmemlog
 
-For statically-linked applications, add the following to your linker flags:
+For statically-linked applications ld's automatic wrapping functionality is
+employed, and the exact set of necessary flags is large, so a file named
+memlog_s_ld_cmds has been provided containing the necessary flags.
 
-  -Wl,--wrap,malloc,--wrap,free,--wrap,realloc,--wrap,calloc,--wrap,memalign \
-    /path/to/memlog/memlog_s.o -lpthread -ldl
+To your linker flags add:
+
+  `cat /path/to/memlog/memlog_s_ld_cmds`
+
+or, if your compiler and wrappers support response files (gcc and clang do, for
+example), simply:
+
+  @/path/to/memlog/memlog_s_ld_cmds
+
+so your overall linking command might look something like this:
+
+  mpic++ -O3 -g -o my_program my_obj1.o my_obj2.o @/path/to/memlog/memlog_s_ld_cmds
 
 ** RUNNING **
@@ -29 +41 @@
 use by running:
 
-  /path/to/memlog/memlog2dot /path/to/HOST.PID.memlog
+  /path/to/memlog/memlog_analyze /path/to/HOST.PID.memlog
 
 this will generate files named HOST.PID.memlog.dot, HOST.PID.memlog.ps and
@@ -36 +48 @@
 in textual form.
 
+If you pass the --leaks option to memlog_analyze, it will provide data on
+allocations active at the end of the program (leaks) instead of those active
+when the peak memory usage is first reached.
+
+You might have many runs of the same application (or output from many ranks of
+an MPI job), and you'd like to pick the one for analysis with the highest
+memory usage. If you provide a glob pattern to memlog_analyze it will do this
+for you. Make sure you quote the glob pattern so that your shell does not
+expand it.
+
+  /path/to/memlog/memlog_analyze "/path/to/*.memlog"
+
+When running under common batch systems, the files are named
+JOB_ID.HOST.PID.memlog, and when running under the BG/Q CNK, the process's rank
+is used instead of the node-local PID.
+
 Note that te peak memory usage is determined by monitoring the processes's
 maximum resident set size, not just the total allocated heap memory.
 
-memlog2dot depends on dot (from the graphviz package) and ps2pdf (from the
+memlog_analyze takes, as a second optional parameter, the name of the output
+directory (the current directory is the default). If the directory does not
+exist, it will be created.
+
+memlog_analyze depends on dot (from the graphviz package) and ps2pdf (from the
 ghostscript package), plus various tools from the binutils package.
 

memlog.cpp

@@ -45 +45 @@
 #include <cstdio>
 #include <cstring>
+#include <cstdint>
 
 // NOTE: This source makes very minimal use of C++11 features. It can still be
@@ -52 +53 @@
 
 #include <limits.h>
+#include <errno.h>
 #include <malloc.h>
 #include <execinfo.h>
+#include <sys/mman.h>
 #include <sys/syscall.h>
 #include <sys/time.h>
@@ -66 +69 @@
 #include <dlfcn.h>
 
+#ifdef __bgq__
+#include <spi/include/kernel/location.h>
+#include <spi/include/kernel/memory.h>
+#endif
+
 using namespace std;
 
@@ -72 +80 @@
 //   -Wl,--wrap,malloc,--wrap,free,--wrap,realloc,--wrap,calloc,--wrap,memalign /path/to/memlog_s.o -lpthread -ldl
 
-FILE *log_file = NULL;
+static FILE *log_file = 0;
 static pthread_mutex_t log_mutex = PTHREAD_MUTEX_INITIALIZER;
 
@@ -80 +88 @@
 static char self_path[PATH_MAX+1] = { '\0' };
 
+#ifdef __bgq__
+static int on_bgq = 0;
+#endif
+
+static void *initial_brk = 0;
+
+static unordered_map<void *, Dl_info> *dladdr_cache = 0;
+
 __attribute__((__constructor__))
 static void record_init() {
@@ -85 +101 @@
   uname(&u);
 
+  int id = (int) getpid();
+#ifdef __bgq__
+  // If we're really running on a BG/Q compute node, use the job rank instead
+  // of the pid because the node name might not really be globally unique.
+  if (!strcmp(u.sysname, "CNK") && !strcmp(u.machine, "BGQ")) {
+    id = (int) Kernel_GetRank();
+    on_bgq = 1;
+  }
+#endif
+
+  // If we're running under a common batch system, add the job id to the output
+  // file names (add it as a prefix so that sorting the files will sort by job
+  // first).
+  char *job_id = 0;
+  const char *job_id_vars[] =
+    { "COBALT_JOBID", "PBS_JOBID", "SLURM_JOB_ID", "JOB_ID" };
+  for (int i = 0; i < sizeof(job_id_vars)/sizeof(job_id_vars[0]); ++i) {
+    job_id = getenv(job_id_vars[i]);
+    if (job_id)
+      break;
+  }
+
   char log_name[PATH_MAX+1];
-  snprintf(log_name, PATH_MAX+1, "%s.%d.memlog", u.nodename, getpid());
+  if (job_id)
+    snprintf(log_name, PATH_MAX+1, "%s.%s.%d.memlog", job_id, u.nodename, id);
+  else
+    snprintf(log_name, PATH_MAX+1, "%s.%d.memlog", u.nodename, id);
   log_file = fopen(log_name, "w");
   if (!log_file)
@@ -93 +134 @@
   const char *link_name = "/proc/self/exe";
   readlink(link_name, self_path, PATH_MAX);
+
+  initial_brk = sbrk(0);
 }
 
@@ -110 +153 @@
   (void) fflush(log_file);
   (void) fclose(log_file);
+
+  if (dladdr_cache)
+    delete dladdr_cache;
 }
 
@@ -115 +161 @@
 // we need to cache the lookup results.
 static int dladdr_cached(void * addr, Dl_info *info) {
-  static unordered_map<void *, Dl_info> dladdr_cache;
-
-  auto I = dladdr_cache.find(addr);
-  if (I == dladdr_cache.end()) {
+  if (!dladdr_cache)
+    dladdr_cache = new unordered_map<void *, Dl_info>;
+
+  auto I = dladdr_cache->find(addr);
+  if (I == dladdr_cache->end()) {
     int r;
     if (!(r = dladdr(addr, info)))
       memset(info, 0, sizeof(Dl_info));
 
-    dladdr_cache.insert(make_pair(addr, *info));
+    dladdr_cache->insert(make_pair(addr, *info));
     return r;
   }
@@ -140 +187 @@
   fprintf(log_file, "\t%ld.%06ld %ld %ld", usage.ru_utime.tv_sec,
           usage.ru_utime.tv_usec, usage.ru_maxrss, syscall(SYS_gettid));
+
+  // Some other memory stats (like with maxrss, report these in KB).
+  size_t arena_size = ((size_t) sbrk(0)) - (size_t) initial_brk;
+
+  uint64_t mmap_size = 0;
+#ifdef __bgq__
+  if (on_bgq)
+    (void) Kernel_GetMemorySize(KERNEL_MEMSIZE_MMAP, &mmap_size);
+#endif
+
+  fprintf(log_file, " %ld %ld", arena_size >> 10, mmap_size >> 10);
 
   if (!show_backtrace)
@@ -233 +291 @@
 }
 
+#ifdef __PIC__
+static int (*__real_posix_memalign)(void **memptr, size_t alignment,
+                                    size_t size) = 0;
+
+static void *(*__real_mmap)(void *addr, size_t length, int prot, int flags,
+                            int fd, off_t offset) = 0;
+static void *(*__real_mmap64)(void *addr, size_t length, int prot, int flags,
+                              int fd, off64_t offset) = 0;
+static int (*__real_munmap)(void *addr, size_t length) = 0;
+#else
+extern "C" {
+extern int __real_posix_memalign(void **memptr, size_t alignment, size_t size);
+
+extern void *__real_mmap(void *addr, size_t length, int prot, int flags,
+                         int fd, off_t offset);
+extern void *__real_mmap64(void *addr, size_t length, int prot, int flags,
+                           int fd, off64_t offset);
+extern int __real_munmap(void *addr, size_t length);
+}
+#endif
+
 // glibc exports its underlying malloc implementation under the name
 // __libc_malloc so that hooks like this can use it.
 extern "C" {
 extern void *__libc_malloc(size_t size);
+extern void *__libc_valloc(size_t size);
 extern void *__libc_realloc(void *ptr, size_t size);
 extern void *__libc_calloc(size_t nmemb, size_t size);
@@ -258 +338 @@
 
   void *ptr = __libc_malloc(size);
-
-  record_malloc(size, ptr, caller);
+  if (ptr)
+    record_malloc(size, ptr, caller);
+
+  in_malloc = 0;
+  return ptr;
+}
+
+void *FUNC(valloc)(size_t size) {
+  const void *caller =
+    __builtin_extract_return_addr(__builtin_return_address(0));
+
+  if (in_malloc)
+    return __libc_valloc(size);
+
+  in_malloc = 1;
+
+  void *ptr = __libc_valloc(size);
+  if (ptr)
+    record_malloc(size, ptr, caller);
 
   in_malloc = 0;
@@ -278 +375 @@
   if (ptr)
     record_free(ptr, caller);
-  record_malloc(size, nptr, caller);
+  if (nptr)
+    record_malloc(size, nptr, caller);
 
   in_malloc = 0;
@@ -296 +394 @@
   void *ptr = __libc_calloc(nmemb, size);
 
-  record_malloc(nmemb*size, ptr, caller);
+  if (ptr)
+    record_malloc(nmemb*size, ptr, caller);
 
   in_malloc = 0;
@@ -314 +413 @@
   void *ptr = __libc_memalign(boundary, size);
 
-  record_malloc(size, ptr, caller);
+  if (ptr)
+    record_malloc(size, ptr, caller);
 
   in_malloc = 0;
@@ -337 +437 @@
 }
 
+int FUNC(posix_memalign)(void **memptr, size_t alignment, size_t size) {
+  const void *caller =
+    __builtin_extract_return_addr(__builtin_return_address(0));
+
+#ifdef __PIC__
+  if (!__real_posix_memalign)
+    if (!(*(void **) (&__real_posix_memalign) =
+        dlsym(RTLD_NEXT, "posix_memalign"))) {
+      return ELIBACC;
+    }
+#endif
+
+  if (in_malloc)
+    return __real_posix_memalign(memptr, alignment, size);
+
+  in_malloc = 1;
+
+  int r = __real_posix_memalign(memptr, alignment, size);
+
+  if (!r)
+    record_malloc(size, *memptr, caller);
+
+  in_malloc = 0;
+
+  return r;
+}
+
+void *FUNC(mmap)(void *addr, size_t length, int prot, int flags,
+                 int fd, off_t offset) {
+  const void *caller =
+    __builtin_extract_return_addr(__builtin_return_address(0));
+
+#ifdef __PIC__
+  if (!__real_mmap)
+    if (!(*(void **) (&__real_mmap) = dlsym(RTLD_NEXT, "mmap"))) {
+      errno = ELIBACC;
+      return MAP_FAILED;
+    }
+#endif
+
+  if (in_malloc)
+    return __real_mmap(addr, length, prot, flags, fd, offset);
+
+  in_malloc = 1;
+
+  void *ptr = __real_mmap(addr, length, prot, flags, fd, offset);
+
+  if (ptr != MAP_FAILED)
+    record_malloc(length, ptr, caller);
+
+  in_malloc = 0;
+
+  return ptr;
+}
+
+void *FUNC(mmap64)(void *addr, size_t length, int prot, int flags,
+                   int fd, off64_t offset) {
+  const void *caller =
+    __builtin_extract_return_addr(__builtin_return_address(0));
+
+#ifdef __PIC__
+  if (!__real_mmap64)
+    if (!(*(void **) (&__real_mmap64) = dlsym(RTLD_NEXT, "mmap64"))) {
+      errno = ELIBACC;
+      return MAP_FAILED;
+    }
+#endif
+
+  if (in_malloc)
+    return __real_mmap64(addr, length, prot, flags, fd, offset);
+
+  in_malloc = 1;
+
+  void *ptr = __real_mmap64(addr, length, prot, flags, fd, offset);
+
+  if (ptr != MAP_FAILED)
+    record_malloc(length, ptr, caller);
+
+  in_malloc = 0;
+
+  return ptr;
+}
+
+int FUNC(munmap)(void *addr, size_t length) {
+  const void *caller =
+    __builtin_extract_return_addr(__builtin_return_address(0));
+
+#ifdef __PIC__
+  if (!__real_munmap)
+    if (!(*(void **) (&__real_munmap) = dlsym(RTLD_NEXT, "munmap"))) {
+      errno = ELIBACC;
+      return -1;
+    }
+#endif
+
+  if (in_malloc)
+    return __real_munmap(addr, length);
+
+  in_malloc = 1;
+
+  record_free(addr, caller);
+
+  int r = __real_munmap(addr, length);
+
+  in_malloc = 0;
+
+  return r;
+}
+
 } // extern "C"
 

memlog_analyze

@@ -42 +42 @@
 use strict;
 use File::Basename;
+use File::Path qw(make_path);
+use Getopt::Long;
+
+my $find_leaks = 0;
+my $print_raw_proc_name = 0;
+my $quiet = 0;
+my $help = 0;
+
+sub print_usage($) {
+  my $ec = $_[0];
+  my $usage = <<EOM;
+Usage: $0 [options] <memlog file or glob> [<output directory>]
+  options:
+    --leaks
+      Provide information on leaks instead of peak usage
+    --print-symbol-names
+      Include symbol names and offsets in the output
+    --quiet or -q
+      Don't print status messages while running
+EOM
+
+  print $usage;
+  exit($ec);
+}
+
+GetOptions("help|h|?" => \$help,
+           "leaks" => \$find_leaks,
+           "print-symbol-names" => \$print_raw_proc_name,
+           "quiet|q" => \$quiet)
+  or print_usage(1);
+
+if ($help) {
+  print_usage(0);
+}
+
+if (scalar(@ARGV) > 2) {
+  print_usage(2);
+}
 
 my $memlog_fn = $ARGV[0];
 my $out_dir = $ARGV[1] || '.';
 
-my $print_raw_proc_name = 0;
+make_path($out_dir);
 
 if (! -f $memlog_fn) {
-  print "Usage: $0 <memlog file> [<output directory>]\n";
-  exit 1;
-}
+  my @pot_fns = glob($memlog_fn);
+  if (scalar(@pot_fns)) {
+    if (!$quiet) {
+      print "Searching all files matching '$memlog_fn'\n";
+    }
+
+    my $pot_max_rss = 0;
+    my $pos_max_rss_fn;
+    foreach my $pot_fn (@pot_fns) {
+      my $last_line = `tail -n 1 '$pot_fn'`;
+      chomp($last_line);
+
+      my @parts = split(/\t/, $last_line);
+
+      my $op = shift(@parts);
+      my $state = shift(@parts);
+
+      my ($time, $then_max_rss, $tid, $then_arena, $then_mmap) =
+        split(/\s+/, $state);
+      if ($pot_max_rss < $then_max_rss) {
+        $pot_max_rss = $then_max_rss;
+        $pos_max_rss_fn = $pot_fn;
+      }
+    }
+
+    if (defined $pos_max_rss_fn) {
+      $memlog_fn = $pos_max_rss_fn;
+      goto have_memlog_fn;
+    }
+  }
+
+  print_usage(1);
+}
+have_memlog_fn:
 
 # The version of addr2line and friends that you use can make a big difference,
@@ -66 +135 @@
 # The first step is to determine the high-water mark.
 my $max_rss = 0;
+my $arena = 0;
+my $mmap = 0;
 foreach my $line (<MEMLOG>) {
   chomp($line);
@@ -73 +144 @@
   my $state = shift(@parts);
 
-  my ($time, $then_max_rss, $tid) = split(/\s+/, $state);
+  my ($time, $then_max_rss, $tid, $then_arena, $then_mmap) =
+    split(/\s+/, $state);
   if ($max_rss < $then_max_rss) {
     $max_rss = $then_max_rss;
+    $arena = $then_arena;
+    $mmap = $then_mmap;
   }
 }
@@ -83 +157 @@
 # Scan the log for malloc/free pairings. We're interested only in active
 # allocations at the time when the rss reaches the final maxrss.
-my $max_rss_time = 0;
+# If we're finding leaks, then go to the very end.
+my $active_alloc_time = 0;
 my %malloc_lines;
 foreach my $line (<MEMLOG>) {
@@ -102 +177 @@
   }
 
-  # If we've reached the max rss, we've seen all we need to see.
-  my ($time, $then_max_rss, $tid) = split(/\s+/, $state);
-  $max_rss_time = $time;
-  if ($then_max_rss == $max_rss) {
-    last;
+  my ($time, $then_max_rss, $tid, $then_arena, $then_mmap) =
+    split(/\s+/, $state);
+  $active_alloc_time = $time;
+
+  if (!$find_leaks) {
+    # If we've reached the max rss, we've seen all we need to see.
+    if ($then_max_rss == $max_rss) {
+      last;
+    }
   }
 }
@@ -114 +193 @@
 # Convert maxrss, currently in KB, to bytes.
 $max_rss *= 1024;
+if (defined $arena) {
+  $arena *= 1024;
+}
+if (defined $mmap) {
+  $mmap *= 1024;
+}
 
 my $total_size = 0;
@@ -130 +215 @@
 
   my ($size, $ptr) = ($op =~ /^M: (\d+) 0x(\w+)/);
-  my ($time, $then_max_rss, $tid) = split(/\s+/, $state);
+  my ($time, $then_max_rss, $tid, $then_arena, $then_mmap) =
+    split(/\s+/, $state);
 
   $total_size += $size;
@@ -192 +278 @@
 my $pdf_fn = "$out_dir/" . basename($memlog_fn) . ".pdf";
 
+if (!$quiet) {
+  print "Creating $txt_fn\n";
+}
+
 open(TXT, ">$txt_fn") || die "Can't open $txt_fn: $!";
+
+if (!$quiet) {
+  print "Creating $dot_fn\n";
+}
+
 open(DOT, ">$dot_fn") || die "Can't open $dot_fn: $!";
 
@@ -208 +303 @@
 }
 
+sub format_bytes_or_unk($) {
+  my $b = $_[0];
+  return defined($b) ? format_bytes($b) : "(unknown)";
+}
+
 print DOT ("digraph \"memlog\" {\n");
 print DOT ("size=\"8,11\";\n");
 print DOT ("node [width=0.375,height=0.25];\n");
 
-printf DOT ("Legend [shape=box, fontsize=100, shape=oval," .
-            "label=\"Total: %s active at maxrss = %s after %s s\"];\n",
-            format_bytes($total_size), format_bytes($max_rss), $max_rss_time);
-
-printf TXT ("memlog: Total: %s active at maxrss = %s after %s s\n\n",
-            format_bytes($total_size), format_bytes($max_rss), $max_rss_time);
+my $find_type = $find_leaks ? " (leaks)" : "";
+print DOT "subgraph cluster_key {\n";
+print DOT "\trank=min;\n";
+print DOT "\tlabel=\"memlog\";\n";
+print DOT "\tfontsize=100;\n";
+print DOT "\trankdir=UR;\n";
+printf DOT ("Legend [shape=box, fontsize=100, shape=plaintext," .
+            "label=\"Total: %s active$find_type at maxrss = %s after %s s\\narena: %s\\nmmap: %s\"];\n",
+            format_bytes($total_size), format_bytes($max_rss),
+            $active_alloc_time, format_bytes_or_unk($arena),
+            format_bytes_or_unk($mmap));
+print DOT "}\n";
+
+printf TXT ("memlog: Total: %s active$find_type at maxrss = %s after %s s\n\tarena: %s\tmmap: %s\n\n",
+            format_bytes($total_size), format_bytes($max_rss),
+            $active_alloc_time, format_bytes_or_unk($arena),
+            format_bytes_or_unk($mmap));
 
 my %cached_names;
@@ -277 +388 @@
     $ret .= $func . '\n';
 
-    if ($loc !~ /^\?/) {
+    if ($loc !~ /^[:?]/) {
       $ret .= $loc . '\n';
     }
@@ -395 +506 @@
 close(DOT);
 
+if (!$quiet) {
+  print "Creating $ps_fn\n";
+}
+
 system("dot -Tps2 < '$dot_fn' > '$ps_fn'");
+
+if (!$quiet) {
+  print "Creating $pdf_fn\n";
+}
+
 system("ps2pdf '$ps_fn' '$pdf_fn'");