1 /*
2 * Copyright (C) 2018 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/proto_trace_tokenizer.h"
18
19 #include <string>
20
21 #include "perfetto/base/logging.h"
22 #include "perfetto/base/utils.h"
23 #include "perfetto/protozero/proto_decoder.h"
24 #include "perfetto/protozero/proto_utils.h"
25 #include "src/trace_processor/event_tracker.h"
26 #include "src/trace_processor/process_tracker.h"
27 #include "src/trace_processor/stats.h"
28 #include "src/trace_processor/trace_blob_view.h"
29 #include "src/trace_processor/trace_sorter.h"
30 #include "src/trace_processor/trace_storage.h"
31
32 #include "perfetto/trace/ftrace/ftrace_event.pbzero.h"
33 #include "perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
34 #include "perfetto/trace/interned_data/interned_data.pbzero.h"
35 #include "perfetto/trace/trace.pbzero.h"
36 #include "perfetto/trace/track_event/task_execution.pbzero.h"
37 #include "perfetto/trace/track_event/thread_descriptor.pbzero.h"
38 #include "perfetto/trace/track_event/track_event.pbzero.h"
39
40 namespace perfetto {
41 namespace trace_processor {
42
43 using protozero::ProtoDecoder;
44 using protozero::proto_utils::MakeTagLengthDelimited;
45 using protozero::proto_utils::MakeTagVarInt;
46 using protozero::proto_utils::ParseVarInt;
47
48 namespace {
49
50 template <typename MessageType>
InternMessage(TraceProcessorContext * context,ProtoIncrementalState::PacketSequenceState * state,TraceBlobView message)51 void InternMessage(TraceProcessorContext* context,
52 ProtoIncrementalState::PacketSequenceState* state,
53 TraceBlobView message) {
54 constexpr auto kIidFieldNumber = MessageType::kIidFieldNumber;
55
56 uint32_t iid = 0;
57 auto message_start = message.data();
58 auto message_size = message.length();
59 protozero::ProtoDecoder decoder(message_start, message_size);
60
61 auto field = decoder.FindField(kIidFieldNumber);
62 if (PERFETTO_UNLIKELY(!field)) {
63 PERFETTO_ELOG("Interned message without interning_id");
64 context->storage->IncrementStats(stats::interned_data_tokenizer_errors);
65 return;
66 }
67 iid = field.as_uint32();
68
69 auto res = state->GetInternedDataMap<MessageType>()->emplace(
70 iid,
71 ProtoIncrementalState::InternedDataView<MessageType>(std::move(message)));
72 // If a message with this ID is already interned, its data should not have
73 // changed (this is forbidden by the InternedData proto).
74 // TODO(eseckler): This DCHECK assumes that the message is encoded the
75 // same way whenever it is re-emitted.
76 PERFETTO_DCHECK(res.second ||
77 (res.first->second.message.length() == message_size &&
78 memcmp(res.first->second.message.data(), message_start,
79 message_size) == 0));
80 }
81
82 } // namespace
83
84 // static
GuessProtoTraceType(const uint8_t * data,size_t size)85 TraceType ProtoTraceTokenizer::GuessProtoTraceType(const uint8_t* data,
86 size_t size) {
87 // Scan at most the first 128MB for a track event packet.
88 constexpr size_t kMaxScanSize = 128 * 1024 * 1024;
89 protos::pbzero::Trace::Decoder decoder(data, std::min(size, kMaxScanSize));
90 if (!decoder.has_packet())
91 return TraceType::kUnknownTraceType;
92 for (auto it = decoder.packet(); it; ++it) {
93 ProtoDecoder packet_decoder(it->data(), it->size());
94 if (PERFETTO_UNLIKELY(packet_decoder.FindField(
95 protos::pbzero::TracePacket::kTrackEventFieldNumber))) {
96 return TraceType::kProtoWithTrackEventsTraceType;
97 }
98 }
99 return TraceType::kProtoTraceType;
100 }
101
ProtoTraceTokenizer(TraceProcessorContext * ctx)102 ProtoTraceTokenizer::ProtoTraceTokenizer(TraceProcessorContext* ctx)
103 : context_(ctx) {}
104 ProtoTraceTokenizer::~ProtoTraceTokenizer() = default;
105
Parse(std::unique_ptr<uint8_t[]> owned_buf,size_t size)106 bool ProtoTraceTokenizer::Parse(std::unique_ptr<uint8_t[]> owned_buf,
107 size_t size) {
108 uint8_t* data = &owned_buf[0];
109 if (!partial_buf_.empty()) {
110 // It takes ~5 bytes for a proto preamble + the varint size.
111 const size_t kHeaderBytes = 5;
112 if (PERFETTO_UNLIKELY(partial_buf_.size() < kHeaderBytes)) {
113 size_t missing_len = std::min(kHeaderBytes - partial_buf_.size(), size);
114 partial_buf_.insert(partial_buf_.end(), &data[0], &data[missing_len]);
115 if (partial_buf_.size() < kHeaderBytes)
116 return true;
117 data += missing_len;
118 size -= missing_len;
119 }
120
121 // At this point we have enough data in |partial_buf_| to read at least the
122 // field header and know the size of the next TracePacket.
123 constexpr uint8_t kTracePacketTag =
124 MakeTagLengthDelimited(protos::pbzero::Trace::kPacketFieldNumber);
125 const uint8_t* pos = &partial_buf_[0];
126 uint8_t proto_field_tag = *pos;
127 uint64_t field_size = 0;
128 const uint8_t* next = ParseVarInt(++pos, &*partial_buf_.end(), &field_size);
129 bool parse_failed = next == pos;
130 pos = next;
131 if (proto_field_tag != kTracePacketTag || field_size == 0 || parse_failed) {
132 PERFETTO_ELOG("Failed parsing a TracePacket from the partial buffer");
133 return false; // Unrecoverable error, stop parsing.
134 }
135
136 // At this point we know how big the TracePacket is.
137 size_t hdr_size = static_cast<size_t>(pos - &partial_buf_[0]);
138 size_t size_incl_header = static_cast<size_t>(field_size + hdr_size);
139 PERFETTO_DCHECK(size_incl_header > partial_buf_.size());
140
141 // There is a good chance that between the |partial_buf_| and the new |data|
142 // of the current call we have enough bytes to parse a TracePacket.
143 if (partial_buf_.size() + size >= size_incl_header) {
144 // Create a new buffer for the whole TracePacket and copy into that:
145 // 1) The beginning of the TracePacket (including the proto header) from
146 // the partial buffer.
147 // 2) The rest of the TracePacket from the current |data| buffer (note
148 // that we might have consumed already a few bytes form |data| earlier
149 // in this function, hence we need to keep |off| into account).
150 std::unique_ptr<uint8_t[]> buf(new uint8_t[size_incl_header]);
151 memcpy(&buf[0], partial_buf_.data(), partial_buf_.size());
152 // |size_missing| is the number of bytes for the rest of the TracePacket
153 // in |data|.
154 size_t size_missing = size_incl_header - partial_buf_.size();
155 memcpy(&buf[partial_buf_.size()], &data[0], size_missing);
156 data += size_missing;
157 size -= size_missing;
158 partial_buf_.clear();
159 uint8_t* buf_start = &buf[0]; // Note that buf is std::moved below.
160 ParseInternal(std::move(buf), buf_start, size_incl_header);
161 } else {
162 partial_buf_.insert(partial_buf_.end(), data, &data[size]);
163 return true;
164 }
165 }
166 ParseInternal(std::move(owned_buf), data, size);
167 return true;
168 }
169
ParseInternal(std::unique_ptr<uint8_t[]> owned_buf,uint8_t * data,size_t size)170 void ProtoTraceTokenizer::ParseInternal(std::unique_ptr<uint8_t[]> owned_buf,
171 uint8_t* data,
172 size_t size) {
173 PERFETTO_DCHECK(data >= &owned_buf[0]);
174 const uint8_t* start = &owned_buf[0];
175 const size_t data_off = static_cast<size_t>(data - start);
176 TraceBlobView whole_buf(std::move(owned_buf), data_off, size);
177
178 protos::pbzero::Trace::Decoder decoder(data, size);
179 for (auto it = decoder.packet(); it; ++it) {
180 size_t field_offset = whole_buf.offset_of(it->data());
181 ParsePacket(whole_buf.slice(field_offset, it->size()));
182 }
183
184 const size_t bytes_left = decoder.bytes_left();
185 if (bytes_left > 0) {
186 PERFETTO_DCHECK(partial_buf_.empty());
187 partial_buf_.insert(partial_buf_.end(), &data[decoder.read_offset()],
188 &data[decoder.read_offset() + bytes_left]);
189 }
190 }
191
ParsePacket(TraceBlobView packet)192 void ProtoTraceTokenizer::ParsePacket(TraceBlobView packet) {
193 protos::pbzero::TracePacket::Decoder decoder(packet.data(), packet.length());
194 PERFETTO_DCHECK(!decoder.bytes_left());
195
196 auto timestamp = decoder.has_timestamp()
197 ? static_cast<int64_t>(decoder.timestamp())
198 : latest_timestamp_;
199 latest_timestamp_ = std::max(timestamp, latest_timestamp_);
200
201 if (decoder.incremental_state_cleared()) {
202 HandleIncrementalStateCleared(decoder);
203 } else if (decoder.previous_packet_dropped()) {
204 HandlePreviousPacketDropped(decoder);
205 }
206
207 if (decoder.has_interned_data()) {
208 auto field = decoder.interned_data();
209 const size_t offset = packet.offset_of(field.data);
210 ParseInternedData(decoder, packet.slice(offset, field.size));
211 }
212
213 if (decoder.has_ftrace_events()) {
214 auto ftrace_field = decoder.ftrace_events();
215 const size_t fld_off = packet.offset_of(ftrace_field.data);
216 ParseFtraceBundle(packet.slice(fld_off, ftrace_field.size));
217 return;
218 }
219
220 if (decoder.has_track_event()) {
221 ParseTrackEventPacket(decoder, std::move(packet));
222 return;
223 }
224
225 if (decoder.has_thread_descriptor()) {
226 ParseThreadDescriptorPacket(decoder);
227 return;
228 }
229
230 // Use parent data and length because we want to parse this again
231 // later to get the exact type of the packet.
232 context_->sorter->PushTracePacket(timestamp, std::move(packet));
233 }
234
HandleIncrementalStateCleared(const protos::pbzero::TracePacket::Decoder & packet_decoder)235 void ProtoTraceTokenizer::HandleIncrementalStateCleared(
236 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
237 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
238 PERFETTO_ELOG(
239 "incremental_state_cleared without trusted_packet_sequence_id");
240 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
241 return;
242 }
243 GetIncrementalStateForPacketSequence(
244 packet_decoder.trusted_packet_sequence_id())
245 ->OnIncrementalStateCleared();
246 }
247
HandlePreviousPacketDropped(const protos::pbzero::TracePacket::Decoder & packet_decoder)248 void ProtoTraceTokenizer::HandlePreviousPacketDropped(
249 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
250 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
251 PERFETTO_ELOG("previous_packet_dropped without trusted_packet_sequence_id");
252 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
253 return;
254 }
255 GetIncrementalStateForPacketSequence(
256 packet_decoder.trusted_packet_sequence_id())
257 ->OnPacketLoss();
258 }
259
ParseInternedData(const protos::pbzero::TracePacket::Decoder & packet_decoder,TraceBlobView interned_data)260 void ProtoTraceTokenizer::ParseInternedData(
261 const protos::pbzero::TracePacket::Decoder& packet_decoder,
262 TraceBlobView interned_data) {
263 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
264 PERFETTO_ELOG("InternedData packet without trusted_packet_sequence_id");
265 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
266 return;
267 }
268
269 auto* state = GetIncrementalStateForPacketSequence(
270 packet_decoder.trusted_packet_sequence_id());
271
272 protos::pbzero::InternedData::Decoder interned_data_decoder(
273 interned_data.data(), interned_data.length());
274
275 // Store references to interned data submessages into the sequence's state.
276 for (auto it = interned_data_decoder.event_categories(); it; ++it) {
277 size_t offset = interned_data.offset_of(it->data());
278 InternMessage<protos::pbzero::EventCategory>(
279 context_, state, interned_data.slice(offset, it->size()));
280 }
281
282 for (auto it = interned_data_decoder.legacy_event_names(); it; ++it) {
283 size_t offset = interned_data.offset_of(it->data());
284 InternMessage<protos::pbzero::LegacyEventName>(
285 context_, state, interned_data.slice(offset, it->size()));
286 }
287
288 for (auto it = interned_data_decoder.debug_annotation_names(); it; ++it) {
289 size_t offset = interned_data.offset_of(it->data());
290 InternMessage<protos::pbzero::DebugAnnotationName>(
291 context_, state, interned_data.slice(offset, it->size()));
292 }
293
294 for (auto it = interned_data_decoder.source_locations(); it; ++it) {
295 size_t offset = interned_data.offset_of(it->data());
296 InternMessage<protos::pbzero::SourceLocation>(
297 context_, state, interned_data.slice(offset, it->size()));
298 }
299 }
300
ParseThreadDescriptorPacket(const protos::pbzero::TracePacket::Decoder & packet_decoder)301 void ProtoTraceTokenizer::ParseThreadDescriptorPacket(
302 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
303 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
304 PERFETTO_ELOG("ThreadDescriptor packet without trusted_packet_sequence_id");
305 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
306 return;
307 }
308
309 auto* state = GetIncrementalStateForPacketSequence(
310 packet_decoder.trusted_packet_sequence_id());
311
312 // TrackEvents will be ignored while incremental state is invalid. As a
313 // consequence, we should also ignore any ThreadDescriptors received in this
314 // state. Otherwise, any delta-encoded timestamps would be calculated
315 // incorrectly once we move out of the packet loss state. Instead, wait until
316 // the first subsequent descriptor after incremental state is cleared.
317 if (!state->IsIncrementalStateValid()) {
318 context_->storage->IncrementStats(
319 stats::track_event_tokenizer_skipped_packets);
320 return;
321 }
322
323 auto thread_descriptor_field = packet_decoder.thread_descriptor();
324 protos::pbzero::ThreadDescriptor::Decoder thread_descriptor_decoder(
325 thread_descriptor_field.data, thread_descriptor_field.size);
326
327 state->SetThreadDescriptor(
328 thread_descriptor_decoder.pid(), thread_descriptor_decoder.tid(),
329 thread_descriptor_decoder.reference_timestamp_us() * 1000,
330 thread_descriptor_decoder.reference_thread_time_us() * 1000);
331 // TODO(eseckler): Handle other thread_descriptor fields (e.g. thread
332 // name/type).
333 }
334
ParseTrackEventPacket(const protos::pbzero::TracePacket::Decoder & packet_decoder,TraceBlobView packet)335 void ProtoTraceTokenizer::ParseTrackEventPacket(
336 const protos::pbzero::TracePacket::Decoder& packet_decoder,
337 TraceBlobView packet) {
338 constexpr auto kTimestampDeltaUsFieldNumber =
339 protos::pbzero::TrackEvent::kTimestampDeltaUsFieldNumber;
340 constexpr auto kTimestampAbsoluteUsFieldNumber =
341 protos::pbzero::TrackEvent::kTimestampAbsoluteUsFieldNumber;
342 constexpr auto kThreadTimeDeltaUsFieldNumber =
343 protos::pbzero::TrackEvent::kThreadTimeDeltaUsFieldNumber;
344 constexpr auto kThreadTimeAbsoluteUsFieldNumber =
345 protos::pbzero::TrackEvent::kThreadTimeAbsoluteUsFieldNumber;
346
347 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
348 PERFETTO_ELOG("TrackEvent packet without trusted_packet_sequence_id");
349 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
350 return;
351 }
352
353 auto* state = GetIncrementalStateForPacketSequence(
354 packet_decoder.trusted_packet_sequence_id());
355
356 // TrackEvents can only be parsed correctly while incremental state for their
357 // sequence is valid and after a ThreadDescriptor has been parsed.
358 if (!state->IsTrackEventStateValid()) {
359 context_->storage->IncrementStats(
360 stats::track_event_tokenizer_skipped_packets);
361 return;
362 }
363
364 auto field = packet_decoder.track_event();
365 ProtoDecoder event_decoder(field.data, field.size);
366
367 int64_t timestamp;
368 int64_t thread_timestamp = 0;
369
370 if (auto ts_delta_field =
371 event_decoder.FindField(kTimestampDeltaUsFieldNumber)) {
372 timestamp = state->IncrementAndGetTrackEventTimeNs(
373 ts_delta_field.as_int64() * 1000);
374 } else if (auto ts_absolute_field =
375 event_decoder.FindField(kTimestampAbsoluteUsFieldNumber)) {
376 // One-off absolute timestamps don't affect delta computation.
377 timestamp = ts_absolute_field.as_int64() * 1000;
378 } else {
379 PERFETTO_ELOG("TrackEvent without timestamp");
380 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
381 return;
382 }
383
384 if (auto tt_delta_field =
385 event_decoder.FindField(kThreadTimeDeltaUsFieldNumber)) {
386 thread_timestamp = state->IncrementAndGetTrackEventThreadTimeNs(
387 tt_delta_field.as_int64() * 1000);
388 } else if (auto tt_absolute_field =
389 event_decoder.FindField(kThreadTimeAbsoluteUsFieldNumber)) {
390 // One-off absolute timestamps don't affect delta computation.
391 thread_timestamp = tt_absolute_field.as_int64() * 1000;
392 }
393
394 context_->sorter->PushTrackEventPacket(timestamp, thread_timestamp, state,
395 std::move(packet));
396 }
397
398 PERFETTO_ALWAYS_INLINE
ParseFtraceBundle(TraceBlobView bundle)399 void ProtoTraceTokenizer::ParseFtraceBundle(TraceBlobView bundle) {
400 protos::pbzero::FtraceEventBundle::Decoder decoder(bundle.data(),
401 bundle.length());
402
403 if (PERFETTO_UNLIKELY(!decoder.has_cpu())) {
404 PERFETTO_ELOG("CPU field not found in FtraceEventBundle");
405 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
406 return;
407 }
408
409 uint32_t cpu = decoder.cpu();
410 if (PERFETTO_UNLIKELY(cpu > base::kMaxCpus)) {
411 PERFETTO_ELOG("CPU larger than kMaxCpus (%u > %zu)", cpu, base::kMaxCpus);
412 return;
413 }
414
415 for (auto it = decoder.event(); it; ++it) {
416 size_t off = bundle.offset_of(it->data());
417 ParseFtraceEvent(cpu, bundle.slice(off, it->size()));
418 }
419 context_->sorter->FinalizeFtraceEventBatch(cpu);
420 }
421
422 PERFETTO_ALWAYS_INLINE
ParseFtraceEvent(uint32_t cpu,TraceBlobView event)423 void ProtoTraceTokenizer::ParseFtraceEvent(uint32_t cpu, TraceBlobView event) {
424 constexpr auto kTimestampFieldNumber =
425 protos::pbzero::FtraceEvent::kTimestampFieldNumber;
426 const uint8_t* data = event.data();
427 const size_t length = event.length();
428 ProtoDecoder decoder(data, length);
429 uint64_t raw_timestamp = 0;
430 bool timestamp_found = false;
431
432 // Speculate on the fact that the timestamp is often the 1st field of the
433 // event.
434 constexpr auto timestampFieldTag = MakeTagVarInt(kTimestampFieldNumber);
435 if (PERFETTO_LIKELY(length > 10 && data[0] == timestampFieldTag)) {
436 // Fastpath.
437 const uint8_t* next = ParseVarInt(data + 1, data + 11, &raw_timestamp);
438 timestamp_found = next != data + 1;
439 decoder.Reset(next);
440 } else {
441 // Slowpath.
442 if (auto ts_field = decoder.FindField(kTimestampFieldNumber)) {
443 timestamp_found = true;
444 raw_timestamp = ts_field.as_uint64();
445 }
446 }
447
448 if (PERFETTO_UNLIKELY(!timestamp_found)) {
449 PERFETTO_ELOG("Timestamp field not found in FtraceEvent");
450 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
451 return;
452 }
453
454 int64_t timestamp = static_cast<int64_t>(raw_timestamp);
455 latest_timestamp_ = std::max(timestamp, latest_timestamp_);
456
457 // We don't need to parse this packet, just push it to be sorted with
458 // the timestamp.
459 context_->sorter->PushFtraceEvent(cpu, timestamp, std::move(event));
460 }
461
462 } // namespace trace_processor
463 } // namespace perfetto
464