| OLD | NEW |
| (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(¶meter_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 | |
| OLD | NEW |