Chromium Code Reviews| OLD | NEW |
|---|---|
| 1 // Copyright (c) 2011 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2011 The Chromium Authors. All rights reserved. |
| 2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
| 3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
| 4 | 4 |
| 5 // Trace events are for tracking application performance. | 5 // Trace events are for tracking application performance and resource usage. |
| 6 // Macros are provided to track: | |
| 7 // Begin and end of function calls | |
| 8 // Counters | |
| 6 // | 9 // |
| 7 // Events are issued against categories. Whereas LOG's | 10 // Events are issued against categories. Whereas LOG's |
| 8 // categories are statically defined, TRACE categories are created | 11 // categories are statically defined, TRACE categories are created |
| 9 // implicitly with a string. For example: | 12 // implicitly with a string. For example: |
| 10 // TRACE_EVENT_INSTANT0("MY_SUBSYSTEM", "SomeImportantEvent") | 13 // TRACE_EVENT_INSTANT0("MY_SUBSYSTEM", "SomeImportantEvent") |
| 11 // | 14 // |
| 12 // Events can be INSTANT, or can be pairs of BEGIN and END: | 15 // Events can be INSTANT, or can be pairs of BEGIN and END: |
| 13 // TRACE_EVENT_BEGIN0("MY_SUBSYSTEM", "SomethingCostly") | 16 // TRACE_EVENT_BEGIN0("MY_SUBSYSTEM", "SomethingCostly") |
| 14 // doSomethingCostly() | 17 // doSomethingCostly() |
| 15 // TRACE_EVENT_END0("MY_SUBSYSTEM", "SomethingCostly") | 18 // TRACE_EVENT_END0("MY_SUBSYSTEM", "SomethingCostly") |
| 16 // | 19 // |
| 17 // A common use case is to trace entire function scopes. This | 20 // A common use case is to trace entire function scopes. This |
| 18 // issues a trace BEGIN and END automatically: | 21 // issues a trace BEGIN and END automatically: |
| 19 // void doSomethingCostly() { | 22 // void doSomethingCostly() { |
| 20 // TRACE_EVENT0("MY_SUBSYSTEM", "doSomethingCostly"); | 23 // TRACE_EVENT0("MY_SUBSYSTEM", "doSomethingCostly"); |
| 21 // ... | 24 // ... |
| 22 // } | 25 // } |
| 23 // | 26 // |
| 24 // Additional parameters can be associated with an event: | 27 // Additional parameters can be associated with an event: |
| 25 // void doSomethingCostly2(int howMuch) { | 28 // void doSomethingCostly2(int howMuch) { |
| 26 // TRACE_EVENT1("MY_SUBSYSTEM", "doSomethingCostly", | 29 // TRACE_EVENT1("MY_SUBSYSTEM", "doSomethingCostly", |
| 27 // "howMuch", howMuch); | 30 // "howMuch", howMuch); |
| 28 // ... | 31 // ... |
| 29 // } | 32 // } |
| 30 // | 33 // |
| 31 // The trace system will automatically add to this information the | 34 // The trace system will automatically add to this information the |
| 32 // current process id, thread id, and a timestamp in microseconds. | 35 // current process id, thread id, and a timestamp in microseconds. |
| 33 // | 36 // |
| 37 // Trace event also supports counters, which is a way to track a quantity | |
| 38 // as it varies over time. Counters are created with the following macro: | |
| 39 // TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter", g_myCounterValue); | |
| 40 // | |
| 41 // Counters are process-specific. The macro itself can be issued from any | |
| 42 // thread, however. | |
| 43 // | |
| 44 // Sometimes, you want to track two counters at once. You cand o this with two | |
|
jbates
2011/11/16 19:16:17
s/o/do
jar (doing other things)
2011/11/16 20:18:41
nit: typo: "cand o" --> "can do"
| |
| 45 // counter macros: | |
| 46 // TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter0", g_myCounterValue[0]); | |
| 47 // TRACE_COUNTER1("MY_SUBSYSTEM", "myCounter1", g_myCounterValue[1]); | |
| 48 // Or you can do it with a combined macro: | |
| 49 // TRACE_COUNTER2("MY_SUBSYSTEM", "myCounter", | |
| 50 // "bytesPinned", g_myCounterValue[0], | |
| 51 // "bytesAllocated", g_myCounterValue[1]); | |
| 52 // This indicates to the tracing UI that these counters should be displayed | |
| 53 // in a single graph, as a summed area chart. | |
| 54 // | |
| 34 // By default, trace collection is compiled in, but turned off at runtime. | 55 // By default, trace collection is compiled in, but turned off at runtime. |
| 35 // Collecting trace data is the responsibility of the embedding | 56 // Collecting trace data is the responsibility of the embedding |
| 36 // application. In Chrome's case, navigating to about:tracing will turn on | 57 // application. In Chrome's case, navigating to about:tracing will turn on |
| 37 // tracing and display data collected across all active processes. | 58 // tracing and display data collected across all active processes. |
| 38 // | 59 // |
| 39 // | 60 // |
| 40 // Memory scoping note: | 61 // Memory scoping note: |
| 41 // Tracing copies the pointers, not the string content, of the strings passed | 62 // Tracing copies the pointers, not the string content, of the strings passed |
| 42 // in for category, name, and arg_names. Thus, the following code will | 63 // in for category, name, and arg_names. Thus, the following code will |
| 43 // cause problems: | 64 // cause problems: |
| (...skipping 203 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 247 TRACE_EVENT_IF_LONGER_THAN1(threshold_us, category, name, NULL, 0) | 268 TRACE_EVENT_IF_LONGER_THAN1(threshold_us, category, name, NULL, 0) |
| 248 #define TRACE_EVENT_IF_LONGER_THAN1( \ | 269 #define TRACE_EVENT_IF_LONGER_THAN1( \ |
| 249 threshold_us, category, name, arg1_name, arg1_val) \ | 270 threshold_us, category, name, arg1_name, arg1_val) \ |
| 250 TRACE_EVENT_IF_LONGER_THAN2(threshold_us, category, name, \ | 271 TRACE_EVENT_IF_LONGER_THAN2(threshold_us, category, name, \ |
| 251 arg1_name, arg1_val, NULL, 0) | 272 arg1_name, arg1_val, NULL, 0) |
| 252 #define TRACE_EVENT_IF_LONGER_THAN2( \ | 273 #define TRACE_EVENT_IF_LONGER_THAN2( \ |
| 253 threshold_us, category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ | 274 threshold_us, category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ |
| 254 INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN(threshold_us, \ | 275 INTERNAL_TRACE_EVENT_ADD_SCOPED_IF_LONGER_THAN(threshold_us, \ |
| 255 category, name, arg1_name, arg1_val, arg2_name, arg2_val) | 276 category, name, arg1_name, arg1_val, arg2_name, arg2_val) |
| 256 | 277 |
| 278 // Records the value of a counter called "name" immediately. Value | |
| 279 // must be representable as a 32 bit integer. | |
| 280 // - category and name strings must have application lifetime (statics or | |
| 281 // literals). They may not include " chars. | |
| 282 #define TRACE_COUNTER1(category, name, value) \ | |
| 283 TRACE_COUNTER2(category, name, "value", value, NULL, 0) | |
| 284 #define TRACE_COPY_COUNTER1(category, name, value) \ | |
| 285 TRACE_COPY_COUNTER2(category, name, "value", value, NULL, 0) | |
| 286 | |
| 287 // Records the values of a multi-parted counter called "name" immediately. | |
| 288 // The UI will treat value1 and value2 as parts of a whole, displaying their | |
| 289 // values as a stacked-bar chart. | |
| 290 // - category and name strings must have application lifetime (statics or | |
| 291 // literals). They may not include " chars. | |
| 292 #define TRACE_COUNTER2(category, name, value1_name, value1_val, \ | |
| 293 value2_name, value2_val) \ | |
| 294 INTERNAL_TRACE_EVENT_ADD_COUNTER( \ | |
| 295 category, name, value1_name, value1_val, value2_name, value2_val, \ | |
| 296 base::debug::TraceLog::EVENT_FLAG_NONE) | |
| 297 #define TRACE_COPY_COUNTER2(category, name, value1_name, value1_val, \ | |
| 298 value2_name, value2_val) \ | |
| 299 INTERNAL_TRACE_EVENT_ADD_COUNTER( \ | |
| 300 category, name, \ | |
| 301 value1_name, value1_val, \ | |
| 302 value2_name, value2_val, \ | |
| 303 base::debug::TraceLog::EVENT_FLAG_COPY) | |
| 304 | |
| 257 | 305 |
| 258 // Implementation detail: trace event macros create temporary variables | 306 // Implementation detail: trace event macros create temporary variables |
| 259 // to keep instrumentation overhead low. These macros give each temporary | 307 // to keep instrumentation overhead low. These macros give each temporary |
| 260 // variable a unique name based on the line number to prevent name collissions. | 308 // variable a unique name based on the line number to prevent name collissions. |
| 261 #define INTERNAL_TRACE_EVENT_UID3(a,b) \ | 309 #define INTERNAL_TRACE_EVENT_UID3(a,b) \ |
| 262 trace_event_unique_##a##b | 310 trace_event_unique_##a##b |
| 263 #define INTERNAL_TRACE_EVENT_UID2(a,b) \ | 311 #define INTERNAL_TRACE_EVENT_UID2(a,b) \ |
| 264 INTERNAL_TRACE_EVENT_UID3(a,b) | 312 INTERNAL_TRACE_EVENT_UID3(a,b) |
| 265 #define INTERNAL_TRACE_EVENT_UID(name_prefix) \ | 313 #define INTERNAL_TRACE_EVENT_UID(name_prefix) \ |
| 266 INTERNAL_TRACE_EVENT_UID2(name_prefix, __LINE__) | 314 INTERNAL_TRACE_EVENT_UID2(name_prefix, __LINE__) |
| (...skipping 13 matching lines...) Expand all Loading... | |
| 280 // event if the category is enabled. | 328 // event if the category is enabled. |
| 281 #define INTERNAL_TRACE_EVENT_ADD( \ | 329 #define INTERNAL_TRACE_EVENT_ADD( \ |
| 282 phase, category, name, arg1_name, arg1_val, arg2_name, arg2_val, flags) \ | 330 phase, category, name, arg1_name, arg1_val, arg2_name, arg2_val, flags) \ |
| 283 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ | 331 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ |
| 284 if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ | 332 if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ |
| 285 base::debug::TraceLog::GetInstance()->AddTraceEvent( \ | 333 base::debug::TraceLog::GetInstance()->AddTraceEvent( \ |
| 286 phase, INTERNAL_TRACE_EVENT_UID(catstatic), \ | 334 phase, INTERNAL_TRACE_EVENT_UID(catstatic), \ |
| 287 name, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, flags); \ | 335 name, arg1_name, arg1_val, arg2_name, arg2_val, -1, 0, flags); \ |
| 288 } | 336 } |
| 289 | 337 |
| 338 // Implementation detail: internal macro to create static category and | |
| 339 // add the counter event if it is enabled. | |
| 340 #define INTERNAL_TRACE_EVENT_ADD_COUNTER( \ | |
| 341 category, name, arg1_name, arg1_val, arg2_name, arg2_val, flags) \ | |
| 342 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ | |
| 343 if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ | |
| 344 base::debug::TraceLog::GetInstance()->AddCounterEvent( \ | |
| 345 INTERNAL_TRACE_EVENT_UID(catstatic), \ | |
| 346 name, arg1_name, arg1_val, arg2_name, arg2_val, flags); \ | |
| 347 } | |
| 348 | |
| 290 // Implementation detail: internal macro to create static category and add begin | 349 // Implementation detail: internal macro to create static category and add begin |
| 291 // event if the category is enabled. Also adds the end event when the scope | 350 // event if the category is enabled. Also adds the end event when the scope |
| 292 // ends. | 351 // ends. |
| 293 #define INTERNAL_TRACE_EVENT_ADD_SCOPED( \ | 352 #define INTERNAL_TRACE_EVENT_ADD_SCOPED( \ |
| 294 category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ | 353 category, name, arg1_name, arg1_val, arg2_name, arg2_val) \ |
| 295 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ | 354 INTERNAL_TRACE_EVENT_GET_CATEGORY_INFO(category); \ |
| 296 base::debug::internal::TraceEndOnScopeClose \ | 355 base::debug::internal::TraceEndOnScopeClose \ |
| 297 INTERNAL_TRACE_EVENT_UID(profileScope); \ | 356 INTERNAL_TRACE_EVENT_UID(profileScope); \ |
| 298 if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ | 357 if (INTERNAL_TRACE_EVENT_UID(catstatic)->enabled) { \ |
| 299 base::debug::TraceLog::GetInstance()->AddTraceEvent( \ | 358 base::debug::TraceLog::GetInstance()->AddTraceEvent( \ |
| (...skipping 40 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 340 volatile bool enabled; | 399 volatile bool enabled; |
| 341 }; | 400 }; |
| 342 | 401 |
| 343 const size_t kTraceMaxNumArgs = 2; | 402 const size_t kTraceMaxNumArgs = 2; |
| 344 | 403 |
| 345 // Phase indicates the nature of an event entry. E.g. part of a begin/end pair. | 404 // Phase indicates the nature of an event entry. E.g. part of a begin/end pair. |
| 346 enum TraceEventPhase { | 405 enum TraceEventPhase { |
| 347 TRACE_EVENT_PHASE_BEGIN, | 406 TRACE_EVENT_PHASE_BEGIN, |
| 348 TRACE_EVENT_PHASE_END, | 407 TRACE_EVENT_PHASE_END, |
| 349 TRACE_EVENT_PHASE_INSTANT, | 408 TRACE_EVENT_PHASE_INSTANT, |
| 350 TRACE_EVENT_PHASE_METADATA | 409 TRACE_EVENT_PHASE_METADATA, |
| 410 TRACE_EVENT_PHASE_COUNTER | |
| 351 }; | 411 }; |
| 352 | 412 |
| 353 // Simple union of values. This is much lighter weight than base::Value, which | 413 // Simple union of values. This is much lighter weight than base::Value, which |
| 354 // requires dynamic allocation and a vtable. To keep the trace runtime overhead | 414 // requires dynamic allocation and a vtable. To keep the trace runtime overhead |
| 355 // low, we want constant size storage here. | 415 // low, we want constant size storage here. |
| 356 class BASE_EXPORT TraceValue { | 416 class BASE_EXPORT TraceValue { |
| 357 public: | 417 public: |
| 358 enum Type { | 418 enum Type { |
| 359 TRACE_TYPE_UNDEFINED, | 419 TRACE_TYPE_UNDEFINED, |
| 360 TRACE_TYPE_BOOL, | 420 TRACE_TYPE_BOOL, |
| (...skipping 296 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 657 EventFlags flags); | 717 EventFlags flags); |
| 658 static void AddTraceEventEtw(TraceEventPhase phase, | 718 static void AddTraceEventEtw(TraceEventPhase phase, |
| 659 const char* name, | 719 const char* name, |
| 660 const void* id, | 720 const void* id, |
| 661 const char* extra); | 721 const char* extra); |
| 662 static void AddTraceEventEtw(TraceEventPhase phase, | 722 static void AddTraceEventEtw(TraceEventPhase phase, |
| 663 const char* name, | 723 const char* name, |
| 664 const void* id, | 724 const void* id, |
| 665 const std::string& extra); | 725 const std::string& extra); |
| 666 | 726 |
| 727 // A wrapper around AddTraceEvent used by TRACE_COUNTERx macros | |
| 728 // that allows only integer values for the counters. | |
| 729 int AddCounterEvent(const TraceCategory* category, | |
| 730 const char* name, | |
| 731 const char* arg1_name, int32 arg1_val, | |
| 732 const char* arg2_name, int32 arg2_val, | |
| 733 EventFlags flags); | |
| 734 | |
| 667 // Exposed for unittesting: | 735 // Exposed for unittesting: |
| 668 | 736 |
| 669 // Allows deleting our singleton instance. | 737 // Allows deleting our singleton instance. |
| 670 static void DeleteForTesting(); | 738 static void DeleteForTesting(); |
| 671 | 739 |
| 672 // Allows resurrecting our singleton instance post-AtExit processing. | 740 // Allows resurrecting our singleton instance post-AtExit processing. |
| 673 static void Resurrect(); | 741 static void Resurrect(); |
| 674 | 742 |
| 675 // Allow tests to inspect TraceEvents. | 743 // Allow tests to inspect TraceEvents. |
| 676 size_t GetEventsSize() const { return logged_events_.size(); } | 744 size_t GetEventsSize() const { return logged_events_.size(); } |
| (...skipping 94 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... | |
| 771 Data* p_data_; | 839 Data* p_data_; |
| 772 Data data_; | 840 Data data_; |
| 773 }; | 841 }; |
| 774 | 842 |
| 775 } // namespace internal | 843 } // namespace internal |
| 776 | 844 |
| 777 } // namespace debug | 845 } // namespace debug |
| 778 } // namespace base | 846 } // namespace base |
| 779 | 847 |
| 780 #endif // BASE_DEBUG_TRACE_EVENT_H_ | 848 #endif // BASE_DEBUG_TRACE_EVENT_H_ |
| OLD | NEW |