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