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