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