• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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