xref: /aosp_15_r20/external/perfetto/src/trace_processor/importers/json/json_trace_parser_impl.cc (revision 6dbdd20afdafa5e3ca9b8809fa73465d530080dc) 
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/logging.h"
26 #include "perfetto/base/status.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/legacy_v8_cpu_profile_tracker.h"
33 #include "src/trace_processor/importers/common/parser_types.h"
34 #include "src/trace_processor/importers/common/process_tracker.h"
35 #include "src/trace_processor/importers/common/slice_tracker.h"
36 #include "src/trace_processor/importers/common/track_tracker.h"
37 #include "src/trace_processor/importers/common/tracks.h"
38 #include "src/trace_processor/importers/common/tracks_common.h"
39 #include "src/trace_processor/importers/common/tracks_internal.h"
40 #include "src/trace_processor/importers/json/json_utils.h"
41 #include "src/trace_processor/importers/systrace/systrace_line.h"
42 #include "src/trace_processor/storage/stats.h"
43 #include "src/trace_processor/storage/trace_storage.h"
44 #include "src/trace_processor/tables/slice_tables_py.h"
45 #include "src/trace_processor/types/trace_processor_context.h"
46 #include "src/trace_processor/types/variadic.h"
47 
48 namespace perfetto::trace_processor {
49 
50 namespace {
51 
MaybeExtractFlowIdentifier(const Json::Value & value,bool version2)52 std::optional<uint64_t> MaybeExtractFlowIdentifier(const Json::Value& value,
53                                                    bool version2) {
54   std::string id_key = (version2 ? "bind_id" : "id");
55   if (!value.isMember(id_key))
56     return std::nullopt;
57   const auto& id = value[id_key];
58   if (id.isNumeric())
59     return id.asUInt64();
60   if (!id.isString())
61     return std::nullopt;
62   const char* c_string = id.asCString();
63   return base::CStringToUInt64(c_string, 16);
64 }
65 
66 }  // namespace
67 
JsonTraceParserImpl(TraceProcessorContext * context)68 JsonTraceParserImpl::JsonTraceParserImpl(TraceProcessorContext* context)
69     : context_(context), systrace_line_parser_(context) {}
70 
71 JsonTraceParserImpl::~JsonTraceParserImpl() = default;
72 
ParseSystraceLine(int64_t,SystraceLine line)73 void JsonTraceParserImpl::ParseSystraceLine(int64_t, SystraceLine line) {
74   systrace_line_parser_.ParseLine(line);
75 }
76 
ParseJsonPacket(int64_t timestamp,std::string string_value)77 void JsonTraceParserImpl::ParseJsonPacket(int64_t timestamp,
78                                           std::string string_value) {
79   PERFETTO_DCHECK(json::IsJsonSupported());
80 
81   auto opt_value = json::ParseJsonString(base::StringView(string_value));
82   if (!opt_value) {
83     context_->storage->IncrementStats(stats::json_parser_failure);
84     return;
85   }
86 
87   ProcessTracker* procs = context_->process_tracker.get();
88   TraceStorage* storage = context_->storage.get();
89   SliceTracker* slice_tracker = context_->slice_tracker.get();
90   FlowTracker* flow_tracker = context_->flow_tracker.get();
91 
92   const Json::Value& value = *opt_value;
93   const auto& ph = value["ph"];
94   if (!ph.isString())
95     return;
96   char phase = *ph.asCString();
97 
98   std::optional<uint32_t> opt_pid;
99   if (value.isMember("pid")) {
100     if (value["pid"].isString()) {
101       // If the pid is a string, treat raw id of the interned string as the pid.
102       // This "hack" which allows emitting "quick-and-dirty" compact JSON
103       // traces: relying on these traces for production is necessarily brittle
104       // as it is not a part of the actual spec.
105       const char* proc_name = value["pid"].asCString();
106       opt_pid = storage->InternString(proc_name).raw_id();
107       procs->SetProcessMetadata(*opt_pid, std::nullopt, proc_name,
108                                 base::StringView());
109     } else {
110       opt_pid = json::CoerceToUint32(value["pid"]);
111     }
112   }
113 
114   std::optional<uint32_t> opt_tid;
115   if (value.isMember("tid")) {
116     if (value["tid"].isString()) {
117       // See the comment for |pid| string handling above: the same applies here.
118       StringId thread_name_id = storage->InternString(value["tid"].asCString());
119       opt_tid = thread_name_id.raw_id();
120       procs->UpdateThreadName(*opt_tid, thread_name_id,
121                               ThreadNamePriority::kOther);
122     } else {
123       opt_tid = json::CoerceToUint32(value["tid"]);
124     }
125   }
126 
127   uint32_t pid = opt_pid.value_or(0);
128   uint32_t tid = opt_tid.value_or(pid);
129   UniqueTid utid = procs->UpdateThread(tid, pid);
130 
131   std::string id = value.isMember("id") ? value["id"].asString() : "";
132 
133   base::StringView cat = value.isMember("cat") && value["cat"].isString()
134                              ? base::StringView(value["cat"].asCString())
135                              : base::StringView();
136   StringId cat_id = storage->InternString(cat);
137 
138   base::StringView name = value.isMember("name")
139                               ? base::StringView(value["name"].asCString())
140                               : base::StringView();
141   StringId name_id = name.empty() ? kNullStringId : storage->InternString(name);
142 
143   auto args_inserter = [this, &value](ArgsTracker::BoundInserter* inserter) {
144     if (value.isMember("args")) {
145       json::AddJsonValueToArgs(value["args"], /* flat_key = */ "args",
146                                /* key = */ "args", context_->storage.get(),
147                                inserter);
148     }
149   };
150 
151   // Only used for 'B', 'E', and 'X' events so wrap in lambda so it gets
152   // ignored in other cases. This lambda is only safe to call within the
153   // scope of this function due to the capture by reference.
154   auto make_slice_row = [&](TrackId track_id) {
155     tables::SliceTable::Row row;
156     row.ts = timestamp;
157     row.track_id = track_id;
158     row.category = cat_id;
159     row.name =
160         name_id == kNullStringId ? storage->InternString("[No name]") : name_id;
161     row.thread_ts = json::CoerceToTs(value["tts"]);
162     // tdur will only exist on 'X' events.
163     row.thread_dur = json::CoerceToTs(value["tdur"]);
164     // JSON traces don't report these counters as part of slices.
165     row.thread_instruction_count = std::nullopt;
166     row.thread_instruction_delta = std::nullopt;
167     return row;
168   };
169 
170   switch (phase) {
171     case 'B': {  // TRACE_EVENT_BEGIN.
172       TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
173       slice_tracker->BeginTyped(storage->mutable_slice_table(),
174                                 make_slice_row(track_id), args_inserter);
175       MaybeAddFlow(track_id, value);
176       break;
177     }
178     case 'E': {  // TRACE_EVENT_END.
179       TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
180       auto opt_slice_id = slice_tracker->End(timestamp, track_id, cat_id,
181                                              name_id, args_inserter);
182       // Now try to update thread_dur if we have a tts field.
183       auto opt_tts = json::CoerceToTs(value["tts"]);
184       if (opt_slice_id.has_value() && opt_tts) {
185         auto* slice = storage->mutable_slice_table();
186         auto rr = *slice->FindById(*opt_slice_id);
187         if (auto start_tts = rr.thread_ts(); start_tts) {
188           rr.set_thread_dur(*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->LegacyInternLegacyChromeAsyncTrack(
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->LegacyInternLegacyChromeAsyncTrack(
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 nid = context_->storage->InternString(counter_name);
278         context_->event_tracker->PushProcessCounterForThread(
279             EventTracker::JsonCounter{nid}, timestamp, counter, utid);
280       }
281       break;
282     }
283     case 'R':
284     case 'I':
285     case 'i': {  // TRACE_EVENT_INSTANT
286       base::StringView scope;
287       if (value.isMember("s")) {
288         scope = value["s"].asCString();
289       }
290 
291       TrackId track_id;
292       if (scope == "g") {
293         track_id = context_->track_tracker->InternTrack(
294             tracks::kLegacyGlobalInstantsBlueprint, tracks::Dimensions(),
295             tracks::BlueprintName(),
296             [this](ArgsTracker::BoundInserter& inserter) {
297               inserter.AddArg(
298                   context_->storage->InternString("source"),
299                   Variadic::String(context_->storage->InternString("chrome")));
300             });
301       } else if (scope == "p") {
302         if (!opt_pid) {
303           context_->storage->IncrementStats(stats::json_parser_failure);
304           break;
305         }
306         UniquePid upid = context_->process_tracker->GetOrCreateProcess(pid);
307         track_id = context_->track_tracker->InternProcessTrack(
308             tracks::chrome_process_instant, upid);
309         context_->args_tracker->AddArgsTo(track_id).AddArg(
310             context_->storage->InternString("source"),
311             Variadic::String(context_->storage->InternString("chrome")));
312       } else if (scope == "t" || scope.data() == nullptr) {
313         if (!opt_tid) {
314           context_->storage->IncrementStats(stats::json_parser_failure);
315           break;
316         }
317         track_id = context_->track_tracker->InternThreadTrack(utid);
318         auto row = make_slice_row(track_id);
319         row.dur = 0;
320         if (row.thread_ts) {
321           // Only set thread_dur to zero if we have a thread_ts.
322           row.thread_dur = 0;
323         }
324         slice_tracker->ScopedTyped(storage->mutable_slice_table(),
325                                    std::move(row), args_inserter);
326         break;
327       } else {
328         context_->storage->IncrementStats(stats::json_parser_failure);
329         break;
330       }
331       context_->slice_tracker->Scoped(timestamp, track_id, cat_id, name_id, 0,
332                                       args_inserter);
333       break;
334     }
335     case 's': {  // TRACE_EVENT_FLOW_START
336       TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
337       auto opt_source_id =
338           MaybeExtractFlowIdentifier(value, /* version2 = */ false);
339       if (opt_source_id) {
340         FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
341             opt_source_id.value(), cat_id, name_id);
342         flow_tracker->Begin(track_id, flow_id);
343       } else {
344         context_->storage->IncrementStats(stats::flow_invalid_id);
345       }
346       break;
347     }
348     case 't': {  // TRACE_EVENT_FLOW_STEP
349       TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
350       auto opt_source_id =
351           MaybeExtractFlowIdentifier(value, /* version2 = */ false);
352       if (opt_source_id) {
353         FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
354             opt_source_id.value(), cat_id, name_id);
355         flow_tracker->Step(track_id, flow_id);
356       } else {
357         context_->storage->IncrementStats(stats::flow_invalid_id);
358       }
359       break;
360     }
361     case 'f': {  // TRACE_EVENT_FLOW_END
362       TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
363       auto opt_source_id =
364           MaybeExtractFlowIdentifier(value, /* version2 = */ false);
365       if (opt_source_id) {
366         FlowId flow_id = flow_tracker->GetFlowIdForV1Event(
367             opt_source_id.value(), cat_id, name_id);
368         bool bind_enclosing_slice =
369             value.isMember("bp") && strcmp(value["bp"].asCString(), "e") == 0;
370         flow_tracker->End(track_id, flow_id, bind_enclosing_slice,
371                           /* close_flow = */ false);
372       } else {
373         context_->storage->IncrementStats(stats::flow_invalid_id);
374       }
375       break;
376     }
377     case 'M': {  // Metadata events (process and thread names).
378       if (name == "thread_name" && !value["args"]["name"].empty()) {
379         const char* thread_name = value["args"]["name"].asCString();
380         auto thread_name_id = context_->storage->InternString(thread_name);
381         procs->UpdateThreadName(tid, thread_name_id,
382                                 ThreadNamePriority::kOther);
383         break;
384       }
385       if (name == "process_name" && !value["args"]["name"].empty()) {
386         const char* proc_name = value["args"]["name"].asCString();
387         procs->SetProcessMetadata(pid, std::nullopt, proc_name,
388                                   base::StringView());
389         break;
390       }
391     }
392   }
393 }
394 
MaybeAddFlow(TrackId track_id,const Json::Value & event)395 void JsonTraceParserImpl::MaybeAddFlow(TrackId track_id,
396                                        const Json::Value& event) {
397   PERFETTO_DCHECK(json::IsJsonSupported());
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 }
416 
ParseLegacyV8ProfileEvent(int64_t ts,LegacyV8CpuProfileEvent event)417 void JsonTraceParserImpl::ParseLegacyV8ProfileEvent(
418     int64_t ts,
419     LegacyV8CpuProfileEvent event) {
420   base::Status status = context_->legacy_v8_cpu_profile_tracker->AddSample(
421       ts, event.session_id, event.pid, event.tid, event.callsite_id);
422   if (!status.ok()) {
423     context_->storage->IncrementStats(
424         stats::legacy_v8_cpu_profile_invalid_sample);
425   }
426   context_->args_tracker->Flush();
427 }
428 
429 }  // namespace perfetto::trace_processor
430