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