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.
5 #include "base/trace_event/trace_event_memory.h"
7 #include "base/debug/leak_annotations.h"
8 #include "base/lazy_instance.h"
9 #include "base/location.h"
10 #include "base/logging.h"
11 #include "base/memory/scoped_ptr.h"
12 #include "base/single_thread_task_runner.h"
13 #include "base/strings/string_number_conversions.h"
14 #include "base/strings/string_split.h"
15 #include "base/strings/string_util.h"
16 #include "base/threading/thread_local_storage.h"
17 #include "base/trace_event/trace_event.h"
20 namespace trace_event
{
24 // Maximum number of nested TRACE_EVENT scopes to record. Must be less than
25 // or equal to HeapProfileTable::kMaxStackDepth / 2 because we record two
26 // entries on the pseudo-stack per scope.
27 const size_t kMaxScopeDepth
= 16;
29 /////////////////////////////////////////////////////////////////////////////
30 // Holds a memory dump until the tracing system needs to serialize it.
31 class MemoryDumpHolder
: public base::trace_event::ConvertableToTraceFormat
{
33 // Takes ownership of dump, which must be a JSON string, allocated with
34 // malloc() and NULL terminated.
35 explicit MemoryDumpHolder(char* dump
) : dump_(dump
) {}
37 // base::trace_event::ConvertableToTraceFormat overrides:
38 void AppendAsTraceFormat(std::string
* out
) const override
{
39 AppendHeapProfileAsTraceFormat(dump_
, out
);
43 ~MemoryDumpHolder() override
{ free(dump_
); }
47 DISALLOW_COPY_AND_ASSIGN(MemoryDumpHolder
);
50 /////////////////////////////////////////////////////////////////////////////
51 // Records a stack of TRACE_MEMORY events. One per thread is required.
52 struct TraceMemoryStack
{
53 TraceMemoryStack() : scope_depth(0) {
54 memset(scope_data
, 0, kMaxScopeDepth
* sizeof(scope_data
[0]));
57 // Depth of the currently nested TRACE_EVENT scopes. Allowed to be greater
58 // than kMaxScopeDepth so we can match scope pushes and pops even if we don't
59 // have enough space to store the EventData.
62 // Stack of categories and names.
63 ScopedTraceMemory::ScopeData scope_data
[kMaxScopeDepth
];
66 // Pointer to a TraceMemoryStack per thread.
67 base::ThreadLocalStorage::StaticSlot tls_trace_memory_stack
= TLS_INITIALIZER
;
69 // Clean up memory pointed to by our thread-local storage.
70 void DeleteStackOnThreadCleanup(void* value
) {
71 TraceMemoryStack
* stack
= static_cast<TraceMemoryStack
*>(value
);
75 // Initializes the thread-local TraceMemoryStack pointer.
76 void InitThreadLocalStorage() {
77 if (tls_trace_memory_stack
.initialized())
79 // Initialize the thread-local storage key.
80 tls_trace_memory_stack
.Initialize(&DeleteStackOnThreadCleanup
);
83 // Clean up thread-local-storage in the main thread.
84 void CleanupThreadLocalStorage() {
85 if (!tls_trace_memory_stack
.initialized())
87 TraceMemoryStack
* stack
=
88 static_cast<TraceMemoryStack
*>(tls_trace_memory_stack
.Get());
90 tls_trace_memory_stack
.Set(NULL
);
91 // Intentionally do not release the thread-local-storage key here, that is,
92 // do not call tls_trace_memory_stack.Free(). Other threads have lazily
93 // created pointers in thread-local-storage via GetTraceMemoryStack() below.
94 // Those threads need to run the DeleteStack() destructor function when they
95 // exit. If we release the key the destructor will not be called and those
96 // threads will not clean up their memory.
99 // Returns the thread-local trace memory stack for the current thread, creating
100 // one if needed. Returns NULL if the thread-local storage key isn't
101 // initialized, which indicates that heap profiling isn't running.
102 TraceMemoryStack
* GetTraceMemoryStack() {
103 TraceMemoryStack
* stack
=
104 static_cast<TraceMemoryStack
*>(tls_trace_memory_stack
.Get());
105 // Lazily initialize TraceMemoryStack objects for new threads.
107 stack
= new TraceMemoryStack
;
108 tls_trace_memory_stack
.Set(stack
);
113 // Returns a "pseudo-stack" of pointers to trace event categories and names.
114 // Because tcmalloc stores one pointer per stack frame this converts N nested
115 // trace events into N * 2 pseudo-stack entries. Thus this macro invocation:
116 // TRACE_EVENT0("category1", "name1");
117 // TRACE_EVENT0("category2", "name2");
118 // becomes this pseudo-stack:
119 // stack_out[0] = "category1"
120 // stack_out[1] = "name1"
121 // stack_out[2] = "category2"
122 // stack_out[3] = "name2"
123 // Returns int instead of size_t to match the signature required by tcmalloc.
124 int GetPseudoStack(int skip_count_ignored
, void** stack_out
) {
125 // If the tracing system isn't fully initialized, just skip this allocation.
126 // Attempting to initialize will allocate memory, causing this function to
127 // be called recursively from inside the allocator.
128 if (!tls_trace_memory_stack
.initialized() || !tls_trace_memory_stack
.Get())
130 TraceMemoryStack
* stack
=
131 static_cast<TraceMemoryStack
*>(tls_trace_memory_stack
.Get());
132 // Copy at most kMaxScopeDepth scope entries.
133 const size_t count
= std::min(stack
->scope_depth
, kMaxScopeDepth
);
134 // Notes that memcpy() works for zero bytes.
137 count
* sizeof(stack
->scope_data
[0]));
138 // Each item in the trace event stack contains both name and category so tell
139 // tcmalloc that we have returned |count| * 2 stack frames.
140 return static_cast<int>(count
* 2);
145 //////////////////////////////////////////////////////////////////////////////
147 TraceMemoryController::TraceMemoryController(
148 scoped_refptr
<SingleThreadTaskRunner
> task_runner
,
149 HeapProfilerStartFunction heap_profiler_start_function
,
150 HeapProfilerStopFunction heap_profiler_stop_function
,
151 GetHeapProfileFunction get_heap_profile_function
)
152 : task_runner_(task_runner
.Pass()),
153 heap_profiler_start_function_(heap_profiler_start_function
),
154 heap_profiler_stop_function_(heap_profiler_stop_function
),
155 get_heap_profile_function_(get_heap_profile_function
),
156 weak_factory_(this) {
157 // Force the "memory" category to show up in the trace viewer.
158 TRACE_EVENT0(TRACE_DISABLED_BY_DEFAULT("memory"), "init");
159 // Watch for the tracing system being enabled.
160 TraceLog::GetInstance()->AddEnabledStateObserver(this);
163 TraceMemoryController::~TraceMemoryController() {
164 if (dump_timer_
.IsRunning())
166 TraceLog::GetInstance()->RemoveEnabledStateObserver(this);
169 // base::trace_event::TraceLog::EnabledStateChangedObserver overrides:
170 void TraceMemoryController::OnTraceLogEnabled() {
171 // Check to see if tracing is enabled for the memory category.
173 TRACE_EVENT_CATEGORY_GROUP_ENABLED(TRACE_DISABLED_BY_DEFAULT("memory"),
177 DVLOG(1) << "OnTraceLogEnabled";
178 task_runner_
->PostTask(FROM_HERE
,
179 base::Bind(&TraceMemoryController::StartProfiling
,
180 weak_factory_
.GetWeakPtr()));
183 void TraceMemoryController::OnTraceLogDisabled() {
184 // The memory category is always disabled before OnTraceLogDisabled() is
185 // called, so we cannot tell if it was enabled before. Always try to turn
187 DVLOG(1) << "OnTraceLogDisabled";
188 task_runner_
->PostTask(FROM_HERE
,
189 base::Bind(&TraceMemoryController::StopProfiling
,
190 weak_factory_
.GetWeakPtr()));
193 void TraceMemoryController::StartProfiling() {
194 // Watch for the tracing framework sending enabling more than once.
195 if (dump_timer_
.IsRunning())
197 DVLOG(1) << "Starting trace memory";
198 InitThreadLocalStorage();
199 ScopedTraceMemory::set_enabled(true);
200 // Call ::HeapProfilerWithPseudoStackStart().
201 heap_profiler_start_function_(&GetPseudoStack
);
202 const int kDumpIntervalSeconds
= 5;
203 dump_timer_
.Start(FROM_HERE
,
204 TimeDelta::FromSeconds(kDumpIntervalSeconds
),
205 base::Bind(&TraceMemoryController::DumpMemoryProfile
,
206 weak_factory_
.GetWeakPtr()));
209 void TraceMemoryController::DumpMemoryProfile() {
210 // Don't trace allocations here in the memory tracing system.
211 INTERNAL_TRACE_MEMORY(TRACE_DISABLED_BY_DEFAULT("memory"),
212 TRACE_MEMORY_IGNORE
);
214 DVLOG(1) << "DumpMemoryProfile";
215 // MemoryDumpHolder takes ownership of this string. See GetHeapProfile() in
216 // tcmalloc for details.
217 char* dump
= get_heap_profile_function_();
218 const int kSnapshotId
= 1;
219 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID(
220 TRACE_DISABLED_BY_DEFAULT("memory"),
223 scoped_refptr
<ConvertableToTraceFormat
>(new MemoryDumpHolder(dump
)));
226 void TraceMemoryController::StopProfiling() {
227 // Watch for the tracing framework sending disabled more than once.
228 if (!dump_timer_
.IsRunning())
230 DVLOG(1) << "Stopping trace memory";
232 ScopedTraceMemory::set_enabled(false);
233 CleanupThreadLocalStorage();
234 // Call ::HeapProfilerStop().
235 heap_profiler_stop_function_();
238 bool TraceMemoryController::IsTimerRunningForTest() const {
239 return dump_timer_
.IsRunning();
242 /////////////////////////////////////////////////////////////////////////////
245 bool ScopedTraceMemory::enabled_
= false;
247 void ScopedTraceMemory::Initialize(const char* category
, const char* name
) {
249 // Get our thread's copy of the stack.
250 TraceMemoryStack
* trace_memory_stack
= GetTraceMemoryStack();
251 const size_t index
= trace_memory_stack
->scope_depth
;
252 // Don't record data for deeply nested scopes, but continue to increment
253 // |stack_depth| so we can match pushes and pops.
254 if (index
< kMaxScopeDepth
) {
255 ScopeData
& event
= trace_memory_stack
->scope_data
[index
];
256 event
.category
= category
;
259 trace_memory_stack
->scope_depth
++;
262 void ScopedTraceMemory::Destroy() {
264 // Get our thread's copy of the stack.
265 TraceMemoryStack
* trace_memory_stack
= GetTraceMemoryStack();
266 // The tracing system can be turned on with ScopedTraceMemory objects
267 // allocated on the stack, so avoid potential underflow as they are destroyed.
268 if (trace_memory_stack
->scope_depth
> 0)
269 trace_memory_stack
->scope_depth
--;
273 void ScopedTraceMemory::InitForTest() {
274 InitThreadLocalStorage();
279 void ScopedTraceMemory::CleanupForTest() {
281 CleanupThreadLocalStorage();
285 int ScopedTraceMemory::GetStackDepthForTest() {
286 TraceMemoryStack
* stack
= GetTraceMemoryStack();
287 return static_cast<int>(stack
->scope_depth
);
291 ScopedTraceMemory::ScopeData
ScopedTraceMemory::GetScopeDataForTest(
293 TraceMemoryStack
* stack
= GetTraceMemoryStack();
294 return stack
->scope_data
[stack_index
];
297 /////////////////////////////////////////////////////////////////////////////
299 void AppendHeapProfileAsTraceFormat(const char* input
, std::string
* output
) {
300 // Heap profile output has a header total line, then a list of stacks with
301 // memory totals, like this:
303 // heap profile: 357: 55227 [ 14653: 2624014] @ heapprofile
304 // 95: 40940 [ 649: 114260] @ 0x7fa7f4b3be13
305 // 77: 32546 [ 742: 106234] @
306 // 68: 4195 [ 1087: 98009] @ 0x7fa7fa9b9ba0 0x7fa7f4b3be13
309 // 1be411fc1000-1be4139e4000 rw-p 00000000 00:00 0
310 // 1be4139e4000-1be4139e5000 ---p 00000000 00:00 0
313 // Skip input after MAPPED_LIBRARIES.
314 std::string input_string
;
315 const char* mapped_libraries
= strstr(input
, "MAPPED_LIBRARIES");
316 if (mapped_libraries
) {
317 input_string
.assign(input
, mapped_libraries
- input
);
319 input_string
.assign(input
);
322 std::vector
<std::string
> lines
= base::SplitString(
323 input_string
, "\n", base::KEEP_WHITESPACE
, base::SPLIT_WANT_NONEMPTY
);
325 DLOG(WARNING
) << "No lines found";
329 // Handle the initial summary line.
331 AppendHeapProfileTotalsAsTraceFormat(lines
[0], output
);
333 // Handle the following stack trace lines.
334 for (size_t i
= 1; i
< lines
.size(); i
++)
335 AppendHeapProfileLineAsTraceFormat(lines
[i
], output
);
336 output
->append("]\n");
339 void AppendHeapProfileTotalsAsTraceFormat(const std::string
& line
,
340 std::string
* output
) {
341 // This is what a line looks like:
342 // heap profile: 357: 55227 [ 14653: 2624014] @ heapprofile
344 // The numbers represent total allocations since profiling was enabled.
345 // From the example above:
346 // 357 = Outstanding allocations (mallocs - frees)
347 // 55227 = Outstanding bytes (malloc bytes - free bytes)
348 // 14653 = Total allocations (mallocs)
349 // 2624014 = Total bytes (malloc bytes)
350 std::vector
<std::string
> tokens
= base::SplitString(
351 line
, " :[]@", base::KEEP_WHITESPACE
, base::SPLIT_WANT_NONEMPTY
);
352 if (tokens
.size() < 4) {
353 DLOG(WARNING
) << "Invalid totals line " << line
;
356 DCHECK_EQ(tokens
[0], "heap");
357 DCHECK_EQ(tokens
[1], "profile");
358 output
->append("{\"current_allocs\": ");
359 output
->append(tokens
[2]);
360 output
->append(", \"current_bytes\": ");
361 output
->append(tokens
[3]);
362 output
->append(", \"trace\": \"\"}");
365 bool AppendHeapProfileLineAsTraceFormat(const std::string
& line
,
366 std::string
* output
) {
367 // This is what a line looks like:
368 // 68: 4195 [ 1087: 98009] @ 0x7fa7fa9b9ba0 0x7fa7f4b3be13
370 // The numbers represent allocations for a particular stack trace since
371 // profiling was enabled. From the example above:
372 // 68 = Outstanding allocations (mallocs - frees)
373 // 4195 = Outstanding bytes (malloc bytes - free bytes)
374 // 1087 = Total allocations (mallocs)
375 // 98009 = Total bytes (malloc bytes)
377 // 0x7fa7fa9b9ba0 0x7fa7f4b3be13 = Stack trace represented as pointers to
378 // static strings from trace event categories
380 std::vector
<std::string
> tokens
= base::SplitString(
381 line
, " :[]@", base::KEEP_WHITESPACE
, base::SPLIT_WANT_NONEMPTY
);
382 // It's valid to have no stack addresses, so only require 4 tokens.
383 if (tokens
.size() < 4) {
384 DLOG(WARNING
) << "Invalid line " << line
;
387 // Don't bother with stacks that have no current allocations.
388 if (tokens
[0] == "0")
390 output
->append(",\n");
391 output
->append("{\"current_allocs\": ");
392 output
->append(tokens
[0]);
393 output
->append(", \"current_bytes\": ");
394 output
->append(tokens
[1]);
395 output
->append(", \"trace\": \"");
397 // Convert pairs of "stack addresses" into category and name strings.
398 const std::string kSingleQuote
= "'";
399 for (size_t t
= 4; t
< tokens
.size(); t
+= 2) {
400 // Casting strings into pointers is ugly but otherwise tcmalloc would need
401 // to gain a special output serializer just for pseudo-stacks.
402 const char* trace_category
= StringFromHexAddress(tokens
[t
]);
403 DCHECK_LT(t
+ 1, tokens
.size());
404 const char* trace_name
= StringFromHexAddress(tokens
[t
+ 1]);
406 // TODO(jamescook): Report the trace category and name separately to the
407 // trace viewer and allow it to decide what decorations to apply. For now
408 // just hard-code a decoration for posted tasks (toplevel).
409 std::string
trace_string(trace_name
);
410 if (!strcmp(trace_category
, "toplevel"))
411 trace_string
.append("->PostTask");
413 // Some trace name strings have double quotes, convert them to single.
414 ReplaceChars(trace_string
, "\"", kSingleQuote
, &trace_string
);
416 output
->append(trace_string
);
418 // Trace viewer expects a trailing space.
421 output
->append("\"}");
425 const char* StringFromHexAddress(const std::string
& hex_address
) {
427 if (!base::HexStringToUInt64(hex_address
, &address
))
431 // Note that this cast handles 64-bit to 32-bit conversion if necessary.
432 return reinterpret_cast<const char*>(address
);
435 } // namespace trace_event