1 /*
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
19 #include <string>
20
21 #include "perfetto/base/logging.h"
22 #include "perfetto/ext/base/string_writer.h"
23 #include "perfetto/trace_processor/status.h"
24 #include "src/trace_processor/args_tracker.h"
25 #include "src/trace_processor/event_tracker.h"
26 #include "src/trace_processor/importers/json/json_utils.h"
27 #include "src/trace_processor/importers/proto/args_table_utils.h"
28 #include "src/trace_processor/importers/proto/packet_sequence_state.h"
29 #include "src/trace_processor/importers/proto/track_event.descriptor.h"
30 #include "src/trace_processor/process_tracker.h"
31 #include "src/trace_processor/status_macros.h"
32 #include "src/trace_processor/track_tracker.h"
33
34 #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
35 #include "protos/perfetto/trace/track_event/chrome_compositor_scheduler_state.pbzero.h"
36 #include "protos/perfetto/trace/track_event/chrome_histogram_sample.pbzero.h"
37 #include "protos/perfetto/trace/track_event/chrome_keyed_service.pbzero.h"
38 #include "protos/perfetto/trace/track_event/chrome_latency_info.pbzero.h"
39 #include "protos/perfetto/trace/track_event/chrome_legacy_ipc.pbzero.h"
40 #include "protos/perfetto/trace/track_event/chrome_process_descriptor.pbzero.h"
41 #include "protos/perfetto/trace/track_event/chrome_thread_descriptor.pbzero.h"
42 #include "protos/perfetto/trace/track_event/chrome_user_event.pbzero.h"
43 #include "protos/perfetto/trace/track_event/counter_descriptor.pbzero.h"
44 #include "protos/perfetto/trace/track_event/debug_annotation.pbzero.h"
45 #include "protos/perfetto/trace/track_event/log_message.pbzero.h"
46 #include "protos/perfetto/trace/track_event/process_descriptor.pbzero.h"
47 #include "protos/perfetto/trace/track_event/source_location.pbzero.h"
48 #include "protos/perfetto/trace/track_event/task_execution.pbzero.h"
49 #include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
50 #include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
51 #include "protos/perfetto/trace/track_event/track_event.pbzero.h"
52
53 namespace perfetto {
54 namespace trace_processor {
55
56 namespace {
57 using BoundInserter = ArgsTracker::BoundInserter;
58 using protos::pbzero::TrackEvent;
59 using LegacyEvent = TrackEvent::LegacyEvent;
60 using protozero::ConstBytes;
61
62 // Slices which have been opened but haven't been closed yet will be marked
63 // with these placeholder values.
64 constexpr int64_t kPendingThreadDuration = -1;
65 constexpr int64_t kPendingThreadInstructionDelta = -1;
66
AddStringToArgsTable(const char * field,const protozero::ConstChars & str,const ProtoToArgsTable::ParsingOverrideState & state,BoundInserter * inserter)67 void AddStringToArgsTable(const char* field,
68 const protozero::ConstChars& str,
69 const ProtoToArgsTable::ParsingOverrideState& state,
70 BoundInserter* inserter) {
71 auto val = state.context->storage->InternString(base::StringView(str));
72 auto key = state.context->storage->InternString(base::StringView(field));
73 inserter->AddArg(key, Variadic::String(val));
74 }
75
MaybeParseSourceLocation(std::string prefix,const ProtoToArgsTable::ParsingOverrideState & state,const protozero::Field & field,BoundInserter * inserter)76 bool MaybeParseSourceLocation(
77 std::string prefix,
78 const ProtoToArgsTable::ParsingOverrideState& state,
79 const protozero::Field& field,
80 BoundInserter* inserter) {
81 auto* decoder = state.sequence_state->LookupInternedMessage<
82 protos::pbzero::InternedData::kSourceLocationsFieldNumber,
83 protos::pbzero::SourceLocation>(field.as_uint64());
84 if (!decoder) {
85 // Lookup failed fall back on default behaviour which will just put
86 // the source_location_iid into the args table.
87 return false;
88 }
89 {
90 ProtoToArgsTable::ScopedStringAppender scoped("file_name", &prefix);
91 AddStringToArgsTable(prefix.c_str(), decoder->file_name(), state, inserter);
92 }
93 {
94 ProtoToArgsTable::ScopedStringAppender scoped("function_name", &prefix);
95 AddStringToArgsTable(prefix.c_str(), decoder->function_name(), state,
96 inserter);
97 }
98 ProtoToArgsTable::ScopedStringAppender scoped("line_number", &prefix);
99 auto key = state.context->storage->InternString(base::StringView(prefix));
100 inserter->AddArg(key, Variadic::Integer(decoder->line_number()));
101 // By returning false we expect this field to be handled like regular.
102 return true;
103 }
104
SafeDebugAnnotationName(const std::string & raw_name)105 std::string SafeDebugAnnotationName(const std::string& raw_name) {
106 std::string result = raw_name;
107 std::replace(result.begin(), result.end(), '.', '_');
108 std::replace(result.begin(), result.end(), '[', '_');
109 std::replace(result.begin(), result.end(), ']', '_');
110 result = "debug." + result;
111 return result;
112 }
113 } // namespace
114
115 class TrackEventParser::EventImporter {
116 public:
EventImporter(TrackEventParser * parser,int64_t ts,TrackEventData * event_data,ConstBytes blob)117 EventImporter(TrackEventParser* parser,
118 int64_t ts,
119 TrackEventData* event_data,
120 ConstBytes blob)
121 : context_(parser->context_),
122 storage_(context_->storage.get()),
123 parser_(parser),
124 ts_(ts),
125 event_data_(event_data),
126 sequence_state_(event_data_->sequence_state),
127 blob_(std::move(blob)),
128 event_(blob_),
129 legacy_event_(event_.legacy_event()),
130 defaults_(sequence_state_->GetTrackEventDefaults()) {}
131
Import()132 util::Status Import() {
133 // TODO(eseckler): This legacy event field will eventually be replaced by
134 // fields in TrackEvent itself.
135 if (PERFETTO_UNLIKELY(!event_.type() && !legacy_event_.has_phase()))
136 return util::ErrStatus("TrackEvent without type or phase");
137
138 category_id_ = ParseTrackEventCategory();
139 name_id_ = ParseTrackEventName();
140
141 RETURN_IF_ERROR(ParseTrackAssociation());
142
143 // Counter-type events don't support arguments (those are on the
144 // CounterDescriptor instead). All they have is a |counter_value|.
145 if (event_.type() == TrackEvent::TYPE_COUNTER) {
146 ParseCounterEvent();
147 return util::OkStatus();
148 }
149
150 // Parse extra counter values before parsing the actual event. This way, we
151 // can update the slice's thread time / instruction count fields based on
152 // these counter values.
153 ParseExtraCounterValues();
154
155 // TODO(eseckler): Replace phase with type and remove handling of
156 // legacy_event_.phase() once it is no longer used by producers.
157 int32_t phase = ParsePhaseOrType();
158
159 switch (static_cast<char>(phase)) {
160 case 'B': // TRACE_EVENT_PHASE_BEGIN.
161 return ParseThreadBeginEvent();
162 case 'E': // TRACE_EVENT_PHASE_END.
163 return ParseThreadEndEvent();
164 case 'X': // TRACE_EVENT_PHASE_COMPLETE.
165 return ParseThreadCompleteEvent();
166 case 'i':
167 case 'I': // TRACE_EVENT_PHASE_INSTANT.
168 return ParseThreadInstantEvent();
169 case 'b': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_BEGIN
170 return ParseAsyncBeginEvent();
171 case 'e': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_END
172 return ParseAsyncEndEvent();
173 case 'n': // TRACE_EVENT_PHASE_NESTABLE_ASYNC_INSTANT
174 return ParseAsyncInstantEvent();
175 case 'M': // TRACE_EVENT_PHASE_METADATA (process and thread names).
176 return ParseMetadataEvent();
177 default:
178 // Other events are proxied via the raw table for JSON export.
179 return ParseLegacyEventAsRawEvent();
180 }
181 }
182
183 private:
ParseTrackEventCategory()184 StringId ParseTrackEventCategory() {
185 StringId category_id = kNullStringId;
186
187 std::vector<uint64_t> category_iids;
188 for (auto it = event_.category_iids(); it; ++it) {
189 category_iids.push_back(*it);
190 }
191 std::vector<protozero::ConstChars> category_strings;
192 for (auto it = event_.categories(); it; ++it) {
193 category_strings.push_back(*it);
194 }
195
196 // If there's a single category, we can avoid building a concatenated
197 // string.
198 if (PERFETTO_LIKELY(category_iids.size() == 1 &&
199 category_strings.empty())) {
200 auto* decoder = sequence_state_->LookupInternedMessage<
201 protos::pbzero::InternedData::kEventCategoriesFieldNumber,
202 protos::pbzero::EventCategory>(category_iids[0]);
203 if (decoder) {
204 category_id = storage_->InternString(decoder->name());
205 } else {
206 char buffer[32];
207 base::StringWriter writer(buffer, sizeof(buffer));
208 writer.AppendLiteral("unknown(");
209 writer.AppendUnsignedInt(category_iids[0]);
210 writer.AppendChar(')');
211 category_id = storage_->InternString(writer.GetStringView());
212 }
213 } else if (category_iids.empty() && category_strings.size() == 1) {
214 category_id = storage_->InternString(category_strings[0]);
215 } else if (category_iids.size() + category_strings.size() > 1) {
216 // We concatenate the category strings together since we currently only
217 // support a single "cat" column.
218 // TODO(eseckler): Support multi-category events in the table schema.
219 std::string categories;
220 for (uint64_t iid : category_iids) {
221 auto* decoder = sequence_state_->LookupInternedMessage<
222 protos::pbzero::InternedData::kEventCategoriesFieldNumber,
223 protos::pbzero::EventCategory>(iid);
224 if (!decoder)
225 continue;
226 base::StringView name = decoder->name();
227 if (!categories.empty())
228 categories.append(",");
229 categories.append(name.data(), name.size());
230 }
231 for (const protozero::ConstChars& cat : category_strings) {
232 if (!categories.empty())
233 categories.append(",");
234 categories.append(cat.data, cat.size);
235 }
236 if (!categories.empty())
237 category_id = storage_->InternString(base::StringView(categories));
238 }
239
240 return category_id;
241 }
242
ParseTrackEventName()243 StringId ParseTrackEventName() {
244 uint64_t name_iid = event_.name_iid();
245 if (!name_iid)
246 name_iid = legacy_event_.name_iid();
247
248 if (PERFETTO_LIKELY(name_iid)) {
249 auto* decoder = sequence_state_->LookupInternedMessage<
250 protos::pbzero::InternedData::kEventNamesFieldNumber,
251 protos::pbzero::EventName>(name_iid);
252 if (decoder)
253 return storage_->InternString(decoder->name());
254 } else if (event_.has_name()) {
255 return storage_->InternString(event_.name());
256 }
257
258 return kNullStringId;
259 }
260
ParseTrackAssociation()261 util::Status ParseTrackAssociation() {
262 TrackTracker* track_tracker = context_->track_tracker.get();
263 ProcessTracker* procs = context_->process_tracker.get();
264
265 // Consider track_uuid from the packet and TrackEventDefaults, fall back to
266 // the default descriptor track (uuid 0).
267 track_uuid_ = event_.has_track_uuid()
268 ? event_.track_uuid()
269 : (defaults_ && defaults_->has_track_uuid()
270 ? defaults_->track_uuid()
271 : 0u);
272
273 // Determine track from track_uuid specified in either TrackEvent or
274 // TrackEventDefaults. If a non-default track is not set, we either:
275 // a) fall back to the track specified by the sequence's (or event's) pid
276 // +
277 // tid (only in case of legacy tracks/events, i.e. events that don't
278 // specify an explicit track uuid or use legacy event phases instead of
279 // TrackEvent types), or
280 // b) a default track.
281 if (track_uuid_) {
282 base::Optional<TrackId> opt_track_id =
283 track_tracker->GetDescriptorTrack(track_uuid_);
284 if (!opt_track_id) {
285 return util::ErrStatus("TrackEvent with unknown track_uuid %" PRIu64,
286 track_uuid_);
287 }
288 track_id_ = *opt_track_id;
289
290 auto thread_track_row =
291 storage_->thread_track_table().id().IndexOf(track_id_);
292 if (thread_track_row) {
293 utid_ = storage_->thread_track_table().utid()[*thread_track_row];
294 upid_ = storage_->thread_table().upid()[*utid_];
295 } else {
296 auto process_track_row =
297 storage_->process_track_table().id().IndexOf(track_id_);
298 if (process_track_row) {
299 upid_ = storage_->process_track_table().upid()[*process_track_row];
300 if (sequence_state_->state()->pid_and_tid_valid()) {
301 uint32_t pid =
302 static_cast<uint32_t>(sequence_state_->state()->pid());
303 uint32_t tid =
304 static_cast<uint32_t>(sequence_state_->state()->tid());
305 UniqueTid utid_candidate = procs->UpdateThread(tid, pid);
306 if (storage_->thread_table().upid()[utid_candidate] == upid_)
307 legacy_passthrough_utid_ = utid_candidate;
308 }
309 }
310 }
311 } else {
312 bool pid_tid_state_valid = sequence_state_->state()->pid_and_tid_valid();
313
314 // We have a 0-value |track_uuid|. Nevertheless, we should only fall back
315 // if we have either no |track_uuid| specified at all or |track_uuid| was
316 // set explicitly to 0 (e.g. to override a default track_uuid) and we have
317 // a legacy phase. Events with real phases should use |track_uuid| to
318 // specify a different track (or use the pid/tid_override fields).
319 bool fallback_to_legacy_pid_tid_tracks =
320 (!event_.has_track_uuid() || !event_.has_type()) &&
321 pid_tid_state_valid;
322
323 // Always allow fallback if we have a process override.
324 fallback_to_legacy_pid_tid_tracks |= legacy_event_.has_pid_override();
325
326 // A thread override requires a valid pid.
327 fallback_to_legacy_pid_tid_tracks |=
328 legacy_event_.has_tid_override() && pid_tid_state_valid;
329
330 if (fallback_to_legacy_pid_tid_tracks) {
331 uint32_t pid = static_cast<uint32_t>(sequence_state_->state()->pid());
332 uint32_t tid = static_cast<uint32_t>(sequence_state_->state()->tid());
333 if (legacy_event_.has_pid_override()) {
334 pid = static_cast<uint32_t>(legacy_event_.pid_override());
335 tid = static_cast<uint32_t>(-1);
336 }
337 if (legacy_event_.has_tid_override())
338 tid = static_cast<uint32_t>(legacy_event_.tid_override());
339
340 utid_ = procs->UpdateThread(tid, pid);
341 upid_ = storage_->thread_table().upid()[*utid_];
342 track_id_ = track_tracker->InternThreadTrack(*utid_);
343 } else {
344 track_id_ = track_tracker->GetOrCreateDefaultDescriptorTrack();
345 }
346 }
347
348 if (!legacy_event_.has_phase())
349 return util::OkStatus();
350
351 // Legacy phases may imply a different track than the one specified by
352 // the fallback (or default track uuid) above.
353 switch (legacy_event_.phase()) {
354 case 'b':
355 case 'e':
356 case 'n': {
357 // Intern tracks for legacy async events based on legacy event ids.
358 int64_t source_id = 0;
359 bool source_id_is_process_scoped = false;
360 if (legacy_event_.has_unscoped_id()) {
361 source_id = static_cast<int64_t>(legacy_event_.unscoped_id());
362 } else if (legacy_event_.has_global_id()) {
363 source_id = static_cast<int64_t>(legacy_event_.global_id());
364 } else if (legacy_event_.has_local_id()) {
365 if (!upid_) {
366 return util::ErrStatus(
367 "TrackEvent with local_id without process association");
368 }
369
370 source_id = static_cast<int64_t>(legacy_event_.local_id());
371 source_id_is_process_scoped = true;
372 } else {
373 return util::ErrStatus("Async LegacyEvent without ID");
374 }
375
376 // Catapult treats nestable async events of different categories with
377 // the same ID as separate tracks. We replicate the same behavior
378 // here.
379 StringId id_scope = category_id_;
380 if (legacy_event_.has_id_scope()) {
381 std::string concat = storage_->GetString(category_id_).ToStdString() +
382 ":" + legacy_event_.id_scope().ToStdString();
383 id_scope = storage_->InternString(base::StringView(concat));
384 }
385
386 track_id_ = context_->track_tracker->InternLegacyChromeAsyncTrack(
387 name_id_, upid_ ? *upid_ : 0, source_id,
388 source_id_is_process_scoped, id_scope);
389 legacy_passthrough_utid_ = utid_;
390 break;
391 }
392 case 'i':
393 case 'I': {
394 // Intern tracks for global or process-scoped legacy instant events.
395 switch (legacy_event_.instant_event_scope()) {
396 case LegacyEvent::SCOPE_UNSPECIFIED:
397 case LegacyEvent::SCOPE_THREAD:
398 // Thread-scoped legacy instant events already have the right
399 // track based on the tid/pid of the sequence.
400 if (!utid_) {
401 return util::ErrStatus(
402 "Thread-scoped instant event without thread association");
403 }
404 break;
405 case LegacyEvent::SCOPE_GLOBAL:
406 track_id_ = context_->track_tracker
407 ->GetOrCreateLegacyChromeGlobalInstantTrack();
408 legacy_passthrough_utid_ = utid_;
409 utid_ = base::nullopt;
410 break;
411 case LegacyEvent::SCOPE_PROCESS:
412 if (!upid_) {
413 return util::ErrStatus(
414 "Process-scoped instant event without process association");
415 }
416
417 track_id_ =
418 context_->track_tracker->InternLegacyChromeProcessInstantTrack(
419 *upid_);
420 legacy_passthrough_utid_ = utid_;
421 utid_ = base::nullopt;
422 break;
423 }
424 break;
425 }
426 default:
427 break;
428 }
429
430 return util::OkStatus();
431 }
432
ParsePhaseOrType()433 int32_t ParsePhaseOrType() {
434 if (legacy_event_.has_phase())
435 return legacy_event_.phase();
436
437 switch (event_.type()) {
438 case TrackEvent::TYPE_SLICE_BEGIN:
439 return utid_ ? 'B' : 'b';
440 case TrackEvent::TYPE_SLICE_END:
441 return utid_ ? 'E' : 'e';
442 case TrackEvent::TYPE_INSTANT:
443 return utid_ ? 'i' : 'n';
444 default:
445 PERFETTO_FATAL("unexpected event type %d", event_.type());
446 return 0;
447 }
448 }
449
ParseCounterEvent()450 void ParseCounterEvent() {
451 // Tokenizer ensures that TYPE_COUNTER events are associated with counter
452 // tracks and have values.
453 PERFETTO_DCHECK(storage_->counter_track_table().id().IndexOf(track_id_));
454 PERFETTO_DCHECK(event_.has_counter_value());
455
456 context_->event_tracker->PushCounter(ts_, event_data_->counter_value,
457 track_id_);
458 }
459
ParseExtraCounterValues()460 void ParseExtraCounterValues() {
461 if (!event_.has_extra_counter_values())
462 return;
463
464 protozero::RepeatedFieldIterator<uint64_t> track_uuid_it;
465 if (event_.has_extra_counter_track_uuids()) {
466 track_uuid_it = event_.extra_counter_track_uuids();
467 } else if (defaults_->has_extra_counter_track_uuids()) {
468 track_uuid_it = defaults_->extra_counter_track_uuids();
469 }
470
471 size_t index = 0;
472 for (auto value_it = event_.extra_counter_values(); value_it;
473 ++value_it, ++track_uuid_it, ++index) {
474 // Tokenizer ensures that there aren't more values than uuids, that we
475 // don't have more values than kMaxNumExtraCounters and that the
476 // track_uuids are for valid counter tracks.
477 PERFETTO_DCHECK(track_uuid_it);
478 PERFETTO_DCHECK(index < TrackEventData::kMaxNumExtraCounters);
479
480 base::Optional<TrackId> track_id =
481 context_->track_tracker->GetDescriptorTrack(*track_uuid_it);
482 base::Optional<uint32_t> counter_row =
483 storage_->counter_track_table().id().IndexOf(*track_id);
484
485 int64_t value = event_data_->extra_counter_values[index];
486 context_->event_tracker->PushCounter(ts_, value, *track_id);
487
488 // Also import thread_time and thread_instruction_count counters into
489 // slice columns to simplify JSON export.
490 StringId counter_name =
491 storage_->counter_track_table().name()[*counter_row];
492 if (counter_name == parser_->counter_name_thread_time_id_) {
493 event_data_->thread_timestamp = value;
494 } else if (counter_name ==
495 parser_->counter_name_thread_instruction_count_id_) {
496 event_data_->thread_instruction_count = value;
497 }
498 }
499 }
500
ParseThreadBeginEvent()501 util::Status ParseThreadBeginEvent() {
502 if (!utid_) {
503 return util::ErrStatus(
504 "TrackEvent with phase B without thread association");
505 }
506
507 auto opt_slice_id = context_->slice_tracker->Begin(
508 ts_, track_id_, category_id_, name_id_,
509 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
510 if (opt_slice_id.has_value()) {
511 auto* thread_slices = storage_->mutable_thread_slices();
512 PERFETTO_DCHECK(!thread_slices->slice_count() ||
513 thread_slices->slice_ids().back() < opt_slice_id.value());
514 thread_slices->AddThreadSlice(
515 opt_slice_id.value(), event_data_->thread_timestamp,
516 kPendingThreadDuration, event_data_->thread_instruction_count,
517 kPendingThreadInstructionDelta);
518 }
519
520 return util::OkStatus();
521 }
522
ParseThreadEndEvent()523 util::Status ParseThreadEndEvent() {
524 if (!utid_) {
525 return util::ErrStatus(
526 "TrackEvent with phase E without thread association");
527 }
528
529 auto opt_slice_id = context_->slice_tracker->End(
530 ts_, track_id_, category_id_, name_id_,
531 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
532 if (opt_slice_id.has_value()) {
533 auto* thread_slices = storage_->mutable_thread_slices();
534 thread_slices->UpdateThreadDeltasForSliceId(
535 opt_slice_id.value(), event_data_->thread_timestamp,
536 event_data_->thread_instruction_count);
537 }
538
539 return util::OkStatus();
540 }
541
ParseThreadCompleteEvent()542 util::Status ParseThreadCompleteEvent() {
543 if (!utid_) {
544 return util::ErrStatus(
545 "TrackEvent with phase X without thread association");
546 }
547
548 auto duration_ns = legacy_event_.duration_us() * 1000;
549 if (duration_ns < 0)
550 return util::ErrStatus("TrackEvent with phase X with negative duration");
551 auto opt_slice_id = context_->slice_tracker->Scoped(
552 ts_, track_id_, category_id_, name_id_, duration_ns,
553 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
554 if (opt_slice_id.has_value()) {
555 auto* thread_slices = storage_->mutable_thread_slices();
556 PERFETTO_DCHECK(!thread_slices->slice_count() ||
557 thread_slices->slice_ids().back() < opt_slice_id.value());
558 auto thread_duration_ns = legacy_event_.thread_duration_us() * 1000;
559 thread_slices->AddThreadSlice(
560 opt_slice_id.value(), event_data_->thread_timestamp,
561 thread_duration_ns, event_data_->thread_instruction_count,
562 legacy_event_.thread_instruction_delta());
563 }
564
565 return util::OkStatus();
566 }
567
ParseThreadInstantEvent()568 util::Status ParseThreadInstantEvent() {
569 // Handle instant events as slices with zero duration, so that they end
570 // up nested underneath their parent slices.
571 int64_t duration_ns = 0;
572 int64_t tidelta = 0;
573 auto opt_slice_id = context_->slice_tracker->Scoped(
574 ts_, track_id_, category_id_, name_id_, duration_ns,
575 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
576 if (utid_ && opt_slice_id.has_value()) {
577 auto* thread_slices = storage_->mutable_thread_slices();
578 PERFETTO_DCHECK(!thread_slices->slice_count() ||
579 thread_slices->slice_ids().back() < opt_slice_id.value());
580 thread_slices->AddThreadSlice(
581 opt_slice_id.value(), event_data_->thread_timestamp, duration_ns,
582 event_data_->thread_instruction_count, tidelta);
583 }
584 return util::OkStatus();
585 }
586
ParseAsyncBeginEvent()587 util::Status ParseAsyncBeginEvent() {
588 auto opt_slice_id = context_->slice_tracker->Begin(
589 ts_, track_id_, category_id_, name_id_,
590 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
591 // For the time beeing, we only create vtrack slice rows if we need to
592 // store thread timestamps/counters.
593 if (legacy_event_.use_async_tts() && opt_slice_id.has_value()) {
594 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
595 PERFETTO_DCHECK(!vtrack_slices->slice_count() ||
596 vtrack_slices->slice_ids().back() < opt_slice_id.value());
597 vtrack_slices->AddVirtualTrackSlice(
598 opt_slice_id.value(), event_data_->thread_timestamp,
599 kPendingThreadDuration, event_data_->thread_instruction_count,
600 kPendingThreadInstructionDelta);
601 }
602 return util::OkStatus();
603 }
604
ParseAsyncEndEvent()605 util::Status ParseAsyncEndEvent() {
606 auto opt_slice_id = context_->slice_tracker->End(
607 ts_, track_id_, category_id_, name_id_,
608 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
609 if (legacy_event_.use_async_tts() && opt_slice_id.has_value()) {
610 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
611 vtrack_slices->UpdateThreadDeltasForSliceId(
612 opt_slice_id.value(), event_data_->thread_timestamp,
613 event_data_->thread_instruction_count);
614 }
615 return util::OkStatus();
616 }
617
ParseAsyncInstantEvent()618 util::Status ParseAsyncInstantEvent() {
619 // Handle instant events as slices with zero duration, so that they end
620 // up nested underneath their parent slices.
621 int64_t duration_ns = 0;
622 int64_t tidelta = 0;
623 auto opt_slice_id = context_->slice_tracker->Scoped(
624 ts_, track_id_, category_id_, name_id_, duration_ns,
625 [this](BoundInserter* inserter) { ParseTrackEventArgs(inserter); });
626 if (legacy_event_.use_async_tts() && opt_slice_id.has_value()) {
627 auto* vtrack_slices = storage_->mutable_virtual_track_slices();
628 PERFETTO_DCHECK(!vtrack_slices->slice_count() ||
629 vtrack_slices->slice_ids().back() < opt_slice_id.value());
630 vtrack_slices->AddVirtualTrackSlice(
631 opt_slice_id.value(), event_data_->thread_timestamp, duration_ns,
632 event_data_->thread_instruction_count, tidelta);
633 }
634 return util::OkStatus();
635 }
636
ParseMetadataEvent()637 util::Status ParseMetadataEvent() {
638 ProcessTracker* procs = context_->process_tracker.get();
639
640 // Parse process and thread names from correspondingly named events.
641 NullTermStringView event_name = storage_->GetString(name_id_);
642 PERFETTO_DCHECK(event_name.data());
643 if (strcmp(event_name.c_str(), "thread_name") == 0) {
644 if (!utid_) {
645 return util::ErrStatus(
646 "thread_name metadata event without thread association");
647 }
648
649 auto it = event_.debug_annotations();
650 if (!it) {
651 return util::ErrStatus(
652 "thread_name metadata event without debug annotations");
653 }
654 protos::pbzero::DebugAnnotation::Decoder annotation(*it);
655 auto thread_name = annotation.string_value();
656 if (!thread_name.size)
657 return util::OkStatus();
658 auto thread_name_id = storage_->InternString(thread_name);
659 // Don't override system-provided names.
660 procs->SetThreadNameIfUnset(*utid_, thread_name_id);
661 return util::OkStatus();
662 }
663 if (strcmp(event_name.c_str(), "process_name") == 0) {
664 if (!upid_) {
665 return util::ErrStatus(
666 "process_name metadata event without process association");
667 }
668
669 auto it = event_.debug_annotations();
670 if (!it) {
671 return util::ErrStatus(
672 "process_name metadata event without debug annotations");
673 }
674 protos::pbzero::DebugAnnotation::Decoder annotation(*it);
675 auto process_name = annotation.string_value();
676 if (!process_name.size)
677 return util::OkStatus();
678 auto process_name_id = storage_->InternString(process_name);
679 // Don't override system-provided names.
680 procs->SetProcessNameIfUnset(*upid_, process_name_id);
681 return util::OkStatus();
682 }
683 // Other metadata events are proxied via the raw table for JSON export.
684 ParseLegacyEventAsRawEvent();
685 return util::OkStatus();
686 }
687
ParseLegacyEventAsRawEvent()688 util::Status ParseLegacyEventAsRawEvent() {
689 if (!utid_)
690 return util::ErrStatus("raw legacy event without thread association");
691
692 RawId id = storage_->mutable_raw_table()
693 ->Insert({ts_, parser_->raw_legacy_event_id_, 0, *utid_})
694 .id;
695
696 ArgsTracker args(context_);
697 auto inserter = args.AddArgsTo(id);
698
699 inserter
700 .AddArg(parser_->legacy_event_category_key_id_,
701 Variadic::String(category_id_))
702 .AddArg(parser_->legacy_event_name_key_id_, Variadic::String(name_id_));
703
704 std::string phase_string(1, static_cast<char>(legacy_event_.phase()));
705 StringId phase_id = storage_->InternString(phase_string.c_str());
706 inserter.AddArg(parser_->legacy_event_phase_key_id_,
707 Variadic::String(phase_id));
708
709 if (legacy_event_.has_duration_us()) {
710 inserter.AddArg(parser_->legacy_event_duration_ns_key_id_,
711 Variadic::Integer(legacy_event_.duration_us() * 1000));
712 }
713
714 if (event_data_->thread_timestamp) {
715 inserter.AddArg(parser_->legacy_event_thread_timestamp_ns_key_id_,
716 Variadic::Integer(event_data_->thread_timestamp));
717 if (legacy_event_.has_thread_duration_us()) {
718 inserter.AddArg(
719 parser_->legacy_event_thread_duration_ns_key_id_,
720 Variadic::Integer(legacy_event_.thread_duration_us() * 1000));
721 }
722 }
723
724 if (event_data_->thread_instruction_count) {
725 inserter.AddArg(parser_->legacy_event_thread_instruction_count_key_id_,
726 Variadic::Integer(event_data_->thread_instruction_count));
727 if (legacy_event_.has_thread_instruction_delta()) {
728 inserter.AddArg(
729 parser_->legacy_event_thread_instruction_delta_key_id_,
730 Variadic::Integer(legacy_event_.thread_instruction_delta()));
731 }
732 }
733
734 if (legacy_event_.use_async_tts()) {
735 inserter.AddArg(parser_->legacy_event_use_async_tts_key_id_,
736 Variadic::Boolean(true));
737 }
738
739 bool has_id = false;
740 if (legacy_event_.has_unscoped_id()) {
741 // Unscoped ids are either global or local depending on the phase. Pass
742 // them through as unscoped IDs to JSON export to preserve this behavior.
743 inserter.AddArg(parser_->legacy_event_unscoped_id_key_id_,
744 Variadic::UnsignedInteger(legacy_event_.unscoped_id()));
745 has_id = true;
746 } else if (legacy_event_.has_global_id()) {
747 inserter.AddArg(parser_->legacy_event_global_id_key_id_,
748 Variadic::UnsignedInteger(legacy_event_.global_id()));
749 has_id = true;
750 } else if (legacy_event_.has_local_id()) {
751 inserter.AddArg(parser_->legacy_event_local_id_key_id_,
752 Variadic::UnsignedInteger(legacy_event_.local_id()));
753 has_id = true;
754 }
755
756 if (has_id && legacy_event_.has_id_scope() &&
757 legacy_event_.id_scope().size) {
758 inserter.AddArg(
759 parser_->legacy_event_id_scope_key_id_,
760 Variadic::String(storage_->InternString(legacy_event_.id_scope())));
761 }
762
763 // No need to parse legacy_event.instant_event_scope() because we import
764 // instant events into the slice table.
765
766 ParseTrackEventArgs(&inserter);
767 return util::OkStatus();
768 }
769
ParseTrackEventArgs(BoundInserter * inserter)770 void ParseTrackEventArgs(BoundInserter* inserter) {
771 auto log_errors = [this](util::Status status) {
772 if (status.ok())
773 return;
774 // Log error but continue parsing the other args.
775 storage_->IncrementStats(stats::track_event_parser_errors);
776 PERFETTO_DLOG("%s", status.c_message());
777 };
778
779 for (auto it = event_.debug_annotations(); it; ++it) {
780 log_errors(ParseDebugAnnotationArgs(*it, inserter));
781 }
782
783 if (event_.has_task_execution()) {
784 log_errors(ParseTaskExecutionArgs(event_.task_execution(), inserter));
785 }
786 if (event_.has_log_message()) {
787 log_errors(ParseLogMessage(event_.log_message(), inserter));
788 }
789 if (event_.has_cc_scheduler_state()) {
790 ParseCcScheduler(event_.cc_scheduler_state(), inserter);
791 }
792 if (event_.has_chrome_user_event()) {
793 ParseChromeUserEvent(event_.chrome_user_event(), inserter);
794 }
795 if (event_.has_chrome_legacy_ipc()) {
796 ParseChromeLegacyIpc(event_.chrome_legacy_ipc(), inserter);
797 }
798 if (event_.has_chrome_keyed_service()) {
799 ParseChromeKeyedService(event_.chrome_keyed_service(), inserter);
800 }
801 if (event_.has_chrome_histogram_sample()) {
802 ParseChromeHistogramSample(event_.chrome_histogram_sample(), inserter);
803 }
804 if (event_.has_chrome_latency_info()) {
805 ParseChromeLatencyInfo(event_.chrome_latency_info(), inserter);
806 }
807
808 if (legacy_passthrough_utid_) {
809 inserter->AddArg(parser_->legacy_event_passthrough_utid_id_,
810 Variadic::UnsignedInteger(*legacy_passthrough_utid_),
811 ArgsTracker::UpdatePolicy::kSkipIfExists);
812 }
813
814 // TODO(eseckler): Parse legacy flow events into flow events table once we
815 // have a design for it.
816 if (legacy_event_.has_bind_id()) {
817 inserter->AddArg(parser_->legacy_event_bind_id_key_id_,
818 Variadic::UnsignedInteger(legacy_event_.bind_id()));
819 }
820
821 if (legacy_event_.bind_to_enclosing()) {
822 inserter->AddArg(parser_->legacy_event_bind_to_enclosing_key_id_,
823 Variadic::Boolean(true));
824 }
825
826 if (legacy_event_.flow_direction()) {
827 StringId value;
828 switch (legacy_event_.flow_direction()) {
829 case LegacyEvent::FLOW_IN:
830 value = parser_->flow_direction_value_in_id_;
831 break;
832 case LegacyEvent::FLOW_OUT:
833 value = parser_->flow_direction_value_out_id_;
834 break;
835 case LegacyEvent::FLOW_INOUT:
836 value = parser_->flow_direction_value_inout_id_;
837 break;
838 default:
839 PERFETTO_FATAL("Unknown flow direction: %d",
840 legacy_event_.flow_direction());
841 break;
842 }
843 inserter->AddArg(parser_->legacy_event_flow_direction_key_id_,
844 Variadic::String(value));
845 }
846 }
847
ParseDebugAnnotationArgs(ConstBytes debug_annotation,BoundInserter * inserter)848 util::Status ParseDebugAnnotationArgs(ConstBytes debug_annotation,
849 BoundInserter* inserter) {
850 protos::pbzero::DebugAnnotation::Decoder annotation(debug_annotation);
851
852 StringId name_id = kNullStringId;
853
854 uint64_t name_iid = annotation.name_iid();
855 if (PERFETTO_LIKELY(name_iid)) {
856 auto* decoder = sequence_state_->LookupInternedMessage<
857 protos::pbzero::InternedData::kDebugAnnotationNamesFieldNumber,
858 protos::pbzero::DebugAnnotationName>(name_iid);
859 if (!decoder)
860 return util::ErrStatus("Debug annotation with invalid name_iid");
861
862 std::string name_prefixed =
863 SafeDebugAnnotationName(decoder->name().ToStdString());
864 name_id = storage_->InternString(base::StringView(name_prefixed));
865 } else if (annotation.has_name()) {
866 name_id = storage_->InternString(annotation.name());
867 } else {
868 return util::ErrStatus("Debug annotation without name");
869 }
870
871 if (annotation.has_bool_value()) {
872 inserter->AddArg(name_id, Variadic::Boolean(annotation.bool_value()));
873 } else if (annotation.has_uint_value()) {
874 inserter->AddArg(name_id,
875 Variadic::UnsignedInteger(annotation.uint_value()));
876 } else if (annotation.has_int_value()) {
877 inserter->AddArg(name_id, Variadic::Integer(annotation.int_value()));
878 } else if (annotation.has_double_value()) {
879 inserter->AddArg(name_id, Variadic::Real(annotation.double_value()));
880 } else if (annotation.has_string_value()) {
881 inserter->AddArg(
882 name_id,
883 Variadic::String(storage_->InternString(annotation.string_value())));
884 } else if (annotation.has_pointer_value()) {
885 inserter->AddArg(name_id, Variadic::Pointer(annotation.pointer_value()));
886 } else if (annotation.has_legacy_json_value()) {
887 if (!json::IsJsonSupported())
888 return util::ErrStatus("Ignoring legacy_json_value (no json support)");
889
890 auto value = json::ParseJsonString(annotation.legacy_json_value());
891 auto name = storage_->GetString(name_id);
892 json::AddJsonValueToArgs(*value, name, name, storage_, inserter);
893 } else if (annotation.has_nested_value()) {
894 auto name = storage_->GetString(name_id);
895 ParseNestedValueArgs(annotation.nested_value(), name, name, inserter);
896 }
897
898 return util::OkStatus();
899 }
900
ParseNestedValueArgs(ConstBytes nested_value,base::StringView flat_key,base::StringView key,BoundInserter * inserter)901 bool ParseNestedValueArgs(ConstBytes nested_value,
902 base::StringView flat_key,
903 base::StringView key,
904 BoundInserter* inserter) {
905 protos::pbzero::DebugAnnotation::NestedValue::Decoder value(nested_value);
906 switch (value.nested_type()) {
907 case protos::pbzero::DebugAnnotation::NestedValue::UNSPECIFIED: {
908 auto flat_key_id = storage_->InternString(flat_key);
909 auto key_id = storage_->InternString(key);
910 // Leaf value.
911 if (value.has_bool_value()) {
912 inserter->AddArg(flat_key_id, key_id,
913 Variadic::Boolean(value.bool_value()));
914 return true;
915 }
916 if (value.has_int_value()) {
917 inserter->AddArg(flat_key_id, key_id,
918 Variadic::Integer(value.int_value()));
919 return true;
920 }
921 if (value.has_double_value()) {
922 inserter->AddArg(flat_key_id, key_id,
923 Variadic::Real(value.double_value()));
924 return true;
925 }
926 if (value.has_string_value()) {
927 inserter->AddArg(
928 flat_key_id, key_id,
929 Variadic::String(storage_->InternString(value.string_value())));
930 return true;
931 }
932 return false;
933 }
934 case protos::pbzero::DebugAnnotation::NestedValue::DICT: {
935 auto key_it = value.dict_keys();
936 auto value_it = value.dict_values();
937 bool inserted = false;
938 for (; key_it && value_it; ++key_it, ++value_it) {
939 std::string child_name = (*key_it).ToStdString();
940 std::string child_flat_key =
941 flat_key.ToStdString() + "." + child_name;
942 std::string child_key = key.ToStdString() + "." + child_name;
943 inserted |=
944 ParseNestedValueArgs(*value_it, base::StringView(child_flat_key),
945 base::StringView(child_key), inserter);
946 }
947 return inserted;
948 }
949 case protos::pbzero::DebugAnnotation::NestedValue::ARRAY: {
950 bool inserted_any = false;
951 std::string array_key = key.ToStdString();
952 StringId array_key_id = storage_->InternString(key);
953 for (auto value_it = value.array_values(); value_it; ++value_it) {
954 size_t array_index = inserter->GetNextArrayEntryIndex(array_key_id);
955 std::string child_key =
956 array_key + "[" + std::to_string(array_index) + "]";
957 bool inserted = ParseNestedValueArgs(
958 *value_it, flat_key, base::StringView(child_key), inserter);
959 if (inserted)
960 inserter->IncrementArrayEntryIndex(array_key_id);
961 inserted_any |= inserted;
962 }
963 return inserted_any;
964 }
965 }
966 return false;
967 }
968
ParseTaskExecutionArgs(ConstBytes task_execution,BoundInserter * inserter)969 util::Status ParseTaskExecutionArgs(ConstBytes task_execution,
970 BoundInserter* inserter) {
971 protos::pbzero::TaskExecution::Decoder task(task_execution);
972 uint64_t iid = task.posted_from_iid();
973 if (!iid)
974 return util::ErrStatus("TaskExecution with invalid posted_from_iid");
975
976 auto* decoder = sequence_state_->LookupInternedMessage<
977 protos::pbzero::InternedData::kSourceLocationsFieldNumber,
978 protos::pbzero::SourceLocation>(iid);
979 if (!decoder)
980 return util::ErrStatus("TaskExecution with invalid posted_from_iid");
981
982 StringId file_name_id = kNullStringId;
983 StringId function_name_id = kNullStringId;
984 uint32_t line_number = 0;
985
986 file_name_id = storage_->InternString(decoder->file_name());
987 function_name_id = storage_->InternString(decoder->function_name());
988 line_number = decoder->line_number();
989
990 inserter->AddArg(parser_->task_file_name_args_key_id_,
991 Variadic::String(file_name_id));
992 inserter->AddArg(parser_->task_function_name_args_key_id_,
993 Variadic::String(function_name_id));
994 inserter->AddArg(parser_->task_line_number_args_key_id_,
995 Variadic::UnsignedInteger(line_number));
996 return util::OkStatus();
997 }
998
ParseLogMessage(ConstBytes blob,BoundInserter * inserter)999 util::Status ParseLogMessage(ConstBytes blob, BoundInserter* inserter) {
1000 if (!utid_)
1001 return util::ErrStatus("LogMessage without thread association");
1002
1003 protos::pbzero::LogMessage::Decoder message(blob);
1004
1005 StringId log_message_id = kNullStringId;
1006
1007 auto* decoder = sequence_state_->LookupInternedMessage<
1008 protos::pbzero::InternedData::kLogMessageBodyFieldNumber,
1009 protos::pbzero::LogMessageBody>(message.body_iid());
1010 if (!decoder)
1011 return util::ErrStatus("LogMessage with invalid body_iid");
1012
1013 log_message_id = storage_->InternString(decoder->body());
1014
1015 // TODO(nicomazz): LogMessage also contains the source of the message (file
1016 // and line number). Android logs doesn't support this so far.
1017 storage_->mutable_android_log_table()->Insert(
1018 {ts_, *utid_,
1019 /*priority*/ 0,
1020 /*tag_id*/ kNullStringId, // TODO(nicomazz): Abuse tag_id to display
1021 // "file_name:line_number".
1022 log_message_id});
1023
1024 inserter->AddArg(parser_->log_message_body_key_id_,
1025 Variadic::String(log_message_id));
1026 // TODO(nicomazz): Add the source location as an argument.
1027 return util::OkStatus();
1028 }
1029
ParseCcScheduler(ConstBytes cc,BoundInserter * outer_inserter)1030 void ParseCcScheduler(ConstBytes cc, BoundInserter* outer_inserter) {
1031 parser_->proto_to_args_.InternProtoIntoArgsTable(
1032 cc, ".perfetto.protos.ChromeCompositorSchedulerState", outer_inserter,
1033 sequence_state_,
1034 /* prefix= */ "cc_scheduler_state");
1035 }
1036
ParseChromeUserEvent(protozero::ConstBytes chrome_user_event,BoundInserter * inserter)1037 void ParseChromeUserEvent(protozero::ConstBytes chrome_user_event,
1038 BoundInserter* inserter) {
1039 protos::pbzero::ChromeUserEvent::Decoder event(chrome_user_event);
1040 if (event.has_action()) {
1041 StringId action_id = storage_->InternString(event.action());
1042 inserter->AddArg(parser_->chrome_user_event_action_args_key_id_,
1043 Variadic::String(action_id));
1044 }
1045 if (event.has_action_hash()) {
1046 inserter->AddArg(parser_->chrome_user_event_action_hash_args_key_id_,
1047 Variadic::UnsignedInteger(event.action_hash()));
1048 }
1049 }
1050
ParseChromeLegacyIpc(protozero::ConstBytes chrome_legacy_ipc,BoundInserter * inserter)1051 void ParseChromeLegacyIpc(protozero::ConstBytes chrome_legacy_ipc,
1052 BoundInserter* inserter) {
1053 protos::pbzero::ChromeLegacyIpc::Decoder event(chrome_legacy_ipc);
1054 if (event.has_message_class()) {
1055 size_t message_class_index = static_cast<size_t>(event.message_class());
1056 if (message_class_index >= parser_->chrome_legacy_ipc_class_ids_.size())
1057 message_class_index = 0;
1058 inserter->AddArg(
1059 parser_->chrome_legacy_ipc_class_args_key_id_,
1060 Variadic::String(
1061 parser_->chrome_legacy_ipc_class_ids_[message_class_index]));
1062 }
1063 if (event.has_message_line()) {
1064 inserter->AddArg(parser_->chrome_legacy_ipc_line_args_key_id_,
1065 Variadic::Integer(event.message_line()));
1066 }
1067 }
1068
ParseChromeKeyedService(protozero::ConstBytes chrome_keyed_service,BoundInserter * inserter)1069 void ParseChromeKeyedService(protozero::ConstBytes chrome_keyed_service,
1070 BoundInserter* inserter) {
1071 protos::pbzero::ChromeKeyedService::Decoder event(chrome_keyed_service);
1072 if (event.has_name()) {
1073 StringId action_id = storage_->InternString(event.name());
1074 inserter->AddArg(parser_->chrome_keyed_service_name_args_key_id_,
1075 Variadic::String(action_id));
1076 }
1077 }
1078
ParseChromeLatencyInfo(protozero::ConstBytes chrome_latency_info,BoundInserter * inserter)1079 void ParseChromeLatencyInfo(protozero::ConstBytes chrome_latency_info,
1080 BoundInserter* inserter) {
1081 parser_->proto_to_args_.InternProtoIntoArgsTable(
1082 chrome_latency_info, ".perfetto.protos.ChromeLatencyInfo", inserter,
1083 sequence_state_, "latency_info");
1084 }
1085
ParseChromeHistogramSample(protozero::ConstBytes chrome_histogram_sample,BoundInserter * inserter)1086 void ParseChromeHistogramSample(protozero::ConstBytes chrome_histogram_sample,
1087 BoundInserter* inserter) {
1088 protos::pbzero::ChromeHistogramSample::Decoder event(
1089 chrome_histogram_sample);
1090 if (event.has_name_hash()) {
1091 uint64_t name_hash = static_cast<uint64_t>(event.name_hash());
1092 inserter->AddArg(parser_->chrome_histogram_sample_name_hash_args_key_id_,
1093 Variadic::UnsignedInteger(name_hash));
1094 }
1095 if (event.has_name()) {
1096 StringId name = storage_->InternString(event.name());
1097 inserter->AddArg(parser_->chrome_keyed_service_name_args_key_id_,
1098 Variadic::String(name));
1099 }
1100 if (event.has_sample()) {
1101 int64_t sample = static_cast<int64_t>(event.sample());
1102 inserter->AddArg(parser_->chrome_histogram_sample_sample_args_key_id_,
1103 Variadic::Integer(sample));
1104 }
1105 }
1106
1107 TraceProcessorContext* context_;
1108 TraceStorage* storage_;
1109 TrackEventParser* parser_;
1110 int64_t ts_;
1111 TrackEventData* event_data_;
1112 PacketSequenceStateGeneration* sequence_state_;
1113 ConstBytes blob_;
1114 TrackEvent::Decoder event_;
1115 LegacyEvent::Decoder legacy_event_;
1116 protos::pbzero::TrackEventDefaults::Decoder* defaults_;
1117
1118 // Importing state.
1119 StringId category_id_;
1120 StringId name_id_;
1121 uint64_t track_uuid_;
1122 TrackId track_id_;
1123 base::Optional<UniqueTid> utid_;
1124 base::Optional<UniqueTid> upid_;
1125 // All events in legacy JSON require a thread ID, but for some types of
1126 // events (e.g. async events or process/global-scoped instants), we don't
1127 // store it in the slice/track model. To pass the utid through to the json
1128 // export, we store it in an arg.
1129 base::Optional<UniqueTid> legacy_passthrough_utid_;
1130 };
1131
TrackEventParser(TraceProcessorContext * context)1132 TrackEventParser::TrackEventParser(TraceProcessorContext* context)
1133 : context_(context),
1134 proto_to_args_(context_),
1135 counter_name_thread_time_id_(
1136 context->storage->InternString("thread_time")),
1137 counter_name_thread_instruction_count_id_(
1138 context->storage->InternString("thread_instruction_count")),
1139 task_file_name_args_key_id_(
1140 context->storage->InternString("task.posted_from.file_name")),
1141 task_function_name_args_key_id_(
1142 context->storage->InternString("task.posted_from.function_name")),
1143 task_line_number_args_key_id_(
1144 context->storage->InternString("task.posted_from.line_number")),
1145 log_message_body_key_id_(
1146 context->storage->InternString("track_event.log_message")),
1147 raw_legacy_event_id_(
1148 context->storage->InternString("track_event.legacy_event")),
1149 legacy_event_passthrough_utid_id_(
1150 context->storage->InternString("legacy_event.passthrough_utid")),
1151 legacy_event_category_key_id_(
1152 context->storage->InternString("legacy_event.category")),
1153 legacy_event_name_key_id_(
1154 context->storage->InternString("legacy_event.name")),
1155 legacy_event_phase_key_id_(
1156 context->storage->InternString("legacy_event.phase")),
1157 legacy_event_duration_ns_key_id_(
1158 context->storage->InternString("legacy_event.duration_ns")),
1159 legacy_event_thread_timestamp_ns_key_id_(
1160 context->storage->InternString("legacy_event.thread_timestamp_ns")),
1161 legacy_event_thread_duration_ns_key_id_(
1162 context->storage->InternString("legacy_event.thread_duration_ns")),
1163 legacy_event_thread_instruction_count_key_id_(
1164 context->storage->InternString(
1165 "legacy_event.thread_instruction_count")),
1166 legacy_event_thread_instruction_delta_key_id_(
1167 context->storage->InternString(
1168 "legacy_event.thread_instruction_delta")),
1169 legacy_event_use_async_tts_key_id_(
1170 context->storage->InternString("legacy_event.use_async_tts")),
1171 legacy_event_unscoped_id_key_id_(
1172 context->storage->InternString("legacy_event.unscoped_id")),
1173 legacy_event_global_id_key_id_(
1174 context->storage->InternString("legacy_event.global_id")),
1175 legacy_event_local_id_key_id_(
1176 context->storage->InternString("legacy_event.local_id")),
1177 legacy_event_id_scope_key_id_(
1178 context->storage->InternString("legacy_event.id_scope")),
1179 legacy_event_bind_id_key_id_(
1180 context->storage->InternString("legacy_event.bind_id")),
1181 legacy_event_bind_to_enclosing_key_id_(
1182 context->storage->InternString("legacy_event.bind_to_enclosing")),
1183 legacy_event_flow_direction_key_id_(
1184 context->storage->InternString("legacy_event.flow_direction")),
1185 flow_direction_value_in_id_(context->storage->InternString("in")),
1186 flow_direction_value_out_id_(context->storage->InternString("out")),
1187 flow_direction_value_inout_id_(context->storage->InternString("inout")),
1188 chrome_user_event_action_args_key_id_(
1189 context->storage->InternString("user_event.action")),
1190 chrome_user_event_action_hash_args_key_id_(
1191 context->storage->InternString("user_event.action_hash")),
1192 chrome_legacy_ipc_class_args_key_id_(
1193 context->storage->InternString("legacy_ipc.class")),
1194 chrome_legacy_ipc_line_args_key_id_(
1195 context->storage->InternString("legacy_ipc.line")),
1196 chrome_keyed_service_name_args_key_id_(
1197 context->storage->InternString("keyed_service.name")),
1198 chrome_histogram_sample_name_hash_args_key_id_(
1199 context->storage->InternString("histogram_sample.name_hash")),
1200 chrome_histogram_sample_name_args_key_id_(
1201 context->storage->InternString("histogram_sample.name")),
1202 chrome_histogram_sample_sample_args_key_id_(
1203 context->storage->InternString("histogram_sample.sample")),
1204 chrome_latency_info_trace_id_key_id_(
1205 context->storage->InternString("latency_info.trace_id")),
1206 chrome_latency_info_step_key_id_(
1207 context->storage->InternString("latency_info.step")),
1208 chrome_latency_info_frame_tree_node_id_key_id_(
1209 context->storage->InternString("latency_info.frame_tree_node_id")),
1210 chrome_latency_info_step_ids_{
1211 {context->storage->InternString("STEP_UNSPECIFIED"),
1212 context->storage->InternString(
1213 "STEP_HANDLE_INPUT_EVENT_MAIN_COMMIT"),
1214 context->storage->InternString("STEP_MAIN_THREAD_SCROLL_UPDATE"),
1215 context->storage->InternString("STEP_SEND_INPUT_EVENT_UI"),
1216 context->storage->InternString("STEP_HANDLE_INPUT_EVENT_MAIN"),
1217 context->storage->InternString("STEP_HANDLE_INPUT_EVENT_IMPL"),
1218 context->storage->InternString("STEP_SWAP_BUFFERS"),
1219 context->storage->InternString("STEP_DRAW_AND_SWAP")}},
1220 chrome_legacy_ipc_class_ids_{
1221 {context->storage->InternString("UNSPECIFIED"),
1222 context->storage->InternString("AUTOMATION"),
1223 context->storage->InternString("FRAME"),
1224 context->storage->InternString("PAGE"),
1225 context->storage->InternString("VIEW"),
1226 context->storage->InternString("WIDGET"),
1227 context->storage->InternString("INPUT"),
1228 context->storage->InternString("TEST"),
1229 context->storage->InternString("WORKER"),
1230 context->storage->InternString("NACL"),
1231 context->storage->InternString("GPU_CHANNEL"),
1232 context->storage->InternString("MEDIA"),
1233 context->storage->InternString("PPAPI"),
1234 context->storage->InternString("CHROME"),
1235 context->storage->InternString("DRAG"),
1236 context->storage->InternString("PRINT"),
1237 context->storage->InternString("EXTENSION"),
1238 context->storage->InternString("TEXT_INPUT_CLIENT"),
1239 context->storage->InternString("BLINK_TEST"),
1240 context->storage->InternString("ACCESSIBILITY"),
1241 context->storage->InternString("PRERENDER"),
1242 context->storage->InternString("CHROMOTING"),
1243 context->storage->InternString("BROWSER_PLUGIN"),
1244 context->storage->InternString("ANDROID_WEB_VIEW"),
1245 context->storage->InternString("NACL_HOST"),
1246 context->storage->InternString("ENCRYPTED_MEDIA"),
1247 context->storage->InternString("CAST"),
1248 context->storage->InternString("GIN_JAVA_BRIDGE"),
1249 context->storage->InternString("CHROME_UTILITY_PRINTING"),
1250 context->storage->InternString("OZONE_GPU"),
1251 context->storage->InternString("WEB_TEST"),
1252 context->storage->InternString("NETWORK_HINTS"),
1253 context->storage->InternString("EXTENSIONS_GUEST_VIEW"),
1254 context->storage->InternString("GUEST_VIEW"),
1255 context->storage->InternString("MEDIA_PLAYER_DELEGATE"),
1256 context->storage->InternString("EXTENSION_WORKER"),
1257 context->storage->InternString("SUBRESOURCE_FILTER"),
1258 context->storage->InternString("UNFREEZABLE_FRAME")}},
1259 chrome_process_name_ids_{
1260 {kNullStringId, context_->storage->InternString("Browser"),
1261 context_->storage->InternString("Renderer"),
1262 context_->storage->InternString("Utility"),
1263 context_->storage->InternString("Zygote"),
1264 context_->storage->InternString("SandboxHelper"),
1265 context_->storage->InternString("Gpu"),
1266 context_->storage->InternString("PpapiPlugin"),
1267 context_->storage->InternString("PpapiBroker")}},
1268 chrome_thread_name_ids_{
1269 {kNullStringId, context_->storage->InternString("CrProcessMain"),
1270 context_->storage->InternString("ChromeIOThread"),
1271 context_->storage->InternString("ThreadPoolBackgroundWorker&"),
1272 context_->storage->InternString("ThreadPoolForegroundWorker&"),
1273 context_->storage->InternString(
1274 "ThreadPoolSingleThreadForegroundBlocking&"),
1275 context_->storage->InternString(
1276 "ThreadPoolSingleThreadBackgroundBlocking&"),
1277 context_->storage->InternString("ThreadPoolService"),
1278 context_->storage->InternString("Compositor"),
1279 context_->storage->InternString("VizCompositorThread"),
1280 context_->storage->InternString("CompositorTileWorker&"),
1281 context_->storage->InternString("ServiceWorkerThread&"),
1282 context_->storage->InternString("MemoryInfra"),
1283 context_->storage->InternString("StackSamplingProfiler")}},
1284 counter_unit_ids_{{kNullStringId, context_->storage->InternString("ns"),
1285 context_->storage->InternString("count"),
1286 context_->storage->InternString("bytes")}} {
1287 auto status = proto_to_args_.AddProtoFileDescriptor(
1288 kTrackEventDescriptor.data(), kTrackEventDescriptor.size());
1289 PERFETTO_DCHECK(status.ok());
1290
1291 // Switch |source_location_iid| into its interned data variant.
1292 proto_to_args_.AddParsingOverride(
1293 "begin_impl_frame_args.current_args.source_location_iid",
1294 [](const ProtoToArgsTable::ParsingOverrideState& state,
__anonf24704120a02(const ProtoToArgsTable::ParsingOverrideState& state, const protozero::Field& field, BoundInserter* inserter) 1295 const protozero::Field& field, BoundInserter* inserter) {
1296 return MaybeParseSourceLocation("begin_impl_frame_args.current_args",
1297 state, field, inserter);
1298 });
1299 proto_to_args_.AddParsingOverride(
1300 "begin_impl_frame_args.last_args.source_location_iid",
1301 [](const ProtoToArgsTable::ParsingOverrideState& state,
__anonf24704120b02(const ProtoToArgsTable::ParsingOverrideState& state, const protozero::Field& field, BoundInserter* inserter) 1302 const protozero::Field& field, BoundInserter* inserter) {
1303 return MaybeParseSourceLocation("begin_impl_frame_args.last_args",
1304 state, field, inserter);
1305 });
1306 proto_to_args_.AddParsingOverride(
1307 "begin_frame_observer_state.last_begin_frame_args.source_location_iid",
1308 [](const ProtoToArgsTable::ParsingOverrideState& state,
__anonf24704120c02(const ProtoToArgsTable::ParsingOverrideState& state, const protozero::Field& field, BoundInserter* inserter) 1309 const protozero::Field& field, BoundInserter* inserter) {
1310 return MaybeParseSourceLocation(
1311 "begin_frame_observer_state.last_begin_frame_args", state, field,
1312 inserter);
1313 });
1314 }
1315
ParseTrackDescriptor(protozero::ConstBytes track_descriptor)1316 void TrackEventParser::ParseTrackDescriptor(
1317 protozero::ConstBytes track_descriptor) {
1318 protos::pbzero::TrackDescriptor::Decoder decoder(track_descriptor);
1319
1320 // Ensure that the track and its parents are resolved. This may start a new
1321 // process and/or thread (i.e. new upid/utid).
1322 TrackId track_id =
1323 *context_->track_tracker->GetDescriptorTrack(decoder.uuid());
1324
1325 if (decoder.has_thread()) {
1326 UniqueTid utid = ParseThreadDescriptor(decoder.thread());
1327 if (decoder.has_chrome_thread())
1328 ParseChromeThreadDescriptor(utid, decoder.chrome_thread());
1329 } else if (decoder.has_process()) {
1330 UniquePid upid = ParseProcessDescriptor(decoder.process());
1331 if (decoder.has_chrome_process())
1332 ParseChromeProcessDescriptor(upid, decoder.chrome_process());
1333 } else if (decoder.has_counter()) {
1334 ParseCounterDescriptor(track_id, decoder.counter());
1335 }
1336
1337 if (decoder.has_name()) {
1338 auto* tracks = context_->storage->mutable_track_table();
1339 StringId name_id = context_->storage->InternString(decoder.name());
1340 tracks->mutable_name()->Set(*tracks->id().IndexOf(track_id), name_id);
1341 }
1342 }
1343
ParseProcessDescriptor(protozero::ConstBytes process_descriptor)1344 UniquePid TrackEventParser::ParseProcessDescriptor(
1345 protozero::ConstBytes process_descriptor) {
1346 protos::pbzero::ProcessDescriptor::Decoder decoder(process_descriptor);
1347 UniquePid upid = context_->process_tracker->GetOrCreateProcess(
1348 static_cast<uint32_t>(decoder.pid()));
1349 if (decoder.has_process_name() && decoder.process_name().size) {
1350 // Don't override system-provided names.
1351 context_->process_tracker->SetProcessNameIfUnset(
1352 upid, context_->storage->InternString(decoder.process_name()));
1353 }
1354 // TODO(skyostil): Remove parsing for legacy chrome_process_type field.
1355 if (decoder.has_chrome_process_type()) {
1356 auto process_type = decoder.chrome_process_type();
1357 size_t name_index =
1358 static_cast<size_t>(process_type) < chrome_process_name_ids_.size()
1359 ? static_cast<size_t>(process_type)
1360 : 0u;
1361 StringId name_id = chrome_process_name_ids_[name_index];
1362 // Don't override system-provided names.
1363 context_->process_tracker->SetProcessNameIfUnset(upid, name_id);
1364 }
1365 return upid;
1366 }
1367
ParseChromeProcessDescriptor(UniquePid upid,protozero::ConstBytes chrome_process_descriptor)1368 void TrackEventParser::ParseChromeProcessDescriptor(
1369 UniquePid upid,
1370 protozero::ConstBytes chrome_process_descriptor) {
1371 protos::pbzero::ChromeProcessDescriptor::Decoder decoder(
1372 chrome_process_descriptor);
1373 auto process_type = decoder.process_type();
1374 size_t name_index =
1375 static_cast<size_t>(process_type) < chrome_process_name_ids_.size()
1376 ? static_cast<size_t>(process_type)
1377 : 0u;
1378 StringId name_id = chrome_process_name_ids_[name_index];
1379 // Don't override system-provided names.
1380 context_->process_tracker->SetProcessNameIfUnset(upid, name_id);
1381 }
1382
ParseThreadDescriptor(protozero::ConstBytes thread_descriptor)1383 UniqueTid TrackEventParser::ParseThreadDescriptor(
1384 protozero::ConstBytes thread_descriptor) {
1385 protos::pbzero::ThreadDescriptor::Decoder decoder(thread_descriptor);
1386 UniqueTid utid = context_->process_tracker->UpdateThread(
1387 static_cast<uint32_t>(decoder.tid()),
1388 static_cast<uint32_t>(decoder.pid()));
1389 StringId name_id = kNullStringId;
1390 if (decoder.has_thread_name() && decoder.thread_name().size) {
1391 name_id = context_->storage->InternString(decoder.thread_name());
1392 } else if (decoder.has_chrome_thread_type()) {
1393 // TODO(skyostil): Remove parsing for legacy chrome_thread_type field.
1394 auto thread_type = decoder.chrome_thread_type();
1395 size_t name_index =
1396 static_cast<size_t>(thread_type) < chrome_thread_name_ids_.size()
1397 ? static_cast<size_t>(thread_type)
1398 : 0u;
1399 name_id = chrome_thread_name_ids_[name_index];
1400 }
1401 if (name_id != kNullStringId) {
1402 // Don't override system-provided names.
1403 context_->process_tracker->SetThreadNameIfUnset(utid, name_id);
1404 }
1405 return utid;
1406 }
1407
ParseChromeThreadDescriptor(UniqueTid utid,protozero::ConstBytes chrome_thread_descriptor)1408 void TrackEventParser::ParseChromeThreadDescriptor(
1409 UniqueTid utid,
1410 protozero::ConstBytes chrome_thread_descriptor) {
1411 protos::pbzero::ChromeThreadDescriptor::Decoder decoder(
1412 chrome_thread_descriptor);
1413 if (!decoder.has_thread_type())
1414 return;
1415
1416 auto thread_type = decoder.thread_type();
1417 size_t name_index =
1418 static_cast<size_t>(thread_type) < chrome_thread_name_ids_.size()
1419 ? static_cast<size_t>(thread_type)
1420 : 0u;
1421 StringId name_id = chrome_thread_name_ids_[name_index];
1422 context_->process_tracker->SetThreadNameIfUnset(utid, name_id);
1423 }
1424
ParseCounterDescriptor(TrackId track_id,protozero::ConstBytes counter_descriptor)1425 void TrackEventParser::ParseCounterDescriptor(
1426 TrackId track_id,
1427 protozero::ConstBytes counter_descriptor) {
1428 using protos::pbzero::CounterDescriptor;
1429
1430 CounterDescriptor::Decoder decoder(counter_descriptor);
1431 auto* counter_tracks = context_->storage->mutable_counter_track_table();
1432
1433 size_t unit_index = static_cast<size_t>(decoder.unit());
1434 if (unit_index >= counter_unit_ids_.size())
1435 unit_index = CounterDescriptor::UNIT_UNSPECIFIED;
1436
1437 switch (decoder.type()) {
1438 case CounterDescriptor::COUNTER_UNSPECIFIED:
1439 break;
1440 case CounterDescriptor::COUNTER_THREAD_TIME_NS:
1441 unit_index = CounterDescriptor::UNIT_TIME_NS;
1442 counter_tracks->mutable_name()->Set(
1443 *counter_tracks->id().IndexOf(track_id),
1444 counter_name_thread_time_id_);
1445 break;
1446 case CounterDescriptor::COUNTER_THREAD_INSTRUCTION_COUNT:
1447 unit_index = CounterDescriptor::UNIT_COUNT;
1448 counter_tracks->mutable_name()->Set(
1449 *counter_tracks->id().IndexOf(track_id),
1450 counter_name_thread_instruction_count_id_);
1451 break;
1452 }
1453
1454 counter_tracks->mutable_unit()->Set(*counter_tracks->id().IndexOf(track_id),
1455 counter_unit_ids_[unit_index]);
1456 }
1457
ParseTrackEvent(int64_t ts,TrackEventData * event_data,ConstBytes blob)1458 void TrackEventParser::ParseTrackEvent(int64_t ts,
1459 TrackEventData* event_data,
1460 ConstBytes blob) {
1461 util::Status status =
1462 EventImporter(this, ts, event_data, std::move(blob)).Import();
1463 if (!status.ok()) {
1464 context_->storage->IncrementStats(stats::track_event_parser_errors);
1465 PERFETTO_DLOG("%s", status.c_message());
1466 }
1467 }
1468
1469 } // namespace trace_processor
1470 } // namespace perfetto
1471