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 <stddef.h>
8
9 #include "base/format_macros.h"
10 #include "base/json/string_escape.h"
11 #include "base/memory/ptr_util.h"
12 #include "base/process/process_handle.h"
13 #include "base/stl_util.h"
14 #include "base/strings/string_number_conversions.h"
15 #include "base/strings/string_util.h"
16 #include "base/strings/stringprintf.h"
17 #include "base/strings/utf_string_conversions.h"
18 #include "base/trace_event/trace_event.h"
19 #include "base/trace_event/trace_log.h"
20 #include "base/trace_event/traced_value.h"
21
22 namespace base {
23 namespace trace_event {
24
AppendToProto(ProtoAppender * appender)25 bool ConvertableToTraceFormat::AppendToProto(ProtoAppender* appender) {
26 return false;
27 }
28
29 // See comment for name TraceEvent::scope_ definition.
30 static_assert(trace_event_internal::kGlobalScope == nullptr,
31 "Invalid TraceEvent::scope default initializer value");
32
33 TraceEvent::TraceEvent() = default;
34
TraceEvent(int thread_id,TimeTicks timestamp,ThreadTicks thread_timestamp,ThreadInstructionCount thread_instruction_count,char phase,const unsigned char * category_group_enabled,const char * name,const char * scope,unsigned long long id,unsigned long long bind_id,TraceArguments * args,unsigned int flags)35 TraceEvent::TraceEvent(int thread_id,
36 TimeTicks timestamp,
37 ThreadTicks thread_timestamp,
38 ThreadInstructionCount thread_instruction_count,
39 char phase,
40 const unsigned char* category_group_enabled,
41 const char* name,
42 const char* scope,
43 unsigned long long id,
44 unsigned long long bind_id,
45 TraceArguments* args,
46 unsigned int flags)
47 : timestamp_(timestamp),
48 thread_timestamp_(thread_timestamp),
49 thread_instruction_count_(thread_instruction_count),
50 scope_(scope),
51 id_(id),
52 category_group_enabled_(category_group_enabled),
53 name_(name),
54 thread_id_(thread_id),
55 flags_(flags),
56 bind_id_(bind_id),
57 phase_(phase) {
58 InitArgs(args);
59 }
60
61 TraceEvent::~TraceEvent() = default;
62
63 TraceEvent::TraceEvent(TraceEvent&& other) noexcept = default;
64 TraceEvent& TraceEvent::operator=(TraceEvent&& other) noexcept = default;
65
Reset()66 void TraceEvent::Reset() {
67 // Only reset fields that won't be initialized in Reset(int, ...), or that may
68 // hold references to other objects.
69 duration_ = TimeDelta::FromInternalValue(-1);
70 thread_instruction_delta_ = ThreadInstructionDelta();
71 args_.Reset();
72 parameter_copy_storage_.Reset();
73 }
74
Reset(int thread_id,TimeTicks timestamp,ThreadTicks thread_timestamp,ThreadInstructionCount thread_instruction_count,char phase,const unsigned char * category_group_enabled,const char * name,const char * scope,unsigned long long id,unsigned long long bind_id,TraceArguments * args,unsigned int flags)75 void TraceEvent::Reset(int thread_id,
76 TimeTicks timestamp,
77 ThreadTicks thread_timestamp,
78 ThreadInstructionCount thread_instruction_count,
79 char phase,
80 const unsigned char* category_group_enabled,
81 const char* name,
82 const char* scope,
83 unsigned long long id,
84 unsigned long long bind_id,
85 TraceArguments* args,
86 unsigned int flags) {
87 Reset();
88 timestamp_ = timestamp;
89 thread_timestamp_ = thread_timestamp;
90 scope_ = scope;
91 id_ = id;
92 category_group_enabled_ = category_group_enabled;
93 name_ = name;
94 thread_id_ = thread_id;
95 flags_ = flags;
96 bind_id_ = bind_id;
97 thread_instruction_count_ = thread_instruction_count;
98 phase_ = phase;
99
100 InitArgs(args);
101 }
102
InitArgs(TraceArguments * args)103 void TraceEvent::InitArgs(TraceArguments* args) {
104 if (args)
105 args_ = std::move(*args);
106 args_.CopyStringsTo(¶meter_copy_storage_,
107 !!(flags_ & TRACE_EVENT_FLAG_COPY), &name_, &scope_);
108 }
109
UpdateDuration(const TimeTicks & now,const ThreadTicks & thread_now,ThreadInstructionCount thread_instruction_now)110 void TraceEvent::UpdateDuration(const TimeTicks& now,
111 const ThreadTicks& thread_now,
112 ThreadInstructionCount thread_instruction_now) {
113 DCHECK_EQ(duration_.ToInternalValue(), -1);
114 duration_ = now - timestamp_;
115
116 // |thread_timestamp_| can be empty if the thread ticks clock wasn't
117 // initialized when it was recorded.
118 if (thread_timestamp_ != ThreadTicks())
119 thread_duration_ = thread_now - thread_timestamp_;
120
121 if (!thread_instruction_count_.is_null()) {
122 thread_instruction_delta_ =
123 thread_instruction_now - thread_instruction_count_;
124 }
125 }
126
EstimateTraceMemoryOverhead(TraceEventMemoryOverhead * overhead)127 void TraceEvent::EstimateTraceMemoryOverhead(
128 TraceEventMemoryOverhead* overhead) {
129 overhead->Add(TraceEventMemoryOverhead::kTraceEvent,
130 parameter_copy_storage_.EstimateTraceMemoryOverhead());
131
132 for (size_t i = 0; i < arg_size(); ++i) {
133 if (arg_type(i) == TRACE_VALUE_TYPE_CONVERTABLE)
134 arg_value(i).as_convertable->EstimateTraceMemoryOverhead(overhead);
135 }
136 }
137
AppendAsJSON(std::string * out,const ArgumentFilterPredicate & argument_filter_predicate) const138 void TraceEvent::AppendAsJSON(
139 std::string* out,
140 const ArgumentFilterPredicate& argument_filter_predicate) const {
141 int64_t time_int64 = timestamp_.ToInternalValue();
142 int process_id;
143 int thread_id;
144 if ((flags_ & TRACE_EVENT_FLAG_HAS_PROCESS_ID) &&
145 process_id_ != kNullProcessId) {
146 process_id = process_id_;
147 thread_id = -1;
148 } else {
149 process_id = TraceLog::GetInstance()->process_id();
150 thread_id = thread_id_;
151 }
152 const char* category_group_name =
153 TraceLog::GetCategoryGroupName(category_group_enabled_);
154
155 // Category group checked at category creation time.
156 DCHECK(!strchr(name_, '"'));
157 StringAppendF(out, "{\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64
158 ",\"ph\":\"%c\",\"cat\":\"%s\",\"name\":",
159 process_id, thread_id, time_int64, phase_, category_group_name);
160 EscapeJSONString(name_, true, out);
161 *out += ",\"args\":";
162
163 // Output argument names and values, stop at first NULL argument name.
164 // TODO(oysteine): The dual predicates here is a bit ugly; if the filtering
165 // capabilities need to grow even more precise we should rethink this
166 // approach
167 ArgumentNameFilterPredicate argument_name_filter_predicate;
168 bool strip_args =
169 arg_size() > 0 && arg_name(0) && !argument_filter_predicate.is_null() &&
170 !argument_filter_predicate.Run(category_group_name, name_,
171 &argument_name_filter_predicate);
172
173 if (strip_args) {
174 *out += "\"__stripped__\"";
175 } else {
176 *out += "{";
177
178 for (size_t i = 0; i < arg_size() && arg_name(i); ++i) {
179 if (i > 0)
180 *out += ",";
181 *out += "\"";
182 *out += arg_name(i);
183 *out += "\":";
184
185 if (argument_name_filter_predicate.is_null() ||
186 argument_name_filter_predicate.Run(arg_name(i))) {
187 arg_value(i).AppendAsJSON(arg_type(i), out);
188 } else {
189 *out += "\"__stripped__\"";
190 }
191 }
192
193 *out += "}";
194 }
195
196 if (phase_ == TRACE_EVENT_PHASE_COMPLETE) {
197 int64_t duration = duration_.ToInternalValue();
198 if (duration != -1)
199 StringAppendF(out, ",\"dur\":%" PRId64, duration);
200 if (!thread_timestamp_.is_null()) {
201 int64_t thread_duration = thread_duration_.ToInternalValue();
202 if (thread_duration != -1)
203 StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration);
204 }
205 if (!thread_instruction_count_.is_null()) {
206 int64_t thread_instructions = thread_instruction_delta_.ToInternalValue();
207 StringAppendF(out, ",\"tidelta\":%" PRId64, thread_instructions);
208 }
209 }
210
211 // Output tts if thread_timestamp is valid.
212 if (!thread_timestamp_.is_null()) {
213 int64_t thread_time_int64 = thread_timestamp_.ToInternalValue();
214 StringAppendF(out, ",\"tts\":%" PRId64, thread_time_int64);
215 }
216
217 // Output ticount if thread_instruction_count is valid.
218 if (!thread_instruction_count_.is_null()) {
219 int64_t thread_instructions = thread_instruction_count_.ToInternalValue();
220 StringAppendF(out, ",\"ticount\":%" PRId64, thread_instructions);
221 }
222
223 // Output async tts marker field if flag is set.
224 if (flags_ & TRACE_EVENT_FLAG_ASYNC_TTS) {
225 StringAppendF(out, ", \"use_async_tts\":1");
226 }
227
228 // If id_ is set, print it out as a hex string so we don't loose any
229 // bits (it might be a 64-bit pointer).
230 unsigned int id_flags_ = flags_ & (TRACE_EVENT_FLAG_HAS_ID |
231 TRACE_EVENT_FLAG_HAS_LOCAL_ID |
232 TRACE_EVENT_FLAG_HAS_GLOBAL_ID);
233 if (id_flags_) {
234 if (scope_ != trace_event_internal::kGlobalScope)
235 StringAppendF(out, ",\"scope\":\"%s\"", scope_);
236
237 switch (id_flags_) {
238 case TRACE_EVENT_FLAG_HAS_ID:
239 StringAppendF(out, ",\"id\":\"0x%" PRIx64 "\"",
240 static_cast<uint64_t>(id_));
241 break;
242
243 case TRACE_EVENT_FLAG_HAS_LOCAL_ID:
244 StringAppendF(out, ",\"id2\":{\"local\":\"0x%" PRIx64 "\"}",
245 static_cast<uint64_t>(id_));
246 break;
247
248 case TRACE_EVENT_FLAG_HAS_GLOBAL_ID:
249 StringAppendF(out, ",\"id2\":{\"global\":\"0x%" PRIx64 "\"}",
250 static_cast<uint64_t>(id_));
251 break;
252
253 default:
254 NOTREACHED() << "More than one of the ID flags are set";
255 break;
256 }
257 }
258
259 if (flags_ & TRACE_EVENT_FLAG_BIND_TO_ENCLOSING)
260 StringAppendF(out, ",\"bp\":\"e\"");
261
262 if ((flags_ & TRACE_EVENT_FLAG_FLOW_OUT) ||
263 (flags_ & TRACE_EVENT_FLAG_FLOW_IN)) {
264 StringAppendF(out, ",\"bind_id\":\"0x%" PRIx64 "\"",
265 static_cast<uint64_t>(bind_id_));
266 }
267 if (flags_ & TRACE_EVENT_FLAG_FLOW_IN)
268 StringAppendF(out, ",\"flow_in\":true");
269 if (flags_ & TRACE_EVENT_FLAG_FLOW_OUT)
270 StringAppendF(out, ",\"flow_out\":true");
271
272 // Instant events also output their scope.
273 if (phase_ == TRACE_EVENT_PHASE_INSTANT) {
274 char scope = '?';
275 switch (flags_ & TRACE_EVENT_FLAG_SCOPE_MASK) {
276 case TRACE_EVENT_SCOPE_GLOBAL:
277 scope = TRACE_EVENT_SCOPE_NAME_GLOBAL;
278 break;
279
280 case TRACE_EVENT_SCOPE_PROCESS:
281 scope = TRACE_EVENT_SCOPE_NAME_PROCESS;
282 break;
283
284 case TRACE_EVENT_SCOPE_THREAD:
285 scope = TRACE_EVENT_SCOPE_NAME_THREAD;
286 break;
287 }
288 StringAppendF(out, ",\"s\":\"%c\"", scope);
289 }
290
291 *out += "}";
292 }
293
AppendPrettyPrinted(std::ostringstream * out) const294 void TraceEvent::AppendPrettyPrinted(std::ostringstream* out) const {
295 *out << name_ << "[";
296 *out << TraceLog::GetCategoryGroupName(category_group_enabled_);
297 *out << "]";
298 if (arg_size() > 0 && arg_name(0)) {
299 *out << ", {";
300 for (size_t i = 0; i < arg_size() && arg_name(i); ++i) {
301 if (i > 0)
302 *out << ", ";
303 *out << arg_name(i) << ":";
304 std::string value_as_text;
305 arg_value(i).AppendAsJSON(arg_type(i), &value_as_text);
306 *out << value_as_text;
307 }
308 *out << "}";
309 }
310 }
311
312 } // namespace trace_event
313 } // namespace base
314