Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(463)

Side by Side Diff: base/trace_event/trace_event_impl.cc

Issue 1647803004: Move base to DEPS (Closed) Base URL: git@github.com:domokit/mojo.git@master
Patch Set: Created 4 years, 10 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch
« no previous file with comments | « base/trace_event/trace_event_impl.h ('k') | base/trace_event/trace_event_impl_constants.cc » ('j') | no next file with comments »
Toggle Intra-line Diffs ('i') | Expand Comments ('e') | Collapse Comments ('c') | Show Comments Hide Comments ('s')
OLDNEW
(Empty)
1 // Copyright (c) 2012 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/trace_event/trace_event_impl.h"
6
7 #include <algorithm>
8 #include <cmath>
9
10 #include "base/base_switches.h"
11 #include "base/bind.h"
12 #include "base/command_line.h"
13 #include "base/debug/leak_annotations.h"
14 #include "base/format_macros.h"
15 #include "base/json/string_escape.h"
16 #include "base/lazy_instance.h"
17 #include "base/location.h"
18 #include "base/memory/singleton.h"
19 #include "base/process/process_metrics.h"
20 #include "base/stl_util.h"
21 #include "base/strings/string_number_conversions.h"
22 #include "base/strings/string_split.h"
23 #include "base/strings/string_tokenizer.h"
24 #include "base/strings/string_util.h"
25 #include "base/strings/stringprintf.h"
26 #include "base/strings/utf_string_conversions.h"
27 #include "base/synchronization/cancellation_flag.h"
28 #include "base/synchronization/waitable_event.h"
29 #include "base/sys_info.h"
30 #include "base/third_party/dynamic_annotations/dynamic_annotations.h"
31 #include "base/thread_task_runner_handle.h"
32 #include "base/threading/platform_thread.h"
33 #include "base/threading/thread_id_name_manager.h"
34 #include "base/threading/worker_pool.h"
35 #include "base/time/time.h"
36 #include "base/trace_event/memory_dump_manager.h"
37 #include "base/trace_event/memory_dump_provider.h"
38 #include "base/trace_event/process_memory_dump.h"
39 #include "base/trace_event/trace_event.h"
40 #include "base/trace_event/trace_event_synthetic_delay.h"
41
42 #if defined(OS_WIN)
43 #include "base/trace_event/trace_event_etw_export_win.h"
44 #include "base/trace_event/trace_event_win.h"
45 #endif
46
47 class DeleteTraceLogForTesting {
48 public:
49 static void Delete() {
50 Singleton<base::trace_event::TraceLog,
51 LeakySingletonTraits<base::trace_event::TraceLog>>::OnExit(0);
52 }
53 };
54
55 // The thread buckets for the sampling profiler.
56 BASE_EXPORT TRACE_EVENT_API_ATOMIC_WORD g_trace_state[3];
57
58 namespace base {
59 namespace trace_event {
60
61 namespace {
62
63 // The overhead of TraceEvent above this threshold will be reported in the
64 // trace.
65 const int kOverheadReportThresholdInMicroseconds = 50;
66
67 // Controls the number of trace events we will buffer in-memory
68 // before throwing them away.
69 const size_t kTraceBufferChunkSize = TraceBufferChunk::kTraceBufferChunkSize;
70 const size_t kTraceEventVectorBigBufferChunks =
71 512000000 / kTraceBufferChunkSize;
72 const size_t kTraceEventVectorBufferChunks = 256000 / kTraceBufferChunkSize;
73 const size_t kTraceEventRingBufferChunks = kTraceEventVectorBufferChunks / 4;
74 const size_t kTraceEventBufferSizeInBytes = 100 * 1024;
75 // Can store results for 30 seconds with 1 ms sampling interval.
76 const size_t kMonitorTraceEventBufferChunks = 30000 / kTraceBufferChunkSize;
77 // ECHO_TO_CONSOLE needs a small buffer to hold the unfinished COMPLETE events.
78 const size_t kEchoToConsoleTraceEventBufferChunks = 256;
79
80 const int kThreadFlushTimeoutMs = 3000;
81
82 #if !defined(OS_NACL)
83 // These categories will cause deadlock when ECHO_TO_CONSOLE. crbug.com/325575.
84 const char kEchoToConsoleCategoryFilter[] = "-ipc,-task";
85 #endif
86
87 #define MAX_CATEGORY_GROUPS 100
88
89 // Parallel arrays g_category_groups and g_category_group_enabled are separate
90 // so that a pointer to a member of g_category_group_enabled can be easily
91 // converted to an index into g_category_groups. This allows macros to deal
92 // only with char enabled pointers from g_category_group_enabled, and we can
93 // convert internally to determine the category name from the char enabled
94 // pointer.
95 const char* g_category_groups[MAX_CATEGORY_GROUPS] = {
96 "toplevel",
97 "tracing already shutdown",
98 "tracing categories exhausted; must increase MAX_CATEGORY_GROUPS",
99 "__metadata",
100 // For reporting trace_event overhead. For thread local event buffers only.
101 "trace_event_overhead"};
102
103 // The enabled flag is char instead of bool so that the API can be used from C.
104 unsigned char g_category_group_enabled[MAX_CATEGORY_GROUPS] = { 0 };
105 // Indexes here have to match the g_category_groups array indexes above.
106 const int g_category_already_shutdown = 1;
107 const int g_category_categories_exhausted = 2;
108 const int g_category_metadata = 3;
109 const int g_category_trace_event_overhead = 4;
110 const int g_num_builtin_categories = 5;
111 // Skip default categories.
112 base::subtle::AtomicWord g_category_index = g_num_builtin_categories;
113
114 // The name of the current thread. This is used to decide if the current
115 // thread name has changed. We combine all the seen thread names into the
116 // output name for the thread.
117 LazyInstance<ThreadLocalPointer<const char> >::Leaky
118 g_current_thread_name = LAZY_INSTANCE_INITIALIZER;
119
120 ThreadTicks ThreadNow() {
121 return ThreadTicks::IsSupported() ? ThreadTicks::Now() : ThreadTicks();
122 }
123
124 class TraceBufferRingBuffer : public TraceBuffer {
125 public:
126 TraceBufferRingBuffer(size_t max_chunks)
127 : max_chunks_(max_chunks),
128 recyclable_chunks_queue_(new size_t[queue_capacity()]),
129 queue_head_(0),
130 queue_tail_(max_chunks),
131 current_iteration_index_(0),
132 current_chunk_seq_(1) {
133 chunks_.reserve(max_chunks);
134 for (size_t i = 0; i < max_chunks; ++i)
135 recyclable_chunks_queue_[i] = i;
136 }
137
138 scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) override {
139 // Because the number of threads is much less than the number of chunks,
140 // the queue should never be empty.
141 DCHECK(!QueueIsEmpty());
142
143 *index = recyclable_chunks_queue_[queue_head_];
144 queue_head_ = NextQueueIndex(queue_head_);
145 current_iteration_index_ = queue_head_;
146
147 if (*index >= chunks_.size())
148 chunks_.resize(*index + 1);
149
150 TraceBufferChunk* chunk = chunks_[*index];
151 chunks_[*index] = NULL; // Put NULL in the slot of a in-flight chunk.
152 if (chunk)
153 chunk->Reset(current_chunk_seq_++);
154 else
155 chunk = new TraceBufferChunk(current_chunk_seq_++);
156
157 return scoped_ptr<TraceBufferChunk>(chunk);
158 }
159
160 void ReturnChunk(size_t index, scoped_ptr<TraceBufferChunk> chunk) override {
161 // When this method is called, the queue should not be full because it
162 // can contain all chunks including the one to be returned.
163 DCHECK(!QueueIsFull());
164 DCHECK(chunk);
165 DCHECK_LT(index, chunks_.size());
166 DCHECK(!chunks_[index]);
167 chunks_[index] = chunk.release();
168 recyclable_chunks_queue_[queue_tail_] = index;
169 queue_tail_ = NextQueueIndex(queue_tail_);
170 }
171
172 bool IsFull() const override { return false; }
173
174 size_t Size() const override {
175 // This is approximate because not all of the chunks are full.
176 return chunks_.size() * kTraceBufferChunkSize;
177 }
178
179 size_t Capacity() const override {
180 return max_chunks_ * kTraceBufferChunkSize;
181 }
182
183 TraceEvent* GetEventByHandle(TraceEventHandle handle) override {
184 if (handle.chunk_index >= chunks_.size())
185 return NULL;
186 TraceBufferChunk* chunk = chunks_[handle.chunk_index];
187 if (!chunk || chunk->seq() != handle.chunk_seq)
188 return NULL;
189 return chunk->GetEventAt(handle.event_index);
190 }
191
192 const TraceBufferChunk* NextChunk() override {
193 if (chunks_.empty())
194 return NULL;
195
196 while (current_iteration_index_ != queue_tail_) {
197 size_t chunk_index = recyclable_chunks_queue_[current_iteration_index_];
198 current_iteration_index_ = NextQueueIndex(current_iteration_index_);
199 if (chunk_index >= chunks_.size()) // Skip uninitialized chunks.
200 continue;
201 DCHECK(chunks_[chunk_index]);
202 return chunks_[chunk_index];
203 }
204 return NULL;
205 }
206
207 scoped_ptr<TraceBuffer> CloneForIteration() const override {
208 scoped_ptr<ClonedTraceBuffer> cloned_buffer(new ClonedTraceBuffer());
209 for (size_t queue_index = queue_head_; queue_index != queue_tail_;
210 queue_index = NextQueueIndex(queue_index)) {
211 size_t chunk_index = recyclable_chunks_queue_[queue_index];
212 if (chunk_index >= chunks_.size()) // Skip uninitialized chunks.
213 continue;
214 TraceBufferChunk* chunk = chunks_[chunk_index];
215 cloned_buffer->chunks_.push_back(chunk ? chunk->Clone().release() : NULL);
216 }
217 return cloned_buffer.Pass();
218 }
219
220 void EstimateTraceMemoryOverhead(
221 TraceEventMemoryOverhead* overhead) override {
222 overhead->Add("TraceBufferRingBuffer", sizeof(*this));
223 for (size_t queue_index = queue_head_; queue_index != queue_tail_;
224 queue_index = NextQueueIndex(queue_index)) {
225 size_t chunk_index = recyclable_chunks_queue_[queue_index];
226 if (chunk_index >= chunks_.size()) // Skip uninitialized chunks.
227 continue;
228 chunks_[chunk_index]->EstimateTraceMemoryOverhead(overhead);
229 }
230 }
231
232 private:
233 class ClonedTraceBuffer : public TraceBuffer {
234 public:
235 ClonedTraceBuffer() : current_iteration_index_(0) {}
236
237 // The only implemented method.
238 const TraceBufferChunk* NextChunk() override {
239 return current_iteration_index_ < chunks_.size() ?
240 chunks_[current_iteration_index_++] : NULL;
241 }
242
243 scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) override {
244 NOTIMPLEMENTED();
245 return scoped_ptr<TraceBufferChunk>();
246 }
247 void ReturnChunk(size_t index, scoped_ptr<TraceBufferChunk>) override {
248 NOTIMPLEMENTED();
249 }
250 bool IsFull() const override { return false; }
251 size_t Size() const override { return 0; }
252 size_t Capacity() const override { return 0; }
253 TraceEvent* GetEventByHandle(TraceEventHandle handle) override {
254 return NULL;
255 }
256 scoped_ptr<TraceBuffer> CloneForIteration() const override {
257 NOTIMPLEMENTED();
258 return scoped_ptr<TraceBuffer>();
259 }
260 void EstimateTraceMemoryOverhead(
261 TraceEventMemoryOverhead* overhead) override {
262 NOTIMPLEMENTED();
263 }
264
265 size_t current_iteration_index_;
266 ScopedVector<TraceBufferChunk> chunks_;
267 };
268
269 bool QueueIsEmpty() const {
270 return queue_head_ == queue_tail_;
271 }
272
273 size_t QueueSize() const {
274 return queue_tail_ > queue_head_ ? queue_tail_ - queue_head_ :
275 queue_tail_ + queue_capacity() - queue_head_;
276 }
277
278 bool QueueIsFull() const {
279 return QueueSize() == queue_capacity() - 1;
280 }
281
282 size_t queue_capacity() const {
283 // One extra space to help distinguish full state and empty state.
284 return max_chunks_ + 1;
285 }
286
287 size_t NextQueueIndex(size_t index) const {
288 index++;
289 if (index >= queue_capacity())
290 index = 0;
291 return index;
292 }
293
294 size_t max_chunks_;
295 ScopedVector<TraceBufferChunk> chunks_;
296
297 scoped_ptr<size_t[]> recyclable_chunks_queue_;
298 size_t queue_head_;
299 size_t queue_tail_;
300
301 size_t current_iteration_index_;
302 uint32 current_chunk_seq_;
303
304 DISALLOW_COPY_AND_ASSIGN(TraceBufferRingBuffer);
305 };
306
307 class TraceBufferVector : public TraceBuffer {
308 public:
309 TraceBufferVector(size_t max_chunks)
310 : in_flight_chunk_count_(0),
311 current_iteration_index_(0),
312 max_chunks_(max_chunks) {
313 chunks_.reserve(max_chunks_);
314 }
315
316 scoped_ptr<TraceBufferChunk> GetChunk(size_t* index) override {
317 // This function may be called when adding normal events or indirectly from
318 // AddMetadataEventsWhileLocked(). We can not DECHECK(!IsFull()) because we
319 // have to add the metadata events and flush thread-local buffers even if
320 // the buffer is full.
321 *index = chunks_.size();
322 chunks_.push_back(NULL); // Put NULL in the slot of a in-flight chunk.
323 ++in_flight_chunk_count_;
324 // + 1 because zero chunk_seq is not allowed.
325 return scoped_ptr<TraceBufferChunk>(
326 new TraceBufferChunk(static_cast<uint32>(*index) + 1));
327 }
328
329 void ReturnChunk(size_t index, scoped_ptr<TraceBufferChunk> chunk) override {
330 DCHECK_GT(in_flight_chunk_count_, 0u);
331 DCHECK_LT(index, chunks_.size());
332 DCHECK(!chunks_[index]);
333 --in_flight_chunk_count_;
334 chunks_[index] = chunk.release();
335 }
336
337 bool IsFull() const override { return chunks_.size() >= max_chunks_; }
338
339 size_t Size() const override {
340 // This is approximate because not all of the chunks are full.
341 return chunks_.size() * kTraceBufferChunkSize;
342 }
343
344 size_t Capacity() const override {
345 return max_chunks_ * kTraceBufferChunkSize;
346 }
347
348 TraceEvent* GetEventByHandle(TraceEventHandle handle) override {
349 if (handle.chunk_index >= chunks_.size())
350 return NULL;
351 TraceBufferChunk* chunk = chunks_[handle.chunk_index];
352 if (!chunk || chunk->seq() != handle.chunk_seq)
353 return NULL;
354 return chunk->GetEventAt(handle.event_index);
355 }
356
357 const TraceBufferChunk* NextChunk() override {
358 while (current_iteration_index_ < chunks_.size()) {
359 // Skip in-flight chunks.
360 const TraceBufferChunk* chunk = chunks_[current_iteration_index_++];
361 if (chunk)
362 return chunk;
363 }
364 return NULL;
365 }
366
367 scoped_ptr<TraceBuffer> CloneForIteration() const override {
368 NOTIMPLEMENTED();
369 return scoped_ptr<TraceBuffer>();
370 }
371
372 void EstimateTraceMemoryOverhead(
373 TraceEventMemoryOverhead* overhead) override {
374 const size_t chunks_ptr_vector_allocated_size =
375 sizeof(*this) + max_chunks_ * sizeof(decltype(chunks_)::value_type);
376 const size_t chunks_ptr_vector_resident_size =
377 sizeof(*this) + chunks_.size() * sizeof(decltype(chunks_)::value_type);
378 overhead->Add("TraceBufferVector", chunks_ptr_vector_allocated_size,
379 chunks_ptr_vector_resident_size);
380 for (size_t i = 0; i < chunks_.size(); ++i) {
381 TraceBufferChunk* chunk = chunks_[i];
382 // Skip the in-flight (nullptr) chunks. They will be accounted by the
383 // per-thread-local dumpers, see ThreadLocalEventBuffer::OnMemoryDump.
384 if (chunk)
385 chunk->EstimateTraceMemoryOverhead(overhead);
386 }
387 }
388
389 private:
390 size_t in_flight_chunk_count_;
391 size_t current_iteration_index_;
392 size_t max_chunks_;
393 ScopedVector<TraceBufferChunk> chunks_;
394
395 DISALLOW_COPY_AND_ASSIGN(TraceBufferVector);
396 };
397
398 template <typename T>
399 void InitializeMetadataEvent(TraceEvent* trace_event,
400 int thread_id,
401 const char* metadata_name, const char* arg_name,
402 const T& value) {
403 if (!trace_event)
404 return;
405
406 int num_args = 1;
407 unsigned char arg_type;
408 unsigned long long arg_value;
409 ::trace_event_internal::SetTraceValue(value, &arg_type, &arg_value);
410 trace_event->Initialize(thread_id,
411 TraceTicks(), ThreadTicks(),
412 TRACE_EVENT_PHASE_METADATA,
413 &g_category_group_enabled[g_category_metadata],
414 metadata_name, ::trace_event_internal::kNoEventId,
415 num_args, &arg_name, &arg_type, &arg_value, NULL,
416 TRACE_EVENT_FLAG_NONE);
417 }
418
419 class AutoThreadLocalBoolean {
420 public:
421 explicit AutoThreadLocalBoolean(ThreadLocalBoolean* thread_local_boolean)
422 : thread_local_boolean_(thread_local_boolean) {
423 DCHECK(!thread_local_boolean_->Get());
424 thread_local_boolean_->Set(true);
425 }
426 ~AutoThreadLocalBoolean() {
427 thread_local_boolean_->Set(false);
428 }
429
430 private:
431 ThreadLocalBoolean* thread_local_boolean_;
432 DISALLOW_COPY_AND_ASSIGN(AutoThreadLocalBoolean);
433 };
434
435 } // namespace
436
437 TraceBufferChunk::TraceBufferChunk(uint32 seq) : next_free_(0), seq_(seq) {}
438
439 TraceBufferChunk::~TraceBufferChunk() {}
440
441 void TraceBufferChunk::Reset(uint32 new_seq) {
442 for (size_t i = 0; i < next_free_; ++i)
443 chunk_[i].Reset();
444 next_free_ = 0;
445 seq_ = new_seq;
446 cached_overhead_estimate_when_full_.reset();
447 }
448
449 TraceEvent* TraceBufferChunk::AddTraceEvent(size_t* event_index) {
450 DCHECK(!IsFull());
451 *event_index = next_free_++;
452 return &chunk_[*event_index];
453 }
454
455 scoped_ptr<TraceBufferChunk> TraceBufferChunk::Clone() const {
456 scoped_ptr<TraceBufferChunk> cloned_chunk(new TraceBufferChunk(seq_));
457 cloned_chunk->next_free_ = next_free_;
458 for (size_t i = 0; i < next_free_; ++i)
459 cloned_chunk->chunk_[i].CopyFrom(chunk_[i]);
460 return cloned_chunk.Pass();
461 }
462
463 void TraceBufferChunk::EstimateTraceMemoryOverhead(
464 TraceEventMemoryOverhead* overhead) {
465 if (cached_overhead_estimate_when_full_) {
466 DCHECK(IsFull());
467 overhead->Update(*cached_overhead_estimate_when_full_);
468 return;
469 }
470
471 // Cache the memory overhead estimate only if the chunk is full.
472 TraceEventMemoryOverhead* estimate = overhead;
473 if (IsFull()) {
474 cached_overhead_estimate_when_full_.reset(new TraceEventMemoryOverhead);
475 estimate = cached_overhead_estimate_when_full_.get();
476 }
477
478 estimate->Add("TraceBufferChunk", sizeof(*this));
479 for (size_t i = 0; i < next_free_; ++i)
480 chunk_[i].EstimateTraceMemoryOverhead(estimate);
481
482 if (IsFull()) {
483 estimate->AddSelf();
484 overhead->Update(*estimate);
485 }
486 }
487
488 // A helper class that allows the lock to be acquired in the middle of the scope
489 // and unlocks at the end of scope if locked.
490 class TraceLog::OptionalAutoLock {
491 public:
492 explicit OptionalAutoLock(Lock* lock) : lock_(lock), locked_(false) {}
493
494 ~OptionalAutoLock() {
495 if (locked_)
496 lock_->Release();
497 }
498
499 void EnsureAcquired() {
500 if (!locked_) {
501 lock_->Acquire();
502 locked_ = true;
503 }
504 }
505
506 private:
507 Lock* lock_;
508 bool locked_;
509 DISALLOW_COPY_AND_ASSIGN(OptionalAutoLock);
510 };
511
512 // Use this function instead of TraceEventHandle constructor to keep the
513 // overhead of ScopedTracer (trace_event.h) constructor minimum.
514 void MakeHandle(uint32 chunk_seq, size_t chunk_index, size_t event_index,
515 TraceEventHandle* handle) {
516 DCHECK(chunk_seq);
517 DCHECK(chunk_index < (1u << 16));
518 DCHECK(event_index < (1u << 16));
519 handle->chunk_seq = chunk_seq;
520 handle->chunk_index = static_cast<uint16>(chunk_index);
521 handle->event_index = static_cast<uint16>(event_index);
522 }
523
524 ////////////////////////////////////////////////////////////////////////////////
525 //
526 // TraceEvent
527 //
528 ////////////////////////////////////////////////////////////////////////////////
529
530 namespace {
531
532 size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; }
533
534 // Copies |*member| into |*buffer|, sets |*member| to point to this new
535 // location, and then advances |*buffer| by the amount written.
536 void CopyTraceEventParameter(char** buffer,
537 const char** member,
538 const char* end) {
539 if (*member) {
540 size_t written = strlcpy(*buffer, *member, end - *buffer) + 1;
541 DCHECK_LE(static_cast<int>(written), end - *buffer);
542 *member = *buffer;
543 *buffer += written;
544 }
545 }
546
547 } // namespace
548
549 TraceEvent::TraceEvent()
550 : duration_(TimeDelta::FromInternalValue(-1)),
551 id_(0u),
552 category_group_enabled_(NULL),
553 name_(NULL),
554 thread_id_(0),
555 phase_(TRACE_EVENT_PHASE_BEGIN),
556 flags_(0) {
557 for (int i = 0; i < kTraceMaxNumArgs; ++i)
558 arg_names_[i] = NULL;
559 memset(arg_values_, 0, sizeof(arg_values_));
560 }
561
562 TraceEvent::~TraceEvent() {
563 }
564
565 void TraceEvent::CopyFrom(const TraceEvent& other) {
566 timestamp_ = other.timestamp_;
567 thread_timestamp_ = other.thread_timestamp_;
568 duration_ = other.duration_;
569 id_ = other.id_;
570 category_group_enabled_ = other.category_group_enabled_;
571 name_ = other.name_;
572 thread_id_ = other.thread_id_;
573 phase_ = other.phase_;
574 flags_ = other.flags_;
575 parameter_copy_storage_ = other.parameter_copy_storage_;
576
577 for (int i = 0; i < kTraceMaxNumArgs; ++i) {
578 arg_names_[i] = other.arg_names_[i];
579 arg_types_[i] = other.arg_types_[i];
580 arg_values_[i] = other.arg_values_[i];
581 convertable_values_[i] = other.convertable_values_[i];
582 }
583 }
584
585 void TraceEvent::Initialize(
586 int thread_id,
587 TraceTicks timestamp,
588 ThreadTicks thread_timestamp,
589 char phase,
590 const unsigned char* category_group_enabled,
591 const char* name,
592 unsigned long long id,
593 int num_args,
594 const char** arg_names,
595 const unsigned char* arg_types,
596 const unsigned long long* arg_values,
597 const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
598 unsigned int flags) {
599 timestamp_ = timestamp;
600 thread_timestamp_ = thread_timestamp;
601 duration_ = TimeDelta::FromInternalValue(-1);
602 id_ = id;
603 category_group_enabled_ = category_group_enabled;
604 name_ = name;
605 thread_id_ = thread_id;
606 phase_ = phase;
607 flags_ = flags;
608
609 // Clamp num_args since it may have been set by a third_party library.
610 num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args;
611 int i = 0;
612 for (; i < num_args; ++i) {
613 arg_names_[i] = arg_names[i];
614 arg_types_[i] = arg_types[i];
615
616 if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE)
617 convertable_values_[i] = convertable_values[i];
618 else
619 arg_values_[i].as_uint = arg_values[i];
620 }
621 for (; i < kTraceMaxNumArgs; ++i) {
622 arg_names_[i] = NULL;
623 arg_values_[i].as_uint = 0u;
624 convertable_values_[i] = NULL;
625 arg_types_[i] = TRACE_VALUE_TYPE_UINT;
626 }
627
628 bool copy = !!(flags & TRACE_EVENT_FLAG_COPY);
629 size_t alloc_size = 0;
630 if (copy) {
631 alloc_size += GetAllocLength(name);
632 for (i = 0; i < num_args; ++i) {
633 alloc_size += GetAllocLength(arg_names_[i]);
634 if (arg_types_[i] == TRACE_VALUE_TYPE_STRING)
635 arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING;
636 }
637 }
638
639 bool arg_is_copy[kTraceMaxNumArgs];
640 for (i = 0; i < num_args; ++i) {
641 // No copying of convertable types, we retain ownership.
642 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
643 continue;
644
645 // We only take a copy of arg_vals if they are of type COPY_STRING.
646 arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING);
647 if (arg_is_copy[i])
648 alloc_size += GetAllocLength(arg_values_[i].as_string);
649 }
650
651 if (alloc_size) {
652 parameter_copy_storage_ = new RefCountedString;
653 parameter_copy_storage_->data().resize(alloc_size);
654 char* ptr = string_as_array(&parameter_copy_storage_->data());
655 const char* end = ptr + alloc_size;
656 if (copy) {
657 CopyTraceEventParameter(&ptr, &name_, end);
658 for (i = 0; i < num_args; ++i) {
659 CopyTraceEventParameter(&ptr, &arg_names_[i], end);
660 }
661 }
662 for (i = 0; i < num_args; ++i) {
663 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
664 continue;
665 if (arg_is_copy[i])
666 CopyTraceEventParameter(&ptr, &arg_values_[i].as_string, end);
667 }
668 DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end;
669 }
670 }
671
672 void TraceEvent::Reset() {
673 // Only reset fields that won't be initialized in Initialize(), or that may
674 // hold references to other objects.
675 duration_ = TimeDelta::FromInternalValue(-1);
676 parameter_copy_storage_ = NULL;
677 for (int i = 0; i < kTraceMaxNumArgs; ++i)
678 convertable_values_[i] = NULL;
679 cached_memory_overhead_estimate_.reset();
680 }
681
682 void TraceEvent::UpdateDuration(const TraceTicks& now,
683 const ThreadTicks& thread_now) {
684 DCHECK_EQ(duration_.ToInternalValue(), -1);
685 duration_ = now - timestamp_;
686 thread_duration_ = thread_now - thread_timestamp_;
687 }
688
689 void TraceEvent::EstimateTraceMemoryOverhead(
690 TraceEventMemoryOverhead* overhead) {
691 if (!cached_memory_overhead_estimate_) {
692 cached_memory_overhead_estimate_.reset(new TraceEventMemoryOverhead);
693 cached_memory_overhead_estimate_->Add("TraceEvent", sizeof(*this));
694 // TODO(primiano): parameter_copy_storage_ is refcounted and, in theory,
695 // could be shared by several events and we might overcount. In practice
696 // this is unlikely but it's worth checking.
697 if (parameter_copy_storage_) {
698 cached_memory_overhead_estimate_->AddRefCountedString(
699 *parameter_copy_storage_.get());
700 }
701 for (size_t i = 0; i < kTraceMaxNumArgs; ++i) {
702 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) {
703 convertable_values_[i]->EstimateTraceMemoryOverhead(
704 cached_memory_overhead_estimate_.get());
705 }
706 }
707 cached_memory_overhead_estimate_->AddSelf();
708 }
709 overhead->Update(*cached_memory_overhead_estimate_);
710 }
711
712 // static
713 void TraceEvent::AppendValueAsJSON(unsigned char type,
714 TraceEvent::TraceValue value,
715 std::string* out) {
716 switch (type) {
717 case TRACE_VALUE_TYPE_BOOL:
718 *out += value.as_bool ? "true" : "false";
719 break;
720 case TRACE_VALUE_TYPE_UINT:
721 StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint));
722 break;
723 case TRACE_VALUE_TYPE_INT:
724 StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int));
725 break;
726 case TRACE_VALUE_TYPE_DOUBLE: {
727 // FIXME: base/json/json_writer.cc is using the same code,
728 // should be made into a common method.
729 std::string real;
730 double val = value.as_double;
731 if (std::isfinite(val)) {
732 real = DoubleToString(val);
733 // Ensure that the number has a .0 if there's no decimal or 'e'. This
734 // makes sure that when we read the JSON back, it's interpreted as a
735 // real rather than an int.
736 if (real.find('.') == std::string::npos &&
737 real.find('e') == std::string::npos &&
738 real.find('E') == std::string::npos) {
739 real.append(".0");
740 }
741 // The JSON spec requires that non-integer values in the range (-1,1)
742 // have a zero before the decimal point - ".52" is not valid, "0.52" is.
743 if (real[0] == '.') {
744 real.insert(0, "0");
745 } else if (real.length() > 1 && real[0] == '-' && real[1] == '.') {
746 // "-.1" bad "-0.1" good
747 real.insert(1, "0");
748 }
749 } else if (std::isnan(val)){
750 // The JSON spec doesn't allow NaN and Infinity (since these are
751 // objects in EcmaScript). Use strings instead.
752 real = "\"NaN\"";
753 } else if (val < 0) {
754 real = "\"-Infinity\"";
755 } else {
756 real = "\"Infinity\"";
757 }
758 StringAppendF(out, "%s", real.c_str());
759 break;
760 }
761 case TRACE_VALUE_TYPE_POINTER:
762 // JSON only supports double and int numbers.
763 // So as not to lose bits from a 64-bit pointer, output as a hex string.
764 StringAppendF(out, "\"0x%" PRIx64 "\"", static_cast<uint64>(
765 reinterpret_cast<intptr_t>(
766 value.as_pointer)));
767 break;
768 case TRACE_VALUE_TYPE_STRING:
769 case TRACE_VALUE_TYPE_COPY_STRING:
770 EscapeJSONString(value.as_string ? value.as_string : "NULL", true, out);
771 break;
772 default:
773 NOTREACHED() << "Don't know how to print this value";
774 break;
775 }
776 }
777
778 void TraceEvent::AppendAsJSON(
779 std::string* out,
780 const ArgumentFilterPredicate& argument_filter_predicate) const {
781 int64 time_int64 = timestamp_.ToInternalValue();
782 int process_id = TraceLog::GetInstance()->process_id();
783 const char* category_group_name =
784 TraceLog::GetCategoryGroupName(category_group_enabled_);
785
786 // Category group checked at category creation time.
787 DCHECK(!strchr(name_, '"'));
788 StringAppendF(out, "{\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64
789 ","
790 "\"ph\":\"%c\",\"cat\":\"%s\",\"name\":\"%s\",\"args\":",
791 process_id, thread_id_, time_int64, phase_, category_group_name,
792 name_);
793
794 // Output argument names and values, stop at first NULL argument name.
795 bool strip_args = arg_names_[0] && !argument_filter_predicate.is_null() &&
796 !argument_filter_predicate.Run(category_group_name, name_);
797
798 if (strip_args) {
799 *out += "\"__stripped__\"";
800 } else {
801 *out += "{";
802
803 for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
804 if (i > 0)
805 *out += ",";
806 *out += "\"";
807 *out += arg_names_[i];
808 *out += "\":";
809
810 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
811 convertable_values_[i]->AppendAsTraceFormat(out);
812 else
813 AppendValueAsJSON(arg_types_[i], arg_values_[i], out);
814 }
815
816 *out += "}";
817 }
818
819 if (phase_ == TRACE_EVENT_PHASE_COMPLETE) {
820 int64 duration = duration_.ToInternalValue();
821 if (duration != -1)
822 StringAppendF(out, ",\"dur\":%" PRId64, duration);
823 if (!thread_timestamp_.is_null()) {
824 int64 thread_duration = thread_duration_.ToInternalValue();
825 if (thread_duration != -1)
826 StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration);
827 }
828 }
829
830 // Output tts if thread_timestamp is valid.
831 if (!thread_timestamp_.is_null()) {
832 int64 thread_time_int64 = thread_timestamp_.ToInternalValue();
833 StringAppendF(out, ",\"tts\":%" PRId64, thread_time_int64);
834 }
835
836 // Output async tts marker field if flag is set.
837 if (flags_ & TRACE_EVENT_FLAG_ASYNC_TTS) {
838 StringAppendF(out, ", \"use_async_tts\":1");
839 }
840
841 // If id_ is set, print it out as a hex string so we don't loose any
842 // bits (it might be a 64-bit pointer).
843 if (flags_ & TRACE_EVENT_FLAG_HAS_ID)
844 StringAppendF(out, ",\"id\":\"0x%" PRIx64 "\"", static_cast<uint64>(id_));
845
846 if (flags_ & TRACE_EVENT_FLAG_BIND_TO_ENCLOSING)
847 StringAppendF(out, ",\"bp\":\"e\"");
848
849 // Instant events also output their scope.
850 if (phase_ == TRACE_EVENT_PHASE_INSTANT) {
851 char scope = '?';
852 switch (flags_ & TRACE_EVENT_FLAG_SCOPE_MASK) {
853 case TRACE_EVENT_SCOPE_GLOBAL:
854 scope = TRACE_EVENT_SCOPE_NAME_GLOBAL;
855 break;
856
857 case TRACE_EVENT_SCOPE_PROCESS:
858 scope = TRACE_EVENT_SCOPE_NAME_PROCESS;
859 break;
860
861 case TRACE_EVENT_SCOPE_THREAD:
862 scope = TRACE_EVENT_SCOPE_NAME_THREAD;
863 break;
864 }
865 StringAppendF(out, ",\"s\":\"%c\"", scope);
866 }
867
868 *out += "}";
869 }
870
871 void TraceEvent::AppendPrettyPrinted(std::ostringstream* out) const {
872 *out << name_ << "[";
873 *out << TraceLog::GetCategoryGroupName(category_group_enabled_);
874 *out << "]";
875 if (arg_names_[0]) {
876 *out << ", {";
877 for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) {
878 if (i > 0)
879 *out << ", ";
880 *out << arg_names_[i] << ":";
881 std::string value_as_text;
882
883 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE)
884 convertable_values_[i]->AppendAsTraceFormat(&value_as_text);
885 else
886 AppendValueAsJSON(arg_types_[i], arg_values_[i], &value_as_text);
887
888 *out << value_as_text;
889 }
890 *out << "}";
891 }
892 }
893
894 ////////////////////////////////////////////////////////////////////////////////
895 //
896 // TraceResultBuffer
897 //
898 ////////////////////////////////////////////////////////////////////////////////
899
900 TraceResultBuffer::OutputCallback
901 TraceResultBuffer::SimpleOutput::GetCallback() {
902 return Bind(&SimpleOutput::Append, Unretained(this));
903 }
904
905 void TraceResultBuffer::SimpleOutput::Append(
906 const std::string& json_trace_output) {
907 json_output += json_trace_output;
908 }
909
910 TraceResultBuffer::TraceResultBuffer() : append_comma_(false) {
911 }
912
913 TraceResultBuffer::~TraceResultBuffer() {
914 }
915
916 void TraceResultBuffer::SetOutputCallback(
917 const OutputCallback& json_chunk_callback) {
918 output_callback_ = json_chunk_callback;
919 }
920
921 void TraceResultBuffer::Start() {
922 append_comma_ = false;
923 output_callback_.Run("[");
924 }
925
926 void TraceResultBuffer::AddFragment(const std::string& trace_fragment) {
927 if (append_comma_)
928 output_callback_.Run(",");
929 append_comma_ = true;
930 output_callback_.Run(trace_fragment);
931 }
932
933 void TraceResultBuffer::Finish() {
934 output_callback_.Run("]");
935 }
936
937 ////////////////////////////////////////////////////////////////////////////////
938 //
939 // TraceSamplingThread
940 //
941 ////////////////////////////////////////////////////////////////////////////////
942 class TraceBucketData;
943 typedef base::Callback<void(TraceBucketData*)> TraceSampleCallback;
944
945 class TraceBucketData {
946 public:
947 TraceBucketData(base::subtle::AtomicWord* bucket,
948 const char* name,
949 TraceSampleCallback callback);
950 ~TraceBucketData();
951
952 TRACE_EVENT_API_ATOMIC_WORD* bucket;
953 const char* bucket_name;
954 TraceSampleCallback callback;
955 };
956
957 // This object must be created on the IO thread.
958 class TraceSamplingThread : public PlatformThread::Delegate {
959 public:
960 TraceSamplingThread();
961 ~TraceSamplingThread() override;
962
963 // Implementation of PlatformThread::Delegate:
964 void ThreadMain() override;
965
966 static void DefaultSamplingCallback(TraceBucketData* bucekt_data);
967
968 void Stop();
969 void WaitSamplingEventForTesting();
970
971 private:
972 friend class TraceLog;
973
974 void GetSamples();
975 // Not thread-safe. Once the ThreadMain has been called, this can no longer
976 // be called.
977 void RegisterSampleBucket(TRACE_EVENT_API_ATOMIC_WORD* bucket,
978 const char* const name,
979 TraceSampleCallback callback);
980 // Splits a combined "category\0name" into the two component parts.
981 static void ExtractCategoryAndName(const char* combined,
982 const char** category,
983 const char** name);
984 std::vector<TraceBucketData> sample_buckets_;
985 bool thread_running_;
986 CancellationFlag cancellation_flag_;
987 WaitableEvent waitable_event_for_testing_;
988 };
989
990
991 TraceSamplingThread::TraceSamplingThread()
992 : thread_running_(false),
993 waitable_event_for_testing_(false, false) {
994 }
995
996 TraceSamplingThread::~TraceSamplingThread() {
997 }
998
999 void TraceSamplingThread::ThreadMain() {
1000 PlatformThread::SetName("Sampling Thread");
1001 thread_running_ = true;
1002 const int kSamplingFrequencyMicroseconds = 1000;
1003 while (!cancellation_flag_.IsSet()) {
1004 PlatformThread::Sleep(
1005 TimeDelta::FromMicroseconds(kSamplingFrequencyMicroseconds));
1006 GetSamples();
1007 waitable_event_for_testing_.Signal();
1008 }
1009 }
1010
1011 // static
1012 void TraceSamplingThread::DefaultSamplingCallback(
1013 TraceBucketData* bucket_data) {
1014 TRACE_EVENT_API_ATOMIC_WORD category_and_name =
1015 TRACE_EVENT_API_ATOMIC_LOAD(*bucket_data->bucket);
1016 if (!category_and_name)
1017 return;
1018 const char* const combined =
1019 reinterpret_cast<const char* const>(category_and_name);
1020 const char* category_group;
1021 const char* name;
1022 ExtractCategoryAndName(combined, &category_group, &name);
1023 TRACE_EVENT_API_ADD_TRACE_EVENT(TRACE_EVENT_PHASE_SAMPLE,
1024 TraceLog::GetCategoryGroupEnabled(category_group),
1025 name, 0, 0, NULL, NULL, NULL, NULL, 0);
1026 }
1027
1028 void TraceSamplingThread::GetSamples() {
1029 for (size_t i = 0; i < sample_buckets_.size(); ++i) {
1030 TraceBucketData* bucket_data = &sample_buckets_[i];
1031 bucket_data->callback.Run(bucket_data);
1032 }
1033 }
1034
1035 void TraceSamplingThread::RegisterSampleBucket(
1036 TRACE_EVENT_API_ATOMIC_WORD* bucket,
1037 const char* const name,
1038 TraceSampleCallback callback) {
1039 // Access to sample_buckets_ doesn't cause races with the sampling thread
1040 // that uses the sample_buckets_, because it is guaranteed that
1041 // RegisterSampleBucket is called before the sampling thread is created.
1042 DCHECK(!thread_running_);
1043 sample_buckets_.push_back(TraceBucketData(bucket, name, callback));
1044 }
1045
1046 // static
1047 void TraceSamplingThread::ExtractCategoryAndName(const char* combined,
1048 const char** category,
1049 const char** name) {
1050 *category = combined;
1051 *name = &combined[strlen(combined) + 1];
1052 }
1053
1054 void TraceSamplingThread::Stop() {
1055 cancellation_flag_.Set();
1056 }
1057
1058 void TraceSamplingThread::WaitSamplingEventForTesting() {
1059 waitable_event_for_testing_.Wait();
1060 }
1061
1062 TraceBucketData::TraceBucketData(base::subtle::AtomicWord* bucket,
1063 const char* name,
1064 TraceSampleCallback callback)
1065 : bucket(bucket),
1066 bucket_name(name),
1067 callback(callback) {
1068 }
1069
1070 TraceBucketData::~TraceBucketData() {
1071 }
1072
1073 ////////////////////////////////////////////////////////////////////////////////
1074 //
1075 // TraceLog
1076 //
1077 ////////////////////////////////////////////////////////////////////////////////
1078
1079 class TraceLog::ThreadLocalEventBuffer
1080 : public MessageLoop::DestructionObserver,
1081 public MemoryDumpProvider {
1082 public:
1083 ThreadLocalEventBuffer(TraceLog* trace_log);
1084 ~ThreadLocalEventBuffer() override;
1085
1086 TraceEvent* AddTraceEvent(TraceEventHandle* handle);
1087
1088 void ReportOverhead(const TraceTicks& event_timestamp,
1089 const ThreadTicks& event_thread_timestamp);
1090
1091 TraceEvent* GetEventByHandle(TraceEventHandle handle) {
1092 if (!chunk_ || handle.chunk_seq != chunk_->seq() ||
1093 handle.chunk_index != chunk_index_)
1094 return NULL;
1095
1096 return chunk_->GetEventAt(handle.event_index);
1097 }
1098
1099 int generation() const { return generation_; }
1100
1101 private:
1102 // MessageLoop::DestructionObserver
1103 void WillDestroyCurrentMessageLoop() override;
1104
1105 // MemoryDumpProvider implementation.
1106 bool OnMemoryDump(ProcessMemoryDump* pmd) override;
1107
1108 void FlushWhileLocked();
1109
1110 void CheckThisIsCurrentBuffer() const {
1111 DCHECK(trace_log_->thread_local_event_buffer_.Get() == this);
1112 }
1113
1114 // Since TraceLog is a leaky singleton, trace_log_ will always be valid
1115 // as long as the thread exists.
1116 TraceLog* trace_log_;
1117 scoped_ptr<TraceBufferChunk> chunk_;
1118 size_t chunk_index_;
1119 int event_count_;
1120 TimeDelta overhead_;
1121 int generation_;
1122
1123 DISALLOW_COPY_AND_ASSIGN(ThreadLocalEventBuffer);
1124 };
1125
1126 TraceLog::ThreadLocalEventBuffer::ThreadLocalEventBuffer(TraceLog* trace_log)
1127 : trace_log_(trace_log),
1128 chunk_index_(0),
1129 event_count_(0),
1130 generation_(trace_log->generation()) {
1131 // ThreadLocalEventBuffer is created only if the thread has a message loop, so
1132 // the following message_loop won't be NULL.
1133 MessageLoop* message_loop = MessageLoop::current();
1134 message_loop->AddDestructionObserver(this);
1135
1136 // This is to report the local memory usage when memory-infra is enabled.
1137 MemoryDumpManager::GetInstance()->RegisterDumpProvider(
1138 this, ThreadTaskRunnerHandle::Get());
1139
1140 AutoLock lock(trace_log->lock_);
1141 trace_log->thread_message_loops_.insert(message_loop);
1142 }
1143
1144 TraceLog::ThreadLocalEventBuffer::~ThreadLocalEventBuffer() {
1145 CheckThisIsCurrentBuffer();
1146 MessageLoop::current()->RemoveDestructionObserver(this);
1147 MemoryDumpManager::GetInstance()->UnregisterDumpProvider(this);
1148
1149 // Zero event_count_ happens in either of the following cases:
1150 // - no event generated for the thread;
1151 // - the thread has no message loop;
1152 // - trace_event_overhead is disabled.
1153 if (event_count_) {
1154 InitializeMetadataEvent(AddTraceEvent(NULL),
1155 static_cast<int>(base::PlatformThread::CurrentId()),
1156 "overhead", "average_overhead",
1157 overhead_.InMillisecondsF() / event_count_);
1158 }
1159
1160 {
1161 AutoLock lock(trace_log_->lock_);
1162 FlushWhileLocked();
1163 trace_log_->thread_message_loops_.erase(MessageLoop::current());
1164 }
1165 trace_log_->thread_local_event_buffer_.Set(NULL);
1166 }
1167
1168 TraceEvent* TraceLog::ThreadLocalEventBuffer::AddTraceEvent(
1169 TraceEventHandle* handle) {
1170 CheckThisIsCurrentBuffer();
1171
1172 if (chunk_ && chunk_->IsFull()) {
1173 AutoLock lock(trace_log_->lock_);
1174 FlushWhileLocked();
1175 chunk_.reset();
1176 }
1177 if (!chunk_) {
1178 AutoLock lock(trace_log_->lock_);
1179 chunk_ = trace_log_->logged_events_->GetChunk(&chunk_index_);
1180 trace_log_->CheckIfBufferIsFullWhileLocked();
1181 }
1182 if (!chunk_)
1183 return NULL;
1184
1185 size_t event_index;
1186 TraceEvent* trace_event = chunk_->AddTraceEvent(&event_index);
1187 if (trace_event && handle)
1188 MakeHandle(chunk_->seq(), chunk_index_, event_index, handle);
1189
1190 return trace_event;
1191 }
1192
1193 void TraceLog::ThreadLocalEventBuffer::ReportOverhead(
1194 const TraceTicks& event_timestamp,
1195 const ThreadTicks& event_thread_timestamp) {
1196 if (!g_category_group_enabled[g_category_trace_event_overhead])
1197 return;
1198
1199 CheckThisIsCurrentBuffer();
1200
1201 event_count_++;
1202 ThreadTicks thread_now = ThreadNow();
1203 TraceTicks now = trace_log_->OffsetNow();
1204 TimeDelta overhead = now - event_timestamp;
1205 if (overhead.InMicroseconds() >= kOverheadReportThresholdInMicroseconds) {
1206 TraceEvent* trace_event = AddTraceEvent(NULL);
1207 if (trace_event) {
1208 trace_event->Initialize(
1209 static_cast<int>(PlatformThread::CurrentId()),
1210 event_timestamp, event_thread_timestamp,
1211 TRACE_EVENT_PHASE_COMPLETE,
1212 &g_category_group_enabled[g_category_trace_event_overhead],
1213 "overhead", 0, 0, NULL, NULL, NULL, NULL, 0);
1214 trace_event->UpdateDuration(now, thread_now);
1215 }
1216 }
1217 overhead_ += overhead;
1218 }
1219
1220 void TraceLog::ThreadLocalEventBuffer::WillDestroyCurrentMessageLoop() {
1221 delete this;
1222 }
1223
1224 bool TraceLog::ThreadLocalEventBuffer::OnMemoryDump(ProcessMemoryDump* pmd) {
1225 if (!chunk_)
1226 return true;
1227 std::string dump_base_name = StringPrintf(
1228 "tracing/thread_%d", static_cast<int>(PlatformThread::CurrentId()));
1229 TraceEventMemoryOverhead overhead;
1230 chunk_->EstimateTraceMemoryOverhead(&overhead);
1231 overhead.DumpInto(dump_base_name.c_str(), pmd);
1232 return true;
1233 }
1234
1235 void TraceLog::ThreadLocalEventBuffer::FlushWhileLocked() {
1236 if (!chunk_)
1237 return;
1238
1239 trace_log_->lock_.AssertAcquired();
1240 if (trace_log_->CheckGeneration(generation_)) {
1241 // Return the chunk to the buffer only if the generation matches.
1242 trace_log_->logged_events_->ReturnChunk(chunk_index_, chunk_.Pass());
1243 }
1244 // Otherwise this method may be called from the destructor, or TraceLog will
1245 // find the generation mismatch and delete this buffer soon.
1246 }
1247
1248 TraceLogStatus::TraceLogStatus() : event_capacity(0), event_count(0) {
1249 }
1250
1251 TraceLogStatus::~TraceLogStatus() {
1252 }
1253
1254 // static
1255 TraceLog* TraceLog::GetInstance() {
1256 return Singleton<TraceLog, LeakySingletonTraits<TraceLog> >::get();
1257 }
1258
1259 TraceLog::TraceLog()
1260 : mode_(DISABLED),
1261 num_traces_recorded_(0),
1262 event_callback_(0),
1263 dispatching_to_observer_list_(false),
1264 process_sort_index_(0),
1265 process_id_hash_(0),
1266 process_id_(0),
1267 watch_category_(0),
1268 trace_options_(kInternalRecordUntilFull),
1269 sampling_thread_handle_(0),
1270 trace_config_(TraceConfig()),
1271 event_callback_trace_config_(TraceConfig()),
1272 thread_shared_chunk_index_(0),
1273 generation_(0),
1274 use_worker_thread_(false) {
1275 // Trace is enabled or disabled on one thread while other threads are
1276 // accessing the enabled flag. We don't care whether edge-case events are
1277 // traced or not, so we allow races on the enabled flag to keep the trace
1278 // macros fast.
1279 // TODO(jbates): ANNOTATE_BENIGN_RACE_SIZED crashes windows TSAN bots:
1280 // ANNOTATE_BENIGN_RACE_SIZED(g_category_group_enabled,
1281 // sizeof(g_category_group_enabled),
1282 // "trace_event category enabled");
1283 for (int i = 0; i < MAX_CATEGORY_GROUPS; ++i) {
1284 ANNOTATE_BENIGN_RACE(&g_category_group_enabled[i],
1285 "trace_event category enabled");
1286 }
1287 #if defined(OS_NACL) // NaCl shouldn't expose the process id.
1288 SetProcessID(0);
1289 #else
1290 SetProcessID(static_cast<int>(GetCurrentProcId()));
1291
1292 // NaCl also shouldn't access the command line.
1293 if (CommandLine::InitializedForCurrentProcess() &&
1294 CommandLine::ForCurrentProcess()->HasSwitch(switches::kTraceToConsole)) {
1295 std::string filter = CommandLine::ForCurrentProcess()->GetSwitchValueASCII(
1296 switches::kTraceToConsole);
1297 if (filter.empty()) {
1298 filter = kEchoToConsoleCategoryFilter;
1299 } else {
1300 filter.append(",");
1301 filter.append(kEchoToConsoleCategoryFilter);
1302 }
1303
1304 LOG(ERROR) << "Start " << switches::kTraceToConsole
1305 << " with CategoryFilter '" << filter << "'.";
1306 SetEnabled(TraceConfig(filter, ECHO_TO_CONSOLE), RECORDING_MODE);
1307 }
1308 #endif
1309
1310 logged_events_.reset(CreateTraceBuffer());
1311
1312 MemoryDumpManager::GetInstance()->RegisterDumpProvider(this);
1313 }
1314
1315 TraceLog::~TraceLog() {
1316 }
1317
1318 void TraceLog::InitializeThreadLocalEventBufferIfSupported() {
1319 // A ThreadLocalEventBuffer needs the message loop
1320 // - to know when the thread exits;
1321 // - to handle the final flush.
1322 // For a thread without a message loop or the message loop may be blocked, the
1323 // trace events will be added into the main buffer directly.
1324 if (thread_blocks_message_loop_.Get() || !MessageLoop::current())
1325 return;
1326 auto thread_local_event_buffer = thread_local_event_buffer_.Get();
1327 if (thread_local_event_buffer &&
1328 !CheckGeneration(thread_local_event_buffer->generation())) {
1329 delete thread_local_event_buffer;
1330 thread_local_event_buffer = NULL;
1331 }
1332 if (!thread_local_event_buffer) {
1333 thread_local_event_buffer = new ThreadLocalEventBuffer(this);
1334 thread_local_event_buffer_.Set(thread_local_event_buffer);
1335 }
1336 }
1337
1338 bool TraceLog::OnMemoryDump(ProcessMemoryDump* pmd) {
1339 TraceEventMemoryOverhead overhead;
1340 overhead.Add("TraceLog", sizeof(*this));
1341 {
1342 AutoLock lock(lock_);
1343 if (logged_events_)
1344 logged_events_->EstimateTraceMemoryOverhead(&overhead);
1345 }
1346 overhead.AddSelf();
1347 overhead.DumpInto("tracing/main_trace_log", pmd);
1348 return true;
1349 }
1350
1351 const unsigned char* TraceLog::GetCategoryGroupEnabled(
1352 const char* category_group) {
1353 TraceLog* tracelog = GetInstance();
1354 if (!tracelog) {
1355 DCHECK(!g_category_group_enabled[g_category_already_shutdown]);
1356 return &g_category_group_enabled[g_category_already_shutdown];
1357 }
1358 return tracelog->GetCategoryGroupEnabledInternal(category_group);
1359 }
1360
1361 const char* TraceLog::GetCategoryGroupName(
1362 const unsigned char* category_group_enabled) {
1363 // Calculate the index of the category group by finding
1364 // category_group_enabled in g_category_group_enabled array.
1365 uintptr_t category_begin =
1366 reinterpret_cast<uintptr_t>(g_category_group_enabled);
1367 uintptr_t category_ptr = reinterpret_cast<uintptr_t>(category_group_enabled);
1368 DCHECK(category_ptr >= category_begin &&
1369 category_ptr < reinterpret_cast<uintptr_t>(
1370 g_category_group_enabled + MAX_CATEGORY_GROUPS)) <<
1371 "out of bounds category pointer";
1372 uintptr_t category_index =
1373 (category_ptr - category_begin) / sizeof(g_category_group_enabled[0]);
1374 return g_category_groups[category_index];
1375 }
1376
1377 void TraceLog::UpdateCategoryGroupEnabledFlag(size_t category_index) {
1378 unsigned char enabled_flag = 0;
1379 const char* category_group = g_category_groups[category_index];
1380 if (mode_ == RECORDING_MODE &&
1381 trace_config_.IsCategoryGroupEnabled(category_group))
1382 enabled_flag |= ENABLED_FOR_RECORDING;
1383 else if (mode_ == MONITORING_MODE &&
1384 trace_config_.IsCategoryGroupEnabled(category_group))
1385 enabled_flag |= ENABLED_FOR_MONITORING;
1386 if (event_callback_ &&
1387 event_callback_trace_config_.IsCategoryGroupEnabled(category_group))
1388 enabled_flag |= ENABLED_FOR_EVENT_CALLBACK;
1389 #if defined(OS_WIN)
1390 if (base::trace_event::TraceEventETWExport::IsCategoryGroupEnabled(
1391 category_group)) {
1392 enabled_flag |= ENABLED_FOR_ETW_EXPORT;
1393 }
1394 #endif
1395
1396 g_category_group_enabled[category_index] = enabled_flag;
1397 }
1398
1399 void TraceLog::UpdateCategoryGroupEnabledFlags() {
1400 size_t category_index = base::subtle::NoBarrier_Load(&g_category_index);
1401 for (size_t i = 0; i < category_index; i++)
1402 UpdateCategoryGroupEnabledFlag(i);
1403 }
1404
1405 void TraceLog::UpdateSyntheticDelaysFromTraceConfig() {
1406 ResetTraceEventSyntheticDelays();
1407 const TraceConfig::StringList& delays =
1408 trace_config_.GetSyntheticDelayValues();
1409 TraceConfig::StringList::const_iterator ci;
1410 for (ci = delays.begin(); ci != delays.end(); ++ci) {
1411 StringTokenizer tokens(*ci, ";");
1412 if (!tokens.GetNext())
1413 continue;
1414 TraceEventSyntheticDelay* delay =
1415 TraceEventSyntheticDelay::Lookup(tokens.token());
1416 while (tokens.GetNext()) {
1417 std::string token = tokens.token();
1418 char* duration_end;
1419 double target_duration = strtod(token.c_str(), &duration_end);
1420 if (duration_end != token.c_str()) {
1421 delay->SetTargetDuration(TimeDelta::FromMicroseconds(
1422 static_cast<int64>(target_duration * 1e6)));
1423 } else if (token == "static") {
1424 delay->SetMode(TraceEventSyntheticDelay::STATIC);
1425 } else if (token == "oneshot") {
1426 delay->SetMode(TraceEventSyntheticDelay::ONE_SHOT);
1427 } else if (token == "alternating") {
1428 delay->SetMode(TraceEventSyntheticDelay::ALTERNATING);
1429 }
1430 }
1431 }
1432 }
1433
1434 const unsigned char* TraceLog::GetCategoryGroupEnabledInternal(
1435 const char* category_group) {
1436 DCHECK(!strchr(category_group, '"')) <<
1437 "Category groups may not contain double quote";
1438 // The g_category_groups is append only, avoid using a lock for the fast path.
1439 size_t current_category_index = base::subtle::Acquire_Load(&g_category_index);
1440
1441 // Search for pre-existing category group.
1442 for (size_t i = 0; i < current_category_index; ++i) {
1443 if (strcmp(g_category_groups[i], category_group) == 0) {
1444 return &g_category_group_enabled[i];
1445 }
1446 }
1447
1448 unsigned char* category_group_enabled = NULL;
1449 // This is the slow path: the lock is not held in the case above, so more
1450 // than one thread could have reached here trying to add the same category.
1451 // Only hold to lock when actually appending a new category, and
1452 // check the categories groups again.
1453 AutoLock lock(lock_);
1454 size_t category_index = base::subtle::Acquire_Load(&g_category_index);
1455 for (size_t i = 0; i < category_index; ++i) {
1456 if (strcmp(g_category_groups[i], category_group) == 0) {
1457 return &g_category_group_enabled[i];
1458 }
1459 }
1460
1461 // Create a new category group.
1462 DCHECK(category_index < MAX_CATEGORY_GROUPS) <<
1463 "must increase MAX_CATEGORY_GROUPS";
1464 if (category_index < MAX_CATEGORY_GROUPS) {
1465 // Don't hold on to the category_group pointer, so that we can create
1466 // category groups with strings not known at compile time (this is
1467 // required by SetWatchEvent).
1468 const char* new_group = strdup(category_group);
1469 ANNOTATE_LEAKING_OBJECT_PTR(new_group);
1470 g_category_groups[category_index] = new_group;
1471 DCHECK(!g_category_group_enabled[category_index]);
1472 // Note that if both included and excluded patterns in the
1473 // TraceConfig are empty, we exclude nothing,
1474 // thereby enabling this category group.
1475 UpdateCategoryGroupEnabledFlag(category_index);
1476 category_group_enabled = &g_category_group_enabled[category_index];
1477 // Update the max index now.
1478 base::subtle::Release_Store(&g_category_index, category_index + 1);
1479 } else {
1480 category_group_enabled =
1481 &g_category_group_enabled[g_category_categories_exhausted];
1482 }
1483 return category_group_enabled;
1484 }
1485
1486 void TraceLog::GetKnownCategoryGroups(
1487 std::vector<std::string>* category_groups) {
1488 AutoLock lock(lock_);
1489 category_groups->push_back(
1490 g_category_groups[g_category_trace_event_overhead]);
1491 size_t category_index = base::subtle::NoBarrier_Load(&g_category_index);
1492 for (size_t i = g_num_builtin_categories; i < category_index; i++)
1493 category_groups->push_back(g_category_groups[i]);
1494 }
1495
1496 void TraceLog::SetEnabled(const TraceConfig& trace_config, Mode mode) {
1497 std::vector<EnabledStateObserver*> observer_list;
1498 {
1499 AutoLock lock(lock_);
1500
1501 // Can't enable tracing when Flush() is in progress.
1502 DCHECK(!flush_task_runner_);
1503
1504 InternalTraceOptions new_options =
1505 GetInternalOptionsFromTraceConfig(trace_config);
1506
1507 InternalTraceOptions old_options = trace_options();
1508
1509 if (IsEnabled()) {
1510 if (new_options != old_options) {
1511 DLOG(ERROR) << "Attempting to re-enable tracing with a different "
1512 << "set of options.";
1513 }
1514
1515 if (mode != mode_) {
1516 DLOG(ERROR) << "Attempting to re-enable tracing with a different mode.";
1517 }
1518
1519 trace_config_.Merge(trace_config);
1520 UpdateCategoryGroupEnabledFlags();
1521 return;
1522 }
1523
1524 if (dispatching_to_observer_list_) {
1525 DLOG(ERROR) <<
1526 "Cannot manipulate TraceLog::Enabled state from an observer.";
1527 return;
1528 }
1529
1530 mode_ = mode;
1531
1532 if (new_options != old_options) {
1533 subtle::NoBarrier_Store(&trace_options_, new_options);
1534 UseNextTraceBuffer();
1535 }
1536
1537 num_traces_recorded_++;
1538
1539 trace_config_ = TraceConfig(trace_config);
1540 UpdateCategoryGroupEnabledFlags();
1541 UpdateSyntheticDelaysFromTraceConfig();
1542
1543 if (new_options & kInternalEnableSampling) {
1544 sampling_thread_.reset(new TraceSamplingThread);
1545 sampling_thread_->RegisterSampleBucket(
1546 &g_trace_state[0],
1547 "bucket0",
1548 Bind(&TraceSamplingThread::DefaultSamplingCallback));
1549 sampling_thread_->RegisterSampleBucket(
1550 &g_trace_state[1],
1551 "bucket1",
1552 Bind(&TraceSamplingThread::DefaultSamplingCallback));
1553 sampling_thread_->RegisterSampleBucket(
1554 &g_trace_state[2],
1555 "bucket2",
1556 Bind(&TraceSamplingThread::DefaultSamplingCallback));
1557 if (!PlatformThread::Create(
1558 0, sampling_thread_.get(), &sampling_thread_handle_)) {
1559 DCHECK(false) << "failed to create thread";
1560 }
1561 }
1562
1563 dispatching_to_observer_list_ = true;
1564 observer_list = enabled_state_observer_list_;
1565 }
1566 // Notify observers outside the lock in case they trigger trace events.
1567 for (size_t i = 0; i < observer_list.size(); ++i)
1568 observer_list[i]->OnTraceLogEnabled();
1569
1570 {
1571 AutoLock lock(lock_);
1572 dispatching_to_observer_list_ = false;
1573 }
1574 }
1575
1576 void TraceLog::SetArgumentFilterPredicate(
1577 const TraceEvent::ArgumentFilterPredicate& argument_filter_predicate) {
1578 AutoLock lock(lock_);
1579 DCHECK(!argument_filter_predicate.is_null());
1580 DCHECK(argument_filter_predicate_.is_null());
1581 argument_filter_predicate_ = argument_filter_predicate;
1582 }
1583
1584 TraceLog::InternalTraceOptions TraceLog::GetInternalOptionsFromTraceConfig(
1585 const TraceConfig& config) {
1586 InternalTraceOptions ret =
1587 config.IsSamplingEnabled() ? kInternalEnableSampling : kInternalNone;
1588 if (config.IsArgumentFilterEnabled())
1589 ret |= kInternalEnableArgumentFilter;
1590 switch (config.GetTraceRecordMode()) {
1591 case RECORD_UNTIL_FULL:
1592 return ret | kInternalRecordUntilFull;
1593 case RECORD_CONTINUOUSLY:
1594 return ret | kInternalRecordContinuously;
1595 case ECHO_TO_CONSOLE:
1596 return ret | kInternalEchoToConsole;
1597 case RECORD_AS_MUCH_AS_POSSIBLE:
1598 return ret | kInternalRecordAsMuchAsPossible;
1599 }
1600 NOTREACHED();
1601 return kInternalNone;
1602 }
1603
1604 TraceConfig TraceLog::GetCurrentTraceConfig() const {
1605 AutoLock lock(lock_);
1606 return trace_config_;
1607 }
1608
1609 void TraceLog::SetDisabled() {
1610 AutoLock lock(lock_);
1611 SetDisabledWhileLocked();
1612 }
1613
1614 void TraceLog::SetDisabledWhileLocked() {
1615 lock_.AssertAcquired();
1616
1617 if (!IsEnabled())
1618 return;
1619
1620 if (dispatching_to_observer_list_) {
1621 DLOG(ERROR)
1622 << "Cannot manipulate TraceLog::Enabled state from an observer.";
1623 return;
1624 }
1625
1626 mode_ = DISABLED;
1627
1628 if (sampling_thread_.get()) {
1629 // Stop the sampling thread.
1630 sampling_thread_->Stop();
1631 lock_.Release();
1632 PlatformThread::Join(sampling_thread_handle_);
1633 lock_.Acquire();
1634 sampling_thread_handle_ = PlatformThreadHandle();
1635 sampling_thread_.reset();
1636 }
1637
1638 trace_config_.Clear();
1639 subtle::NoBarrier_Store(&watch_category_, 0);
1640 watch_event_name_ = "";
1641 UpdateCategoryGroupEnabledFlags();
1642 AddMetadataEventsWhileLocked();
1643
1644 dispatching_to_observer_list_ = true;
1645 std::vector<EnabledStateObserver*> observer_list =
1646 enabled_state_observer_list_;
1647
1648 {
1649 // Dispatch to observers outside the lock in case the observer triggers a
1650 // trace event.
1651 AutoUnlock unlock(lock_);
1652 for (size_t i = 0; i < observer_list.size(); ++i)
1653 observer_list[i]->OnTraceLogDisabled();
1654 }
1655 dispatching_to_observer_list_ = false;
1656 }
1657
1658 int TraceLog::GetNumTracesRecorded() {
1659 AutoLock lock(lock_);
1660 if (!IsEnabled())
1661 return -1;
1662 return num_traces_recorded_;
1663 }
1664
1665 void TraceLog::AddEnabledStateObserver(EnabledStateObserver* listener) {
1666 enabled_state_observer_list_.push_back(listener);
1667 }
1668
1669 void TraceLog::RemoveEnabledStateObserver(EnabledStateObserver* listener) {
1670 std::vector<EnabledStateObserver*>::iterator it =
1671 std::find(enabled_state_observer_list_.begin(),
1672 enabled_state_observer_list_.end(),
1673 listener);
1674 if (it != enabled_state_observer_list_.end())
1675 enabled_state_observer_list_.erase(it);
1676 }
1677
1678 bool TraceLog::HasEnabledStateObserver(EnabledStateObserver* listener) const {
1679 std::vector<EnabledStateObserver*>::const_iterator it =
1680 std::find(enabled_state_observer_list_.begin(),
1681 enabled_state_observer_list_.end(),
1682 listener);
1683 return it != enabled_state_observer_list_.end();
1684 }
1685
1686 TraceLogStatus TraceLog::GetStatus() const {
1687 AutoLock lock(lock_);
1688 TraceLogStatus result;
1689 result.event_capacity = logged_events_->Capacity();
1690 result.event_count = logged_events_->Size();
1691 return result;
1692 }
1693
1694 bool TraceLog::BufferIsFull() const {
1695 AutoLock lock(lock_);
1696 return logged_events_->IsFull();
1697 }
1698
1699 TraceBuffer* TraceLog::CreateTraceBuffer() {
1700 InternalTraceOptions options = trace_options();
1701 if (options & kInternalRecordContinuously)
1702 return new TraceBufferRingBuffer(kTraceEventRingBufferChunks);
1703 else if ((options & kInternalEnableSampling) && mode_ == MONITORING_MODE)
1704 return new TraceBufferRingBuffer(kMonitorTraceEventBufferChunks);
1705 else if (options & kInternalEchoToConsole)
1706 return new TraceBufferRingBuffer(kEchoToConsoleTraceEventBufferChunks);
1707 else if (options & kInternalRecordAsMuchAsPossible)
1708 return CreateTraceBufferVectorOfSize(kTraceEventVectorBigBufferChunks);
1709 return CreateTraceBufferVectorOfSize(kTraceEventVectorBufferChunks);
1710 }
1711
1712 TraceBuffer* TraceLog::CreateTraceBufferVectorOfSize(size_t max_chunks) {
1713 return new TraceBufferVector(max_chunks);
1714 }
1715
1716 TraceEvent* TraceLog::AddEventToThreadSharedChunkWhileLocked(
1717 TraceEventHandle* handle, bool check_buffer_is_full) {
1718 lock_.AssertAcquired();
1719
1720 if (thread_shared_chunk_ && thread_shared_chunk_->IsFull()) {
1721 logged_events_->ReturnChunk(thread_shared_chunk_index_,
1722 thread_shared_chunk_.Pass());
1723 }
1724
1725 if (!thread_shared_chunk_) {
1726 thread_shared_chunk_ = logged_events_->GetChunk(
1727 &thread_shared_chunk_index_);
1728 if (check_buffer_is_full)
1729 CheckIfBufferIsFullWhileLocked();
1730 }
1731 if (!thread_shared_chunk_)
1732 return NULL;
1733
1734 size_t event_index;
1735 TraceEvent* trace_event = thread_shared_chunk_->AddTraceEvent(&event_index);
1736 if (trace_event && handle) {
1737 MakeHandle(thread_shared_chunk_->seq(), thread_shared_chunk_index_,
1738 event_index, handle);
1739 }
1740 return trace_event;
1741 }
1742
1743 void TraceLog::CheckIfBufferIsFullWhileLocked() {
1744 lock_.AssertAcquired();
1745 if (logged_events_->IsFull()) {
1746 if (buffer_limit_reached_timestamp_.is_null()) {
1747 buffer_limit_reached_timestamp_ = OffsetNow();
1748 }
1749 SetDisabledWhileLocked();
1750 }
1751 }
1752
1753 void TraceLog::SetEventCallbackEnabled(const TraceConfig& trace_config,
1754 EventCallback cb) {
1755 AutoLock lock(lock_);
1756 subtle::NoBarrier_Store(&event_callback_,
1757 reinterpret_cast<subtle::AtomicWord>(cb));
1758 event_callback_trace_config_ = trace_config;
1759 UpdateCategoryGroupEnabledFlags();
1760 };
1761
1762 void TraceLog::SetEventCallbackDisabled() {
1763 AutoLock lock(lock_);
1764 subtle::NoBarrier_Store(&event_callback_, 0);
1765 UpdateCategoryGroupEnabledFlags();
1766 }
1767
1768 // Flush() works as the following:
1769 // 1. Flush() is called in thread A whose task runner is saved in
1770 // flush_task_runner_;
1771 // 2. If thread_message_loops_ is not empty, thread A posts task to each message
1772 // loop to flush the thread local buffers; otherwise finish the flush;
1773 // 3. FlushCurrentThread() deletes the thread local event buffer:
1774 // - The last batch of events of the thread are flushed into the main buffer;
1775 // - The message loop will be removed from thread_message_loops_;
1776 // If this is the last message loop, finish the flush;
1777 // 4. If any thread hasn't finish its flush in time, finish the flush.
1778 void TraceLog::Flush(const TraceLog::OutputCallback& cb,
1779 bool use_worker_thread) {
1780 FlushInternal(cb, use_worker_thread, false);
1781 }
1782
1783 void TraceLog::CancelTracing(const OutputCallback& cb) {
1784 SetDisabled();
1785 FlushInternal(cb, false, true);
1786 }
1787
1788 void TraceLog::FlushInternal(const TraceLog::OutputCallback& cb,
1789 bool use_worker_thread,
1790 bool discard_events) {
1791 use_worker_thread_ = use_worker_thread;
1792 if (IsEnabled()) {
1793 // Can't flush when tracing is enabled because otherwise PostTask would
1794 // - generate more trace events;
1795 // - deschedule the calling thread on some platforms causing inaccurate
1796 // timing of the trace events.
1797 scoped_refptr<RefCountedString> empty_result = new RefCountedString;
1798 if (!cb.is_null())
1799 cb.Run(empty_result, false);
1800 LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled";
1801 return;
1802 }
1803
1804 int generation = this->generation();
1805 // Copy of thread_message_loops_ to be used without locking.
1806 std::vector<scoped_refptr<SingleThreadTaskRunner> >
1807 thread_message_loop_task_runners;
1808 {
1809 AutoLock lock(lock_);
1810 DCHECK(!flush_task_runner_);
1811 flush_task_runner_ = ThreadTaskRunnerHandle::IsSet()
1812 ? ThreadTaskRunnerHandle::Get()
1813 : nullptr;
1814 DCHECK_IMPLIES(thread_message_loops_.size(), flush_task_runner_);
1815 flush_output_callback_ = cb;
1816
1817 if (thread_shared_chunk_) {
1818 logged_events_->ReturnChunk(thread_shared_chunk_index_,
1819 thread_shared_chunk_.Pass());
1820 }
1821
1822 if (thread_message_loops_.size()) {
1823 for (hash_set<MessageLoop*>::const_iterator it =
1824 thread_message_loops_.begin();
1825 it != thread_message_loops_.end(); ++it) {
1826 thread_message_loop_task_runners.push_back((*it)->task_runner());
1827 }
1828 }
1829 }
1830
1831 if (thread_message_loop_task_runners.size()) {
1832 for (size_t i = 0; i < thread_message_loop_task_runners.size(); ++i) {
1833 thread_message_loop_task_runners[i]->PostTask(
1834 FROM_HERE, Bind(&TraceLog::FlushCurrentThread, Unretained(this),
1835 generation, discard_events));
1836 }
1837 flush_task_runner_->PostDelayedTask(
1838 FROM_HERE, Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation,
1839 discard_events),
1840 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs));
1841 return;
1842 }
1843
1844 FinishFlush(generation, discard_events);
1845 }
1846
1847 // Usually it runs on a different thread.
1848 void TraceLog::ConvertTraceEventsToTraceFormat(
1849 scoped_ptr<TraceBuffer> logged_events,
1850 const OutputCallback& flush_output_callback,
1851 const TraceEvent::ArgumentFilterPredicate& argument_filter_predicate) {
1852 if (flush_output_callback.is_null())
1853 return;
1854
1855 // The callback need to be called at least once even if there is no events
1856 // to let the caller know the completion of flush.
1857 scoped_refptr<RefCountedString> json_events_str_ptr = new RefCountedString();
1858 while (const TraceBufferChunk* chunk = logged_events->NextChunk()) {
1859 for (size_t j = 0; j < chunk->size(); ++j) {
1860 size_t size = json_events_str_ptr->size();
1861 if (size > kTraceEventBufferSizeInBytes) {
1862 flush_output_callback.Run(json_events_str_ptr, true);
1863 json_events_str_ptr = new RefCountedString();
1864 } else if (size) {
1865 json_events_str_ptr->data().append(",\n");
1866 }
1867 chunk->GetEventAt(j)->AppendAsJSON(&(json_events_str_ptr->data()),
1868 argument_filter_predicate);
1869 }
1870 }
1871 flush_output_callback.Run(json_events_str_ptr, false);
1872 }
1873
1874 void TraceLog::FinishFlush(int generation, bool discard_events) {
1875 scoped_ptr<TraceBuffer> previous_logged_events;
1876 OutputCallback flush_output_callback;
1877 TraceEvent::ArgumentFilterPredicate argument_filter_predicate;
1878
1879 if (!CheckGeneration(generation))
1880 return;
1881
1882 {
1883 AutoLock lock(lock_);
1884
1885 previous_logged_events.swap(logged_events_);
1886 UseNextTraceBuffer();
1887 thread_message_loops_.clear();
1888
1889 flush_task_runner_ = NULL;
1890 flush_output_callback = flush_output_callback_;
1891 flush_output_callback_.Reset();
1892
1893 if (trace_options() & kInternalEnableArgumentFilter) {
1894 CHECK(!argument_filter_predicate_.is_null());
1895 argument_filter_predicate = argument_filter_predicate_;
1896 }
1897 }
1898
1899 if (discard_events) {
1900 if (!flush_output_callback.is_null()) {
1901 scoped_refptr<RefCountedString> empty_result = new RefCountedString;
1902 flush_output_callback.Run(empty_result, false);
1903 }
1904 return;
1905 }
1906
1907 if (use_worker_thread_ &&
1908 WorkerPool::PostTask(
1909 FROM_HERE, Bind(&TraceLog::ConvertTraceEventsToTraceFormat,
1910 Passed(&previous_logged_events),
1911 flush_output_callback, argument_filter_predicate),
1912 true)) {
1913 return;
1914 }
1915
1916 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(),
1917 flush_output_callback,
1918 argument_filter_predicate);
1919 }
1920
1921 // Run in each thread holding a local event buffer.
1922 void TraceLog::FlushCurrentThread(int generation, bool discard_events) {
1923 {
1924 AutoLock lock(lock_);
1925 if (!CheckGeneration(generation) || !flush_task_runner_) {
1926 // This is late. The corresponding flush has finished.
1927 return;
1928 }
1929 }
1930
1931 // This will flush the thread local buffer.
1932 delete thread_local_event_buffer_.Get();
1933
1934 AutoLock lock(lock_);
1935 if (!CheckGeneration(generation) || !flush_task_runner_ ||
1936 thread_message_loops_.size())
1937 return;
1938
1939 flush_task_runner_->PostTask(
1940 FROM_HERE, Bind(&TraceLog::FinishFlush, Unretained(this), generation,
1941 discard_events));
1942 }
1943
1944 void TraceLog::OnFlushTimeout(int generation, bool discard_events) {
1945 {
1946 AutoLock lock(lock_);
1947 if (!CheckGeneration(generation) || !flush_task_runner_) {
1948 // Flush has finished before timeout.
1949 return;
1950 }
1951
1952 LOG(WARNING) <<
1953 "The following threads haven't finished flush in time. "
1954 "If this happens stably for some thread, please call "
1955 "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from "
1956 "the thread to avoid its trace events from being lost.";
1957 for (hash_set<MessageLoop*>::const_iterator it =
1958 thread_message_loops_.begin();
1959 it != thread_message_loops_.end(); ++it) {
1960 LOG(WARNING) << "Thread: " << (*it)->thread_name();
1961 }
1962 }
1963 FinishFlush(generation, discard_events);
1964 }
1965
1966 void TraceLog::FlushButLeaveBufferIntact(
1967 const TraceLog::OutputCallback& flush_output_callback) {
1968 scoped_ptr<TraceBuffer> previous_logged_events;
1969 TraceEvent::ArgumentFilterPredicate argument_filter_predicate;
1970 {
1971 AutoLock lock(lock_);
1972 AddMetadataEventsWhileLocked();
1973 if (thread_shared_chunk_) {
1974 // Return the chunk to the main buffer to flush the sampling data.
1975 logged_events_->ReturnChunk(thread_shared_chunk_index_,
1976 thread_shared_chunk_.Pass());
1977 }
1978 previous_logged_events = logged_events_->CloneForIteration().Pass();
1979
1980 if (trace_options() & kInternalEnableArgumentFilter) {
1981 CHECK(!argument_filter_predicate_.is_null());
1982 argument_filter_predicate = argument_filter_predicate_;
1983 }
1984 } // release lock
1985
1986 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(),
1987 flush_output_callback,
1988 argument_filter_predicate);
1989 }
1990
1991 void TraceLog::UseNextTraceBuffer() {
1992 logged_events_.reset(CreateTraceBuffer());
1993 subtle::NoBarrier_AtomicIncrement(&generation_, 1);
1994 thread_shared_chunk_.reset();
1995 thread_shared_chunk_index_ = 0;
1996 }
1997
1998 TraceEventHandle TraceLog::AddTraceEvent(
1999 char phase,
2000 const unsigned char* category_group_enabled,
2001 const char* name,
2002 unsigned long long id,
2003 int num_args,
2004 const char** arg_names,
2005 const unsigned char* arg_types,
2006 const unsigned long long* arg_values,
2007 const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
2008 unsigned int flags) {
2009 int thread_id = static_cast<int>(base::PlatformThread::CurrentId());
2010 base::TraceTicks now = base::TraceTicks::Now();
2011 return AddTraceEventWithThreadIdAndTimestamp(phase, category_group_enabled,
2012 name, id, thread_id, now,
2013 num_args, arg_names,
2014 arg_types, arg_values,
2015 convertable_values, flags);
2016 }
2017
2018 TraceEventHandle TraceLog::AddTraceEventWithThreadIdAndTimestamp(
2019 char phase,
2020 const unsigned char* category_group_enabled,
2021 const char* name,
2022 unsigned long long id,
2023 int thread_id,
2024 const TraceTicks& timestamp,
2025 int num_args,
2026 const char** arg_names,
2027 const unsigned char* arg_types,
2028 const unsigned long long* arg_values,
2029 const scoped_refptr<ConvertableToTraceFormat>* convertable_values,
2030 unsigned int flags) {
2031 TraceEventHandle handle = { 0, 0, 0 };
2032 if (!*category_group_enabled)
2033 return handle;
2034
2035 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when
2036 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) ->
2037 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ...
2038 if (thread_is_in_trace_event_.Get())
2039 return handle;
2040
2041 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_);
2042
2043 DCHECK(name);
2044 DCHECK(!timestamp.is_null());
2045
2046 if (flags & TRACE_EVENT_FLAG_MANGLE_ID)
2047 id = MangleEventId(id);
2048
2049 TraceTicks offset_event_timestamp = OffsetTimestamp(timestamp);
2050 TraceTicks now = flags & TRACE_EVENT_FLAG_EXPLICIT_TIMESTAMP ?
2051 OffsetNow() : offset_event_timestamp;
2052 ThreadTicks thread_now = ThreadNow();
2053
2054 // |thread_local_event_buffer_| can be null if the current thread doesn't have
2055 // a message loop or the message loop is blocked.
2056 InitializeThreadLocalEventBufferIfSupported();
2057 auto thread_local_event_buffer = thread_local_event_buffer_.Get();
2058
2059 // Check and update the current thread name only if the event is for the
2060 // current thread to avoid locks in most cases.
2061 if (thread_id == static_cast<int>(PlatformThread::CurrentId())) {
2062 const char* new_name = ThreadIdNameManager::GetInstance()->
2063 GetName(thread_id);
2064 // Check if the thread name has been set or changed since the previous
2065 // call (if any), but don't bother if the new name is empty. Note this will
2066 // not detect a thread name change within the same char* buffer address: we
2067 // favor common case performance over corner case correctness.
2068 if (new_name != g_current_thread_name.Get().Get() &&
2069 new_name && *new_name) {
2070 g_current_thread_name.Get().Set(new_name);
2071
2072 AutoLock thread_info_lock(thread_info_lock_);
2073
2074 hash_map<int, std::string>::iterator existing_name =
2075 thread_names_.find(thread_id);
2076 if (existing_name == thread_names_.end()) {
2077 // This is a new thread id, and a new name.
2078 thread_names_[thread_id] = new_name;
2079 } else {
2080 // This is a thread id that we've seen before, but potentially with a
2081 // new name.
2082 std::vector<StringPiece> existing_names = base::SplitStringPiece(
2083 existing_name->second, ",", base::KEEP_WHITESPACE,
2084 base::SPLIT_WANT_NONEMPTY);
2085 bool found = std::find(existing_names.begin(),
2086 existing_names.end(),
2087 new_name) != existing_names.end();
2088 if (!found) {
2089 if (existing_names.size())
2090 existing_name->second.push_back(',');
2091 existing_name->second.append(new_name);
2092 }
2093 }
2094 }
2095 }
2096
2097 #if defined(OS_WIN)
2098 // This is done sooner rather than later, to avoid creating the event and
2099 // acquiring the lock, which is not needed for ETW as it's already threadsafe.
2100 if (*category_group_enabled & ENABLED_FOR_ETW_EXPORT)
2101 TraceEventETWExport::AddEvent(phase, category_group_enabled, name, id,
2102 num_args, arg_names, arg_types, arg_values,
2103 convertable_values);
2104 #endif // OS_WIN
2105
2106 std::string console_message;
2107 if (*category_group_enabled &
2108 (ENABLED_FOR_RECORDING | ENABLED_FOR_MONITORING)) {
2109 OptionalAutoLock lock(&lock_);
2110
2111 TraceEvent* trace_event = NULL;
2112 if (thread_local_event_buffer) {
2113 trace_event = thread_local_event_buffer->AddTraceEvent(&handle);
2114 } else {
2115 lock.EnsureAcquired();
2116 trace_event = AddEventToThreadSharedChunkWhileLocked(&handle, true);
2117 }
2118
2119 if (trace_event) {
2120 trace_event->Initialize(thread_id, offset_event_timestamp, thread_now,
2121 phase, category_group_enabled, name, id,
2122 num_args, arg_names, arg_types, arg_values,
2123 convertable_values, flags);
2124
2125 #if defined(OS_ANDROID)
2126 trace_event->SendToATrace();
2127 #endif
2128 }
2129
2130 if (trace_options() & kInternalEchoToConsole) {
2131 console_message = EventToConsoleMessage(
2132 phase == TRACE_EVENT_PHASE_COMPLETE ? TRACE_EVENT_PHASE_BEGIN : phase,
2133 timestamp, trace_event);
2134 }
2135 }
2136
2137 if (console_message.size())
2138 LOG(ERROR) << console_message;
2139
2140 if (reinterpret_cast<const unsigned char*>(subtle::NoBarrier_Load(
2141 &watch_category_)) == category_group_enabled) {
2142 bool event_name_matches;
2143 WatchEventCallback watch_event_callback_copy;
2144 {
2145 AutoLock lock(lock_);
2146 event_name_matches = watch_event_name_ == name;
2147 watch_event_callback_copy = watch_event_callback_;
2148 }
2149 if (event_name_matches) {
2150 if (!watch_event_callback_copy.is_null())
2151 watch_event_callback_copy.Run();
2152 }
2153 }
2154
2155 if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
2156 EventCallback event_callback = reinterpret_cast<EventCallback>(
2157 subtle::NoBarrier_Load(&event_callback_));
2158 if (event_callback) {
2159 event_callback(offset_event_timestamp,
2160 phase == TRACE_EVENT_PHASE_COMPLETE ?
2161 TRACE_EVENT_PHASE_BEGIN : phase,
2162 category_group_enabled, name, id,
2163 num_args, arg_names, arg_types, arg_values,
2164 flags);
2165 }
2166 }
2167
2168 if (thread_local_event_buffer)
2169 thread_local_event_buffer->ReportOverhead(now, thread_now);
2170
2171 return handle;
2172 }
2173
2174 // May be called when a COMPELETE event ends and the unfinished event has been
2175 // recycled (phase == TRACE_EVENT_PHASE_END and trace_event == NULL).
2176 std::string TraceLog::EventToConsoleMessage(unsigned char phase,
2177 const TraceTicks& timestamp,
2178 TraceEvent* trace_event) {
2179 AutoLock thread_info_lock(thread_info_lock_);
2180
2181 // The caller should translate TRACE_EVENT_PHASE_COMPLETE to
2182 // TRACE_EVENT_PHASE_BEGIN or TRACE_EVENT_END.
2183 DCHECK(phase != TRACE_EVENT_PHASE_COMPLETE);
2184
2185 TimeDelta duration;
2186 int thread_id = trace_event ?
2187 trace_event->thread_id() : PlatformThread::CurrentId();
2188 if (phase == TRACE_EVENT_PHASE_END) {
2189 duration = timestamp - thread_event_start_times_[thread_id].top();
2190 thread_event_start_times_[thread_id].pop();
2191 }
2192
2193 std::string thread_name = thread_names_[thread_id];
2194 if (thread_colors_.find(thread_name) == thread_colors_.end())
2195 thread_colors_[thread_name] = (thread_colors_.size() % 6) + 1;
2196
2197 std::ostringstream log;
2198 log << base::StringPrintf("%s: \x1b[0;3%dm",
2199 thread_name.c_str(),
2200 thread_colors_[thread_name]);
2201
2202 size_t depth = 0;
2203 if (thread_event_start_times_.find(thread_id) !=
2204 thread_event_start_times_.end())
2205 depth = thread_event_start_times_[thread_id].size();
2206
2207 for (size_t i = 0; i < depth; ++i)
2208 log << "| ";
2209
2210 if (trace_event)
2211 trace_event->AppendPrettyPrinted(&log);
2212 if (phase == TRACE_EVENT_PHASE_END)
2213 log << base::StringPrintf(" (%.3f ms)", duration.InMillisecondsF());
2214
2215 log << "\x1b[0;m";
2216
2217 if (phase == TRACE_EVENT_PHASE_BEGIN)
2218 thread_event_start_times_[thread_id].push(timestamp);
2219
2220 return log.str();
2221 }
2222
2223 void TraceLog::AddTraceEventEtw(char phase,
2224 const char* name,
2225 const void* id,
2226 const char* extra) {
2227 #if defined(OS_WIN)
2228 TraceEventETWProvider::Trace(name, phase, id, extra);
2229 #endif
2230 INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
2231 TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
2232 }
2233
2234 void TraceLog::AddTraceEventEtw(char phase,
2235 const char* name,
2236 const void* id,
2237 const std::string& extra) {
2238 #if defined(OS_WIN)
2239 TraceEventETWProvider::Trace(name, phase, id, extra);
2240 #endif
2241 INTERNAL_TRACE_EVENT_ADD(phase, "ETW Trace Event", name,
2242 TRACE_EVENT_FLAG_COPY, "id", id, "extra", extra);
2243 }
2244
2245 void TraceLog::UpdateTraceEventDuration(
2246 const unsigned char* category_group_enabled,
2247 const char* name,
2248 TraceEventHandle handle) {
2249 // Avoid re-entrance of AddTraceEvent. This may happen in GPU process when
2250 // ECHO_TO_CONSOLE is enabled: AddTraceEvent -> LOG(ERROR) ->
2251 // GpuProcessLogMessageHandler -> PostPendingTask -> TRACE_EVENT ...
2252 if (thread_is_in_trace_event_.Get())
2253 return;
2254
2255 AutoThreadLocalBoolean thread_is_in_trace_event(&thread_is_in_trace_event_);
2256
2257 ThreadTicks thread_now = ThreadNow();
2258 TraceTicks now = OffsetNow();
2259
2260 std::string console_message;
2261 if (*category_group_enabled & ENABLED_FOR_RECORDING) {
2262 OptionalAutoLock lock(&lock_);
2263
2264 TraceEvent* trace_event = GetEventByHandleInternal(handle, &lock);
2265 if (trace_event) {
2266 DCHECK(trace_event->phase() == TRACE_EVENT_PHASE_COMPLETE);
2267 trace_event->UpdateDuration(now, thread_now);
2268 #if defined(OS_ANDROID)
2269 trace_event->SendToATrace();
2270 #endif
2271 }
2272
2273 if (trace_options() & kInternalEchoToConsole) {
2274 console_message = EventToConsoleMessage(TRACE_EVENT_PHASE_END,
2275 now, trace_event);
2276 }
2277 }
2278
2279 if (console_message.size())
2280 LOG(ERROR) << console_message;
2281
2282 if (*category_group_enabled & ENABLED_FOR_EVENT_CALLBACK) {
2283 EventCallback event_callback = reinterpret_cast<EventCallback>(
2284 subtle::NoBarrier_Load(&event_callback_));
2285 if (event_callback) {
2286 event_callback(now, TRACE_EVENT_PHASE_END, category_group_enabled, name,
2287 trace_event_internal::kNoEventId, 0, NULL, NULL, NULL,
2288 TRACE_EVENT_FLAG_NONE);
2289 }
2290 }
2291 }
2292
2293 void TraceLog::SetWatchEvent(const std::string& category_name,
2294 const std::string& event_name,
2295 const WatchEventCallback& callback) {
2296 const unsigned char* category = GetCategoryGroupEnabled(
2297 category_name.c_str());
2298 AutoLock lock(lock_);
2299 subtle::NoBarrier_Store(&watch_category_,
2300 reinterpret_cast<subtle::AtomicWord>(category));
2301 watch_event_name_ = event_name;
2302 watch_event_callback_ = callback;
2303 }
2304
2305 void TraceLog::CancelWatchEvent() {
2306 AutoLock lock(lock_);
2307 subtle::NoBarrier_Store(&watch_category_, 0);
2308 watch_event_name_ = "";
2309 watch_event_callback_.Reset();
2310 }
2311
2312 uint64 TraceLog::MangleEventId(uint64 id) {
2313 return id ^ process_id_hash_;
2314 }
2315
2316 void TraceLog::AddMetadataEventsWhileLocked() {
2317 lock_.AssertAcquired();
2318
2319 #if !defined(OS_NACL) // NaCl shouldn't expose the process id.
2320 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2321 0,
2322 "num_cpus", "number",
2323 base::SysInfo::NumberOfProcessors());
2324 #endif
2325
2326
2327 int current_thread_id = static_cast<int>(base::PlatformThread::CurrentId());
2328 if (process_sort_index_ != 0) {
2329 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2330 current_thread_id,
2331 "process_sort_index", "sort_index",
2332 process_sort_index_);
2333 }
2334
2335 if (process_name_.size()) {
2336 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2337 current_thread_id,
2338 "process_name", "name",
2339 process_name_);
2340 }
2341
2342 if (process_labels_.size() > 0) {
2343 std::vector<std::string> labels;
2344 for(base::hash_map<int, std::string>::iterator it = process_labels_.begin();
2345 it != process_labels_.end();
2346 it++) {
2347 labels.push_back(it->second);
2348 }
2349 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2350 current_thread_id, "process_labels", "labels",
2351 base::JoinString(labels, ","));
2352 }
2353
2354 // Thread sort indices.
2355 for(hash_map<int, int>::iterator it = thread_sort_indices_.begin();
2356 it != thread_sort_indices_.end();
2357 it++) {
2358 if (it->second == 0)
2359 continue;
2360 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2361 it->first,
2362 "thread_sort_index", "sort_index",
2363 it->second);
2364 }
2365
2366 // Thread names.
2367 AutoLock thread_info_lock(thread_info_lock_);
2368 for(hash_map<int, std::string>::iterator it = thread_names_.begin();
2369 it != thread_names_.end();
2370 it++) {
2371 if (it->second.empty())
2372 continue;
2373 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2374 it->first,
2375 "thread_name", "name",
2376 it->second);
2377 }
2378
2379 // If buffer is full, add a metadata record to report this.
2380 if (!buffer_limit_reached_timestamp_.is_null()) {
2381 InitializeMetadataEvent(AddEventToThreadSharedChunkWhileLocked(NULL, false),
2382 current_thread_id,
2383 "trace_buffer_overflowed",
2384 "overflowed_at_ts",
2385 buffer_limit_reached_timestamp_);
2386 }
2387 }
2388
2389 void TraceLog::WaitSamplingEventForTesting() {
2390 if (!sampling_thread_)
2391 return;
2392 sampling_thread_->WaitSamplingEventForTesting();
2393 }
2394
2395 void TraceLog::DeleteForTesting() {
2396 DeleteTraceLogForTesting::Delete();
2397 }
2398
2399 TraceEvent* TraceLog::GetEventByHandle(TraceEventHandle handle) {
2400 return GetEventByHandleInternal(handle, NULL);
2401 }
2402
2403 TraceEvent* TraceLog::GetEventByHandleInternal(TraceEventHandle handle,
2404 OptionalAutoLock* lock) {
2405 if (!handle.chunk_seq)
2406 return NULL;
2407
2408 if (thread_local_event_buffer_.Get()) {
2409 TraceEvent* trace_event =
2410 thread_local_event_buffer_.Get()->GetEventByHandle(handle);
2411 if (trace_event)
2412 return trace_event;
2413 }
2414
2415 // The event has been out-of-control of the thread local buffer.
2416 // Try to get the event from the main buffer with a lock.
2417 if (lock)
2418 lock->EnsureAcquired();
2419
2420 if (thread_shared_chunk_ &&
2421 handle.chunk_index == thread_shared_chunk_index_) {
2422 return handle.chunk_seq == thread_shared_chunk_->seq() ?
2423 thread_shared_chunk_->GetEventAt(handle.event_index) : NULL;
2424 }
2425
2426 return logged_events_->GetEventByHandle(handle);
2427 }
2428
2429 void TraceLog::SetProcessID(int process_id) {
2430 process_id_ = process_id;
2431 // Create a FNV hash from the process ID for XORing.
2432 // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details.
2433 unsigned long long offset_basis = 14695981039346656037ull;
2434 unsigned long long fnv_prime = 1099511628211ull;
2435 unsigned long long pid = static_cast<unsigned long long>(process_id_);
2436 process_id_hash_ = (offset_basis ^ pid) * fnv_prime;
2437 }
2438
2439 void TraceLog::SetProcessSortIndex(int sort_index) {
2440 AutoLock lock(lock_);
2441 process_sort_index_ = sort_index;
2442 }
2443
2444 void TraceLog::SetProcessName(const std::string& process_name) {
2445 AutoLock lock(lock_);
2446 process_name_ = process_name;
2447 }
2448
2449 void TraceLog::UpdateProcessLabel(
2450 int label_id, const std::string& current_label) {
2451 if(!current_label.length())
2452 return RemoveProcessLabel(label_id);
2453
2454 AutoLock lock(lock_);
2455 process_labels_[label_id] = current_label;
2456 }
2457
2458 void TraceLog::RemoveProcessLabel(int label_id) {
2459 AutoLock lock(lock_);
2460 base::hash_map<int, std::string>::iterator it = process_labels_.find(
2461 label_id);
2462 if (it == process_labels_.end())
2463 return;
2464
2465 process_labels_.erase(it);
2466 }
2467
2468 void TraceLog::SetThreadSortIndex(PlatformThreadId thread_id, int sort_index) {
2469 AutoLock lock(lock_);
2470 thread_sort_indices_[static_cast<int>(thread_id)] = sort_index;
2471 }
2472
2473 void TraceLog::SetTimeOffset(TimeDelta offset) {
2474 time_offset_ = offset;
2475 }
2476
2477 size_t TraceLog::GetObserverCountForTest() const {
2478 return enabled_state_observer_list_.size();
2479 }
2480
2481 void TraceLog::SetCurrentThreadBlocksMessageLoop() {
2482 thread_blocks_message_loop_.Set(true);
2483 if (thread_local_event_buffer_.Get()) {
2484 // This will flush the thread local buffer.
2485 delete thread_local_event_buffer_.Get();
2486 }
2487 }
2488
2489 void ConvertableToTraceFormat::EstimateTraceMemoryOverhead(
2490 TraceEventMemoryOverhead* overhead) {
2491 overhead->Add("ConvertableToTraceFormat(Unknown)", sizeof(*this));
2492 }
2493
2494 } // namespace trace_event
2495 } // namespace base
2496
2497 namespace trace_event_internal {
2498
2499 ScopedTraceBinaryEfficient::ScopedTraceBinaryEfficient(
2500 const char* category_group, const char* name) {
2501 // The single atom works because for now the category_group can only be "gpu".
2502 DCHECK_EQ(strcmp(category_group, "gpu"), 0);
2503 static TRACE_EVENT_API_ATOMIC_WORD atomic = 0;
2504 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO_CUSTOM_VARIABLES(
2505 category_group, atomic, category_group_enabled_);
2506 name_ = name;
2507 if (*category_group_enabled_) {
2508 event_handle_ =
2509 TRACE_EVENT_API_ADD_TRACE_EVENT_WITH_THREAD_ID_AND_TIMESTAMP(
2510 TRACE_EVENT_PHASE_COMPLETE, category_group_enabled_, name,
2511 trace_event_internal::kNoEventId,
2512 static_cast<int>(base::PlatformThread::CurrentId()),
2513 base::TraceTicks::Now(), 0, NULL, NULL, NULL, NULL,
2514 TRACE_EVENT_FLAG_NONE);
2515 }
2516 }
2517
2518 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() {
2519 if (*category_group_enabled_) {
2520 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_,
2521 name_, event_handle_);
2522 }
2523 }
2524
2525 } // namespace trace_event_internal
OLDNEW
« no previous file with comments | « base/trace_event/trace_event_impl.h ('k') | base/trace_event/trace_event_impl_constants.cc » ('j') | no next file with comments »

Powered by Google App Engine
This is Rietveld 408576698