| // Copyright (c) 2012 The Chromium Authors. All rights reserved. |
| // Use of this source code is governed by a BSD-style license that can be |
| // found in the LICENSE file. |
| |
| #include "base/trace_event/trace_event_impl.h" |
| |
| #include "base/format_macros.h" |
| #include "base/json/string_escape.h" |
| #include "base/process/process_handle.h" |
| #include "base/stl_util.h" |
| #include "base/strings/string_number_conversions.h" |
| #include "base/strings/string_util.h" |
| #include "base/strings/stringprintf.h" |
| #include "base/strings/utf_string_conversions.h" |
| #include "base/trace_event/trace_event.h" |
| #include "base/trace_event/trace_log.h" |
| |
| namespace base { |
| namespace trace_event { |
| |
| namespace { |
| |
| size_t GetAllocLength(const char* str) { return str ? strlen(str) + 1 : 0; } |
| |
| // Copies |*member| into |*buffer|, sets |*member| to point to this new |
| // location, and then advances |*buffer| by the amount written. |
| void CopyTraceEventParameter(char** buffer, |
| const char** member, |
| const char* end) { |
| if (*member) { |
| size_t written = strlcpy(*buffer, *member, end - *buffer) + 1; |
| DCHECK_LE(static_cast<int>(written), end - *buffer); |
| *member = *buffer; |
| *buffer += written; |
| } |
| } |
| |
| } // namespace |
| |
| TraceEvent::TraceEvent() |
| : duration_(TimeDelta::FromInternalValue(-1)), |
| id_(0u), |
| category_group_enabled_(NULL), |
| name_(NULL), |
| thread_id_(0), |
| flags_(0), |
| phase_(TRACE_EVENT_PHASE_BEGIN) { |
| for (int i = 0; i < kTraceMaxNumArgs; ++i) |
| arg_names_[i] = NULL; |
| memset(arg_values_, 0, sizeof(arg_values_)); |
| } |
| |
| TraceEvent::~TraceEvent() { |
| } |
| |
| void TraceEvent::CopyFrom(const TraceEvent& other) { |
| timestamp_ = other.timestamp_; |
| thread_timestamp_ = other.thread_timestamp_; |
| duration_ = other.duration_; |
| id_ = other.id_; |
| category_group_enabled_ = other.category_group_enabled_; |
| name_ = other.name_; |
| if (other.flags_ & TRACE_EVENT_FLAG_HAS_PROCESS_ID) |
| process_id_ = other.process_id_; |
| else |
| thread_id_ = other.thread_id_; |
| phase_ = other.phase_; |
| flags_ = other.flags_; |
| parameter_copy_storage_ = other.parameter_copy_storage_; |
| |
| for (int i = 0; i < kTraceMaxNumArgs; ++i) { |
| arg_names_[i] = other.arg_names_[i]; |
| arg_types_[i] = other.arg_types_[i]; |
| arg_values_[i] = other.arg_values_[i]; |
| convertable_values_[i] = other.convertable_values_[i]; |
| } |
| } |
| |
| void TraceEvent::Initialize( |
| int thread_id, |
| TimeTicks timestamp, |
| ThreadTicks thread_timestamp, |
| char phase, |
| const unsigned char* category_group_enabled, |
| const char* name, |
| unsigned long long id, |
| unsigned long long bind_id, |
| int num_args, |
| const char** arg_names, |
| const unsigned char* arg_types, |
| const unsigned long long* arg_values, |
| const scoped_refptr<ConvertableToTraceFormat>* convertable_values, |
| unsigned int flags) { |
| timestamp_ = timestamp; |
| thread_timestamp_ = thread_timestamp; |
| duration_ = TimeDelta::FromInternalValue(-1); |
| id_ = id; |
| category_group_enabled_ = category_group_enabled; |
| name_ = name; |
| thread_id_ = thread_id; |
| phase_ = phase; |
| flags_ = flags; |
| bind_id_ = bind_id; |
| |
| // Clamp num_args since it may have been set by a third_party library. |
| num_args = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args; |
| int i = 0; |
| for (; i < num_args; ++i) { |
| arg_names_[i] = arg_names[i]; |
| arg_types_[i] = arg_types[i]; |
| |
| if (arg_types[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| convertable_values_[i] = convertable_values[i]; |
| else |
| arg_values_[i].as_uint = arg_values[i]; |
| } |
| for (; i < kTraceMaxNumArgs; ++i) { |
| arg_names_[i] = NULL; |
| arg_values_[i].as_uint = 0u; |
| convertable_values_[i] = NULL; |
| arg_types_[i] = TRACE_VALUE_TYPE_UINT; |
| } |
| |
| bool copy = !!(flags & TRACE_EVENT_FLAG_COPY); |
| size_t alloc_size = 0; |
| if (copy) { |
| alloc_size += GetAllocLength(name); |
| for (i = 0; i < num_args; ++i) { |
| alloc_size += GetAllocLength(arg_names_[i]); |
| if (arg_types_[i] == TRACE_VALUE_TYPE_STRING) |
| arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING; |
| } |
| } |
| |
| bool arg_is_copy[kTraceMaxNumArgs]; |
| for (i = 0; i < num_args; ++i) { |
| // No copying of convertable types, we retain ownership. |
| if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| continue; |
| |
| // We only take a copy of arg_vals if they are of type COPY_STRING. |
| arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING); |
| if (arg_is_copy[i]) |
| alloc_size += GetAllocLength(arg_values_[i].as_string); |
| } |
| |
| if (alloc_size) { |
| parameter_copy_storage_ = new RefCountedString; |
| parameter_copy_storage_->data().resize(alloc_size); |
| char* ptr = string_as_array(¶meter_copy_storage_->data()); |
| const char* end = ptr + alloc_size; |
| if (copy) { |
| CopyTraceEventParameter(&ptr, &name_, end); |
| for (i = 0; i < num_args; ++i) { |
| CopyTraceEventParameter(&ptr, &arg_names_[i], end); |
| } |
| } |
| for (i = 0; i < num_args; ++i) { |
| if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| continue; |
| if (arg_is_copy[i]) |
| CopyTraceEventParameter(&ptr, &arg_values_[i].as_string, end); |
| } |
| DCHECK_EQ(end, ptr) << "Overrun by " << ptr - end; |
| } |
| } |
| |
| void TraceEvent::Reset() { |
| // Only reset fields that won't be initialized in Initialize(), or that may |
| // hold references to other objects. |
| duration_ = TimeDelta::FromInternalValue(-1); |
| parameter_copy_storage_ = NULL; |
| for (int i = 0; i < kTraceMaxNumArgs; ++i) |
| convertable_values_[i] = NULL; |
| } |
| |
| void TraceEvent::UpdateDuration(const TimeTicks& now, |
| const ThreadTicks& thread_now) { |
| DCHECK_EQ(duration_.ToInternalValue(), -1); |
| duration_ = now - timestamp_; |
| |
| // |thread_timestamp_| can be empty if the thread ticks clock wasn't |
| // initialized when it was recorded. |
| if (thread_timestamp_ != ThreadTicks()) |
| thread_duration_ = thread_now - thread_timestamp_; |
| } |
| |
| void TraceEvent::EstimateTraceMemoryOverhead( |
| TraceEventMemoryOverhead* overhead) { |
| overhead->Add("TraceEvent", sizeof(*this)); |
| |
| // TODO(primiano): parameter_copy_storage_ is refcounted and, in theory, |
| // could be shared by several events and we might overcount. In practice |
| // this is unlikely but it's worth checking. |
| if (parameter_copy_storage_) |
| overhead->AddRefCountedString(*parameter_copy_storage_.get()); |
| |
| for (size_t i = 0; i < kTraceMaxNumArgs; ++i) { |
| if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| convertable_values_[i]->EstimateTraceMemoryOverhead(overhead); |
| } |
| } |
| |
| // static |
| void TraceEvent::AppendValueAsJSON(unsigned char type, |
| TraceEvent::TraceValue value, |
| std::string* out) { |
| switch (type) { |
| case TRACE_VALUE_TYPE_BOOL: |
| *out += value.as_bool ? "true" : "false"; |
| break; |
| case TRACE_VALUE_TYPE_UINT: |
| StringAppendF(out, "%" PRIu64, static_cast<uint64>(value.as_uint)); |
| break; |
| case TRACE_VALUE_TYPE_INT: |
| StringAppendF(out, "%" PRId64, static_cast<int64>(value.as_int)); |
| break; |
| case TRACE_VALUE_TYPE_DOUBLE: { |
| // FIXME: base/json/json_writer.cc is using the same code, |
| // should be made into a common method. |
| std::string real; |
| double val = value.as_double; |
| if (std::isfinite(val)) { |
| real = DoubleToString(val); |
| // Ensure that the number has a .0 if there's no decimal or 'e'. This |
| // makes sure that when we read the JSON back, it's interpreted as a |
| // real rather than an int. |
| if (real.find('.') == std::string::npos && |
| real.find('e') == std::string::npos && |
| real.find('E') == std::string::npos) { |
| real.append(".0"); |
| } |
| // The JSON spec requires that non-integer values in the range (-1,1) |
| // have a zero before the decimal point - ".52" is not valid, "0.52" is. |
| if (real[0] == '.') { |
| real.insert(0, "0"); |
| } else if (real.length() > 1 && real[0] == '-' && real[1] == '.') { |
| // "-.1" bad "-0.1" good |
| real.insert(1, "0"); |
| } |
| } else if (std::isnan(val)){ |
| // The JSON spec doesn't allow NaN and Infinity (since these are |
| // objects in EcmaScript). Use strings instead. |
| real = "\"NaN\""; |
| } else if (val < 0) { |
| real = "\"-Infinity\""; |
| } else { |
| real = "\"Infinity\""; |
| } |
| StringAppendF(out, "%s", real.c_str()); |
| break; |
| } |
| case TRACE_VALUE_TYPE_POINTER: |
| // JSON only supports double and int numbers. |
| // So as not to lose bits from a 64-bit pointer, output as a hex string. |
| StringAppendF(out, "\"0x%" PRIx64 "\"", static_cast<uint64>( |
| reinterpret_cast<intptr_t>( |
| value.as_pointer))); |
| break; |
| case TRACE_VALUE_TYPE_STRING: |
| case TRACE_VALUE_TYPE_COPY_STRING: |
| EscapeJSONString(value.as_string ? value.as_string : "NULL", true, out); |
| break; |
| default: |
| NOTREACHED() << "Don't know how to print this value"; |
| break; |
| } |
| } |
| |
| void TraceEvent::AppendAsJSON( |
| std::string* out, |
| const ArgumentFilterPredicate& argument_filter_predicate) const { |
| int64 time_int64 = timestamp_.ToInternalValue(); |
| int process_id; |
| int thread_id; |
| if ((flags_ & TRACE_EVENT_FLAG_HAS_PROCESS_ID) && |
| process_id_ != kNullProcessId) { |
| process_id = process_id_; |
| thread_id = -1; |
| } else { |
| process_id = TraceLog::GetInstance()->process_id(); |
| thread_id = thread_id_; |
| } |
| const char* category_group_name = |
| TraceLog::GetCategoryGroupName(category_group_enabled_); |
| |
| // Category group checked at category creation time. |
| DCHECK(!strchr(name_, '"')); |
| StringAppendF(out, "{\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 |
| "," |
| "\"ph\":\"%c\",\"cat\":\"%s\",\"name\":\"%s\",\"args\":", |
| process_id, thread_id, time_int64, phase_, category_group_name, |
| name_); |
| |
| // Output argument names and values, stop at first NULL argument name. |
| // TODO(oysteine): The dual predicates here is a bit ugly; if the filtering |
| // capabilities need to grow even more precise we should rethink this |
| // approach |
| ArgumentNameFilterPredicate argument_name_filter_predicate; |
| bool strip_args = |
| arg_names_[0] && !argument_filter_predicate.is_null() && |
| !argument_filter_predicate.Run(category_group_name, name_, |
| &argument_name_filter_predicate); |
| |
| if (strip_args) { |
| *out += "\"__stripped__\""; |
| } else { |
| *out += "{"; |
| |
| for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { |
| if (i > 0) |
| *out += ","; |
| *out += "\""; |
| *out += arg_names_[i]; |
| *out += "\":"; |
| |
| if (argument_name_filter_predicate.is_null() || |
| argument_name_filter_predicate.Run(arg_names_[i])) { |
| if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| convertable_values_[i]->AppendAsTraceFormat(out); |
| else |
| AppendValueAsJSON(arg_types_[i], arg_values_[i], out); |
| } else { |
| *out += "\"__stripped__\""; |
| } |
| } |
| |
| *out += "}"; |
| } |
| |
| if (phase_ == TRACE_EVENT_PHASE_COMPLETE) { |
| int64 duration = duration_.ToInternalValue(); |
| if (duration != -1) |
| StringAppendF(out, ",\"dur\":%" PRId64, duration); |
| if (!thread_timestamp_.is_null()) { |
| int64 thread_duration = thread_duration_.ToInternalValue(); |
| if (thread_duration != -1) |
| StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration); |
| } |
| } |
| |
| // Output tts if thread_timestamp is valid. |
| if (!thread_timestamp_.is_null()) { |
| int64 thread_time_int64 = thread_timestamp_.ToInternalValue(); |
| StringAppendF(out, ",\"tts\":%" PRId64, thread_time_int64); |
| } |
| |
| // Output async tts marker field if flag is set. |
| if (flags_ & TRACE_EVENT_FLAG_ASYNC_TTS) { |
| StringAppendF(out, ", \"use_async_tts\":1"); |
| } |
| |
| // If id_ is set, print it out as a hex string so we don't loose any |
| // bits (it might be a 64-bit pointer). |
| if (flags_ & TRACE_EVENT_FLAG_HAS_ID) |
| StringAppendF(out, ",\"id\":\"0x%" PRIx64 "\"", static_cast<uint64>(id_)); |
| |
| if (flags_ & TRACE_EVENT_FLAG_BIND_TO_ENCLOSING) |
| StringAppendF(out, ",\"bp\":\"e\""); |
| |
| if ((flags_ & TRACE_EVENT_FLAG_FLOW_OUT) || |
| (flags_ & TRACE_EVENT_FLAG_FLOW_IN)) { |
| StringAppendF(out, ",\"bind_id\":\"0x%" PRIx64 "\"", |
| static_cast<uint64>(bind_id_)); |
| } |
| if (flags_ & TRACE_EVENT_FLAG_FLOW_IN) |
| StringAppendF(out, ",\"flow_in\":true"); |
| if (flags_ & TRACE_EVENT_FLAG_FLOW_OUT) |
| StringAppendF(out, ",\"flow_out\":true"); |
| |
| // Instant events also output their scope. |
| if (phase_ == TRACE_EVENT_PHASE_INSTANT) { |
| char scope = '?'; |
| switch (flags_ & TRACE_EVENT_FLAG_SCOPE_MASK) { |
| case TRACE_EVENT_SCOPE_GLOBAL: |
| scope = TRACE_EVENT_SCOPE_NAME_GLOBAL; |
| break; |
| |
| case TRACE_EVENT_SCOPE_PROCESS: |
| scope = TRACE_EVENT_SCOPE_NAME_PROCESS; |
| break; |
| |
| case TRACE_EVENT_SCOPE_THREAD: |
| scope = TRACE_EVENT_SCOPE_NAME_THREAD; |
| break; |
| } |
| StringAppendF(out, ",\"s\":\"%c\"", scope); |
| } |
| |
| *out += "}"; |
| } |
| |
| void TraceEvent::AppendPrettyPrinted(std::ostringstream* out) const { |
| *out << name_ << "["; |
| *out << TraceLog::GetCategoryGroupName(category_group_enabled_); |
| *out << "]"; |
| if (arg_names_[0]) { |
| *out << ", {"; |
| for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { |
| if (i > 0) |
| *out << ", "; |
| *out << arg_names_[i] << ":"; |
| std::string value_as_text; |
| |
| if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| convertable_values_[i]->AppendAsTraceFormat(&value_as_text); |
| else |
| AppendValueAsJSON(arg_types_[i], arg_values_[i], &value_as_text); |
| |
| *out << value_as_text; |
| } |
| *out << "}"; |
| } |
| } |
| |
| } // namespace trace_event |
| } // namespace base |