1 // Copyright 2013 The Chromium Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style license that can be 3 // found in the LICENSE file. 4 5 #include "base/debug/trace_event_memory.h" 6 7 #include "base/debug/leak_annotations.h" 8 #include "base/debug/trace_event.h" 9 #include "base/lazy_instance.h" 10 #include "base/logging.h" 11 #include "base/memory/scoped_ptr.h" 12 #include "base/message_loop/message_loop.h" 13 #include "base/strings/string_number_conversions.h" 14 #include "base/strings/string_util.h" 15 #include "base/threading/thread_local_storage.h" 16 17 namespace base { 18 namespace debug { 19 20 namespace { 21 22 // Maximum number of nested TRACE_MEMORY scopes to record. Must be greater than 23 // or equal to HeapProfileTable::kMaxStackDepth. 24 const size_t kMaxStackSize = 32; 25 26 ///////////////////////////////////////////////////////////////////////////// 27 // Holds a memory dump until the tracing system needs to serialize it. 28 class MemoryDumpHolder : public base::debug::ConvertableToTraceFormat { 29 public: 30 // Takes ownership of dump, which must be a JSON string, allocated with 31 // malloc() and NULL terminated. 32 explicit MemoryDumpHolder(char* dump) : dump_(dump) {} 33 virtual ~MemoryDumpHolder() { free(dump_); } 34 35 // base::debug::ConvertableToTraceFormat overrides: 36 virtual void AppendAsTraceFormat(std::string* out) const OVERRIDE { 37 AppendHeapProfileAsTraceFormat(dump_, out); 38 } 39 40 private: 41 char* dump_; 42 43 DISALLOW_COPY_AND_ASSIGN(MemoryDumpHolder); 44 }; 45 46 ///////////////////////////////////////////////////////////////////////////// 47 // Records a stack of TRACE_MEMORY events. One per thread is required. 48 struct TraceMemoryStack { 49 TraceMemoryStack() : index_(0) { 50 memset(category_stack_, 0, kMaxStackSize * sizeof(category_stack_[0])); 51 } 52 53 // Points to the next free entry. 54 size_t index_; 55 const char* category_stack_[kMaxStackSize]; 56 }; 57 58 // Pointer to a TraceMemoryStack per thread. 59 base::ThreadLocalStorage::StaticSlot tls_trace_memory_stack = TLS_INITIALIZER; 60 61 // Clean up memory pointed to by our thread-local storage. 62 void DeleteStackOnThreadCleanup(void* value) { 63 TraceMemoryStack* stack = static_cast<TraceMemoryStack*>(value); 64 delete stack; 65 } 66 67 // Initializes the thread-local TraceMemoryStack pointer. Returns true on 68 // success or if it is already initialized. 69 bool InitThreadLocalStorage() { 70 if (tls_trace_memory_stack.initialized()) 71 return true; 72 // Initialize the thread-local storage key, returning true on success. 73 return tls_trace_memory_stack.Initialize(&DeleteStackOnThreadCleanup); 74 } 75 76 // Clean up thread-local-storage in the main thread. 77 void CleanupThreadLocalStorage() { 78 if (!tls_trace_memory_stack.initialized()) 79 return; 80 TraceMemoryStack* stack = 81 static_cast<TraceMemoryStack*>(tls_trace_memory_stack.Get()); 82 delete stack; 83 tls_trace_memory_stack.Set(NULL); 84 // Intentionally do not release the thread-local-storage key here, that is, 85 // do not call tls_trace_memory_stack.Free(). Other threads have lazily 86 // created pointers in thread-local-storage via GetTraceMemoryStack() below. 87 // Those threads need to run the DeleteStack() destructor function when they 88 // exit. If we release the key the destructor will not be called and those 89 // threads will not clean up their memory. 90 } 91 92 // Returns the thread-local trace memory stack for the current thread, creating 93 // one if needed. Returns NULL if the thread-local storage key isn't 94 // initialized, which indicates that heap profiling isn't running. 95 TraceMemoryStack* GetTraceMemoryStack() { 96 TraceMemoryStack* stack = 97 static_cast<TraceMemoryStack*>(tls_trace_memory_stack.Get()); 98 // Lazily initialize TraceMemoryStack objects for new threads. 99 if (!stack) { 100 stack = new TraceMemoryStack; 101 tls_trace_memory_stack.Set(stack); 102 } 103 return stack; 104 } 105 106 // Returns a "pseudo-stack" of pointers to trace events. 107 // TODO(jamescook): Record both category and name, perhaps in a pair for speed. 108 int GetPseudoStack(int skip_count_ignored, void** stack_out) { 109 // If the tracing system isn't fully initialized, just skip this allocation. 110 // Attempting to initialize will allocate memory, causing this function to 111 // be called recursively from inside the allocator. 112 if (!tls_trace_memory_stack.initialized() || !tls_trace_memory_stack.Get()) 113 return 0; 114 TraceMemoryStack* stack = 115 static_cast<TraceMemoryStack*>(tls_trace_memory_stack.Get()); 116 // Copy at most kMaxStackSize stack entries. 117 const size_t count = std::min(stack->index_, kMaxStackSize); 118 // Notes that memcpy() works for zero bytes. 119 memcpy(stack_out, 120 stack->category_stack_, 121 count * sizeof(stack->category_stack_[0])); 122 // Function must return an int to match the signature required by tcmalloc. 123 return static_cast<int>(count); 124 } 125 126 } // namespace 127 128 ////////////////////////////////////////////////////////////////////////////// 129 130 TraceMemoryController::TraceMemoryController( 131 scoped_refptr<MessageLoopProxy> message_loop_proxy, 132 HeapProfilerStartFunction heap_profiler_start_function, 133 HeapProfilerStopFunction heap_profiler_stop_function, 134 GetHeapProfileFunction get_heap_profile_function) 135 : message_loop_proxy_(message_loop_proxy), 136 heap_profiler_start_function_(heap_profiler_start_function), 137 heap_profiler_stop_function_(heap_profiler_stop_function), 138 get_heap_profile_function_(get_heap_profile_function), 139 weak_factory_(this) { 140 // Force the "memory" category to show up in the trace viewer. 141 TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("memory"), "init"); 142 // Watch for the tracing system being enabled. 143 TraceLog::GetInstance()->AddEnabledStateObserver(this); 144 } 145 146 TraceMemoryController::~TraceMemoryController() { 147 if (dump_timer_.IsRunning()) 148 StopProfiling(); 149 TraceLog::GetInstance()->RemoveEnabledStateObserver(this); 150 } 151 152 // base::debug::TraceLog::EnabledStateChangedObserver overrides: 153 void TraceMemoryController::OnTraceLogEnabled() { 154 // Check to see if tracing is enabled for the memory category. 155 bool enabled; 156 TRACE_EVENT_CATEGORY_GROUP_ENABLED(TRACE_DISABLED_BY_DEFAULT("memory"), 157 &enabled); 158 if (!enabled) 159 return; 160 DVLOG(1) << "OnTraceLogEnabled"; 161 message_loop_proxy_->PostTask( 162 FROM_HERE, 163 base::Bind(&TraceMemoryController::StartProfiling, 164 weak_factory_.GetWeakPtr())); 165 } 166 167 void TraceMemoryController::OnTraceLogDisabled() { 168 // The memory category is always disabled before OnTraceLogDisabled() is 169 // called, so we cannot tell if it was enabled before. Always try to turn 170 // off profiling. 171 DVLOG(1) << "OnTraceLogDisabled"; 172 message_loop_proxy_->PostTask( 173 FROM_HERE, 174 base::Bind(&TraceMemoryController::StopProfiling, 175 weak_factory_.GetWeakPtr())); 176 } 177 178 void TraceMemoryController::StartProfiling() { 179 // Watch for the tracing framework sending enabling more than once. 180 if (dump_timer_.IsRunning()) 181 return; 182 DVLOG(1) << "Starting trace memory"; 183 if (!InitThreadLocalStorage()) 184 return; 185 ScopedTraceMemory::set_enabled(true); 186 // Call ::HeapProfilerWithPseudoStackStart(). 187 heap_profiler_start_function_(&GetPseudoStack); 188 const int kDumpIntervalSeconds = 5; 189 dump_timer_.Start(FROM_HERE, 190 TimeDelta::FromSeconds(kDumpIntervalSeconds), 191 base::Bind(&TraceMemoryController::DumpMemoryProfile, 192 weak_factory_.GetWeakPtr())); 193 } 194 195 void TraceMemoryController::DumpMemoryProfile() { 196 // Don't trace allocations here in the memory tracing system. 197 INTERNAL_TRACE_MEMORY(TRACE_DISABLED_BY_DEFAULT("memory"), 198 TRACE_MEMORY_IGNORE); 199 200 DVLOG(1) << "DumpMemoryProfile"; 201 // MemoryDumpHolder takes ownership of this string. See GetHeapProfile() in 202 // tcmalloc for details. 203 char* dump = get_heap_profile_function_(); 204 scoped_ptr<MemoryDumpHolder> dump_holder(new MemoryDumpHolder(dump)); 205 const int kSnapshotId = 1; 206 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID( 207 TRACE_DISABLED_BY_DEFAULT("memory"), 208 "memory::Heap", 209 kSnapshotId, 210 dump_holder.PassAs<base::debug::ConvertableToTraceFormat>()); 211 } 212 213 void TraceMemoryController::StopProfiling() { 214 // Watch for the tracing framework sending disabled more than once. 215 if (!dump_timer_.IsRunning()) 216 return; 217 DVLOG(1) << "Stopping trace memory"; 218 dump_timer_.Stop(); 219 ScopedTraceMemory::set_enabled(false); 220 CleanupThreadLocalStorage(); 221 // Call ::HeapProfilerStop(). 222 heap_profiler_stop_function_(); 223 } 224 225 bool TraceMemoryController::IsTimerRunningForTest() const { 226 return dump_timer_.IsRunning(); 227 } 228 229 ///////////////////////////////////////////////////////////////////////////// 230 231 // static 232 bool ScopedTraceMemory::enabled_ = false; 233 234 ScopedTraceMemory::ScopedTraceMemory(const char* category) { 235 // Not enabled indicates that the trace system isn't running, so don't 236 // record anything. 237 if (!enabled_) 238 return; 239 // Get our thread's copy of the stack. 240 TraceMemoryStack* trace_memory_stack = GetTraceMemoryStack(); 241 const size_t index = trace_memory_stack->index_; 242 // Allow deep nesting of stacks (needed for tests), but only record 243 // |kMaxStackSize| entries. 244 if (index < kMaxStackSize) 245 trace_memory_stack->category_stack_[index] = category; 246 trace_memory_stack->index_++; 247 } 248 249 ScopedTraceMemory::~ScopedTraceMemory() { 250 // Not enabled indicates that the trace system isn't running, so don't 251 // record anything. 252 if (!enabled_) 253 return; 254 // Get our thread's copy of the stack. 255 TraceMemoryStack* trace_memory_stack = GetTraceMemoryStack(); 256 // The tracing system can be turned on with ScopedTraceMemory objects 257 // allocated on the stack, so avoid potential underflow as they are destroyed. 258 if (trace_memory_stack->index_ > 0) 259 trace_memory_stack->index_--; 260 } 261 262 // static 263 void ScopedTraceMemory::InitForTest() { 264 InitThreadLocalStorage(); 265 enabled_ = true; 266 } 267 268 // static 269 void ScopedTraceMemory::CleanupForTest() { 270 enabled_ = false; 271 CleanupThreadLocalStorage(); 272 } 273 274 // static 275 int ScopedTraceMemory::GetStackIndexForTest() { 276 TraceMemoryStack* stack = GetTraceMemoryStack(); 277 return static_cast<int>(stack->index_); 278 } 279 280 // static 281 const char* ScopedTraceMemory::GetItemForTest(int index) { 282 TraceMemoryStack* stack = GetTraceMemoryStack(); 283 return stack->category_stack_[index]; 284 } 285 286 ///////////////////////////////////////////////////////////////////////////// 287 288 void AppendHeapProfileAsTraceFormat(const char* input, std::string* output) { 289 // Heap profile output has a header total line, then a list of stacks with 290 // memory totals, like this: 291 // 292 // heap profile: 357: 55227 [ 14653: 2624014] @ heapprofile 293 // 95: 40940 [ 649: 114260] @ 0x7fa7f4b3be13 294 // 77: 32546 [ 742: 106234] @ 295 // 68: 4195 [ 1087: 98009] @ 0x7fa7fa9b9ba0 0x7fa7f4b3be13 296 // 297 // MAPPED_LIBRARIES: 298 // 1be411fc1000-1be4139e4000 rw-p 00000000 00:00 0 299 // 1be4139e4000-1be4139e5000 ---p 00000000 00:00 0 300 // ... 301 // 302 // Skip input after MAPPED_LIBRARIES. 303 std::string input_string; 304 const char* mapped_libraries = strstr(input, "MAPPED_LIBRARIES"); 305 if (mapped_libraries) { 306 input_string.assign(input, mapped_libraries - input); 307 } else { 308 input_string.assign(input); 309 } 310 311 std::vector<std::string> lines; 312 size_t line_count = Tokenize(input_string, "\n", &lines); 313 if (line_count == 0) { 314 DLOG(WARNING) << "No lines found"; 315 return; 316 } 317 318 // Handle the initial summary line. 319 output->append("["); 320 AppendHeapProfileTotalsAsTraceFormat(lines[0], output); 321 322 // Handle the following stack trace lines. 323 for (size_t i = 1; i < line_count; ++i) { 324 const std::string& line = lines[i]; 325 AppendHeapProfileLineAsTraceFormat(line, output); 326 } 327 output->append("]\n"); 328 } 329 330 void AppendHeapProfileTotalsAsTraceFormat(const std::string& line, 331 std::string* output) { 332 // This is what a line looks like: 333 // heap profile: 357: 55227 [ 14653: 2624014] @ heapprofile 334 // 335 // The numbers represent total allocations since profiling was enabled. 336 // From the example above: 337 // 357 = Outstanding allocations (mallocs - frees) 338 // 55227 = Outstanding bytes (malloc bytes - free bytes) 339 // 14653 = Total allocations (mallocs) 340 // 2624014 = Total bytes (malloc bytes) 341 std::vector<std::string> tokens; 342 Tokenize(line, " :[]@", &tokens); 343 if (tokens.size() < 4) { 344 DLOG(WARNING) << "Invalid totals line " << line; 345 return; 346 } 347 DCHECK_EQ(tokens[0], "heap"); 348 DCHECK_EQ(tokens[1], "profile"); 349 output->append("{\"current_allocs\": "); 350 output->append(tokens[2]); 351 output->append(", \"current_bytes\": "); 352 output->append(tokens[3]); 353 output->append(", \"trace\": \"\"}"); 354 } 355 356 bool AppendHeapProfileLineAsTraceFormat(const std::string& line, 357 std::string* output) { 358 // This is what a line looks like: 359 // 68: 4195 [ 1087: 98009] @ 0x7fa7fa9b9ba0 0x7fa7f4b3be13 360 // 361 // The numbers represent allocations for a particular stack trace since 362 // profiling was enabled. From the example above: 363 // 68 = Outstanding allocations (mallocs - frees) 364 // 4195 = Outstanding bytes (malloc bytes - free bytes) 365 // 1087 = Total allocations (mallocs) 366 // 98009 = Total bytes (malloc bytes) 367 // 368 // 0x7fa7fa9b9ba0 0x7fa7f4b3be13 = Stack trace represented as pointers to 369 // static strings from trace event names. 370 std::vector<std::string> tokens; 371 Tokenize(line, " :[]@", &tokens); 372 // It's valid to have no stack addresses, so only require 4 tokens. 373 if (tokens.size() < 4) { 374 DLOG(WARNING) << "Invalid line " << line; 375 return false; 376 } 377 // Don't bother with stacks that have no current allocations. 378 if (tokens[0] == "0") 379 return false; 380 output->append(",\n"); 381 output->append("{\"current_allocs\": "); 382 output->append(tokens[0]); 383 output->append(", \"current_bytes\": "); 384 output->append(tokens[1]); 385 output->append(", \"trace\": \""); 386 387 // Convert the "stack addresses" into strings. 388 const std::string kSingleQuote = "'"; 389 for (size_t t = 4; t < tokens.size(); ++t) { 390 // Each stack address is a pointer to a constant trace name string. 391 uint64 address = 0; 392 if (!base::HexStringToUInt64(tokens[t], &address)) 393 break; 394 // This is ugly but otherwise tcmalloc would need to gain a special output 395 // serializer for pseudo-stacks. Note that this cast also handles 64-bit to 396 // 32-bit conversion if necessary. Tests use a null address. 397 const char* trace_name = 398 address ? reinterpret_cast<const char*>(address) : "null"; 399 400 // Some trace name strings have double quotes, convert them to single. 401 std::string trace_name_string(trace_name); 402 ReplaceChars(trace_name_string, "\"", kSingleQuote, &trace_name_string); 403 404 output->append(trace_name_string); 405 406 // Trace viewer expects a trailing space. 407 output->append(" "); 408 } 409 output->append("\"}"); 410 return true; 411 } 412 413 } // namespace debug 414 } // namespace base 415