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_tokenizer.h"
18
19 #include "perfetto/base/logging.h"
20 #include "perfetto/trace_processor/trace_blob_view.h"
21 #include "src/trace_processor/importers/common/clock_tracker.h"
22 #include "src/trace_processor/importers/common/metadata_tracker.h"
23 #include "src/trace_processor/importers/common/process_tracker.h"
24 #include "src/trace_processor/importers/common/track_tracker.h"
25 #include "src/trace_processor/importers/proto/packet_sequence_state.h"
26 #include "src/trace_processor/importers/proto/proto_trace_reader.h"
27 #include "src/trace_processor/importers/proto/track_event_tracker.h"
28 #include "src/trace_processor/sorter/trace_sorter.h"
29 #include "src/trace_processor/storage/stats.h"
30 #include "src/trace_processor/storage/trace_storage.h"
31
32 #include "protos/perfetto/common/builtin_clock.pbzero.h"
33 #include "protos/perfetto/trace/trace_packet.pbzero.h"
34 #include "protos/perfetto/trace/track_event/chrome_process_descriptor.pbzero.h"
35 #include "protos/perfetto/trace/track_event/chrome_thread_descriptor.pbzero.h"
36 #include "protos/perfetto/trace/track_event/counter_descriptor.pbzero.h"
37 #include "protos/perfetto/trace/track_event/process_descriptor.pbzero.h"
38 #include "protos/perfetto/trace/track_event/range_of_interest.pbzero.h"
39 #include "protos/perfetto/trace/track_event/thread_descriptor.pbzero.h"
40 #include "protos/perfetto/trace/track_event/track_descriptor.pbzero.h"
41 #include "protos/perfetto/trace/track_event/track_event.pbzero.h"
42
43 namespace perfetto {
44 namespace trace_processor {
45
46 namespace {
47 using protos::pbzero::CounterDescriptor;
48 }
49
TrackEventTokenizer(TraceProcessorContext * context,TrackEventTracker * track_event_tracker)50 TrackEventTokenizer::TrackEventTokenizer(TraceProcessorContext* context,
51 TrackEventTracker* track_event_tracker)
52 : context_(context),
53 track_event_tracker_(track_event_tracker),
54 counter_name_thread_time_id_(
55 context_->storage->InternString("thread_time")),
56 counter_name_thread_instruction_count_id_(
57 context_->storage->InternString("thread_instruction_count")) {}
58
TokenizeRangeOfInterestPacket(PacketSequenceState *,const protos::pbzero::TracePacket::Decoder & packet,int64_t)59 ModuleResult TrackEventTokenizer::TokenizeRangeOfInterestPacket(
60 PacketSequenceState* /*state*/,
61 const protos::pbzero::TracePacket::Decoder& packet,
62 int64_t /*packet_timestamp*/) {
63 protos::pbzero::TrackEventRangeOfInterest::Decoder range_of_interest(
64 packet.track_event_range_of_interest());
65 if (!range_of_interest.has_start_us()) {
66 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
67 return ModuleResult::Handled();
68 }
69 track_event_tracker_->SetRangeOfInterestStartUs(range_of_interest.start_us());
70 context_->metadata_tracker->SetMetadata(
71 metadata::range_of_interest_start_us,
72 Variadic::Integer(range_of_interest.start_us()));
73 return ModuleResult::Handled();
74 }
75
TokenizeTrackDescriptorPacket(PacketSequenceState * state,const protos::pbzero::TracePacket::Decoder & packet,int64_t packet_timestamp)76 ModuleResult TrackEventTokenizer::TokenizeTrackDescriptorPacket(
77 PacketSequenceState* state,
78 const protos::pbzero::TracePacket::Decoder& packet,
79 int64_t packet_timestamp) {
80 auto track_descriptor_field = packet.track_descriptor();
81 protos::pbzero::TrackDescriptor::Decoder track(track_descriptor_field.data,
82 track_descriptor_field.size);
83
84 if (!track.has_uuid()) {
85 PERFETTO_ELOG("TrackDescriptor packet without uuid");
86 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
87 return ModuleResult::Handled();
88 }
89
90 StringId name_id = kNullStringId;
91 if (track.has_name())
92 name_id = context_->storage->InternString(track.name());
93
94 if (packet.has_trusted_pid()) {
95 context_->process_tracker->UpdateTrustedPid(
96 static_cast<uint32_t>(packet.trusted_pid()), track.uuid());
97 }
98
99 if (track.has_thread()) {
100 protos::pbzero::ThreadDescriptor::Decoder thread(track.thread());
101
102 if (!thread.has_pid() || !thread.has_tid()) {
103 PERFETTO_ELOG(
104 "No pid or tid in ThreadDescriptor for track with uuid %" PRIu64,
105 track.uuid());
106 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
107 return ModuleResult::Handled();
108 }
109
110 if (state->IsIncrementalStateValid()) {
111 TokenizeThreadDescriptor(state, thread);
112 }
113
114 track_event_tracker_->ReserveDescriptorThreadTrack(
115 track.uuid(), track.parent_uuid(), name_id,
116 static_cast<uint32_t>(thread.pid()),
117 static_cast<uint32_t>(thread.tid()), packet_timestamp,
118 track.disallow_merging_with_system_tracks());
119 } else if (track.has_process()) {
120 protos::pbzero::ProcessDescriptor::Decoder process(track.process());
121
122 if (!process.has_pid()) {
123 PERFETTO_ELOG("No pid in ProcessDescriptor for track with uuid %" PRIu64,
124 track.uuid());
125 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
126 return ModuleResult::Handled();
127 }
128
129 track_event_tracker_->ReserveDescriptorProcessTrack(
130 track.uuid(), name_id, static_cast<uint32_t>(process.pid()),
131 packet_timestamp);
132 } else if (track.has_counter()) {
133 protos::pbzero::CounterDescriptor::Decoder counter(track.counter());
134
135 StringId category_id = kNullStringId;
136 if (counter.has_categories()) {
137 // TODO(eseckler): Support multi-category events in the table schema.
138 std::string categories;
139 for (auto it = counter.categories(); it; ++it) {
140 if (!categories.empty())
141 categories += ",";
142 categories.append((*it).data, (*it).size);
143 }
144 if (!categories.empty()) {
145 category_id =
146 context_->storage->InternString(base::StringView(categories));
147 }
148 }
149
150 // TODO(eseckler): Intern counter tracks for specific counter types like
151 // thread time, so that the same counter can be referred to from tracks with
152 // different uuids. (Chrome may emit thread time values on behalf of other
153 // threads, in which case it has to use absolute values on a different
154 // track_uuid. Right now these absolute values are imported onto a separate
155 // counter track than the other thread's regular thread time values.)
156 if (name_id.is_null()) {
157 switch (counter.type()) {
158 case CounterDescriptor::COUNTER_UNSPECIFIED:
159 break;
160 case CounterDescriptor::COUNTER_THREAD_TIME_NS:
161 name_id = counter_name_thread_time_id_;
162 break;
163 case CounterDescriptor::COUNTER_THREAD_INSTRUCTION_COUNT:
164 name_id = counter_name_thread_instruction_count_id_;
165 break;
166 }
167 }
168
169 track_event_tracker_->ReserveDescriptorCounterTrack(
170 track.uuid(), track.parent_uuid(), name_id, category_id,
171 counter.unit_multiplier(), counter.is_incremental(),
172 packet.trusted_packet_sequence_id());
173 } else {
174 track_event_tracker_->ReserveDescriptorChildTrack(
175 track.uuid(), track.parent_uuid(), name_id);
176 }
177
178 // Let ProtoTraceReader forward the packet to the parser.
179 return ModuleResult::Ignored();
180 }
181
TokenizeThreadDescriptorPacket(PacketSequenceState * state,const protos::pbzero::TracePacket::Decoder & packet)182 ModuleResult TrackEventTokenizer::TokenizeThreadDescriptorPacket(
183 PacketSequenceState* state,
184 const protos::pbzero::TracePacket::Decoder& packet) {
185 if (PERFETTO_UNLIKELY(!packet.has_trusted_packet_sequence_id())) {
186 PERFETTO_ELOG("ThreadDescriptor packet without trusted_packet_sequence_id");
187 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
188 return ModuleResult::Handled();
189 }
190
191 // TrackEvents will be ignored while incremental state is invalid. As a
192 // consequence, we should also ignore any ThreadDescriptors received in this
193 // state. Otherwise, any delta-encoded timestamps would be calculated
194 // incorrectly once we move out of the packet loss state. Instead, wait until
195 // the first subsequent descriptor after incremental state is cleared.
196 if (!state->IsIncrementalStateValid()) {
197 context_->storage->IncrementStats(stats::tokenizer_skipped_packets);
198 return ModuleResult::Handled();
199 }
200
201 protos::pbzero::ThreadDescriptor::Decoder thread(packet.thread_descriptor());
202 TokenizeThreadDescriptor(state, thread);
203
204 // Let ProtoTraceReader forward the packet to the parser.
205 return ModuleResult::Ignored();
206 }
207
TokenizeThreadDescriptor(PacketSequenceState * state,const protos::pbzero::ThreadDescriptor::Decoder & thread)208 void TrackEventTokenizer::TokenizeThreadDescriptor(
209 PacketSequenceState* state,
210 const protos::pbzero::ThreadDescriptor::Decoder& thread) {
211 // TODO(eseckler): Remove support for legacy thread descriptor-based default
212 // tracks and delta timestamps.
213 state->SetThreadDescriptor(thread.pid(), thread.tid(),
214 thread.reference_timestamp_us() * 1000,
215 thread.reference_thread_time_us() * 1000,
216 thread.reference_thread_instruction_count());
217 }
218
TokenizeTrackEventPacket(PacketSequenceState * state,const protos::pbzero::TracePacket::Decoder & packet,TraceBlobView * packet_blob,int64_t packet_timestamp)219 void TrackEventTokenizer::TokenizeTrackEventPacket(
220 PacketSequenceState* state,
221 const protos::pbzero::TracePacket::Decoder& packet,
222 TraceBlobView* packet_blob,
223 int64_t packet_timestamp) {
224 if (PERFETTO_UNLIKELY(!packet.has_trusted_packet_sequence_id())) {
225 PERFETTO_ELOG("TrackEvent packet without trusted_packet_sequence_id");
226 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
227 return;
228 }
229
230 auto field = packet.track_event();
231 protos::pbzero::TrackEvent::Decoder event(field.data, field.size);
232
233 protos::pbzero::TrackEventDefaults::Decoder* defaults =
234 state->current_generation()->GetTrackEventDefaults();
235
236 int64_t timestamp;
237 TrackEventData data(std::move(*packet_blob), state->current_generation());
238
239 // TODO(eseckler): Remove handling of timestamps relative to ThreadDescriptors
240 // once all producers have switched to clock-domain timestamps (e.g.
241 // TracePacket's timestamp).
242
243 if (event.has_timestamp_delta_us()) {
244 // Delta timestamps require a valid ThreadDescriptor packet since the last
245 // packet loss.
246 if (!state->track_event_timestamps_valid()) {
247 context_->storage->IncrementStats(stats::tokenizer_skipped_packets);
248 return;
249 }
250 timestamp = state->IncrementAndGetTrackEventTimeNs(
251 event.timestamp_delta_us() * 1000);
252
253 // Legacy TrackEvent timestamp fields are in MONOTONIC domain. Adjust to
254 // trace time if we have a clock snapshot.
255 base::StatusOr<int64_t> trace_ts = context_->clock_tracker->ToTraceTime(
256 protos::pbzero::BUILTIN_CLOCK_MONOTONIC, timestamp);
257 if (trace_ts.ok())
258 timestamp = trace_ts.value();
259 } else if (int64_t ts_absolute_us = event.timestamp_absolute_us()) {
260 // One-off absolute timestamps don't affect delta computation.
261 timestamp = ts_absolute_us * 1000;
262
263 // Legacy TrackEvent timestamp fields are in MONOTONIC domain. Adjust to
264 // trace time if we have a clock snapshot.
265 base::StatusOr<int64_t> trace_ts = context_->clock_tracker->ToTraceTime(
266 protos::pbzero::BUILTIN_CLOCK_MONOTONIC, timestamp);
267 if (trace_ts.ok())
268 timestamp = trace_ts.value();
269 } else if (packet.has_timestamp()) {
270 timestamp = packet_timestamp;
271 } else {
272 PERFETTO_ELOG("TrackEvent without valid timestamp");
273 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
274 return;
275 }
276
277 if (event.has_thread_time_delta_us()) {
278 // Delta timestamps require a valid ThreadDescriptor packet since the last
279 // packet loss.
280 if (!state->track_event_timestamps_valid()) {
281 context_->storage->IncrementStats(stats::tokenizer_skipped_packets);
282 return;
283 }
284 data.thread_timestamp = state->IncrementAndGetTrackEventThreadTimeNs(
285 event.thread_time_delta_us() * 1000);
286 } else if (event.has_thread_time_absolute_us()) {
287 // One-off absolute timestamps don't affect delta computation.
288 data.thread_timestamp = event.thread_time_absolute_us() * 1000;
289 }
290
291 if (event.has_thread_instruction_count_delta()) {
292 // Delta timestamps require a valid ThreadDescriptor packet since the last
293 // packet loss.
294 if (!state->track_event_timestamps_valid()) {
295 context_->storage->IncrementStats(stats::tokenizer_skipped_packets);
296 return;
297 }
298 data.thread_instruction_count =
299 state->IncrementAndGetTrackEventThreadInstructionCount(
300 event.thread_instruction_count_delta());
301 } else if (event.has_thread_instruction_count_absolute()) {
302 // One-off absolute timestamps don't affect delta computation.
303 data.thread_instruction_count = event.thread_instruction_count_absolute();
304 }
305
306 if (event.type() == protos::pbzero::TrackEvent::TYPE_COUNTER) {
307 // Consider track_uuid from the packet and TrackEventDefaults.
308 uint64_t track_uuid;
309 if (event.has_track_uuid()) {
310 track_uuid = event.track_uuid();
311 } else if (defaults && defaults->has_track_uuid()) {
312 track_uuid = defaults->track_uuid();
313 } else {
314 PERFETTO_DLOG(
315 "Ignoring TrackEvent with counter_value but without track_uuid");
316 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
317 return;
318 }
319
320 if (!event.has_counter_value() && !event.has_double_counter_value()) {
321 PERFETTO_DLOG(
322 "Ignoring TrackEvent with TYPE_COUNTER but without counter_value or "
323 "double_counter_value for "
324 "track_uuid %" PRIu64,
325 track_uuid);
326 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
327 return;
328 }
329
330 std::optional<double> value;
331 if (event.has_counter_value()) {
332 value = track_event_tracker_->ConvertToAbsoluteCounterValue(
333 track_uuid, packet.trusted_packet_sequence_id(),
334 static_cast<double>(event.counter_value()));
335 } else {
336 value = track_event_tracker_->ConvertToAbsoluteCounterValue(
337 track_uuid, packet.trusted_packet_sequence_id(),
338 event.double_counter_value());
339 }
340
341 if (!value) {
342 PERFETTO_DLOG("Ignoring TrackEvent with invalid track_uuid %" PRIu64,
343 track_uuid);
344 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
345 return;
346 }
347
348 data.counter_value = *value;
349 }
350
351 size_t index = 0;
352 const protozero::RepeatedFieldIterator<uint64_t> kEmptyIterator;
353 auto result = AddExtraCounterValues(
354 data, index, packet.trusted_packet_sequence_id(),
355 event.extra_counter_values(), event.extra_counter_track_uuids(),
356 defaults ? defaults->extra_counter_track_uuids() : kEmptyIterator);
357 if (!result.ok()) {
358 PERFETTO_DLOG("%s", result.c_message());
359 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
360 return;
361 }
362 result = AddExtraCounterValues(
363 data, index, packet.trusted_packet_sequence_id(),
364 event.extra_double_counter_values(),
365 event.extra_double_counter_track_uuids(),
366 defaults ? defaults->extra_double_counter_track_uuids() : kEmptyIterator);
367 if (!result.ok()) {
368 PERFETTO_DLOG("%s", result.c_message());
369 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
370 return;
371 }
372
373 context_->sorter->PushTrackEventPacket(timestamp, std::move(data));
374 }
375
376 template <typename T>
AddExtraCounterValues(TrackEventData & data,size_t & index,uint32_t trusted_packet_sequence_id,protozero::RepeatedFieldIterator<T> value_it,protozero::RepeatedFieldIterator<uint64_t> packet_track_uuid_it,protozero::RepeatedFieldIterator<uint64_t> default_track_uuid_it)377 base::Status TrackEventTokenizer::AddExtraCounterValues(
378 TrackEventData& data,
379 size_t& index,
380 uint32_t trusted_packet_sequence_id,
381 protozero::RepeatedFieldIterator<T> value_it,
382 protozero::RepeatedFieldIterator<uint64_t> packet_track_uuid_it,
383 protozero::RepeatedFieldIterator<uint64_t> default_track_uuid_it) {
384 if (!value_it)
385 return base::OkStatus();
386
387 // Consider extra_{double_,}counter_track_uuids from the packet and
388 // TrackEventDefaults.
389 protozero::RepeatedFieldIterator<uint64_t> track_uuid_it;
390 if (packet_track_uuid_it) {
391 track_uuid_it = packet_track_uuid_it;
392 } else if (default_track_uuid_it) {
393 track_uuid_it = default_track_uuid_it;
394 } else {
395 return base::Status(
396 "Ignoring TrackEvent with extra_{double_,}counter_values but without "
397 "extra_{double_,}counter_track_uuids");
398 }
399
400 for (; value_it; ++value_it, ++track_uuid_it, ++index) {
401 if (!*track_uuid_it) {
402 return base::Status(
403 "Ignoring TrackEvent with more extra_{double_,}counter_values than "
404 "extra_{double_,}counter_track_uuids");
405 }
406 if (index >= TrackEventData::kMaxNumExtraCounters) {
407 return base::Status(
408 "Ignoring TrackEvent with more extra_{double_,}counter_values than "
409 "TrackEventData::kMaxNumExtraCounters");
410 }
411 std::optional<double> abs_value =
412 track_event_tracker_->ConvertToAbsoluteCounterValue(
413 *track_uuid_it, trusted_packet_sequence_id,
414 static_cast<double>(*value_it));
415 if (!abs_value) {
416 return base::Status(
417 "Ignoring TrackEvent with invalid extra counter track");
418 }
419 data.extra_counter_values[index] = *abs_value;
420 }
421 return base::OkStatus();
422 }
423
424 } // namespace trace_processor
425 } // namespace perfetto
426