| OLD | NEW |
|---|
| (Empty) |
| 1 /* | |
| 2 * Copyright (c) 2012 The WebRTC project authors. All Rights Reserved. | |
| 3 * | |
| 4 * Use of this source code is governed by a BSD-style license | |
| 5 * that can be found in the LICENSE file in the root of the source | |
| 6 * tree. An additional intellectual property rights grant can be found | |
| 7 * in the file PATENTS. All contributing project authors may | |
| 8 * be found in the AUTHORS file in the root of the source tree. | |
| 9 */ | |
| 10 #include "webrtc/base/event_tracer.h" | |
| 11 | |
| 12 #include <inttypes.h> | |
| 13 | |
| 14 #include <string> | |
| 15 #include <vector> | |
| 16 | |
| 17 #include "webrtc/base/checks.h" | |
| 18 #include "webrtc/base/criticalsection.h" | |
| 19 #include "webrtc/base/event.h" | |
| 20 #include "webrtc/base/logging.h" | |
| 21 #include "webrtc/base/platform_thread.h" | |
| 22 #include "webrtc/base/stringutils.h" | |
| 23 #include "webrtc/base/timeutils.h" | |
| 24 #include "webrtc/base/trace_event.h" | |
| 25 | |
| 26 // This is a guesstimate that should be enough in most cases. | |
| 27 static const size_t kEventLoggerArgsStrBufferInitialSize = 256; | |
| 28 static const size_t kTraceArgBufferLength = 32; | |
| 29 | |
| 30 namespace webrtc { | |
| 31 | |
| 32 namespace { | |
| 33 | |
| 34 GetCategoryEnabledPtr g_get_category_enabled_ptr = nullptr; | |
| 35 AddTraceEventPtr g_add_trace_event_ptr = nullptr; | |
| 36 | |
| 37 } // namespace | |
| 38 | |
| 39 void SetupEventTracer(GetCategoryEnabledPtr get_category_enabled_ptr, | |
| 40 AddTraceEventPtr add_trace_event_ptr) { | |
| 41 g_get_category_enabled_ptr = get_category_enabled_ptr; | |
| 42 g_add_trace_event_ptr = add_trace_event_ptr; | |
| 43 } | |
| 44 | |
| 45 const unsigned char* EventTracer::GetCategoryEnabled(const char* name) { | |
| 46 if (g_get_category_enabled_ptr) | |
| 47 return g_get_category_enabled_ptr(name); | |
| 48 | |
| 49 // A string with null terminator means category is disabled. | |
| 50 return reinterpret_cast<const unsigned char*>("\0"); | |
| 51 } | |
| 52 | |
| 53 // Arguments to this function (phase, etc.) are as defined in | |
| 54 // webrtc/base/trace_event.h. | |
| 55 void EventTracer::AddTraceEvent(char phase, | |
| 56 const unsigned char* category_enabled, | |
| 57 const char* name, | |
| 58 unsigned long long id, | |
| 59 int num_args, | |
| 60 const char** arg_names, | |
| 61 const unsigned char* arg_types, | |
| 62 const unsigned long long* arg_values, | |
| 63 unsigned char flags) { | |
| 64 if (g_add_trace_event_ptr) { | |
| 65 g_add_trace_event_ptr(phase, | |
| 66 category_enabled, | |
| 67 name, | |
| 68 id, | |
| 69 num_args, | |
| 70 arg_names, | |
| 71 arg_types, | |
| 72 arg_values, | |
| 73 flags); | |
| 74 } | |
| 75 } | |
| 76 | |
| 77 } // namespace webrtc | |
| 78 | |
| 79 namespace rtc { | |
| 80 namespace tracing { | |
| 81 namespace { | |
| 82 | |
| 83 static void EventTracingThreadFunc(void* params); | |
| 84 | |
| 85 // Atomic-int fast path for avoiding logging when disabled. | |
| 86 static volatile int g_event_logging_active = 0; | |
| 87 | |
| 88 // TODO(pbos): Log metadata for all threads, etc. | |
| 89 class EventLogger final { | |
| 90 public: | |
| 91 EventLogger() | |
| 92 : logging_thread_(EventTracingThreadFunc, | |
| 93 this, | |
| 94 "EventTracingThread", | |
| 95 kLowPriority), | |
| 96 shutdown_event_(false, false) {} | |
| 97 ~EventLogger() { RTC_DCHECK(thread_checker_.CalledOnValidThread()); } | |
| 98 | |
| 99 void AddTraceEvent(const char* name, | |
| 100 const unsigned char* category_enabled, | |
| 101 char phase, | |
| 102 int num_args, | |
| 103 const char** arg_names, | |
| 104 const unsigned char* arg_types, | |
| 105 const unsigned long long* arg_values, | |
| 106 uint64_t timestamp, | |
| 107 int pid, | |
| 108 rtc::PlatformThreadId thread_id) { | |
| 109 std::vector<TraceArg> args(num_args); | |
| 110 for (int i = 0; i < num_args; ++i) { | |
| 111 TraceArg& arg = args[i]; | |
| 112 arg.name = arg_names[i]; | |
| 113 arg.type = arg_types[i]; | |
| 114 arg.value.as_uint = arg_values[i]; | |
| 115 | |
| 116 // Value is a pointer to a temporary string, so we have to make a copy. | |
| 117 if (arg.type == TRACE_VALUE_TYPE_COPY_STRING) { | |
| 118 // Space for the string and for the terminating null character. | |
| 119 size_t str_length = strlen(arg.value.as_string) + 1; | |
| 120 char* str_copy = new char[str_length]; | |
| 121 memcpy(str_copy, arg.value.as_string, str_length); | |
| 122 arg.value.as_string = str_copy; | |
| 123 } | |
| 124 } | |
| 125 rtc::CritScope lock(&crit_); | |
| 126 trace_events_.push_back( | |
| 127 {name, category_enabled, phase, args, timestamp, 1, thread_id}); | |
| 128 } | |
| 129 | |
| 130 // The TraceEvent format is documented here: | |
| 131 // https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAy
SU/preview | |
| 132 void Log() { | |
| 133 RTC_DCHECK(output_file_); | |
| 134 static const int kLoggingIntervalMs = 100; | |
| 135 fprintf(output_file_, "{ \"traceEvents\": [\n"); | |
| 136 bool has_logged_event = false; | |
| 137 while (true) { | |
| 138 bool shutting_down = shutdown_event_.Wait(kLoggingIntervalMs); | |
| 139 std::vector<TraceEvent> events; | |
| 140 { | |
| 141 rtc::CritScope lock(&crit_); | |
| 142 trace_events_.swap(events); | |
| 143 } | |
| 144 std::string args_str; | |
| 145 args_str.reserve(kEventLoggerArgsStrBufferInitialSize); | |
| 146 for (TraceEvent& e : events) { | |
| 147 args_str.clear(); | |
| 148 if (!e.args.empty()) { | |
| 149 args_str += ", \"args\": {"; | |
| 150 bool is_first_argument = true; | |
| 151 for (TraceArg& arg : e.args) { | |
| 152 if (!is_first_argument) | |
| 153 args_str += ","; | |
| 154 is_first_argument = false; | |
| 155 args_str += " \""; | |
| 156 args_str += arg.name; | |
| 157 args_str += "\": "; | |
| 158 args_str += TraceArgValueAsString(arg); | |
| 159 | |
| 160 // Delete our copy of the string. | |
| 161 if (arg.type == TRACE_VALUE_TYPE_COPY_STRING) { | |
| 162 delete[] arg.value.as_string; | |
| 163 arg.value.as_string = nullptr; | |
| 164 } | |
| 165 } | |
| 166 args_str += " }"; | |
| 167 } | |
| 168 fprintf(output_file_, | |
| 169 "%s{ \"name\": \"%s\"" | |
| 170 ", \"cat\": \"%s\"" | |
| 171 ", \"ph\": \"%c\"" | |
| 172 ", \"ts\": %" PRIu64 | |
| 173 ", \"pid\": %d" | |
| 174 #if defined(WEBRTC_WIN) | |
| 175 ", \"tid\": %lu" | |
| 176 #else | |
| 177 ", \"tid\": %d" | |
| 178 #endif // defined(WEBRTC_WIN) | |
| 179 "%s" | |
| 180 "}\n", | |
| 181 has_logged_event ? "," : " ", e.name, e.category_enabled, | |
| 182 e.phase, e.timestamp, e.pid, e.tid, args_str.c_str()); | |
| 183 has_logged_event = true; | |
| 184 } | |
| 185 if (shutting_down) | |
| 186 break; | |
| 187 } | |
| 188 fprintf(output_file_, "]}\n"); | |
| 189 if (output_file_owned_) | |
| 190 fclose(output_file_); | |
| 191 output_file_ = nullptr; | |
| 192 } | |
| 193 | |
| 194 void Start(FILE* file, bool owned) { | |
| 195 RTC_DCHECK(thread_checker_.CalledOnValidThread()); | |
| 196 RTC_DCHECK(file); | |
| 197 RTC_DCHECK(!output_file_); | |
| 198 output_file_ = file; | |
| 199 output_file_owned_ = owned; | |
| 200 { | |
| 201 rtc::CritScope lock(&crit_); | |
| 202 // Since the atomic fast-path for adding events to the queue can be | |
| 203 // bypassed while the logging thread is shutting down there may be some | |
| 204 // stale events in the queue, hence the vector needs to be cleared to not | |
| 205 // log events from a previous logging session (which may be days old). | |
| 206 trace_events_.clear(); | |
| 207 } | |
| 208 // Enable event logging (fast-path). This should be disabled since starting | |
| 209 // shouldn't be done twice. | |
| 210 RTC_CHECK_EQ(0, | |
| 211 rtc::AtomicOps::CompareAndSwap(&g_event_logging_active, 0, 1)); | |
| 212 | |
| 213 // Finally start, everything should be set up now. | |
| 214 logging_thread_.Start(); | |
| 215 TRACE_EVENT_INSTANT0("webrtc", "EventLogger::Start"); | |
| 216 } | |
| 217 | |
| 218 void Stop() { | |
| 219 RTC_DCHECK(thread_checker_.CalledOnValidThread()); | |
| 220 TRACE_EVENT_INSTANT0("webrtc", "EventLogger::Stop"); | |
| 221 // Try to stop. Abort if we're not currently logging. | |
| 222 if (rtc::AtomicOps::CompareAndSwap(&g_event_logging_active, 1, 0) == 0) | |
| 223 return; | |
| 224 | |
| 225 // Wake up logging thread to finish writing. | |
| 226 shutdown_event_.Set(); | |
| 227 // Join the logging thread. | |
| 228 logging_thread_.Stop(); | |
| 229 } | |
| 230 | |
| 231 private: | |
| 232 struct TraceArg { | |
| 233 const char* name; | |
| 234 unsigned char type; | |
| 235 // Copied from webrtc/base/trace_event.h TraceValueUnion. | |
| 236 union TraceArgValue { | |
| 237 bool as_bool; | |
| 238 unsigned long long as_uint; | |
| 239 long long as_int; | |
| 240 double as_double; | |
| 241 const void* as_pointer; | |
| 242 const char* as_string; | |
| 243 } value; | |
| 244 | |
| 245 // Assert that the size of the union is equal to the size of the as_uint | |
| 246 // field since we are assigning to arbitrary types using it. | |
| 247 static_assert(sizeof(TraceArgValue) == sizeof(unsigned long long), | |
| 248 "Size of TraceArg value union is not equal to the size of " | |
| 249 "the uint field of that union."); | |
| 250 }; | |
| 251 | |
| 252 struct TraceEvent { | |
| 253 const char* name; | |
| 254 const unsigned char* category_enabled; | |
| 255 char phase; | |
| 256 std::vector<TraceArg> args; | |
| 257 uint64_t timestamp; | |
| 258 int pid; | |
| 259 rtc::PlatformThreadId tid; | |
| 260 }; | |
| 261 | |
| 262 static std::string TraceArgValueAsString(TraceArg arg) { | |
| 263 std::string output; | |
| 264 | |
| 265 if (arg.type == TRACE_VALUE_TYPE_STRING || | |
| 266 arg.type == TRACE_VALUE_TYPE_COPY_STRING) { | |
| 267 // Space for every character to be an espaced character + two for | |
| 268 // quatation marks. | |
| 269 output.reserve(strlen(arg.value.as_string) * 2 + 2); | |
| 270 output += '\"'; | |
| 271 const char* c = arg.value.as_string; | |
| 272 do { | |
| 273 if (*c == '"' || *c == '\\') { | |
| 274 output += '\\'; | |
| 275 output += *c; | |
| 276 } else { | |
| 277 output += *c; | |
| 278 } | |
| 279 } while (*++c); | |
| 280 output += '\"'; | |
| 281 } else { | |
| 282 output.resize(kTraceArgBufferLength); | |
| 283 size_t print_length = 0; | |
| 284 switch (arg.type) { | |
| 285 case TRACE_VALUE_TYPE_BOOL: | |
| 286 if (arg.value.as_bool) { | |
| 287 strcpy(&output[0], "true"); | |
| 288 print_length = 4; | |
| 289 } else { | |
| 290 strcpy(&output[0], "false"); | |
| 291 print_length = 5; | |
| 292 } | |
| 293 break; | |
| 294 case TRACE_VALUE_TYPE_UINT: | |
| 295 print_length = sprintfn(&output[0], kTraceArgBufferLength, "%llu", | |
| 296 arg.value.as_uint); | |
| 297 break; | |
| 298 case TRACE_VALUE_TYPE_INT: | |
| 299 print_length = sprintfn(&output[0], kTraceArgBufferLength, "%lld", | |
| 300 arg.value.as_int); | |
| 301 break; | |
| 302 case TRACE_VALUE_TYPE_DOUBLE: | |
| 303 print_length = sprintfn(&output[0], kTraceArgBufferLength, "%f", | |
| 304 arg.value.as_double); | |
| 305 break; | |
| 306 case TRACE_VALUE_TYPE_POINTER: | |
| 307 print_length = sprintfn(&output[0], kTraceArgBufferLength, "\"%p\"", | |
| 308 arg.value.as_pointer); | |
| 309 break; | |
| 310 } | |
| 311 size_t output_length = print_length < kTraceArgBufferLength | |
| 312 ? print_length | |
| 313 : kTraceArgBufferLength - 1; | |
| 314 // This will hopefully be very close to nop. On most implementations, it | |
| 315 // just writes null byte and sets the length field of the string. | |
| 316 output.resize(output_length); | |
| 317 } | |
| 318 | |
| 319 return output; | |
| 320 } | |
| 321 | |
| 322 rtc::CriticalSection crit_; | |
| 323 std::vector<TraceEvent> trace_events_ GUARDED_BY(crit_); | |
| 324 rtc::PlatformThread logging_thread_; | |
| 325 rtc::Event shutdown_event_; | |
| 326 rtc::ThreadChecker thread_checker_; | |
| 327 FILE* output_file_ = nullptr; | |
| 328 bool output_file_owned_ = false; | |
| 329 }; | |
| 330 | |
| 331 static void EventTracingThreadFunc(void* params) { | |
| 332 static_cast<EventLogger*>(params)->Log(); | |
| 333 } | |
| 334 | |
| 335 static EventLogger* volatile g_event_logger = nullptr; | |
| 336 static const char* const kDisabledTracePrefix = TRACE_DISABLED_BY_DEFAULT(""); | |
| 337 const unsigned char* InternalGetCategoryEnabled(const char* name) { | |
| 338 const char* prefix_ptr = &kDisabledTracePrefix[0]; | |
| 339 const char* name_ptr = name; | |
| 340 // Check whether name contains the default-disabled prefix. | |
| 341 while (*prefix_ptr == *name_ptr && *prefix_ptr != '\0') { | |
| 342 ++prefix_ptr; | |
| 343 ++name_ptr; | |
| 344 } | |
| 345 return reinterpret_cast<const unsigned char*>(*prefix_ptr == '\0' ? "" | |
| 346 : name); | |
| 347 } | |
| 348 | |
| 349 void InternalAddTraceEvent(char phase, | |
| 350 const unsigned char* category_enabled, | |
| 351 const char* name, | |
| 352 unsigned long long id, | |
| 353 int num_args, | |
| 354 const char** arg_names, | |
| 355 const unsigned char* arg_types, | |
| 356 const unsigned long long* arg_values, | |
| 357 unsigned char flags) { | |
| 358 // Fast path for when event tracing is inactive. | |
| 359 if (rtc::AtomicOps::AcquireLoad(&g_event_logging_active) == 0) | |
| 360 return; | |
| 361 | |
| 362 g_event_logger->AddTraceEvent(name, category_enabled, phase, num_args, | |
| 363 arg_names, arg_types, arg_values, | |
| 364 rtc::TimeMicros(), 1, rtc::CurrentThreadId()); | |
| 365 } | |
| 366 | |
| 367 } // namespace | |
| 368 | |
| 369 void SetupInternalTracer() { | |
| 370 RTC_CHECK(rtc::AtomicOps::CompareAndSwapPtr( | |
| 371 &g_event_logger, static_cast<EventLogger*>(nullptr), | |
| 372 new EventLogger()) == nullptr); | |
| 373 webrtc::SetupEventTracer(InternalGetCategoryEnabled, InternalAddTraceEvent); | |
| 374 } | |
| 375 | |
| 376 void StartInternalCaptureToFile(FILE* file) { | |
| 377 g_event_logger->Start(file, false); | |
| 378 } | |
| 379 | |
| 380 bool StartInternalCapture(const char* filename) { | |
| 381 FILE* file = fopen(filename, "w"); | |
| 382 if (!file) { | |
| 383 LOG(LS_ERROR) << "Failed to open trace file '" << filename | |
| 384 << "' for writing."; | |
| 385 return false; | |
| 386 } | |
| 387 g_event_logger->Start(file, true); | |
| 388 return true; | |
| 389 } | |
| 390 | |
| 391 void StopInternalCapture() { | |
| 392 g_event_logger->Stop(); | |
| 393 } | |
| 394 | |
| 395 void ShutdownInternalTracer() { | |
| 396 StopInternalCapture(); | |
| 397 EventLogger* old_logger = rtc::AtomicOps::AcquireLoadPtr(&g_event_logger); | |
| 398 RTC_DCHECK(old_logger); | |
| 399 RTC_CHECK(rtc::AtomicOps::CompareAndSwapPtr( | |
| 400 &g_event_logger, old_logger, | |
| 401 static_cast<EventLogger*>(nullptr)) == old_logger); | |
| 402 delete old_logger; | |
| 403 webrtc::SetupEventTracer(nullptr, nullptr); | |
| 404 } | |
| 405 | |
| 406 } // namespace tracing | |
| 407 } // namespace rtc | |
| OLD | NEW |
|---|
Chromium Code Reviews
Issue 2877023002:
Move webrtc/{base => rtc_base} (Closed)
