1 /*
2 * Copyright (C) 2018 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #include "src/trace_processor/importers/json/json_trace_parser.h"
18
19 #include <cinttypes>
20 #include <limits>
21 #include <optional>
22 #include <string>
23
24 #include "perfetto/base/logging.h"
25 #include "perfetto/ext/base/string_utils.h"
26 #include "perfetto/ext/base/string_view.h"
27 #include "src/trace_processor/importers/common/event_tracker.h"
28 #include "src/trace_processor/importers/common/flow_tracker.h"
29 #include "src/trace_processor/importers/common/process_tracker.h"
30 #include "src/trace_processor/importers/common/slice_tracker.h"
31 #include "src/trace_processor/importers/common/track_tracker.h"
32 #include "src/trace_processor/importers/json/json_utils.h"
33 #include "src/trace_processor/storage/trace_storage.h"
34 #include "src/trace_processor/types/trace_processor_context.h"
35
36 namespace perfetto {
37 namespace trace_processor {
38
39 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
40 namespace {
41
MaybeExtractFlowIdentifier(const Json::Value & value,bool version2)42 std::optional<uint64_t> MaybeExtractFlowIdentifier(const Json::Value& value,
43 bool version2) {
44 std::string id_key = (version2 ? "bind_id" : "id");
45 if (!value.isMember(id_key))
46 return std::nullopt;
47 auto id = value[id_key];
48 if (id.isNumeric())
49 return id.asUInt64();
50 if (!id.isString())
51 return std::nullopt;
52 const char* c_string = id.asCString();
53 return base::CStringToUInt64(c_string, 16);
54 }
55
56 } // namespace
57 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
58
JsonTraceParser(TraceProcessorContext * context)59 JsonTraceParser::JsonTraceParser(TraceProcessorContext* context)
60 : context_(context), systrace_line_parser_(context) {}
61
62 JsonTraceParser::~JsonTraceParser() = default;
63
ParseSystraceLine(int64_t,SystraceLine line)64 void JsonTraceParser::ParseSystraceLine(int64_t, SystraceLine line) {
65 systrace_line_parser_.ParseLine(line);
66 }
67
ParseJsonPacket(int64_t timestamp,std::string string_value)68 void JsonTraceParser::ParseJsonPacket(int64_t timestamp,
69 std::string string_value) {
70 PERFETTO_DCHECK(json::IsJsonSupported());
71
72 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
73 auto opt_value = json::ParseJsonString(base::StringView(string_value));
74 if (!opt_value) {
75 context_->storage->IncrementStats(stats::json_parser_failure);
76 return;
77 }
78
79 ProcessTracker* procs = context_->process_tracker.get();
80 TraceStorage* storage = context_->storage.get();
81 SliceTracker* slice_tracker = context_->slice_tracker.get();
82 FlowTracker* flow_tracker = context_->flow_tracker.get();
83
84 const Json::Value& value = *opt_value;
85 auto& ph = value["ph"];
86 if (!ph.isString())
87 return;
88 char phase = *ph.asCString();
89
90 std::optional<uint32_t> opt_pid;
91 std::optional<uint32_t> opt_tid;
92
93 if (value.isMember("pid"))
94 opt_pid = json::CoerceToUint32(value["pid"]);
95 if (value.isMember("tid"))
96 opt_tid = json::CoerceToUint32(value["tid"]);
97
98 uint32_t pid = opt_pid.value_or(0);
99 uint32_t tid = opt_tid.value_or(pid);
100 UniqueTid utid = procs->UpdateThread(tid, pid);
101
102 std::string id = value.isMember("id") ? value["id"].asString() : "";
103
104 base::StringView cat = value.isMember("cat")
105 ? base::StringView(value["cat"].asCString())
106 : base::StringView();
107 StringId cat_id = storage->InternString(cat);
108
109 base::StringView name = value.isMember("name")
110 ? base::StringView(value["name"].asCString())
111 : base::StringView();
112 StringId name_id = name.empty() ? kNullStringId : storage->InternString(name);
113
114 auto args_inserter = [this, &value](ArgsTracker::BoundInserter* inserter) {
115 if (value.isMember("args")) {
116 json::AddJsonValueToArgs(value["args"], /* flat_key = */ "args",
117 /* key = */ "args", context_->storage.get(),
118 inserter);
119 }
120 };
121
122 // Only used for 'B', 'E', and 'X' events so wrap in lambda so it gets
123 // ignored in other cases. This lambda is only safe to call within the
124 // scope of this function due to the capture by reference.
125 auto make_slice_row = [&](TrackId track_id) {
126 tables::SliceTable::Row row;
127 row.ts = timestamp;
128 row.track_id = track_id;
129 row.category = cat_id;
130 row.name = name_id;
131 row.thread_ts = json::CoerceToTs(value["tts"]);
132 // tdur will only exist on 'X' events.
133 row.thread_dur = json::CoerceToTs(value["tdur"]);
134 // JSON traces don't report these counters as part of slices.
135 row.thread_instruction_count = std::nullopt;
136 row.thread_instruction_delta = std::nullopt;
137 return row;
138 };
139
140 switch (phase) {
141 case 'B': { // TRACE_EVENT_BEGIN.
142 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
143 slice_tracker->BeginTyped(storage->mutable_slice_table(),
144 make_slice_row(track_id), args_inserter);
145 MaybeAddFlow(track_id, value);
146 break;
147 }
148 case 'E': { // TRACE_EVENT_END.
149 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
150 auto opt_slice_id = slice_tracker->End(timestamp, track_id, cat_id,
151 name_id, args_inserter);
152 // Now try to update thread_dur if we have a tts field.
153 auto opt_tts = json::CoerceToTs(value["tts"]);
154 if (opt_slice_id.has_value() && opt_tts) {
155 auto* slice = storage->mutable_slice_table();
156 auto maybe_row = slice->id().IndexOf(*opt_slice_id);
157 PERFETTO_DCHECK(maybe_row.has_value());
158 auto start_tts = slice->thread_ts()[*maybe_row];
159 if (start_tts) {
160 slice->mutable_thread_dur()->Set(*maybe_row, *opt_tts - *start_tts);
161 }
162 }
163 break;
164 }
165 case 'b':
166 case 'e':
167 case 'n': {
168 if (!opt_pid || id.empty()) {
169 context_->storage->IncrementStats(stats::json_parser_failure);
170 break;
171 }
172 UniquePid upid = context_->process_tracker->GetOrCreateProcess(pid);
173 int64_t cookie = static_cast<int64_t>(base::Hasher::Combine(id.c_str()));
174 StringId scope = kNullStringId;
175 TrackId track_id = context_->track_tracker->InternLegacyChromeAsyncTrack(
176 name_id, upid, cookie, true /* source_id_is_process_scoped */, scope);
177
178 if (phase == 'b') {
179 slice_tracker->BeginTyped(storage->mutable_slice_table(),
180 make_slice_row(track_id), args_inserter);
181 MaybeAddFlow(track_id, value);
182 } else if (phase == 'e') {
183 slice_tracker->End(timestamp, track_id, cat_id, name_id, args_inserter);
184 // We don't handle tts here as we do in the 'E'
185 // case above as it's not well defined for aysnc slices.
186 } else {
187 context_->slice_tracker->Scoped(timestamp, track_id, cat_id, name_id,
188 0);
189 MaybeAddFlow(track_id, value);
190 }
191 break;
192 }
193 case 'X': { // TRACE_EVENT (scoped event).
194 std::optional<int64_t> opt_dur = json::CoerceToTs(value["dur"]);
195 if (!opt_dur.has_value())
196 return;
197 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
198 auto row = make_slice_row(track_id);
199 row.dur = opt_dur.value();
200 slice_tracker->ScopedTyped(storage->mutable_slice_table(), std::move(row),
201 args_inserter);
202 MaybeAddFlow(track_id, value);
203 break;
204 }
205 case 'C': { // TRACE_EVENT_COUNTER
206 auto args = value["args"];
207 if (!args.isObject()) {
208 context_->storage->IncrementStats(stats::json_parser_failure);
209 break;
210 }
211
212 std::string counter_name_prefix = name.ToStdString();
213 if (!id.empty()) {
214 counter_name_prefix += " id: " + id;
215 }
216
217 for (auto it = args.begin(); it != args.end(); ++it) {
218 double counter;
219 if (it->isString()) {
220 auto opt = base::CStringToDouble(it->asCString());
221 if (!opt.has_value()) {
222 context_->storage->IncrementStats(stats::json_parser_failure);
223 continue;
224 }
225 counter = opt.value();
226 } else if (it->isNumeric()) {
227 counter = it->asDouble();
228 } else {
229 context_->storage->IncrementStats(stats::json_parser_failure);
230 continue;
231 }
232 std::string counter_name = counter_name_prefix + " " + it.name();
233 StringId counter_name_id =
234 context_->storage->InternString(base::StringView(counter_name));
235 context_->event_tracker->PushProcessCounterForThread(
236 timestamp, counter, counter_name_id, utid);
237 }
238 break;
239 }
240 case 'R':
241 case 'I':
242 case 'i': { // TRACE_EVENT_INSTANT
243 base::StringView scope;
244 if (value.isMember("s")) {
245 scope = value["s"].asCString();
246 }
247
248 TrackId track_id;
249 if (scope == "g") {
250 track_id = context_->track_tracker
251 ->GetOrCreateLegacyChromeGlobalInstantTrack();
252 } else if (scope == "p") {
253 if (!opt_pid) {
254 context_->storage->IncrementStats(stats::json_parser_failure);
255 break;
256 }
257 UniquePid upid = context_->process_tracker->GetOrCreateProcess(pid);
258 track_id =
259 context_->track_tracker->InternLegacyChromeProcessInstantTrack(
260 upid);
261 } else if (scope == "t" || scope.data() == nullptr) {
262 if (!opt_tid) {
263 context_->storage->IncrementStats(stats::json_parser_failure);
264 break;
265 }
266 track_id = context_->track_tracker->InternThreadTrack(utid);
267 auto row = make_slice_row(track_id);
268 row.dur = 0;
269 if (row.thread_ts) {
270 // Only set thread_dur to zero if we have a thread_ts.
271 row.thread_dur = 0;
272 }
273 slice_tracker->ScopedTyped(storage->mutable_slice_table(),
274 std::move(row), args_inserter);
275 break;
276 } else {
277 context_->storage->IncrementStats(stats::json_parser_failure);
278 break;
279 }
280 context_->slice_tracker->Scoped(timestamp, track_id, cat_id, name_id, 0,
281 args_inserter);
282 break;
283 }
284 case 's': { // TRACE_EVENT_FLOW_START
285 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
286 auto opt_source_id =
287 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
288 if (opt_source_id) {
289 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
290 opt_source_id.value(), cat_id, name_id);
291 flow_tracker->Begin(track_id, flow_id);
292 } else {
293 context_->storage->IncrementStats(stats::flow_invalid_id);
294 }
295 break;
296 }
297 case 't': { // TRACE_EVENT_FLOW_STEP
298 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
299 auto opt_source_id =
300 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
301 if (opt_source_id) {
302 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
303 opt_source_id.value(), cat_id, name_id);
304 flow_tracker->Step(track_id, flow_id);
305 } else {
306 context_->storage->IncrementStats(stats::flow_invalid_id);
307 }
308 break;
309 }
310 case 'f': { // TRACE_EVENT_FLOW_END
311 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
312 auto opt_source_id =
313 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
314 if (opt_source_id) {
315 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
316 opt_source_id.value(), cat_id, name_id);
317 bool bind_enclosing_slice =
318 value.isMember("bp") && strcmp(value["bp"].asCString(), "e") == 0;
319 flow_tracker->End(track_id, flow_id, bind_enclosing_slice,
320 /* close_flow = */ false);
321 } else {
322 context_->storage->IncrementStats(stats::flow_invalid_id);
323 }
324 break;
325 }
326 case 'M': { // Metadata events (process and thread names).
327 if (name == "thread_name" && !value["args"]["name"].empty()) {
328 const char* thread_name = value["args"]["name"].asCString();
329 auto thread_name_id = context_->storage->InternString(thread_name);
330 procs->UpdateThreadName(tid, thread_name_id,
331 ThreadNamePriority::kOther);
332 break;
333 }
334 if (name == "process_name" && !value["args"]["name"].empty()) {
335 const char* proc_name = value["args"]["name"].asCString();
336 procs->SetProcessMetadata(pid, std::nullopt, proc_name,
337 base::StringView());
338 break;
339 }
340 }
341 }
342 #else
343 perfetto::base::ignore_result(timestamp);
344 perfetto::base::ignore_result(context_);
345 perfetto::base::ignore_result(string_value);
346 PERFETTO_ELOG("Cannot parse JSON trace due to missing JSON support");
347 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
348 }
349
MaybeAddFlow(TrackId track_id,const Json::Value & event)350 void JsonTraceParser::MaybeAddFlow(TrackId track_id, const Json::Value& event) {
351 PERFETTO_DCHECK(json::IsJsonSupported());
352 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
353 auto opt_bind_id = MaybeExtractFlowIdentifier(event, /* version2 = */ true);
354 if (opt_bind_id) {
355 FlowTracker* flow_tracker = context_->flow_tracker.get();
356 bool flow_out = event.isMember("flow_out") && event["flow_out"].asBool();
357 bool flow_in = event.isMember("flow_in") && event["flow_in"].asBool();
358 if (flow_in && flow_out) {
359 flow_tracker->Step(track_id, opt_bind_id.value());
360 } else if (flow_out) {
361 flow_tracker->Begin(track_id, opt_bind_id.value());
362 } else if (flow_in) {
363 // bind_enclosing_slice is always true for v2 flow events
364 flow_tracker->End(track_id, opt_bind_id.value(), true,
365 /* close_flow = */ false);
366 } else {
367 context_->storage->IncrementStats(stats::flow_without_direction);
368 }
369 }
370 #else
371 perfetto::base::ignore_result(track_id);
372 perfetto::base::ignore_result(event);
373 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
374 }
375
376 } // namespace trace_processor
377 } // namespace perfetto
378