A deeper heap profile dumper in third_party/tcmalloc/chromium.

third_party/tcmalloc/chromium/src/deep-heap-profile.cc

+// Copyright (c) 2011 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+// ---
+// Author: Sainbayar Sukhbaatar
+//         Dai Mikurube
+//
+
+#include "deep-heap-profile.h"
+
+#ifdef DEEP_HEAP_PROFILE
+#include <fcntl.h>
+#include <sys/stat.h>
+#include <sys/types.h>
+#ifdef HAVE_UNISTD_H
+#include <unistd.h>  // for getpid()
+#endif
+
+#include "base/cycleclock.h"
+#include "base/sysinfo.h"
+
+static const int kProfilerBufferSize = 1 << 20;
+static const int kHashTableSize = 179999;  // The same as heap-profile-table.cc.
+
+static const int PAGE_SIZE = 4096;
+static const int PAGEMAP_BYTES = 8;
+static const uint64 TOP_ADDRESS = kuint64max;
+
+// Header strings of the dumped heap profile.
+static const char kProfileHeader[] = "Deep Memory Profile\n";
+static const char kGlobalStatsHeader[] = "GLOBAL_STATS:\n";
+static const char kStacktraceHeader[] = "STACKTRACES:\n";
+static const char kProcSelfMapsHeader[] = "\nMAPPED_LIBRARIES:\n";
+
+DeepHeapProfile::DeepHeapProfile(HeapProfileTable* heap_profile,
+                                 const char* prefix)
+    : heap_profile_(heap_profile),
+      pagemap_fd_(-1),
+      most_recent_pid_(-1),
+      stats_(),
+      dump_count_(0),
+      filename_prefix_(NULL),
+      profiler_buffer_(NULL),
+      bucket_id_(0) {
+  deep_bucket_map_ = new(heap_profile_->alloc_(sizeof(DeepBucketMap)))
+      DeepBucketMap(heap_profile_->alloc_, heap_profile_->dealloc_);
+
+  // Copy filename prefix.
+  const int prefix_length = strlen(prefix);
+  filename_prefix_ =
+      reinterpret_cast<char*>(heap_profile_->alloc_(prefix_length + 1));
+  memcpy(filename_prefix_, prefix, prefix_length);
+  filename_prefix_[prefix_length] = '\0';
+
+  profiler_buffer_ =
+      reinterpret_cast<char*>(heap_profile_->alloc_(kProfilerBufferSize));
+}
+
+DeepHeapProfile::~DeepHeapProfile() {
+  heap_profile_->dealloc_(profiler_buffer_);
+  heap_profile_->dealloc_(filename_prefix_);
+  deep_bucket_map_->~DeepBucketMap();
+  heap_profile_->dealloc_(deep_bucket_map_);
+}
+
+int DeepHeapProfile::FillOrderedProfile(char buf[], int size) {
+#ifndef NDEBUG
+  int64 starting_cycles = CycleClock::Now();
+#endif
+  ++dump_count_;
+
+  // Re-open files in /proc/pid/ if the process is newly forked one.
+  if (most_recent_pid_ != getpid()) {
+    most_recent_pid_ = getpid();
+    OpenProcPagemap();
+
+    // Write maps into a .maps file with using the global buffer.
+    WriteMapsToFile(profiler_buffer_, kProfilerBufferSize);
+  }
+
+  // Reset committed sizes of buckets.
+  ResetCommittedSize(heap_profile_->malloc_table_);
+  ResetCommittedSize(heap_profile_->mmap_table_);
+
+  GetGlobalStats();
+  size_t anonymous_committed = stats_.anonymous.committed_bytes;
+
+  // Note: Don't allocate any memory from here.
+
+  // Record committed sizes.
+  RecordAllAllocs();
+
+  // Check if committed bytes changed during RecordAllAllocs.
+  GetGlobalStats();
+#ifndef NDEBUG
+  size_t committed_difference =
+      stats_.anonymous.committed_bytes - anonymous_committed;
+  if (committed_difference != 0)
+    RAW_LOG(0, "Difference in committed size: %ld", committed_difference);
+#endif
+
+  HeapProfileTable::Stats stats;
+  memset(&stats, 0, sizeof(stats));
+
+  // Start filling buf with the ordered profile.
+  int printed = snprintf(buf, size, kProfileHeader);
+  if (printed < 0 || printed >= size) return 0;

[jar (doing other things), 2012/01/06 03:05:10]

nit: prefer putting condition on separate line unless condition is very brief.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.  I like the "separated lines" policy actually, but I was following the
existing format in heap-profile-table.cc for consistency.

+  int bucket_length = printed;

[jar (doing other things), 2012/01/06 03:05:10]

nit: I really liked you variable name |printed|, but this |bucket_length| is
then much harder to grok.

How about:
used_in_buf

This also calls into question the use of the appreviation |buf|, and perhaps
|buffer| would be better.  ... leading to:

used_in_buffer

or some similar (better?) name.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Agreed.  Replaced to 'used_in_buffer'.

On 2012/01/06 03:05:10, jar wrote:

+
+  // Fill buf with the global stats.
+  printed = snprintf(buf + bucket_length, size - bucket_length,
+       kGlobalStatsHeader);

[jar (doing other things), 2012/01/06 03:05:10]

nit: wrap args at paren.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  if (printed < 0 || printed >= size - bucket_length) return bucket_length;

[jar (doing other things), 2012/01/06 03:05:10]

nit: prefer putting condition on separate line unless condition is very brief.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  bucket_length += printed;
+
+  bucket_length = UnparseGlobalStats(buf, bucket_length, size);
+
+  // Fill buf with the header for buckets.
+  printed = snprintf(buf + bucket_length, size - bucket_length,
+      kStacktraceHeader);
+  if (printed < 0 || printed >= size - bucket_length) return bucket_length;

[jar (doing other things), 2012/01/06 03:05:10]

nit: prefer putting condition on separate line unless condition is very brief.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  bucket_length += printed;
+
+  printed = snprintf(buf + bucket_length, size - bucket_length,
+      "%10s %10s\n", "virtual", "committed");
+  if (printed < 0 || printed >= size - bucket_length) return bucket_length;

[jar (doing other things), 2012/01/06 03:05:10]

nit: condition on separate line please.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  bucket_length += printed;
+
+  // Fill buf with stack trace buckets.
+  bucket_length = FillBucketTable(heap_profile_->malloc_table_,
+                                  buf, size, bucket_length, &stats);
+  bucket_length = FillBucketTable(heap_profile_->mmap_table_,
+                                  buf, size, bucket_length, &stats);
+
+  RAW_DCHECK(bucket_length < size, "");
+
+  // Note: Don't allocate any memory until here.
+
+  // Write the bucket listing into a .bucket file.
+  WriteBucketsToBucketFile();
+
+#ifndef NDEBUG
+  int64 elapsed_cycles = CycleClock::Now() - starting_cycles;
+  double elapsed_seconds = elapsed_cycles / CyclesPerSecond();
+  RAW_LOG(0, "Time spent on DeepProfiler: %.3f sec\n", elapsed_seconds);
+#endif
+
+  return bucket_length;
+}
+
+DeepHeapProfile::DeepBucket*
+DeepHeapProfile::GetDeepBucket(Bucket* bucket) {
+  DeepBucket* found = deep_bucket_map_->FindMutable(bucket);
+  if (found == NULL) {
+    DeepBucket created;
+    created.bucket = bucket;
+    created.committed_size = 0;
+    created.id = (bucket_id_++);
+    created.is_logged = false;
+    deep_bucket_map_->Insert(bucket, created);
+    return deep_bucket_map_->FindMutable(bucket);
+  } else {
+    return found;
+  }
+}
+
+void DeepHeapProfile::ResetCommittedSize(Bucket** table) {
+  for (int i = 0; i < kHashTableSize; i++) {
+    for (Bucket* b = table[i]; b != 0; b = b->next) {
+      DeepBucket* db = GetDeepBucket(b);
+      db->committed_size = 0;
+    }
+  }
+}
+
+int DeepHeapProfile::FillBucketTable(Bucket** table,
+                                     char buf[], int size, int bucket_length,
+                                     HeapProfileTable::Stats* stats) {
+  for (int i = 0; i < kHashTableSize; i++) {
+    for (Bucket* b = table[i]; b != 0; b = b->next) {
+      if (b->alloc_size - b->free_size == 0)
+        continue;  // Skip empty buckets.
+      const DeepBucket& db = *GetDeepBucket(b);
+      bucket_length = UnparseBucket(db, buf, bucket_length, size, "", stats);
+    }
+  }
+  return bucket_length;
+}
+
+// This function need to be called after each fork.
+void DeepHeapProfile::OpenProcPagemap() {
+  char filename[100];
+  sprintf(filename, "/proc/%d/pagemap", getpid());
+  pagemap_fd_ = open(filename, O_RDONLY);
+  RAW_DCHECK(pagemap_fd_ != -1, "Failed to open /proc/self/pagemap");
+}
+
+bool DeepHeapProfile::SeekProcPagemap(uint64 address) {
+  uint64 index = (address / PAGE_SIZE) * PAGEMAP_BYTES;
+  uint64 o = lseek64(pagemap_fd_, index, SEEK_SET);
+  RAW_DCHECK(o == index, "");
+  return true;
+}
+
+bool DeepHeapProfile::ReadProcPagemap(PageState* state) {
+  static const uint64 U64_1 = 1;
+  static const uint64 PFN_FILTER = (U64_1 << 55) - U64_1;
+  static const uint64 PAGE_PRESENT = U64_1 << 63;
+  static const uint64 PAGE_SWAP = U64_1 << 62;
+  static const uint64 PAGE_RESERVED = U64_1 << 61;
+  static const uint64 FLAG_NOPAGE = U64_1 << 20;
+  static const uint64 FLAG_KSM = U64_1 << 21;
+  static const uint64 FLAG_MMAP = U64_1 << 11;
+
+  uint64 pagemap_value;
+  int result = read(pagemap_fd_, &pagemap_value, PAGEMAP_BYTES);
+  if (result != PAGEMAP_BYTES)
+    return false;
+
+  // Check if the page is committed.
+  state->is_committed = (pagemap_value & (PAGE_PRESENT | PAGE_SWAP));
+
+  state->is_present = (pagemap_value & PAGE_PRESENT);
+  state->is_swapped = (pagemap_value & PAGE_SWAP);
+  state->is_shared = false;
+
+  return true;
+}
+
+size_t DeepHeapProfile::GetCommittedSize(uint64 address, size_t size) {
+  uint64 page_address = (address / PAGE_SIZE) * PAGE_SIZE;
+  size_t committed_size = 0;
+
+  SeekProcPagemap(address);
+
+  // Check every page on which the allocation resides.
+  while (page_address < address + size) {
+    // Read corresponding physical page.
+    PageState state;
+    if (ReadProcPagemap(&state) == false) {
+      // We can't read the last region (e.g vsyscall).
+#ifndef NDEBUG
+      RAW_LOG(0, "pagemap read failed @ %#llx %"PRId64" bytes", address, size);
+#endif
+      return 0;
+    }
+
+    if (state.is_committed) {
+      // Calculate the size of the allocation part in this page.
+      size_t bytes = PAGE_SIZE;
+      if (address + size <= page_address - 1 + PAGE_SIZE)
+        bytes = address + size - page_address;
+      if (page_address < address)
+        bytes -= address - page_address;
+
+      committed_size += bytes;
+    }
+    if (page_address > TOP_ADDRESS - PAGE_SIZE) {
+      break;
+    }
+    page_address += PAGE_SIZE;
+  }
+
+  return committed_size;
+}
+
+void DeepHeapProfile::InitRegionStats(RegionStats* stats) {
+  stats->virtual_bytes = 0;
+  stats->committed_bytes = 0;
+}
+
+void DeepHeapProfile::RecordRegionStats(uint64 start,
+                                        uint64 end,
+                                        RegionStats* stats) {
+  size_t size = static_cast<size_t>(end - start);
+  stats->virtual_bytes += size;
+  stats->committed_bytes += GetCommittedSize(start, size);
+}
+
+void DeepHeapProfile::GetGlobalStats() {
+  ProcMapsIterator::Buffer iterator_buffer;
+  ProcMapsIterator it(0, &iterator_buffer);
+  uint64 start, end, offset;
+  int64 inode;
+  char *flags, *filename;
+
+  InitRegionStats(&(stats_.total));
+  InitRegionStats(&(stats_.file_mapped));
+  InitRegionStats(&(stats_.anonymous));
+  InitRegionStats(&(stats_.other));
+
+  while (it.Next(&start, &end, &flags, &offset, &inode, &filename)) {
+    if (strcmp("[vsyscall]", filename) == 0)
+      continue;  // Reading pagemap will fail in [vsyscall].
+
+    int64 committed_bytes = stats_.total.committed_bytes;
+    RecordRegionStats(start, end, &(stats_.total));
+    committed_bytes = stats_.total.committed_bytes - committed_bytes;
+
+    if (filename[0] == '/') {
+      RecordRegionStats(start, end, &(stats_.file_mapped));
+    } else if (filename[0] == '\0' || filename[0] == '\n') {
+      RecordRegionStats(start, end, &(stats_.anonymous));
+    } else {
+      RecordRegionStats(start, end, &(stats_.other));
+    }
+  }
+}
+
+void DeepHeapProfile::RecordAlloc(const void* pointer,
+                                  AllocValue* v,
+                                  DeepHeapProfile* deep_profile) {
+  uint64 alloc_address = reinterpret_cast<uintptr_t>(pointer);
+  size_t committed = deep_profile->GetCommittedSize(alloc_address, v->bytes);
+
+  (deep_profile->GetDeepBucket(v->bucket()))->committed_size += committed;
+  deep_profile->stats_.record_tcmalloc.virtual_bytes += v->bytes;
+  deep_profile->stats_.record_tcmalloc.committed_bytes += committed;
+}
+
+void DeepHeapProfile::RecordMMap(const void* pointer,
+                                 AllocValue* v,
+                                 DeepHeapProfile* deep_profile) {
+  uint64 alloc_address = reinterpret_cast<uintptr_t>(pointer);
+  size_t committed = deep_profile->GetCommittedSize(alloc_address, v->bytes);
+
+  (deep_profile->GetDeepBucket(v->bucket()))->committed_size += committed;
+  deep_profile->stats_.record_mmap.virtual_bytes += v->bytes;
+  deep_profile->stats_.record_mmap.committed_bytes += committed;
+}
+
+void DeepHeapProfile::RecordAllAllocs() {
+  stats_.record_mmap.virtual_bytes = 0;
+  stats_.record_mmap.committed_bytes = 0;
+  stats_.record_tcmalloc.virtual_bytes = 0;
+  stats_.record_tcmalloc.committed_bytes = 0;
+
+  // tcmalloc allocations.
+  heap_profile_->allocation_->Iterate(RecordAlloc, this);
+
+  // mmap allocations.
+  heap_profile_->mmap_allocation_->Iterate(RecordMMap, this);
+}
+
+void DeepHeapProfile::WriteMapsToFile(char buf[], int size) {
+  char file_name[100];
+  snprintf(file_name, sizeof(file_name),
+           "%s.%05d.maps", filename_prefix_, getpid());
+
+  RawFD maps_fd = RawOpenForWriting(file_name);
+  RAW_DCHECK(maps_fd != kIllegalRawFD, "");
+
+  int map_length;
+  bool wrote_all;
+  map_length = tcmalloc::FillProcSelfMaps(
+      profiler_buffer_, kProfilerBufferSize, &wrote_all);
+  RAW_DCHECK(wrote_all, "");
+  RAW_DCHECK(map_length <= kProfilerBufferSize, "");
+  RawWrite(maps_fd, profiler_buffer_, map_length);
+  RawClose(maps_fd);
+}
+
+int DeepHeapProfile::FillBucketForBucketFile(const DeepBucket* deep_bucket,
+                                             char buf[], int bufsize) {
+  const Bucket* bucket = deep_bucket->bucket;
+  int printed = snprintf(buf, bufsize, "%05d", deep_bucket->id);
+  if (printed < 0 || printed >= bufsize) return 0;

[jar (doing other things), 2012/01/06 03:05:10]

nit: put return on next line.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  int buflen = printed;
+
+  for (int d = 0; d < bucket->depth; d++) {
+    printed = snprintf(buf + buflen, bufsize - buflen,
+        " 0x%08" PRIxPTR, reinterpret_cast<uintptr_t>(bucket->stack[d]));
+    if (printed < 0 || printed >= bufsize - buflen) return buflen;

[jar (doing other things), 2012/01/06 03:05:10]

nit: return on next line.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+    buflen += printed;

[jar (doing other things), 2012/01/06 03:05:10]

Maybe |buflen| is a better name than bucket_size mentioned earlier.... but
again, the style guide suggests not using abbreviation or shortened words. 
Probably buffer_length would be stylistically better in both places.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  }
+  printed = snprintf(buf + buflen, bufsize - buflen, "\n");
+  if (printed < 0 || printed >= bufsize - buflen) return buflen;

[jar (doing other things), 2012/01/06 03:05:10]

nit: return on next line.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  buflen += printed;
+
+  return buflen;
+}
+
+void DeepHeapProfile::WriteBucketsTableToBucketFile(Bucket** table,
+                                                    RawFD bucket_fd) {
+  // We will use the global buffer here.
+  char* buf = profiler_buffer_;
+  int size = kProfilerBufferSize;
+  int buflen = 0;
+
+  for (int i = 0; i < kHashTableSize; i++) {
+    for (Bucket* b = table[i]; b != 0; b = b->next) {
+      DeepBucket* db = GetDeepBucket(b);
+      if (db->is_logged) continue;  // Skip the bucket if it is already logged.
+      if (b->alloc_size - b->free_size <= 64) continue;  // Skip small buckets.
+
+      buflen += FillBucketForBucketFile(db, buf + buflen, size - buflen);
+      db->is_logged = true;
+
+      // Write to file if buffer 80% full.
+      if (buflen > size * 0.8) {
+        RawWrite(bucket_fd, buf, buflen);
+        buflen = 0;
+      }
+    }
+  }
+
+  RawWrite(bucket_fd, buf, buflen);
+}
+
+void DeepHeapProfile::WriteBucketsToBucketFile() {
+  char file_name[100];
+  snprintf(file_name, sizeof(file_name), "%s.%05d.%04d.buckets",
+           filename_prefix_, getpid(), dump_count_);
+  RawFD bucket_fd = RawOpenForWriting(file_name);
+  RAW_DCHECK(bucket_fd != kIllegalRawFD, "");
+
+  WriteBucketsTableToBucketFile(heap_profile_->malloc_table_, bucket_fd);
+  WriteBucketsTableToBucketFile(heap_profile_->mmap_table_, bucket_fd);
+
+  RawClose(bucket_fd);
+}
+
+int DeepHeapProfile::UnparseBucket(const DeepBucket& deep_bucket,
+                                   char* buf, int buflen, int bufsize,
+                                   const char* extra,
+                                   Stats* profile_stats) {
+  const Bucket& bucket = *deep_bucket.bucket;
+  if (profile_stats != NULL) {
+    profile_stats->allocs += bucket.allocs;
+    profile_stats->alloc_size += bucket.alloc_size;
+    profile_stats->frees += bucket.frees;
+    profile_stats->free_size += bucket.free_size;
+  }
+
+  int printed = snprintf(buf + buflen, bufsize - buflen,
+      "%10"PRId64" %10"PRId64" %6d %6d @%s %d\n",
+       bucket.alloc_size - bucket.free_size, deep_bucket.committed_size,
+       bucket.allocs, bucket.frees, extra, deep_bucket.id);
+  // If it looks like the snprintf failed, ignore the fact we printed anything.
+  if (printed < 0 || printed >= bufsize - buflen) return buflen;
+  buflen += printed;
+
+  return buflen;
+}
+
+int DeepHeapProfile::UnparseRegionStats(const RegionStats* stats,
+                                        const char* name,
+                                        char* buf,
+                                        int buflen,
+                                        int bufsize) {
+  int printed = snprintf(buf + buflen, bufsize - buflen,
+                         "%15s %10ld %10ld\n",
+                         name,
+                         stats->virtual_bytes,
+                         stats->committed_bytes);
+  if (printed < 0 || printed >= bufsize - buflen) return buflen;

[jar (doing other things), 2012/01/06 03:05:10]

nit: two lines.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  buflen += printed;
+
+  return buflen;
+}
+
+int DeepHeapProfile::UnparseGlobalStats(char* buf, int buflen, int bufsize) {
+  int printed = snprintf(buf + buflen, bufsize - buflen,
+      "%15s %10s %10s\n", "", "virtual", "committed");
+  if (printed < 0 || printed >= bufsize - buflen) return buflen;

[jar (doing other things), 2012/01/06 03:05:10]

nit: two lines.

[Dai Mikurube (NOT FULLTIME), 2012/01/06 20:11:27]

Done.

+  buflen += printed;
+
+  buflen = UnparseRegionStats(
+      &(stats_.total), "total", buf, buflen, bufsize);
+  buflen = UnparseRegionStats(
+      &(stats_.file_mapped), "file mapped", buf, buflen, bufsize);
+  buflen = UnparseRegionStats(
+      &(stats_.anonymous), "anonymous", buf, buflen, bufsize);
+  buflen = UnparseRegionStats(
+      &(stats_.other), "other", buf, buflen, bufsize);
+  buflen = UnparseRegionStats(
+      &(stats_.record_mmap), "mmap", buf, buflen, bufsize);
+  buflen = UnparseRegionStats(
+      &(stats_.record_tcmalloc), "tcmalloc", buf, buflen, bufsize);
+  return buflen;
+}
+#else  // DEEP_HEAP_PROFILE
+
+DeepHeapProfile::DeepHeapProfile(HeapProfileTable* heap_profile,
+                                 const char* prefix)
+    : heap_profile_(heap_profile) {
+}
+
+DeepHeapProfile::~DeepHeapProfile() {
+}
+
+int DeepHeapProfile::FillOrderedProfile(char buf[], int size) {
+  return heap_profile_->FillOrderedProfile(buf, size);
+}
+
+#endif  // DEEP_HEAP_PROFILE