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 <string>
22
23 #include "perfetto/base/logging.h"
24 #include "perfetto/ext/base/optional.h"
25 #include "perfetto/ext/base/string_utils.h"
26 #include "perfetto/ext/base/string_view.h"
27 #include "perfetto/ext/base/utils.h"
28 #include "src/trace_processor/importers/common/event_tracker.h"
29 #include "src/trace_processor/importers/common/flow_tracker.h"
30 #include "src/trace_processor/importers/common/process_tracker.h"
31 #include "src/trace_processor/importers/common/slice_tracker.h"
32 #include "src/trace_processor/importers/common/track_tracker.h"
33 #include "src/trace_processor/importers/json/json_utils.h"
34 #include "src/trace_processor/tables/slice_tables.h"
35 #include "src/trace_processor/types/trace_processor_context.h"
36
37 namespace perfetto {
38 namespace trace_processor {
39
40 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
41 namespace {
42
MaybeExtractFlowIdentifier(const Json::Value & value,bool version2)43 base::Optional<uint64_t> MaybeExtractFlowIdentifier(const Json::Value& value,
44 bool version2) {
45 std::string id_key = (version2 ? "bind_id" : "id");
46 if (!value.isMember(id_key))
47 return base::nullopt;
48 auto id = value[id_key];
49 if (id.isNumeric())
50 return id.asUInt64();
51 if (!id.isString())
52 return base::nullopt;
53 const char* c_string = id.asCString();
54 return base::CStringToUInt64(c_string, 16);
55 }
56
57 } // namespace
58 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
59
JsonTraceParser(TraceProcessorContext * context)60 JsonTraceParser::JsonTraceParser(TraceProcessorContext* context)
61 : context_(context), systrace_line_parser_(context) {}
62
63 JsonTraceParser::~JsonTraceParser() = default;
64
ParseFtracePacket(uint32_t,int64_t,TimestampedTracePiece)65 void JsonTraceParser::ParseFtracePacket(uint32_t,
66 int64_t,
67 TimestampedTracePiece) {
68 PERFETTO_FATAL("Json Trace Parser cannot handle ftrace packets.");
69 }
70
ParseTracePacket(int64_t timestamp,TimestampedTracePiece ttp)71 void JsonTraceParser::ParseTracePacket(int64_t timestamp,
72 TimestampedTracePiece ttp) {
73 PERFETTO_DCHECK(json::IsJsonSupported());
74
75 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
76 PERFETTO_DCHECK(ttp.type == TimestampedTracePiece::Type::kJsonValue ||
77 ttp.type == TimestampedTracePiece::Type::kSystraceLine);
78 if (ttp.type == TimestampedTracePiece::Type::kSystraceLine) {
79 systrace_line_parser_.ParseLine(*ttp.systrace_line);
80 return;
81 }
82
83 auto opt_value = json::ParseJsonString(base::StringView(ttp.json_value));
84 if (!opt_value) {
85 context_->storage->IncrementStats(stats::json_parser_failure);
86 return;
87 }
88
89 ProcessTracker* procs = context_->process_tracker.get();
90 TraceStorage* storage = context_->storage.get();
91 SliceTracker* slice_tracker = context_->slice_tracker.get();
92 FlowTracker* flow_tracker = context_->flow_tracker.get();
93
94 const Json::Value& value = *opt_value;
95 auto& ph = value["ph"];
96 if (!ph.isString())
97 return;
98 char phase = *ph.asCString();
99
100 base::Optional<uint32_t> opt_pid;
101 base::Optional<uint32_t> opt_tid;
102
103 if (value.isMember("pid"))
104 opt_pid = json::CoerceToUint32(value["pid"]);
105 if (value.isMember("tid"))
106 opt_tid = json::CoerceToUint32(value["tid"]);
107
108 uint32_t pid = opt_pid.value_or(0);
109 uint32_t tid = opt_tid.value_or(pid);
110
111 base::StringView cat = value.isMember("cat")
112 ? base::StringView(value["cat"].asCString())
113 : base::StringView();
114 base::StringView name = value.isMember("name")
115 ? base::StringView(value["name"].asCString())
116 : base::StringView();
117
118 StringId cat_id = storage->InternString(cat);
119 StringId name_id = storage->InternString(name);
120 UniqueTid utid = procs->UpdateThread(tid, pid);
121
122 auto args_inserter = [this, &value](ArgsTracker::BoundInserter* inserter) {
123 if (value.isMember("args")) {
124 json::AddJsonValueToArgs(value["args"], /* flat_key = */ "args",
125 /* key = */ "args", context_->storage.get(),
126 inserter);
127 }
128 };
129
130 // Only used for 'B', 'E', and 'X' events so wrap in lambda so it gets
131 // ignored in other cases. This lambda is only safe to call within the
132 // scope of this function due to the capture by reference.
133 auto make_thread_slice_row = [&](TrackId track_id) {
134 tables::ThreadSliceTable::Row row;
135 row.ts = timestamp;
136 row.track_id = track_id;
137 row.category = cat_id;
138 row.name = name_id;
139 row.thread_ts = json::CoerceToTs(value["tts"]);
140 // tdur will only exist on 'X' events.
141 row.thread_dur = json::CoerceToTs(value["tdur"]);
142 // JSON traces don't report these counters as part of slices.
143 row.thread_instruction_count = base::nullopt;
144 row.thread_instruction_delta = base::nullopt;
145 return row;
146 };
147
148 switch (phase) {
149 case 'B': { // TRACE_EVENT_BEGIN.
150 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
151 slice_tracker->BeginTyped(storage->mutable_thread_slice_table(),
152 make_thread_slice_row(track_id), args_inserter);
153 MaybeAddFlow(track_id, value);
154 break;
155 }
156 case 'E': { // TRACE_EVENT_END.
157 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
158 auto opt_slice_id = slice_tracker->End(timestamp, track_id, cat_id,
159 name_id, args_inserter);
160 // Now try to update thread_dur if we have a tts field.
161 auto opt_tts = json::CoerceToTs(value["tts"]);
162 if (opt_slice_id.has_value() && opt_tts) {
163 auto* thread_slice = storage->mutable_thread_slice_table();
164 auto maybe_row = thread_slice->id().IndexOf(*opt_slice_id);
165 PERFETTO_DCHECK(maybe_row.has_value());
166 auto start_tts = thread_slice->thread_ts()[*maybe_row];
167 if (start_tts) {
168 thread_slice->mutable_thread_dur()->Set(*maybe_row,
169 *opt_tts - *start_tts);
170 }
171 }
172 break;
173 }
174 case 'X': { // TRACE_EVENT (scoped event).
175 base::Optional<int64_t> opt_dur = json::CoerceToTs(value["dur"]);
176 if (!opt_dur.has_value())
177 return;
178 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
179 auto row = make_thread_slice_row(track_id);
180 row.dur = opt_dur.value();
181 slice_tracker->ScopedTyped(storage->mutable_thread_slice_table(),
182 std::move(row), args_inserter);
183 MaybeAddFlow(track_id, value);
184 break;
185 }
186 case 'C': { // TRACE_EVENT_COUNTER
187 auto args = value["args"];
188 if (!args.isObject()) {
189 context_->storage->IncrementStats(stats::json_parser_failure);
190 break;
191 }
192
193 std::string counter_name_prefix = name.ToStdString();
194 if (value.isMember("id")) {
195 counter_name_prefix += " id: " + value["id"].asString();
196 }
197
198 for (auto it = args.begin(); it != args.end(); ++it) {
199 double counter;
200 if (it->isString()) {
201 auto opt = base::CStringToDouble(it->asCString());
202 if (!opt.has_value()) {
203 context_->storage->IncrementStats(stats::json_parser_failure);
204 continue;
205 }
206 counter = opt.value();
207 } else if (it->isNumeric()) {
208 counter = it->asDouble();
209 } else {
210 context_->storage->IncrementStats(stats::json_parser_failure);
211 continue;
212 }
213 std::string counter_name = counter_name_prefix + " " + it.name();
214 StringId counter_name_id =
215 context_->storage->InternString(base::StringView(counter_name));
216 context_->event_tracker->PushProcessCounterForThread(
217 timestamp, counter, counter_name_id, utid);
218 }
219 break;
220 }
221 case 'i': { // TRACE_EVENT_INSTANT
222 base::StringView scope;
223 if (value.isMember("s")) {
224 scope = value["s"].asCString();
225 }
226
227 TrackId track_id;
228 if (scope == "g") {
229 track_id = context_->track_tracker
230 ->GetOrCreateLegacyChromeGlobalInstantTrack();
231 } else if (scope == "p") {
232 if (!opt_pid) {
233 context_->storage->IncrementStats(stats::json_parser_failure);
234 break;
235 }
236 UniquePid upid = context_->process_tracker->GetOrCreateProcess(pid);
237 track_id =
238 context_->track_tracker->InternLegacyChromeProcessInstantTrack(
239 upid);
240 } else if (scope == "t" || scope.data() == nullptr) {
241 if (!opt_tid) {
242 context_->storage->IncrementStats(stats::json_parser_failure);
243 break;
244 }
245 track_id = context_->track_tracker->InternThreadTrack(utid);
246 auto row = make_thread_slice_row(track_id);
247 row.dur = 0;
248 if (row.thread_ts) {
249 // Only set thread_dur to zero if we have a thread_ts.
250 row.thread_dur = 0;
251 }
252 slice_tracker->ScopedTyped(storage->mutable_thread_slice_table(),
253 std::move(row), args_inserter);
254 break;
255 } else {
256 context_->storage->IncrementStats(stats::json_parser_failure);
257 break;
258 }
259 context_->slice_tracker->Scoped(timestamp, track_id, cat_id, name_id, 0);
260 break;
261 }
262 case 's': { // TRACE_EVENT_FLOW_START
263 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
264 auto opt_source_id =
265 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
266 if (opt_source_id) {
267 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
268 opt_source_id.value(), cat_id, name_id);
269 flow_tracker->Begin(track_id, flow_id);
270 } else {
271 context_->storage->IncrementStats(stats::flow_invalid_id);
272 }
273 break;
274 }
275 case 't': { // TRACE_EVENT_FLOW_STEP
276 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
277 auto opt_source_id =
278 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
279 if (opt_source_id) {
280 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
281 opt_source_id.value(), cat_id, name_id);
282 flow_tracker->Step(track_id, flow_id);
283 } else {
284 context_->storage->IncrementStats(stats::flow_invalid_id);
285 }
286 break;
287 }
288 case 'f': { // TRACE_EVENT_FLOW_END
289 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
290 auto opt_source_id =
291 MaybeExtractFlowIdentifier(value, /* version2 = */ false);
292 if (opt_source_id) {
293 FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
294 opt_source_id.value(), cat_id, name_id);
295 bool bind_enclosing_slice =
296 value.isMember("bp") && strcmp(value["bp"].asCString(), "e") == 0;
297 flow_tracker->End(track_id, flow_id, bind_enclosing_slice,
298 /* close_flow = */ false);
299 } else {
300 context_->storage->IncrementStats(stats::flow_invalid_id);
301 }
302 break;
303 }
304 case 'M': { // Metadata events (process and thread names).
305 if (name == "thread_name" && !value["args"]["name"].empty()) {
306 const char* thread_name = value["args"]["name"].asCString();
307 auto thread_name_id = context_->storage->InternString(thread_name);
308 procs->UpdateThreadName(tid, thread_name_id,
309 ThreadNamePriority::kOther);
310 break;
311 }
312 if (name == "process_name" && !value["args"]["name"].empty()) {
313 const char* proc_name = value["args"]["name"].asCString();
314 procs->SetProcessMetadata(pid, base::nullopt, proc_name,
315 base::StringView());
316 break;
317 }
318 }
319 }
320 #else
321 perfetto::base::ignore_result(timestamp);
322 perfetto::base::ignore_result(ttp);
323 perfetto::base::ignore_result(context_);
324 PERFETTO_ELOG("Cannot parse JSON trace due to missing JSON support");
325 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
326 }
327
MaybeAddFlow(TrackId track_id,const Json::Value & event)328 void JsonTraceParser::MaybeAddFlow(TrackId track_id, const Json::Value& event) {
329 PERFETTO_DCHECK(json::IsJsonSupported());
330 #if PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
331 auto opt_bind_id = MaybeExtractFlowIdentifier(event, /* version2 = */ true);
332 if (opt_bind_id) {
333 FlowTracker* flow_tracker = context_->flow_tracker.get();
334 bool flow_out = event.isMember("flow_out") && event["flow_out"].asBool();
335 bool flow_in = event.isMember("flow_in") && event["flow_in"].asBool();
336 if (flow_in && flow_out) {
337 flow_tracker->Step(track_id, opt_bind_id.value());
338 } else if (flow_out) {
339 flow_tracker->Begin(track_id, opt_bind_id.value());
340 } else if (flow_in) {
341 // bind_enclosing_slice is always true for v2 flow events
342 flow_tracker->End(track_id, opt_bind_id.value(), true,
343 /* close_flow = */ false);
344 } else {
345 context_->storage->IncrementStats(stats::flow_without_direction);
346 }
347 }
348 #endif // PERFETTO_BUILDFLAG(PERFETTO_TP_JSON)
349 }
350
351 } // namespace trace_processor
352 } // namespace perfetto
353