blob: 8b93efd8a65fa4c23e20b47f40cfa7bfa98097ae [file] [log] [blame]
Eric Seckler771960c2019-10-22 15:37:12 +01001/*
2 * Copyright (C) 2019 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/proto/track_event_parser.h"
18
Andrew Shulaev46b12a92020-07-09 00:45:37 +010019#include <iostream>
Eric Seckler771960c2019-10-22 15:37:12 +010020#include <string>
21
22#include "perfetto/base/logging.h"
Stephen Nuskof848d462021-04-06 13:28:04 +010023#include "perfetto/ext/base/optional.h"
Raymond Chiub2463992020-02-25 16:23:20 -080024#include "perfetto/ext/base/string_writer.h"
Eric Seckler926b3372020-03-06 16:17:53 +000025#include "perfetto/trace_processor/status.h"
Lalit Maganti617deae2020-04-14 21:00:49 +010026#include "src/trace_processor/importers/common/args_tracker.h"
Lalit Magantid5c45f42020-04-14 21:01:50 +010027#include "src/trace_processor/importers/common/event_tracker.h"
Andrii703edd32020-08-07 13:57:56 +030028#include "src/trace_processor/importers/common/flow_tracker.h"
Lalit Maganti617deae2020-04-14 21:00:49 +010029#include "src/trace_processor/importers/common/process_tracker.h"
30#include "src/trace_processor/importers/common/track_tracker.h"
Lalit Maganti0bfeb972020-03-14 03:57:30 +000031#include "src/trace_processor/importers/json/json_utils.h"
Eric Seckler771960c2019-10-22 15:37:12 +010032#include "src/trace_processor/importers/proto/packet_sequence_state.h"
Lalit Maganti62b741f2020-12-10 18:24:00 +000033#include "src/trace_processor/importers/proto/track_event_tracker.h"
Alexander Timin97d87852021-05-17 18:01:33 +000034#include "src/trace_processor/util/debug_annotation_parser.h"
Alexander Timin5a99b5c2021-05-11 22:48:07 +000035#include "src/trace_processor/util/proto_to_args_parser.h"
Lalit Maganti3d9bbff2020-04-15 13:40:58 +010036#include "src/trace_processor/util/status_macros.h"
Eric Seckler771960c2019-10-22 15:37:12 +010037
Alexander Timin5a99b5c2021-05-11 22:48:07 +000038#include "protos/perfetto/trace/extension_descriptor.pbzero.h"
Eric Seckler771960c2019-10-22 15:37:12 +010039#include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
Stephen Nuskobc76a6c2019-12-03 11:55:27 +000040#include "protos/perfetto/trace/track_event/chrome_compositor_scheduler_state.pbzero.h"
nuwandab14efd32020-09-28 11:19:40 +000041#include "protos/perfetto/trace/track_event/chrome_histogram_sample.pbzero.h"
Eric Secklere1e8ff42019-12-04 11:05:43 +000042#include "protos/perfetto/trace/track_event/chrome_legacy_ipc.pbzero.h"
Eric Seckler3183c6d2020-01-14 15:45:20 +000043#include "protos/perfetto/trace/track_event/chrome_process_descriptor.pbzero.h"
44#include "protos/perfetto/trace/track_event/chrome_thread_descriptor.pbzero.h"
Eric Secklerfbd9aed2020-03-10 18:07:38 +000045#include "protos/perfetto/trace/track_event/counter_descriptor.pbzero.h"
Eric Seckler771960c2019-10-22 15:37:12 +010046#include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
47#include "protos/perfetto/trace/track_event/log_message.pbzero.h"
Eric Seckler3183c6d2020-01-14 15:45:20 +000048#include "protos/perfetto/trace/track_event/process_descriptor.pbzero.h"
Eric Seckler771960c2019-10-22 15:37:12 +010049#include "protos/perfetto/trace/track_event/source_location.pbzero.h"
50#include "protos/perfetto/trace/track_event/task_execution.pbzero.h"
Eric Seckler3183c6d2020-01-14 15:45:20 +000051#include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
52#include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
Eric Secklerd2af9892019-11-01 10:10:53 +000053#include "protos/perfetto/trace/track_event/track_event.pbzero.h"
Eric Seckler771960c2019-10-22 15:37:12 +010054
55namespace perfetto {
56namespace trace_processor {
57
58namespace {
Eric Seckler926b3372020-03-06 16:17:53 +000059using BoundInserter = ArgsTracker::BoundInserter;
60using protos::pbzero::TrackEvent;
61using LegacyEvent = TrackEvent::LegacyEvent;
Eric Seckler771960c2019-10-22 15:37:12 +010062using protozero::ConstBytes;
63
64// Slices which have been opened but haven't been closed yet will be marked
65// with these placeholder values.
66constexpr int64_t kPendingThreadDuration = -1;
67constexpr int64_t kPendingThreadInstructionDelta = -1;
Stephen Nuskobc76a6c2019-12-03 11:55:27 +000068
Alexander Timin5a99b5c2021-05-11 22:48:07 +000069class TrackEventArgsParser : public util::ProtoToArgsParser::Delegate {
70 public:
71 TrackEventArgsParser(BoundInserter& inserter,
72 TraceStorage& storage,
73 PacketSequenceStateGeneration& sequence_state)
74 : inserter_(inserter),
75 storage_(storage),
76 sequence_state_(sequence_state) {}
77 ~TrackEventArgsParser() override;
Stephen Nuskobc76a6c2019-12-03 11:55:27 +000078
Alexander Timin5a99b5c2021-05-11 22:48:07 +000079 using Key = util::ProtoToArgsParser::Key;
80
81 void AddInteger(const Key& key, int64_t value) final {
82 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
83 storage_.InternString(base::StringView(key.key)),
84 Variadic::Integer(value));
85 }
86 void AddUnsignedInteger(const Key& key, uint64_t value) final {
87 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
88 storage_.InternString(base::StringView(key.key)),
89 Variadic::UnsignedInteger(value));
90 }
91 void AddString(const Key& key, const protozero::ConstChars& value) final {
92 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
93 storage_.InternString(base::StringView(key.key)),
94 Variadic::String(storage_.InternString(value)));
95 }
96 void AddDouble(const Key& key, double value) final {
97 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
98 storage_.InternString(base::StringView(key.key)),
99 Variadic::Real(value));
100 }
101 void AddPointer(const Key& key, const void* value) final {
102 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
103 storage_.InternString(base::StringView(key.key)),
104 Variadic::Pointer(reinterpret_cast<uintptr_t>(value)));
105 }
106 void AddBoolean(const Key& key, bool value) final {
107 inserter_.AddArg(storage_.InternString(base::StringView(key.flat_key)),
108 storage_.InternString(base::StringView(key.key)),
109 Variadic::Boolean(value));
110 }
Alexander Timin97d87852021-05-17 18:01:33 +0000111 bool AddJson(const Key& key, const protozero::ConstChars& value) final {
112 auto json_value = json::ParseJsonString(value);
113 return json::AddJsonValueToArgs(*json_value, base::StringView(key.flat_key),
114 base::StringView(key.key), &storage_,
115 &inserter_);
116 }
117
118 size_t GetArrayEntryIndex(const std::string& array_key) final {
119 return inserter_.GetNextArrayEntryIndex(
120 storage_.InternString(base::StringView(array_key)));
121 }
122
123 size_t IncrementArrayEntryIndex(const std::string& array_key) final {
124 return inserter_.IncrementArrayEntryIndex(
125 storage_.InternString(base::StringView(array_key)));
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000126 }
127
Alexander Timin99653b12021-05-11 22:50:00 +0000128 InternedMessageView* GetInternedMessageView(uint32_t field_id,
129 uint64_t iid) final {
130 return sequence_state_.GetInternedMessageView(field_id, iid);
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000131 }
132
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000133 private:
134 BoundInserter& inserter_;
135 TraceStorage& storage_;
136 PacketSequenceStateGeneration& sequence_state_;
137};
138
139TrackEventArgsParser::~TrackEventArgsParser() = default;
140
141base::Optional<base::Status> MaybeParseSourceLocation(
Stephen Nuskobc76a6c2019-12-03 11:55:27 +0000142 std::string prefix,
Lalit Maganti7449dc82019-12-30 15:52:35 +0000143 const protozero::Field& field,
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000144 util::ProtoToArgsParser::Delegate& delegate) {
Alexander Timin99653b12021-05-11 22:50:00 +0000145 auto* decoder = delegate.GetInternedMessage(
146 protos::pbzero::InternedData::kSourceLocations, field.as_uint64());
Stephen Nuskobc76a6c2019-12-03 11:55:27 +0000147 if (!decoder) {
148 // Lookup failed fall back on default behaviour which will just put
149 // the source_location_iid into the args table.
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000150 return base::nullopt;
Stephen Nuskobc76a6c2019-12-03 11:55:27 +0000151 }
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000152
Alexander Timin99653b12021-05-11 22:50:00 +0000153 delegate.AddString(util::ProtoToArgsParser::Key(prefix + ".file_name"),
154 decoder->file_name());
155 delegate.AddString(util::ProtoToArgsParser::Key(prefix + ".function_name"),
156 decoder->function_name());
157 delegate.AddInteger(util::ProtoToArgsParser::Key(prefix + ".line_number"),
158 decoder->line_number());
Alexander Timin5a99b5c2021-05-11 22:48:07 +0000159
160 return base::OkStatus();
Stephen Nuskobc76a6c2019-12-03 11:55:27 +0000161}
Mikhail Khokhlovac134ed2020-01-07 14:35:49 +0000162
Eric Seckler771960c2019-10-22 15:37:12 +0100163} // namespace
164
Eric Seckler926b3372020-03-06 16:17:53 +0000165class TrackEventParser::EventImporter {
166 public:
167 EventImporter(TrackEventParser* parser,
168 int64_t ts,
169 TrackEventData* event_data,
170 ConstBytes blob)
171 : context_(parser->context_),
Lalit Maganti62b741f2020-12-10 18:24:00 +0000172 track_event_tracker_(parser->track_event_tracker_),
Eric Seckler926b3372020-03-06 16:17:53 +0000173 storage_(context_->storage.get()),
174 parser_(parser),
175 ts_(ts),
176 event_data_(event_data),
Lalit Maganti9a843112020-11-10 13:39:05 +0000177 sequence_state_(event_data->sequence_state.get()),
Eric Seckler926b3372020-03-06 16:17:53 +0000178 blob_(std::move(blob)),
179 event_(blob_),
180 legacy_event_(event_.legacy_event()),
Lalit Maganti9a843112020-11-10 13:39:05 +0000181 defaults_(event_data->sequence_state->GetTrackEventDefaults()) {}
Eric Seckler926b3372020-03-06 16:17:53 +0000182
183 util::Status Import() {
184 // TODO(eseckler): This legacy event field will eventually be replaced by
185 // fields in TrackEvent itself.
186 if (PERFETTO_UNLIKELY(!event_.type() && !legacy_event_.has_phase()))
187 return util::ErrStatus("TrackEvent without type or phase");
188
189 category_id_ = ParseTrackEventCategory();
190 name_id_ = ParseTrackEventName();
191
192 RETURN_IF_ERROR(ParseTrackAssociation());
193
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000194 // Counter-type events don't support arguments (those are on the
Sami Kyostilab51e3802021-02-03 16:56:35 +0000195 // CounterDescriptor instead). All they have is a |{double_,}counter_value|.
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000196 if (event_.type() == TrackEvent::TYPE_COUNTER) {
197 ParseCounterEvent();
198 return util::OkStatus();
199 }
200
Eric Seckler063ed392020-04-03 18:26:30 +0100201 // If we have legacy thread time / instruction count fields, also parse them
202 // into the counters tables.
203 ParseLegacyThreadTimeAndInstructionsAsCounters();
204
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000205 // Parse extra counter values before parsing the actual event. This way, we
206 // can update the slice's thread time / instruction count fields based on
Eric Seckler063ed392020-04-03 18:26:30 +0100207 // these counter values and also parse them as slice attributes / arguments.
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000208 ParseExtraCounterValues();
209
Eric Seckler926b3372020-03-06 16:17:53 +0000210 // TODO(eseckler): Replace phase with type and remove handling of
211 // legacy_event_.phase() once it is no longer used by producers.
Lalit Maganti627f4a62020-12-09 16:10:35 +0000212 char phase = static_cast<char>(ParsePhaseOrType());
Eric Seckler926b3372020-03-06 16:17:53 +0000213
Lalit Maganti627f4a62020-12-09 16:10:35 +0000214 switch (phase) {
Eric Seckler926b3372020-03-06 16:17:53 +0000215 case 'B': // TRACE_EVENT_PHASE_BEGIN.
216 return ParseThreadBeginEvent();
217 case 'E': // TRACE_EVENT_PHASE_END.
218 return ParseThreadEndEvent();
219 case 'X': // TRACE_EVENT_PHASE_COMPLETE.
220 return ParseThreadCompleteEvent();
Andrii703edd32020-08-07 13:57:56 +0300221 case 's': // TRACE_EVENT_PHASE_FLOW_BEGIN.
Andrii703edd32020-08-07 13:57:56 +0300222 case 't': // TRACE_EVENT_PHASE_FLOW_STEP.
Andrii703edd32020-08-07 13:57:56 +0300223 case 'f': // TRACE_EVENT_PHASE_FLOW_END.
Lalit Maganti627f4a62020-12-09 16:10:35 +0000224 return ParseFlowEventV1(phase);
Eric Seckler926b3372020-03-06 16:17:53 +0000225 case 'i':
226 case 'I': // TRACE_EVENT_PHASE_INSTANT.
Sami Kyostila56c899a2021-02-03 18:50:53 +0000227 case 'R': // TRACE_EVENT_PHASE_MARK.
Sami Kyostila4e07ae32021-04-30 16:25:02 +0100228 return ParseThreadInstantEvent(phase);
Eric Seckler926b3372020-03-06 16:17:53 +0000229 case 'b': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN
ssid3154c0c2021-02-22 20:53:54 -0800230 case 'S':
231 return ParseAsyncBeginEvent(phase);
Eric Seckler926b3372020-03-06 16:17:53 +0000232 case 'e': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_END
ssid3154c0c2021-02-22 20:53:54 -0800233 case 'F':
Eric Seckler926b3372020-03-06 16:17:53 +0000234 return ParseAsyncEndEvent();
235 case 'n': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT
236 return ParseAsyncInstantEvent();
ssid3154c0c2021-02-22 20:53:54 -0800237 case 'T':
238 case 'p':
239 return ParseAsyncStepEvent(phase);
Eric Seckler926b3372020-03-06 16:17:53 +0000240 case 'M': // TRACE_EVENT_PHASE_METADATA (process and thread names).
241 return ParseMetadataEvent();
242 default:
243 // Other events are proxied via the raw table for JSON export.
244 return ParseLegacyEventAsRawEvent();
245 }
246 }
247
248 private:
249 StringId ParseTrackEventCategory() {
250 StringId category_id = kNullStringId;
251
252 std::vector<uint64_t> category_iids;
253 for (auto it = event_.category_iids(); it; ++it) {
254 category_iids.push_back(*it);
255 }
256 std::vector<protozero::ConstChars> category_strings;
257 for (auto it = event_.categories(); it; ++it) {
258 category_strings.push_back(*it);
259 }
260
261 // If there's a single category, we can avoid building a concatenated
262 // string.
263 if (PERFETTO_LIKELY(category_iids.size() == 1 &&
264 category_strings.empty())) {
265 auto* decoder = sequence_state_->LookupInternedMessage<
266 protos::pbzero::InternedData::kEventCategoriesFieldNumber,
267 protos::pbzero::EventCategory>(category_iids[0]);
268 if (decoder) {
269 category_id = storage_->InternString(decoder->name());
270 } else {
271 char buffer[32];
272 base::StringWriter writer(buffer, sizeof(buffer));
273 writer.AppendLiteral("unknown(");
274 writer.AppendUnsignedInt(category_iids[0]);
275 writer.AppendChar(')');
276 category_id = storage_->InternString(writer.GetStringView());
277 }
278 } else if (category_iids.empty() && category_strings.size() == 1) {
279 category_id = storage_->InternString(category_strings[0]);
280 } else if (category_iids.size() + category_strings.size() > 1) {
281 // We concatenate the category strings together since we currently only
282 // support a single "cat" column.
283 // TODO(eseckler): Support multi-category events in the table schema.
284 std::string categories;
285 for (uint64_t iid : category_iids) {
286 auto* decoder = sequence_state_->LookupInternedMessage<
287 protos::pbzero::InternedData::kEventCategoriesFieldNumber,
288 protos::pbzero::EventCategory>(iid);
289 if (!decoder)
290 continue;
291 base::StringView name = decoder->name();
292 if (!categories.empty())
293 categories.append(",");
294 categories.append(name.data(), name.size());
295 }
296 for (const protozero::ConstChars& cat : category_strings) {
297 if (!categories.empty())
298 categories.append(",");
299 categories.append(cat.data, cat.size);
300 }
301 if (!categories.empty())
302 category_id = storage_->InternString(base::StringView(categories));
303 }
304
305 return category_id;
306 }
307
308 StringId ParseTrackEventName() {
309 uint64_t name_iid = event_.name_iid();
310 if (!name_iid)
311 name_iid = legacy_event_.name_iid();
312
313 if (PERFETTO_LIKELY(name_iid)) {
314 auto* decoder = sequence_state_->LookupInternedMessage<
315 protos::pbzero::InternedData::kEventNamesFieldNumber,
316 protos::pbzero::EventName>(name_iid);
317 if (decoder)
318 return storage_->InternString(decoder->name());
319 } else if (event_.has_name()) {
320 return storage_->InternString(event_.name());
321 }
322
323 return kNullStringId;
324 }
325
326 util::Status ParseTrackAssociation() {
327 TrackTracker* track_tracker = context_->track_tracker.get();
328 ProcessTracker* procs = context_->process_tracker.get();
329
330 // Consider track_uuid from the packet and TrackEventDefaults, fall back to
331 // the default descriptor track (uuid 0).
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000332 track_uuid_ = event_.has_track_uuid()
333 ? event_.track_uuid()
334 : (defaults_ && defaults_->has_track_uuid()
335 ? defaults_->track_uuid()
336 : 0u);
Eric Seckler926b3372020-03-06 16:17:53 +0000337
338 // Determine track from track_uuid specified in either TrackEvent or
339 // TrackEventDefaults. If a non-default track is not set, we either:
340 // a) fall back to the track specified by the sequence's (or event's) pid
Eric Seckler962ffee2020-10-07 17:27:23 +0100341 // + tid (only in case of legacy tracks/events, i.e. events that don't
Eric Seckler926b3372020-03-06 16:17:53 +0000342 // specify an explicit track uuid or use legacy event phases instead of
343 // TrackEvent types), or
344 // b) a default track.
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000345 if (track_uuid_) {
Eric Seckler926b3372020-03-06 16:17:53 +0000346 base::Optional<TrackId> opt_track_id =
Lalit Maganti62b741f2020-12-10 18:24:00 +0000347 track_event_tracker_->GetDescriptorTrack(track_uuid_, name_id_);
Eric Seckler926b3372020-03-06 16:17:53 +0000348 if (!opt_track_id) {
Lalit Maganti62b741f2020-12-10 18:24:00 +0000349 track_event_tracker_->ReserveDescriptorChildTrack(track_uuid_,
350 /*parent_uuid=*/0,
351 name_id_);
352 opt_track_id =
353 track_event_tracker_->GetDescriptorTrack(track_uuid_, name_id_);
Eric Seckler926b3372020-03-06 16:17:53 +0000354 }
355 track_id_ = *opt_track_id;
356
357 auto thread_track_row =
358 storage_->thread_track_table().id().IndexOf(track_id_);
359 if (thread_track_row) {
360 utid_ = storage_->thread_track_table().utid()[*thread_track_row];
361 upid_ = storage_->thread_table().upid()[*utid_];
362 } else {
363 auto process_track_row =
364 storage_->process_track_table().id().IndexOf(track_id_);
365 if (process_track_row) {
366 upid_ = storage_->process_track_table().upid()[*process_track_row];
367 if (sequence_state_->state()->pid_and_tid_valid()) {
368 uint32_t pid =
369 static_cast<uint32_t>(sequence_state_->state()->pid());
370 uint32_t tid =
371 static_cast<uint32_t>(sequence_state_->state()->tid());
372 UniqueTid utid_candidate = procs->UpdateThread(tid, pid);
373 if (storage_->thread_table().upid()[utid_candidate] == upid_)
374 legacy_passthrough_utid_ = utid_candidate;
375 }
Andrew Shulaevf0f1bd92020-04-06 18:57:20 +0100376 } else {
377 auto* tracks = context_->storage->mutable_track_table();
378 auto track_index = tracks->id().IndexOf(track_id_);
379 if (track_index) {
380 const StringPool::Id& id = tracks->name()[*track_index];
381 if (id.is_null())
382 tracks->mutable_name()->Set(*track_index, name_id_);
383 }
384
385 if (sequence_state_->state()->pid_and_tid_valid()) {
386 uint32_t pid =
387 static_cast<uint32_t>(sequence_state_->state()->pid());
388 uint32_t tid =
389 static_cast<uint32_t>(sequence_state_->state()->tid());
390 legacy_passthrough_utid_ = procs->UpdateThread(tid, pid);
391 }
Eric Seckler926b3372020-03-06 16:17:53 +0000392 }
393 }
394 } else {
395 bool pid_tid_state_valid = sequence_state_->state()->pid_and_tid_valid();
396
397 // We have a 0-value |track_uuid|. Nevertheless, we should only fall back
398 // if we have either no |track_uuid| specified at all or |track_uuid| was
399 // set explicitly to 0 (e.g. to override a default track_uuid) and we have
400 // a legacy phase. Events with real phases should use |track_uuid| to
401 // specify a different track (or use the pid/tid_override fields).
402 bool fallback_to_legacy_pid_tid_tracks =
403 (!event_.has_track_uuid() || !event_.has_type()) &&
404 pid_tid_state_valid;
405
406 // Always allow fallback if we have a process override.
407 fallback_to_legacy_pid_tid_tracks |= legacy_event_.has_pid_override();
408
409 // A thread override requires a valid pid.
410 fallback_to_legacy_pid_tid_tracks |=
411 legacy_event_.has_tid_override() && pid_tid_state_valid;
412
413 if (fallback_to_legacy_pid_tid_tracks) {
414 uint32_t pid = static_cast<uint32_t>(sequence_state_->state()->pid());
415 uint32_t tid = static_cast<uint32_t>(sequence_state_->state()->tid());
416 if (legacy_event_.has_pid_override()) {
417 pid = static_cast<uint32_t>(legacy_event_.pid_override());
418 tid = static_cast<uint32_t>(-1);
419 }
420 if (legacy_event_.has_tid_override())
421 tid = static_cast<uint32_t>(legacy_event_.tid_override());
422
423 utid_ = procs->UpdateThread(tid, pid);
424 upid_ = storage_->thread_table().upid()[*utid_];
425 track_id_ = track_tracker->InternThreadTrack(*utid_);
426 } else {
Lalit Maganti62b741f2020-12-10 18:24:00 +0000427 track_id_ = track_event_tracker_->GetOrCreateDefaultDescriptorTrack();
Eric Seckler926b3372020-03-06 16:17:53 +0000428 }
429 }
430
431 if (!legacy_event_.has_phase())
432 return util::OkStatus();
433
434 // Legacy phases may imply a different track than the one specified by
435 // the fallback (or default track uuid) above.
436 switch (legacy_event_.phase()) {
437 case 'b':
438 case 'e':
ssid3154c0c2021-02-22 20:53:54 -0800439 case 'n':
440 case 'S':
441 case 'T':
442 case 'p':
443 case 'F': {
Eric Seckler926b3372020-03-06 16:17:53 +0000444 // Intern tracks for legacy async events based on legacy event ids.
445 int64_t source_id = 0;
446 bool source_id_is_process_scoped = false;
447 if (legacy_event_.has_unscoped_id()) {
448 source_id = static_cast<int64_t>(legacy_event_.unscoped_id());
449 } else if (legacy_event_.has_global_id()) {
450 source_id = static_cast<int64_t>(legacy_event_.global_id());
451 } else if (legacy_event_.has_local_id()) {
452 if (!upid_) {
453 return util::ErrStatus(
454 "TrackEvent with local_id without process association");
455 }
456
457 source_id = static_cast<int64_t>(legacy_event_.local_id());
458 source_id_is_process_scoped = true;
459 } else {
460 return util::ErrStatus("Async LegacyEvent without ID");
461 }
462
463 // Catapult treats nestable async events of different categories with
464 // the same ID as separate tracks. We replicate the same behavior
ssid3154c0c2021-02-22 20:53:54 -0800465 // here. For legacy async events, it uses different tracks based on
466 // event names.
467 const bool legacy_async =
468 legacy_event_.phase() == 'S' || legacy_event_.phase() == 'T' ||
469 legacy_event_.phase() == 'p' || legacy_event_.phase() == 'F';
470 StringId id_scope = legacy_async ? name_id_ : category_id_;
Eric Seckler926b3372020-03-06 16:17:53 +0000471 if (legacy_event_.has_id_scope()) {
472 std::string concat = storage_->GetString(category_id_).ToStdString() +
473 ":" + legacy_event_.id_scope().ToStdString();
474 id_scope = storage_->InternString(base::StringView(concat));
475 }
476
477 track_id_ = context_->track_tracker->InternLegacyChromeAsyncTrack(
478 name_id_, upid_ ? *upid_ : 0, source_id,
479 source_id_is_process_scoped, id_scope);
480 legacy_passthrough_utid_ = utid_;
481 break;
482 }
483 case 'i':
484 case 'I': {
485 // Intern tracks for global or process-scoped legacy instant events.
486 switch (legacy_event_.instant_event_scope()) {
487 case LegacyEvent::SCOPE_UNSPECIFIED:
488 case LegacyEvent::SCOPE_THREAD:
489 // Thread-scoped legacy instant events already have the right
490 // track based on the tid/pid of the sequence.
491 if (!utid_) {
492 return util::ErrStatus(
493 "Thread-scoped instant event without thread association");
494 }
495 break;
496 case LegacyEvent::SCOPE_GLOBAL:
497 track_id_ = context_->track_tracker
498 ->GetOrCreateLegacyChromeGlobalInstantTrack();
499 legacy_passthrough_utid_ = utid_;
500 utid_ = base::nullopt;
501 break;
502 case LegacyEvent::SCOPE_PROCESS:
503 if (!upid_) {
504 return util::ErrStatus(
505 "Process-scoped instant event without process association");
506 }
507
508 track_id_ =
509 context_->track_tracker->InternLegacyChromeProcessInstantTrack(
510 *upid_);
511 legacy_passthrough_utid_ = utid_;
512 utid_ = base::nullopt;
513 break;
514 }
515 break;
516 }
517 default:
518 break;
519 }
520
521 return util::OkStatus();
522 }
523
524 int32_t ParsePhaseOrType() {
525 if (legacy_event_.has_phase())
526 return legacy_event_.phase();
527
528 switch (event_.type()) {
529 case TrackEvent::TYPE_SLICE_BEGIN:
530 return utid_ ? 'B' : 'b';
531 case TrackEvent::TYPE_SLICE_END:
532 return utid_ ? 'E' : 'e';
533 case TrackEvent::TYPE_INSTANT:
534 return utid_ ? 'i' : 'n';
535 default:
Eric Seckler9ccafbc2020-04-23 14:32:54 +0100536 PERFETTO_ELOG("unexpected event type %d", event_.type());
Eric Seckler926b3372020-03-06 16:17:53 +0000537 return 0;
538 }
539 }
540
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000541 void ParseCounterEvent() {
542 // Tokenizer ensures that TYPE_COUNTER events are associated with counter
543 // tracks and have values.
544 PERFETTO_DCHECK(storage_->counter_track_table().id().IndexOf(track_id_));
Sami Kyostilab51e3802021-02-03 16:56:35 +0000545 PERFETTO_DCHECK(event_.has_counter_value() ||
546 event_.has_double_counter_value());
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000547
Florian Mayer39e40d42020-07-16 14:52:07 +0200548 context_->event_tracker->PushCounter(
549 ts_, static_cast<double>(event_data_->counter_value), track_id_);
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000550 }
551
Eric Seckler063ed392020-04-03 18:26:30 +0100552 void ParseLegacyThreadTimeAndInstructionsAsCounters() {
553 if (!utid_)
554 return;
555 // When these fields are set, we don't expect TrackDescriptor-based counters
556 // for thread time or instruction count for this thread in the trace, so we
Eric Seckler411e9c82020-05-04 13:36:25 +0100557 // intern separate counter tracks based on name + utid. Note that we cannot
558 // import the counter values from the end of a complete event, because the
559 // EventTracker expects counters to be pushed in order of their timestamps.
560 // One more reason to switch to split begin/end events.
Eric Seckler063ed392020-04-03 18:26:30 +0100561 if (event_data_->thread_timestamp) {
562 TrackId track_id = context_->track_tracker->InternThreadCounterTrack(
563 parser_->counter_name_thread_time_id_, *utid_);
Florian Mayer39e40d42020-07-16 14:52:07 +0200564 context_->event_tracker->PushCounter(
Stephen Nuskof848d462021-04-06 13:28:04 +0100565 ts_, static_cast<double>(*event_data_->thread_timestamp), track_id);
Eric Seckler063ed392020-04-03 18:26:30 +0100566 }
567 if (event_data_->thread_instruction_count) {
568 TrackId track_id = context_->track_tracker->InternThreadCounterTrack(
569 parser_->counter_name_thread_instruction_count_id_, *utid_);
570 context_->event_tracker->PushCounter(
Stephen Nuskof848d462021-04-06 13:28:04 +0100571 ts_, static_cast<double>(*event_data_->thread_instruction_count),
Florian Mayer39e40d42020-07-16 14:52:07 +0200572 track_id);
Eric Seckler063ed392020-04-03 18:26:30 +0100573 }
574 }
575
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000576 void ParseExtraCounterValues() {
Sami Kyostilab51e3802021-02-03 16:56:35 +0000577 if (!event_.has_extra_counter_values() &&
578 !event_.has_extra_double_counter_values()) {
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000579 return;
Sami Kyostilab51e3802021-02-03 16:56:35 +0000580 }
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000581
Sami Kyostilab51e3802021-02-03 16:56:35 +0000582 // Add integer extra counter values.
583 size_t index = 0;
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000584 protozero::RepeatedFieldIterator<uint64_t> track_uuid_it;
585 if (event_.has_extra_counter_track_uuids()) {
586 track_uuid_it = event_.extra_counter_track_uuids();
Eric Seckler9ccafbc2020-04-23 14:32:54 +0100587 } else if (defaults_ && defaults_->has_extra_counter_track_uuids()) {
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000588 track_uuid_it = defaults_->extra_counter_track_uuids();
589 }
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000590 for (auto value_it = event_.extra_counter_values(); value_it;
591 ++value_it, ++track_uuid_it, ++index) {
Sami Kyostilab51e3802021-02-03 16:56:35 +0000592 AddExtraCounterValue(track_uuid_it, index);
593 }
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000594
Sami Kyostilab51e3802021-02-03 16:56:35 +0000595 // Add double extra counter values.
596 track_uuid_it = protozero::RepeatedFieldIterator<uint64_t>();
597 if (event_.has_extra_double_counter_track_uuids()) {
598 track_uuid_it = event_.extra_double_counter_track_uuids();
599 } else if (defaults_ && defaults_->has_extra_double_counter_track_uuids()) {
600 track_uuid_it = defaults_->extra_double_counter_track_uuids();
601 }
602 for (auto value_it = event_.extra_double_counter_values(); value_it;
603 ++value_it, ++track_uuid_it, ++index) {
604 AddExtraCounterValue(track_uuid_it, index);
605 }
606 }
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000607
Sami Kyostilab51e3802021-02-03 16:56:35 +0000608 void AddExtraCounterValue(
609 protozero::RepeatedFieldIterator<uint64_t> track_uuid_it,
610 size_t index) {
611 // Tokenizer ensures that there aren't more values than uuids, that we
612 // don't have more values than kMaxNumExtraCounters and that the
613 // track_uuids are for valid counter tracks.
614 PERFETTO_DCHECK(track_uuid_it);
615 PERFETTO_DCHECK(index < TrackEventData::kMaxNumExtraCounters);
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000616
Sami Kyostilab51e3802021-02-03 16:56:35 +0000617 base::Optional<TrackId> track_id =
618 track_event_tracker_->GetDescriptorTrack(*track_uuid_it);
619 base::Optional<uint32_t> counter_row =
620 storage_->counter_track_table().id().IndexOf(*track_id);
621
622 double value = event_data_->extra_counter_values[index];
623 context_->event_tracker->PushCounter(ts_, value, *track_id);
624
625 // Also import thread_time and thread_instruction_count counters into
626 // slice columns to simplify JSON export.
627 StringId counter_name =
628 storage_->counter_track_table().name()[*counter_row];
629 if (counter_name == parser_->counter_name_thread_time_id_) {
630 event_data_->thread_timestamp = static_cast<int64_t>(value);
631 } else if (counter_name ==
632 parser_->counter_name_thread_instruction_count_id_) {
633 event_data_->thread_instruction_count = static_cast<int64_t>(value);
Eric Secklerfbd9aed2020-03-10 18:07:38 +0000634 }
635 }
636
Eric Seckler926b3372020-03-06 16:17:53 +0000637 util::Status ParseThreadBeginEvent() {
638 if (!utid_) {
639 return util::ErrStatus(
640 "TrackEvent with phase B without thread association");
641 }
642
Stephen Nusko7e8ab0a2021-04-09 16:07:16 +0100643 auto* thread_slices = storage_->mutable_thread_slice_table();
644 auto opt_slice_id = context_->slice_tracker->BeginTyped(
645 thread_slices, MakeThreadSliceRow(),
646 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
Stephen Nuskof848d462021-04-06 13:28:04 +0100647
Eric Seckler926b3372020-03-06 16:17:53 +0000648 if (opt_slice_id.has_value()) {
Andrii1b50d2e2020-10-05 16:05:30 +0300649 MaybeParseFlowEvents();
Eric Seckler926b3372020-03-06 16:17:53 +0000650 }
651
652 return util::OkStatus();
653 }
654
655 util::Status ParseThreadEndEvent() {
656 if (!utid_) {
657 return util::ErrStatus(
658 "TrackEvent with phase E without thread association");
659 }
660
661 auto opt_slice_id = context_->slice_tracker->End(
662 ts_, track_id_, category_id_, name_id_,
663 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
664 if (opt_slice_id.has_value()) {
Stephen Nuskof848d462021-04-06 13:28:04 +0100665 auto* thread_slices = storage_->mutable_thread_slice_table();
666 auto maybe_row = thread_slices->id().IndexOf(*opt_slice_id);
667 PERFETTO_DCHECK(maybe_row.has_value());
668 auto tts = thread_slices->thread_ts()[*maybe_row];
669 if (tts) {
670 PERFETTO_DCHECK(event_data_->thread_timestamp);
671 thread_slices->mutable_thread_dur()->Set(
672 *maybe_row, *event_data_->thread_timestamp - *tts);
673 }
674 auto tic = thread_slices->thread_instruction_count()[*maybe_row];
675 if (tic) {
676 PERFETTO_DCHECK(event_data_->thread_instruction_count);
677 thread_slices->mutable_thread_instruction_delta()->Set(
678 *maybe_row, *event_data_->thread_instruction_count - *tic);
679 }
Eric Seckler926b3372020-03-06 16:17:53 +0000680 }
681
682 return util::OkStatus();
683 }
684
685 util::Status ParseThreadCompleteEvent() {
686 if (!utid_) {
687 return util::ErrStatus(
688 "TrackEvent with phase X without thread association");
689 }
690
691 auto duration_ns = legacy_event_.duration_us() * 1000;
692 if (duration_ns < 0)
693 return util::ErrStatus("TrackEvent with phase X with negative duration");
Stephen Nuskof848d462021-04-06 13:28:04 +0100694
Stephen Nusko7e8ab0a2021-04-09 16:07:16 +0100695 auto* thread_slices = storage_->mutable_thread_slice_table();
696 tables::ThreadSliceTable::Row row = MakeThreadSliceRow();
697 row.dur = duration_ns;
698 if (legacy_event_.has_thread_duration_us()) {
699 row.thread_dur = legacy_event_.thread_duration_us() * 1000;
Stephen Nuskof848d462021-04-06 13:28:04 +0100700 }
Stephen Nusko7e8ab0a2021-04-09 16:07:16 +0100701 if (legacy_event_.has_thread_instruction_delta()) {
702 row.thread_instruction_delta = legacy_event_.thread_instruction_delta();
703 }
704 auto opt_slice_id = context_->slice_tracker->ScopedTyped(
705 thread_slices, std::move(row),
706 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
Stephen Nuskof848d462021-04-06 13:28:04 +0100707
Eric Seckler926b3372020-03-06 16:17:53 +0000708 if (opt_slice_id.has_value()) {
Andrii1b50d2e2020-10-05 16:05:30 +0300709 MaybeParseFlowEvents();
Eric Seckler926b3372020-03-06 16:17:53 +0000710 }
711
712 return util::OkStatus();
713 }
714
Andrii703edd32020-08-07 13:57:56 +0300715 base::Optional<uint64_t> GetLegacyEventId() {
716 if (legacy_event_.has_unscoped_id())
717 return legacy_event_.unscoped_id();
718 // TODO(andrewbb): Catapult doesn't support global_id and local_id on flow
719 // events. We could add support in trace processor (e.g. because there seem
720 // to be some callsites supplying local_id in chromium), but we would have
721 // to consider the process ID for local IDs and use a separate ID scope for
722 // global_id and unscoped_id.
723 return base::nullopt;
724 }
725
726 util::Status ParseFlowEventV1(char phase) {
727 auto opt_source_id = GetLegacyEventId();
728 if (!opt_source_id) {
729 storage_->IncrementStats(stats::flow_invalid_id);
Andriidd07cb12020-09-10 16:09:01 +0300730 return util::ErrStatus("Invalid id for flow event v1");
Andrii703edd32020-08-07 13:57:56 +0300731 }
732 FlowId flow_id = context_->flow_tracker->GetFlowIdForV1Event(
733 opt_source_id.value(), category_id_, name_id_);
734 switch (phase) {
735 case 's':
736 context_->flow_tracker->Begin(track_id_, flow_id);
737 break;
738 case 't':
739 context_->flow_tracker->Step(track_id_, flow_id);
740 break;
741 case 'f':
742 context_->flow_tracker->End(track_id_, flow_id,
Andrii1b50d2e2020-10-05 16:05:30 +0300743 legacy_event_.bind_to_enclosing(),
744 /* close_flow = */ false);
Andrii703edd32020-08-07 13:57:56 +0300745 break;
746 }
Andriidd07cb12020-09-10 16:09:01 +0300747 return util::OkStatus();
Andrii703edd32020-08-07 13:57:56 +0300748 }
749
Andrii1b50d2e2020-10-05 16:05:30 +0300750 void MaybeParseTrackEventFlows() {
751 if (event_.has_flow_ids()) {
Andrii1b50d2e2020-10-05 16:05:30 +0300752 auto it = event_.flow_ids();
Alexander Timinbb7ed112020-11-02 14:46:53 +0000753 for (; it; ++it) {
Andrii1b50d2e2020-10-05 16:05:30 +0300754 FlowId flow_id = *it;
755 if (!context_->flow_tracker->IsActive(flow_id)) {
756 context_->flow_tracker->Begin(track_id_, flow_id);
757 continue;
758 }
Alexander Timinbb7ed112020-11-02 14:46:53 +0000759 context_->flow_tracker->Step(track_id_, flow_id);
760 }
761 }
762 if (event_.has_terminating_flow_ids()) {
763 auto it = event_.terminating_flow_ids();
764 for (; it; ++it) {
765 FlowId flow_id = *it;
766 if (!context_->flow_tracker->IsActive(flow_id)) {
767 // If we should terminate a flow, do not begin a new one if it's not
768 // active already.
769 continue;
Andrii1b50d2e2020-10-05 16:05:30 +0300770 }
Alexander Timinbb7ed112020-11-02 14:46:53 +0000771 context_->flow_tracker->End(track_id_, flow_id,
Hector Dearman2c2dd632021-01-14 14:20:18 +0000772 /* bind_enclosing_slice = */ true,
Alexander Timinbb7ed112020-11-02 14:46:53 +0000773 /* close_flow = */ true);
Andrii1b50d2e2020-10-05 16:05:30 +0300774 }
775 }
776 }
777
Andrii703edd32020-08-07 13:57:56 +0300778 void MaybeParseFlowEventV2() {
779 if (!legacy_event_.has_bind_id()) {
780 return;
781 }
782 if (!legacy_event_.has_flow_direction()) {
783 storage_->IncrementStats(stats::flow_without_direction);
784 return;
785 }
786
787 auto bind_id = legacy_event_.bind_id();
788 switch (legacy_event_.flow_direction()) {
789 case LegacyEvent::FLOW_OUT:
790 context_->flow_tracker->Begin(track_id_, bind_id);
791 break;
792 case LegacyEvent::FLOW_INOUT:
793 context_->flow_tracker->Step(track_id_, bind_id);
794 break;
795 case LegacyEvent::FLOW_IN:
796 context_->flow_tracker->End(track_id_, bind_id,
Andrii1b50d2e2020-10-05 16:05:30 +0300797 /* bind_enclosing_slice = */ true,
798 /* close_flow = */ false);
Andrii703edd32020-08-07 13:57:56 +0300799 break;
800 default:
801 storage_->IncrementStats(stats::flow_without_direction);
802 }
803 }
804
Andrii1b50d2e2020-10-05 16:05:30 +0300805 void MaybeParseFlowEvents() {
806 MaybeParseFlowEventV2();
807 MaybeParseTrackEventFlows();
808 }
809
Sami Kyostila4e07ae32021-04-30 16:25:02 +0100810 util::Status ParseThreadInstantEvent(char phase) {
Eric Seckler926b3372020-03-06 16:17:53 +0000811 // Handle instant events as slices with zero duration, so that they end
812 // up nested underneath their parent slices.
813 int64_t duration_ns = 0;
814 int64_t tidelta = 0;
Stephen Nuskof848d462021-04-06 13:28:04 +0100815 base::Optional<tables::SliceTable::Id> opt_slice_id;
Sami Kyostila4e07ae32021-04-30 16:25:02 +0100816 auto args_inserter = [this, phase](BoundInserter* inserter) {
Stephen Nuskof848d462021-04-06 13:28:04 +0100817 ParseTrackEventArgs(inserter);
Sami Kyostila4e07ae32021-04-30 16:25:02 +0100818 // For legacy MARK event, add phase for JSON exporter.
819 if (phase == 'R') {
820 std::string phase_string(1, static_cast<char>(phase));
821 StringId phase_id = storage_->InternString(phase_string.c_str());
822 inserter->AddArg(parser_->legacy_event_phase_key_id_,
823 Variadic::String(phase_id));
824 }
Stephen Nuskof848d462021-04-06 13:28:04 +0100825 };
826 if (utid_) {
827 auto* thread_slices = storage_->mutable_thread_slice_table();
828 tables::ThreadSliceTable::Row row = MakeThreadSliceRow();
Stephen Nusko7e8ab0a2021-04-09 16:07:16 +0100829 row.dur = duration_ns;
Stephen Nuskof848d462021-04-06 13:28:04 +0100830 if (event_data_->thread_timestamp) {
831 row.thread_dur = duration_ns;
832 }
833 if (event_data_->thread_instruction_count) {
834 row.thread_instruction_delta = tidelta;
835 }
836 opt_slice_id = context_->slice_tracker->ScopedTyped(
837 thread_slices, row, std::move(args_inserter));
838 } else {
839 opt_slice_id = context_->slice_tracker->Scoped(
840 ts_, track_id_, category_id_, name_id_, duration_ns,
841 std::move(args_inserter));
842 }
Stephen Nusko3d3f68f2021-01-28 13:23:18 -0500843 if (!opt_slice_id.has_value()) {
844 return util::OkStatus();
845 }
846 MaybeParseFlowEvents();
Eric Seckler926b3372020-03-06 16:17:53 +0000847 return util::OkStatus();
848 }
849
ssid3154c0c2021-02-22 20:53:54 -0800850 util::Status ParseAsyncBeginEvent(char phase) {
851 auto args_inserter = [this, phase](BoundInserter* inserter) {
852 ParseTrackEventArgs(inserter);
853
854 if (phase == 'b')
855 return;
856 PERFETTO_DCHECK(phase == 'S');
857 // For legacy ASYNC_BEGIN, add phase for JSON exporter.
858 std::string phase_string(1, static_cast<char>(phase));
859 StringId phase_id = storage_->InternString(phase_string.c_str());
860 inserter->AddArg(parser_->legacy_event_phase_key_id_,
861 Variadic::String(phase_id));
862 };
Eric Seckler926b3372020-03-06 16:17:53 +0000863 auto opt_slice_id = context_->slice_tracker->Begin(
ssid3154c0c2021-02-22 20:53:54 -0800864 ts_, track_id_, category_id_, name_id_, args_inserter);
Stephen Nusko3d3f68f2021-01-28 13:23:18 -0500865 if (!opt_slice_id.has_value()) {
866 return util::OkStatus();
867 }
868 MaybeParseFlowEvents();
ssid3154c0c2021-02-22 20:53:54 -0800869 // For the time being, we only create vtrack slice rows if we need to
Eric Seckler926b3372020-03-06 16:17:53 +0000870 // store thread timestamps/counters.
Stephen Nusko3d3f68f2021-01-28 13:23:18 -0500871 if (legacy_event_.use_async_tts()) {
Eric Seckler926b3372020-03-06 16:17:53 +0000872 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
873 PERFETTO_DCHECK(!vtrack_slices->slice_count() ||
874 vtrack_slices->slice_ids().back() < opt_slice_id.value());
Stephen Nuskof848d462021-04-06 13:28:04 +0100875 int64_t tts =
876 event_data_->thread_timestamp ? *event_data_->thread_timestamp : 0;
877 int64_t tic = event_data_->thread_instruction_count
878 ? *event_data_->thread_instruction_count
879 : 0;
880 vtrack_slices->AddVirtualTrackSlice(opt_slice_id.value(), tts,
881 kPendingThreadDuration, tic,
882 kPendingThreadInstructionDelta);
Eric Seckler926b3372020-03-06 16:17:53 +0000883 }
884 return util::OkStatus();
885 }
886
887 util::Status ParseAsyncEndEvent() {
888 auto opt_slice_id = context_->slice_tracker->End(
889 ts_, track_id_, category_id_, name_id_,
890 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
891 if (legacy_event_.use_async_tts() && opt_slice_id.has_value()) {
892 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
Stephen Nuskof848d462021-04-06 13:28:04 +0100893 int64_t tts =
894 event_data_->thread_timestamp ? *event_data_->thread_timestamp : 0;
895 int64_t tic = event_data_->thread_instruction_count
896 ? *event_data_->thread_instruction_count
897 : 0;
898 vtrack_slices->UpdateThreadDeltasForSliceId(opt_slice_id.value(), tts,
899 tic);
Eric Seckler926b3372020-03-06 16:17:53 +0000900 }
901 return util::OkStatus();
902 }
903
ssid3154c0c2021-02-22 20:53:54 -0800904 util::Status ParseAsyncStepEvent(char phase) {
905 // Parse step events as instant events. Reconstructing the begin/end times
906 // of the child slice would be too complicated, see b/178540838. For JSON
907 // export, we still record the original step's phase in an arg.
908 int64_t duration_ns = 0;
909 context_->slice_tracker->Scoped(
910 ts_, track_id_, category_id_, name_id_, duration_ns,
911 [this, phase](BoundInserter* inserter) {
912 ParseTrackEventArgs(inserter);
913
914 PERFETTO_DCHECK(phase == 'T' || phase == 'p');
915 std::string phase_string(1, static_cast<char>(phase));
916 StringId phase_id = storage_->InternString(phase_string.c_str());
917 inserter->AddArg(parser_->legacy_event_phase_key_id_,
918 Variadic::String(phase_id));
919 });
920 // Step events don't support thread timestamps, so no need to add a row to
921 // virtual_track_slices.
922 return util::OkStatus();
923 }
924
Eric Seckler926b3372020-03-06 16:17:53 +0000925 util::Status ParseAsyncInstantEvent() {
926 // Handle instant events as slices with zero duration, so that they end
927 // up nested underneath their parent slices.
928 int64_t duration_ns = 0;
929 int64_t tidelta = 0;
930 auto opt_slice_id = context_->slice_tracker->Scoped(
931 ts_, track_id_, category_id_, name_id_, duration_ns,
932 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
Stephen Nusko3d3f68f2021-01-28 13:23:18 -0500933 if (!opt_slice_id.has_value()) {
934 return util::OkStatus();
935 }
936 MaybeParseFlowEvents();
937 if (legacy_event_.use_async_tts()) {
Eric Seckler926b3372020-03-06 16:17:53 +0000938 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
939 PERFETTO_DCHECK(!vtrack_slices->slice_count() ||
940 vtrack_slices->slice_ids().back() < opt_slice_id.value());
Stephen Nuskof848d462021-04-06 13:28:04 +0100941 int64_t tts =
942 event_data_->thread_timestamp ? *event_data_->thread_timestamp : 0;
943 int64_t tic = event_data_->thread_instruction_count
944 ? *event_data_->thread_instruction_count
945 : 0;
946 vtrack_slices->AddVirtualTrackSlice(opt_slice_id.value(), tts,
947 duration_ns, tic, tidelta);
Eric Seckler926b3372020-03-06 16:17:53 +0000948 }
949 return util::OkStatus();
950 }
951
952 util::Status ParseMetadataEvent() {
953 ProcessTracker* procs = context_->process_tracker.get();
954
Eric Secklera3c259f2020-06-04 14:06:50 +0100955 if (name_id_ == kNullStringId)
956 return util::ErrStatus("Metadata event without name");
957
Eric Seckler926b3372020-03-06 16:17:53 +0000958 // Parse process and thread names from correspondingly named events.
959 NullTermStringView event_name = storage_->GetString(name_id_);
960 PERFETTO_DCHECK(event_name.data());
961 if (strcmp(event_name.c_str(), "thread_name") == 0) {
962 if (!utid_) {
963 return util::ErrStatus(
964 "thread_name metadata event without thread association");
965 }
966
967 auto it = event_.debug_annotations();
968 if (!it) {
969 return util::ErrStatus(
970 "thread_name metadata event without debug annotations");
971 }
972 protos::pbzero::DebugAnnotation::Decoder annotation(*it);
973 auto thread_name = annotation.string_value();
974 if (!thread_name.size)
975 return util::OkStatus();
976 auto thread_name_id = storage_->InternString(thread_name);
Mikhail Khokhlov511d4542020-07-27 18:04:30 +0100977 procs->UpdateThreadNameByUtid(
978 *utid_, thread_name_id,
979 ThreadNamePriority::kTrackDescriptorThreadType);
Eric Seckler926b3372020-03-06 16:17:53 +0000980 return util::OkStatus();
981 }
982 if (strcmp(event_name.c_str(), "process_name") == 0) {
983 if (!upid_) {
984 return util::ErrStatus(
985 "process_name metadata event without process association");
986 }
987
988 auto it = event_.debug_annotations();
989 if (!it) {
990 return util::ErrStatus(
991 "process_name metadata event without debug annotations");
992 }
993 protos::pbzero::DebugAnnotation::Decoder annotation(*it);
994 auto process_name = annotation.string_value();
995 if (!process_name.size)
996 return util::OkStatus();
Alexander Timin562cb1f2021-04-14 16:15:29 +0000997 auto process_name_id =
998 storage_->InternString(base::StringView(process_name));
Eric Seckler926b3372020-03-06 16:17:53 +0000999 // Don't override system-provided names.
1000 procs->SetProcessNameIfUnset(*upid_, process_name_id);
1001 return util::OkStatus();
1002 }
1003 // Other metadata events are proxied via the raw table for JSON export.
1004 ParseLegacyEventAsRawEvent();
1005 return util::OkStatus();
1006 }
1007
1008 util::Status ParseLegacyEventAsRawEvent() {
1009 if (!utid_)
1010 return util::ErrStatus("raw legacy event without thread association");
1011
1012 RawId id = storage_->mutable_raw_table()
1013 ->Insert({ts_, parser_->raw_legacy_event_id_, 0, *utid_})
1014 .id;
1015
1016 ArgsTracker args(context_);
1017 auto inserter = args.AddArgsTo(id);
1018
1019 inserter
1020 .AddArg(parser_->legacy_event_category_key_id_,
1021 Variadic::String(category_id_))
1022 .AddArg(parser_->legacy_event_name_key_id_, Variadic::String(name_id_));
1023
1024 std::string phase_string(1, static_cast<char>(legacy_event_.phase()));
1025 StringId phase_id = storage_->InternString(phase_string.c_str());
1026 inserter.AddArg(parser_->legacy_event_phase_key_id_,
1027 Variadic::String(phase_id));
1028
1029 if (legacy_event_.has_duration_us()) {
1030 inserter.AddArg(parser_->legacy_event_duration_ns_key_id_,
1031 Variadic::Integer(legacy_event_.duration_us() * 1000));
1032 }
1033
1034 if (event_data_->thread_timestamp) {
1035 inserter.AddArg(parser_->legacy_event_thread_timestamp_ns_key_id_,
Stephen Nuskof848d462021-04-06 13:28:04 +01001036 Variadic::Integer(*event_data_->thread_timestamp));
Eric Seckler926b3372020-03-06 16:17:53 +00001037 if (legacy_event_.has_thread_duration_us()) {
1038 inserter.AddArg(
1039 parser_->legacy_event_thread_duration_ns_key_id_,
1040 Variadic::Integer(legacy_event_.thread_duration_us() * 1000));
1041 }
1042 }
1043
1044 if (event_data_->thread_instruction_count) {
Stephen Nuskof848d462021-04-06 13:28:04 +01001045 inserter.AddArg(
1046 parser_->legacy_event_thread_instruction_count_key_id_,
1047 Variadic::Integer(*event_data_->thread_instruction_count));
Eric Seckler926b3372020-03-06 16:17:53 +00001048 if (legacy_event_.has_thread_instruction_delta()) {
1049 inserter.AddArg(
1050 parser_->legacy_event_thread_instruction_delta_key_id_,
1051 Variadic::Integer(legacy_event_.thread_instruction_delta()));
1052 }
1053 }
1054
1055 if (legacy_event_.use_async_tts()) {
1056 inserter.AddArg(parser_->legacy_event_use_async_tts_key_id_,
1057 Variadic::Boolean(true));
1058 }
1059
1060 bool has_id = false;
1061 if (legacy_event_.has_unscoped_id()) {
1062 // Unscoped ids are either global or local depending on the phase. Pass
1063 // them through as unscoped IDs to JSON export to preserve this behavior.
1064 inserter.AddArg(parser_->legacy_event_unscoped_id_key_id_,
1065 Variadic::UnsignedInteger(legacy_event_.unscoped_id()));
1066 has_id = true;
1067 } else if (legacy_event_.has_global_id()) {
1068 inserter.AddArg(parser_->legacy_event_global_id_key_id_,
1069 Variadic::UnsignedInteger(legacy_event_.global_id()));
1070 has_id = true;
1071 } else if (legacy_event_.has_local_id()) {
1072 inserter.AddArg(parser_->legacy_event_local_id_key_id_,
1073 Variadic::UnsignedInteger(legacy_event_.local_id()));
1074 has_id = true;
1075 }
1076
1077 if (has_id && legacy_event_.has_id_scope() &&
1078 legacy_event_.id_scope().size) {
1079 inserter.AddArg(
1080 parser_->legacy_event_id_scope_key_id_,
1081 Variadic::String(storage_->InternString(legacy_event_.id_scope())));
1082 }
1083
1084 // No need to parse legacy_event.instant_event_scope() because we import
1085 // instant events into the slice table.
1086
1087 ParseTrackEventArgs(&inserter);
1088 return util::OkStatus();
1089 }
1090
1091 void ParseTrackEventArgs(BoundInserter* inserter) {
1092 auto log_errors = [this](util::Status status) {
Eric Seckler0c624552020-03-10 10:43:32 +00001093 if (status.ok())
1094 return;
Eric Seckler926b3372020-03-06 16:17:53 +00001095 // Log error but continue parsing the other args.
1096 storage_->IncrementStats(stats::track_event_parser_errors);
Eric Seckler411e9c82020-05-04 13:36:25 +01001097 PERFETTO_DLOG("ParseTrackEventArgs error: %s", status.c_message());
Eric Seckler926b3372020-03-06 16:17:53 +00001098 };
1099
ssid9add2ec2021-03-04 13:06:12 -08001100 if (event_.has_source_location_iid()) {
1101 log_errors(AddSourceLocationArgs(event_.source_location_iid(), inserter));
1102 }
1103
Eric Seckler926b3372020-03-06 16:17:53 +00001104 if (event_.has_task_execution()) {
1105 log_errors(ParseTaskExecutionArgs(event_.task_execution(), inserter));
1106 }
1107 if (event_.has_log_message()) {
1108 log_errors(ParseLogMessage(event_.log_message(), inserter));
1109 }
nuwandab14efd32020-09-28 11:19:40 +00001110 if (event_.has_chrome_histogram_sample()) {
1111 log_errors(
1112 ParseHistogramName(event_.chrome_histogram_sample(), inserter));
1113 }
Andrew Shulaev31bc1bc2020-04-30 12:57:09 +01001114
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001115 TrackEventArgsParser args_writer(*inserter, *storage_, *sequence_state_);
1116 log_errors(parser_->args_parser_.ParseMessage(
1117 blob_, ".perfetto.protos.TrackEvent", &parser_->reflect_fields_,
1118 args_writer));
Eric Seckler926b3372020-03-06 16:17:53 +00001119
Alexander Timin97d87852021-05-17 18:01:33 +00001120 {
1121 auto key = parser_->args_parser_.EnterDictionary("debug");
1122 util::DebugAnnotationParser parser(parser_->args_parser_);
1123 for (auto it = event_.debug_annotations(); it; ++it) {
1124 log_errors(parser.Parse(*it, args_writer));
1125 }
1126 }
1127
Eric Seckler926b3372020-03-06 16:17:53 +00001128 if (legacy_passthrough_utid_) {
1129 inserter->AddArg(parser_->legacy_event_passthrough_utid_id_,
1130 Variadic::UnsignedInteger(*legacy_passthrough_utid_),
1131 ArgsTracker::UpdatePolicy::kSkipIfExists);
1132 }
Eric Seckler926b3372020-03-06 16:17:53 +00001133 }
1134
Eric Seckler926b3372020-03-06 16:17:53 +00001135 util::Status ParseTaskExecutionArgs(ConstBytes task_execution,
1136 BoundInserter* inserter) {
1137 protos::pbzero::TaskExecution::Decoder task(task_execution);
1138 uint64_t iid = task.posted_from_iid();
1139 if (!iid)
1140 return util::ErrStatus("TaskExecution with invalid posted_from_iid");
1141
1142 auto* decoder = sequence_state_->LookupInternedMessage<
1143 protos::pbzero::InternedData::kSourceLocationsFieldNumber,
1144 protos::pbzero::SourceLocation>(iid);
1145 if (!decoder)
1146 return util::ErrStatus("TaskExecution with invalid posted_from_iid");
1147
1148 StringId file_name_id = kNullStringId;
1149 StringId function_name_id = kNullStringId;
1150 uint32_t line_number = 0;
1151
1152 file_name_id = storage_->InternString(decoder->file_name());
1153 function_name_id = storage_->InternString(decoder->function_name());
1154 line_number = decoder->line_number();
1155
1156 inserter->AddArg(parser_->task_file_name_args_key_id_,
1157 Variadic::String(file_name_id));
1158 inserter->AddArg(parser_->task_function_name_args_key_id_,
1159 Variadic::String(function_name_id));
1160 inserter->AddArg(parser_->task_line_number_args_key_id_,
1161 Variadic::UnsignedInteger(line_number));
1162 return util::OkStatus();
1163 }
1164
ssid9add2ec2021-03-04 13:06:12 -08001165 util::Status AddSourceLocationArgs(uint64_t iid, BoundInserter* inserter) {
1166 if (!iid)
1167 return util::ErrStatus("SourceLocation with invalid iid");
1168
1169 auto* decoder = sequence_state_->LookupInternedMessage<
1170 protos::pbzero::InternedData::kSourceLocationsFieldNumber,
1171 protos::pbzero::SourceLocation>(iid);
1172 if (!decoder)
1173 return util::ErrStatus("SourceLocation with invalid iid");
1174
1175 StringId file_name_id = kNullStringId;
1176 StringId function_name_id = kNullStringId;
1177 uint32_t line_number = 0;
1178
1179 file_name_id = storage_->InternString(decoder->file_name());
1180 function_name_id = storage_->InternString(decoder->function_name());
1181 line_number = decoder->line_number();
1182
1183 inserter->AddArg(parser_->source_location_file_name_key_id_,
1184 Variadic::String(file_name_id));
1185 inserter->AddArg(parser_->source_location_function_name_key_id_,
1186 Variadic::String(function_name_id));
1187 inserter->AddArg(parser_->source_location_line_number_key_id_,
1188 Variadic::UnsignedInteger(line_number));
1189 return util::OkStatus();
1190 }
1191
Eric Seckler926b3372020-03-06 16:17:53 +00001192 util::Status ParseLogMessage(ConstBytes blob, BoundInserter* inserter) {
1193 if (!utid_)
1194 return util::ErrStatus("LogMessage without thread association");
1195
1196 protos::pbzero::LogMessage::Decoder message(blob);
1197
1198 StringId log_message_id = kNullStringId;
1199
1200 auto* decoder = sequence_state_->LookupInternedMessage<
1201 protos::pbzero::InternedData::kLogMessageBodyFieldNumber,
1202 protos::pbzero::LogMessageBody>(message.body_iid());
1203 if (!decoder)
1204 return util::ErrStatus("LogMessage with invalid body_iid");
1205
1206 log_message_id = storage_->InternString(decoder->body());
1207
1208 // TODO(nicomazz): LogMessage also contains the source of the message (file
1209 // and line number). Android logs doesn't support this so far.
1210 storage_->mutable_android_log_table()->Insert(
1211 {ts_, *utid_,
1212 /*priority*/ 0,
1213 /*tag_id*/ kNullStringId, // TODO(nicomazz): Abuse tag_id to display
1214 // "file_name:line_number".
1215 log_message_id});
1216
1217 inserter->AddArg(parser_->log_message_body_key_id_,
1218 Variadic::String(log_message_id));
1219 // TODO(nicomazz): Add the source location as an argument.
1220 return util::OkStatus();
1221 }
1222
nuwandab14efd32020-09-28 11:19:40 +00001223 util::Status ParseHistogramName(ConstBytes blob, BoundInserter* inserter) {
1224 protos::pbzero::ChromeHistogramSample::Decoder sample(blob);
ssid31952bb2021-01-06 10:57:17 -08001225 if (!sample.has_name_iid())
nuwandab14efd32020-09-28 11:19:40 +00001226 return util::OkStatus();
nuwandab14efd32020-09-28 11:19:40 +00001227
1228 if (sample.has_name()) {
1229 return util::ErrStatus(
1230 "name is already set for ChromeHistogramSample: only one of name and "
1231 "name_iid can be set.");
1232 }
1233
1234 auto* decoder = sequence_state_->LookupInternedMessage<
1235 protos::pbzero::InternedData::kHistogramNamesFieldNumber,
1236 protos::pbzero::HistogramName>(sample.name_iid());
1237 if (!decoder)
1238 return util::ErrStatus("HistogramName with invalid name_iid");
1239
1240 inserter->AddArg(parser_->histogram_name_key_id_,
1241 Variadic::String(storage_->InternString(decoder->name())));
1242 return util::OkStatus();
1243 }
1244
Stephen Nuskof848d462021-04-06 13:28:04 +01001245 tables::ThreadSliceTable::Row MakeThreadSliceRow() {
1246 tables::ThreadSliceTable::Row row;
1247 row.ts = ts_;
1248 row.track_id = track_id_;
1249 row.category = category_id_;
1250 row.name = name_id_;
1251 row.thread_ts = event_data_->thread_timestamp;
1252 row.thread_dur = base::nullopt;
1253 row.thread_instruction_count = event_data_->thread_instruction_count;
1254 row.thread_instruction_delta = base::nullopt;
1255 return row;
1256 }
1257
Eric Seckler926b3372020-03-06 16:17:53 +00001258 TraceProcessorContext* context_;
Lalit Maganti62b741f2020-12-10 18:24:00 +00001259 TrackEventTracker* track_event_tracker_;
Eric Seckler926b3372020-03-06 16:17:53 +00001260 TraceStorage* storage_;
1261 TrackEventParser* parser_;
1262 int64_t ts_;
1263 TrackEventData* event_data_;
1264 PacketSequenceStateGeneration* sequence_state_;
1265 ConstBytes blob_;
1266 TrackEvent::Decoder event_;
1267 LegacyEvent::Decoder legacy_event_;
1268 protos::pbzero::TrackEventDefaults::Decoder* defaults_;
1269
1270 // Importing state.
1271 StringId category_id_;
1272 StringId name_id_;
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001273 uint64_t track_uuid_;
Eric Seckler926b3372020-03-06 16:17:53 +00001274 TrackId track_id_;
1275 base::Optional<UniqueTid> utid_;
1276 base::Optional<UniqueTid> upid_;
1277 // All events in legacy JSON require a thread ID, but for some types of
1278 // events (e.g. async events or process/global-scoped instants), we don't
1279 // store it in the slice/track model. To pass the utid through to the json
1280 // export, we store it in an arg.
1281 base::Optional<UniqueTid> legacy_passthrough_utid_;
1282};
1283
Lalit Maganti62b741f2020-12-10 18:24:00 +00001284TrackEventParser::TrackEventParser(TraceProcessorContext* context,
1285 TrackEventTracker* track_event_tracker)
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001286 : args_parser_(*context->descriptor_pool_.get()),
1287 context_(context),
Lalit Maganti62b741f2020-12-10 18:24:00 +00001288 track_event_tracker_(track_event_tracker),
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001289 counter_name_thread_time_id_(
1290 context->storage->InternString("thread_time")),
1291 counter_name_thread_instruction_count_id_(
1292 context->storage->InternString("thread_instruction_count")),
Eric Seckler771960c2019-10-22 15:37:12 +01001293 task_file_name_args_key_id_(
1294 context->storage->InternString("task.posted_from.file_name")),
1295 task_function_name_args_key_id_(
1296 context->storage->InternString("task.posted_from.function_name")),
1297 task_line_number_args_key_id_(
1298 context->storage->InternString("task.posted_from.line_number")),
1299 log_message_body_key_id_(
1300 context->storage->InternString("track_event.log_message")),
ssid9add2ec2021-03-04 13:06:12 -08001301 source_location_function_name_key_id_(
1302 context->storage->InternString("source.function_name")),
1303 source_location_file_name_key_id_(
1304 context->storage->InternString("source.file_name")),
1305 source_location_line_number_key_id_(
1306 context->storage->InternString("source.line_number")),
Eric Seckler771960c2019-10-22 15:37:12 +01001307 raw_legacy_event_id_(
1308 context->storage->InternString("track_event.legacy_event")),
Eric Secklerbb0e1542020-01-16 13:44:13 +00001309 legacy_event_passthrough_utid_id_(
1310 context->storage->InternString("legacy_event.passthrough_utid")),
Eric Seckler771960c2019-10-22 15:37:12 +01001311 legacy_event_category_key_id_(
1312 context->storage->InternString("legacy_event.category")),
1313 legacy_event_name_key_id_(
1314 context->storage->InternString("legacy_event.name")),
1315 legacy_event_phase_key_id_(
1316 context->storage->InternString("legacy_event.phase")),
1317 legacy_event_duration_ns_key_id_(
1318 context->storage->InternString("legacy_event.duration_ns")),
1319 legacy_event_thread_timestamp_ns_key_id_(
1320 context->storage->InternString("legacy_event.thread_timestamp_ns")),
1321 legacy_event_thread_duration_ns_key_id_(
1322 context->storage->InternString("legacy_event.thread_duration_ns")),
1323 legacy_event_thread_instruction_count_key_id_(
1324 context->storage->InternString(
1325 "legacy_event.thread_instruction_count")),
1326 legacy_event_thread_instruction_delta_key_id_(
1327 context->storage->InternString(
1328 "legacy_event.thread_instruction_delta")),
1329 legacy_event_use_async_tts_key_id_(
1330 context->storage->InternString("legacy_event.use_async_tts")),
1331 legacy_event_unscoped_id_key_id_(
1332 context->storage->InternString("legacy_event.unscoped_id")),
1333 legacy_event_global_id_key_id_(
1334 context->storage->InternString("legacy_event.global_id")),
1335 legacy_event_local_id_key_id_(
1336 context->storage->InternString("legacy_event.local_id")),
1337 legacy_event_id_scope_key_id_(
1338 context->storage->InternString("legacy_event.id_scope")),
1339 legacy_event_bind_id_key_id_(
1340 context->storage->InternString("legacy_event.bind_id")),
1341 legacy_event_bind_to_enclosing_key_id_(
1342 context->storage->InternString("legacy_event.bind_to_enclosing")),
1343 legacy_event_flow_direction_key_id_(
1344 context->storage->InternString("legacy_event.flow_direction")),
nuwandab14efd32020-09-28 11:19:40 +00001345 histogram_name_key_id_(
1346 context->storage->InternString("chrome_histogram_sample.name")),
Eric Seckler771960c2019-10-22 15:37:12 +01001347 flow_direction_value_in_id_(context->storage->InternString("in")),
1348 flow_direction_value_out_id_(context->storage->InternString("out")),
Eric Secklere1e8ff42019-12-04 11:05:43 +00001349 flow_direction_value_inout_id_(context->storage->InternString("inout")),
Eric Secklere1e8ff42019-12-04 11:05:43 +00001350 chrome_legacy_ipc_class_args_key_id_(
1351 context->storage->InternString("legacy_ipc.class")),
1352 chrome_legacy_ipc_line_args_key_id_(
1353 context->storage->InternString("legacy_ipc.line")),
Eric Secklerfbbf0222020-07-23 17:26:29 +01001354 chrome_host_app_package_name_id_(
1355 context->storage->InternString("chrome.host_app_package_name")),
ssida1104602021-03-10 11:47:05 -08001356 chrome_crash_trace_id_name_id_(
1357 context->storage->InternString("chrome.crash_trace_id")),
Oystein Eftevaag8e39ed82021-03-30 13:52:58 -07001358 chrome_string_lookup_(context->storage.get()),
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001359 counter_unit_ids_{{kNullStringId, context_->storage->InternString("ns"),
1360 context_->storage->InternString("count"),
1361 context_->storage->InternString("bytes")}} {
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001362 // Switch |source_location_iid| into its interned data variant.
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001363 args_parser_.AddParsingOverride(
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001364 "begin_impl_frame_args.current_args.source_location_iid",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001365 [](const protozero::Field& field,
1366 util::ProtoToArgsParser::Delegate& delegate) {
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001367 return MaybeParseSourceLocation("begin_impl_frame_args.current_args",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001368 field, delegate);
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001369 });
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001370 args_parser_.AddParsingOverride(
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001371 "begin_impl_frame_args.last_args.source_location_iid",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001372 [](const protozero::Field& field,
1373 util::ProtoToArgsParser::Delegate& delegate) {
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001374 return MaybeParseSourceLocation("begin_impl_frame_args.last_args",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001375 field, delegate);
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001376 });
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001377 args_parser_.AddParsingOverride(
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001378 "begin_frame_observer_state.last_begin_frame_args.source_location_iid",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001379 [](const protozero::Field& field,
1380 util::ProtoToArgsParser::Delegate& delegate) {
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001381 return MaybeParseSourceLocation(
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001382 "begin_frame_observer_state.last_begin_frame_args", field,
1383 delegate);
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001384 });
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001385 args_parser_.AddParsingOverride(
Andrew Shulaevc758c7e2021-04-07 13:27:20 +01001386 "chrome_memory_pressure_notification.creation_location_iid",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001387 [](const protozero::Field& field,
1388 util::ProtoToArgsParser::Delegate& delegate) {
Andrew Shulaevc758c7e2021-04-07 13:27:20 +01001389 return MaybeParseSourceLocation("chrome_memory_pressure_notification",
Alexander Timin5a99b5c2021-05-11 22:48:07 +00001390 field, delegate);
Andrew Shulaevc758c7e2021-04-07 13:27:20 +01001391 });
Andrew Shulaev31bc1bc2020-04-30 12:57:09 +01001392
1393 for (uint16_t index : kReflectFields) {
1394 reflect_fields_.push_back(index);
1395 }
Andrew Shulaeve80864c2020-03-05 15:41:09 +00001396}
Eric Seckler3183c6d2020-01-14 15:45:20 +00001397
1398void TrackEventParser::ParseTrackDescriptor(
1399 protozero::ConstBytes track_descriptor) {
1400 protos::pbzero::TrackDescriptor::Decoder decoder(track_descriptor);
1401
1402 // Ensure that the track and its parents are resolved. This may start a new
1403 // process and/or thread (i.e. new upid/utid).
Lalit Maganti62b741f2020-12-10 18:24:00 +00001404 TrackId track_id = *track_event_tracker_->GetDescriptorTrack(decoder.uuid());
Eric Seckler3183c6d2020-01-14 15:45:20 +00001405
Eric Seckler3183c6d2020-01-14 15:45:20 +00001406 if (decoder.has_thread()) {
1407 UniqueTid utid = ParseThreadDescriptor(decoder.thread());
1408 if (decoder.has_chrome_thread())
1409 ParseChromeThreadDescriptor(utid, decoder.chrome_thread());
Eric Seckler926b3372020-03-06 16:17:53 +00001410 } else if (decoder.has_process()) {
1411 UniquePid upid = ParseProcessDescriptor(decoder.process());
1412 if (decoder.has_chrome_process())
1413 ParseChromeProcessDescriptor(upid, decoder.chrome_process());
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001414 } else if (decoder.has_counter()) {
1415 ParseCounterDescriptor(track_id, decoder.counter());
Eric Seckler3183c6d2020-01-14 15:45:20 +00001416 }
1417
Eric Secklerf1497812020-04-30 10:43:23 +01001418 // Override the name with the most recent name seen (after sorting by ts).
Eric Seckler3183c6d2020-01-14 15:45:20 +00001419 if (decoder.has_name()) {
1420 auto* tracks = context_->storage->mutable_track_table();
1421 StringId name_id = context_->storage->InternString(decoder.name());
1422 tracks->mutable_name()->Set(*tracks->id().IndexOf(track_id), name_id);
1423 }
1424}
1425
1426UniquePid TrackEventParser::ParseProcessDescriptor(
1427 protozero::ConstBytes process_descriptor) {
1428 protos::pbzero::ProcessDescriptor::Decoder decoder(process_descriptor);
1429 UniquePid upid = context_->process_tracker->GetOrCreateProcess(
1430 static_cast<uint32_t>(decoder.pid()));
Eric Seckler612949e2020-01-24 09:36:26 +00001431 if (decoder.has_process_name() && decoder.process_name().size) {
Eric Seckler3183c6d2020-01-14 15:45:20 +00001432 // Don't override system-provided names.
1433 context_->process_tracker->SetProcessNameIfUnset(
1434 upid, context_->storage->InternString(decoder.process_name()));
1435 }
Salvador Guerrero22b9be52021-02-11 15:41:05 -08001436 if (decoder.has_start_timestamp_ns() && decoder.start_timestamp_ns() > 0) {
1437 context_->process_tracker->SetStartTsIfUnset(upid,
1438 decoder.start_timestamp_ns());
1439 }
Eric Seckler3183c6d2020-01-14 15:45:20 +00001440 // TODO(skyostil): Remove parsing for legacy chrome_process_type field.
1441 if (decoder.has_chrome_process_type()) {
Oystein Eftevaag8e39ed82021-03-30 13:52:58 -07001442 StringId name_id =
1443 chrome_string_lookup_.GetProcessName(decoder.chrome_process_type());
Eric Seckler3183c6d2020-01-14 15:45:20 +00001444 // Don't override system-provided names.
1445 context_->process_tracker->SetProcessNameIfUnset(upid, name_id);
1446 }
1447 return upid;
1448}
1449
1450void TrackEventParser::ParseChromeProcessDescriptor(
1451 UniquePid upid,
1452 protozero::ConstBytes chrome_process_descriptor) {
1453 protos::pbzero::ChromeProcessDescriptor::Decoder decoder(
1454 chrome_process_descriptor);
Eric Secklerfbbf0222020-07-23 17:26:29 +01001455
Oystein Eftevaag8e39ed82021-03-30 13:52:58 -07001456 StringId name_id =
1457 chrome_string_lookup_.GetProcessName(decoder.process_type());
Eric Seckler3183c6d2020-01-14 15:45:20 +00001458 // Don't override system-provided names.
1459 context_->process_tracker->SetProcessNameIfUnset(upid, name_id);
Eric Secklerfbbf0222020-07-23 17:26:29 +01001460
ssida1104602021-03-10 11:47:05 -08001461 ArgsTracker::BoundInserter process_args =
1462 context_->process_tracker->AddArgsTo(upid);
Eric Secklerfbbf0222020-07-23 17:26:29 +01001463 if (decoder.has_host_app_package_name()) {
Eric Secklerfbbf0222020-07-23 17:26:29 +01001464 process_args.AddArg(chrome_host_app_package_name_id_,
1465 Variadic::String(context_->storage->InternString(
1466 decoder.host_app_package_name())));
1467 }
ssida1104602021-03-10 11:47:05 -08001468 if (decoder.has_crash_trace_id()) {
1469 process_args.AddArg(chrome_crash_trace_id_name_id_,
1470 Variadic::UnsignedInteger(decoder.crash_trace_id()));
1471 }
Eric Seckler3183c6d2020-01-14 15:45:20 +00001472}
1473
Mikhail Khokhlov642b8352020-07-24 10:04:39 +01001474UniqueTid TrackEventParser::ParseThreadDescriptor(
Eric Seckler3183c6d2020-01-14 15:45:20 +00001475 protozero::ConstBytes thread_descriptor) {
1476 protos::pbzero::ThreadDescriptor::Decoder decoder(thread_descriptor);
Mikhail Khokhlov642b8352020-07-24 10:04:39 +01001477 UniqueTid utid = context_->process_tracker->UpdateThread(
1478 static_cast<uint32_t>(decoder.tid()),
1479 static_cast<uint32_t>(decoder.pid()));
Eric Seckler3183c6d2020-01-14 15:45:20 +00001480 StringId name_id = kNullStringId;
Eric Seckler612949e2020-01-24 09:36:26 +00001481 if (decoder.has_thread_name() && decoder.thread_name().size) {
Eric Seckler3183c6d2020-01-14 15:45:20 +00001482 name_id = context_->storage->InternString(decoder.thread_name());
1483 } else if (decoder.has_chrome_thread_type()) {
1484 // TODO(skyostil): Remove parsing for legacy chrome_thread_type field.
Oystein Eftevaag8e39ed82021-03-30 13:52:58 -07001485 name_id = chrome_string_lookup_.GetThreadName(decoder.chrome_thread_type());
Eric Seckler3183c6d2020-01-14 15:45:20 +00001486 }
Mikhail Khokhlov642b8352020-07-24 10:04:39 +01001487 context_->process_tracker->UpdateThreadNameByUtid(
1488 utid, name_id, ThreadNamePriority::kTrackDescriptor);
1489 return utid;
Eric Seckler3183c6d2020-01-14 15:45:20 +00001490}
1491
1492void TrackEventParser::ParseChromeThreadDescriptor(
Mikhail Khokhlov642b8352020-07-24 10:04:39 +01001493 UniqueTid utid,
Eric Seckler3183c6d2020-01-14 15:45:20 +00001494 protozero::ConstBytes chrome_thread_descriptor) {
1495 protos::pbzero::ChromeThreadDescriptor::Decoder decoder(
1496 chrome_thread_descriptor);
1497 if (!decoder.has_thread_type())
1498 return;
1499
Oystein Eftevaag8e39ed82021-03-30 13:52:58 -07001500 StringId name_id = chrome_string_lookup_.GetThreadName(decoder.thread_type());
Mikhail Khokhlov642b8352020-07-24 10:04:39 +01001501 context_->process_tracker->UpdateThreadNameByUtid(
1502 utid, name_id, ThreadNamePriority::kTrackDescriptorThreadType);
Eric Seckler3183c6d2020-01-14 15:45:20 +00001503}
Eric Seckler771960c2019-10-22 15:37:12 +01001504
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001505void TrackEventParser::ParseCounterDescriptor(
1506 TrackId track_id,
1507 protozero::ConstBytes counter_descriptor) {
1508 using protos::pbzero::CounterDescriptor;
1509
1510 CounterDescriptor::Decoder decoder(counter_descriptor);
1511 auto* counter_tracks = context_->storage->mutable_counter_track_table();
1512
1513 size_t unit_index = static_cast<size_t>(decoder.unit());
1514 if (unit_index >= counter_unit_ids_.size())
1515 unit_index = CounterDescriptor::UNIT_UNSPECIFIED;
1516
Florian Mayerc5ee4952020-07-08 16:05:48 +01001517 auto opt_track_idx = counter_tracks->id().IndexOf(track_id);
1518 if (!opt_track_idx) {
1519 context_->storage->IncrementStats(stats::track_event_parser_errors);
1520 return;
1521 }
1522
1523 auto track_idx = *opt_track_idx;
1524
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001525 switch (decoder.type()) {
1526 case CounterDescriptor::COUNTER_UNSPECIFIED:
1527 break;
1528 case CounterDescriptor::COUNTER_THREAD_TIME_NS:
1529 unit_index = CounterDescriptor::UNIT_TIME_NS;
Florian Mayerc5ee4952020-07-08 16:05:48 +01001530 counter_tracks->mutable_name()->Set(track_idx,
1531 counter_name_thread_time_id_);
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001532 break;
1533 case CounterDescriptor::COUNTER_THREAD_INSTRUCTION_COUNT:
1534 unit_index = CounterDescriptor::UNIT_COUNT;
1535 counter_tracks->mutable_name()->Set(
Florian Mayerc5ee4952020-07-08 16:05:48 +01001536 track_idx, counter_name_thread_instruction_count_id_);
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001537 break;
1538 }
1539
Florian Mayerc5ee4952020-07-08 16:05:48 +01001540 counter_tracks->mutable_unit()->Set(track_idx, counter_unit_ids_[unit_index]);
Eric Secklerfbd9aed2020-03-10 18:07:38 +00001541}
1542
Eric Seckler926b3372020-03-06 16:17:53 +00001543void TrackEventParser::ParseTrackEvent(int64_t ts,
1544 TrackEventData* event_data,
1545 ConstBytes blob) {
1546 util::Status status =
1547 EventImporter(this, ts, event_data, std::move(blob)).Import();
1548 if (!status.ok()) {
Eric Seckler771960c2019-10-22 15:37:12 +01001549 context_->storage->IncrementStats(stats::track_event_parser_errors);
Eric Seckler411e9c82020-05-04 13:36:25 +01001550 PERFETTO_DLOG("ParseTrackEvent error: %s", status.c_message());
Oystein Eftevaagd3369062019-12-18 11:33:42 -08001551 }
1552}
1553
Eric Seckler771960c2019-10-22 15:37:12 +01001554} // namespace trace_processor
1555} // namespace perfetto