blob: 8c4dd51c3f3f55db7a35c28f60de2fef3eb92778 [file] [log] [blame]
Primiano Tuccid933d912018-09-04 09:15:07 +01001/*
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
Hector Dearman33610d22019-08-07 13:00:20 +010021#include <zlib.h>
22
Primiano Tuccid933d912018-09-04 09:15:07 +010023#include "perfetto/base/logging.h"
Hector Dearman33610d22019-08-07 13:00:20 +010024#include "perfetto/ext/base/optional.h"
Primiano Tucci2c5488f2019-06-01 03:27:28 +010025#include "perfetto/ext/base/utils.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010026#include "perfetto/protozero/proto_decoder.h"
27#include "perfetto/protozero/proto_utils.h"
Primiano Tucci6756fb02019-08-14 15:49:18 +020028#include "src/trace_processor/clock_tracker.h"
Isabelle Taylora97c5f52018-10-23 17:36:12 +010029#include "src/trace_processor/event_tracker.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010030#include "src/trace_processor/process_tracker.h"
Primiano Tucci0e38a142019-01-07 20:51:09 +000031#include "src/trace_processor/stats.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010032#include "src/trace_processor/trace_blob_view.h"
33#include "src/trace_processor/trace_sorter.h"
Primiano Tucci0e38a142019-01-07 20:51:09 +000034#include "src/trace_processor/trace_storage.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010035
Lalit Maganti295a8612019-05-21 13:57:42 +010036#include "perfetto/config/trace_config.pbzero.h"
Primiano Tucci6756fb02019-08-14 15:49:18 +020037#include "perfetto/trace/clock_snapshot.pbzero.h"
Primiano Tuccic1678872019-03-20 11:30:54 +000038#include "perfetto/trace/ftrace/ftrace_event.pbzero.h"
39#include "perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
Eric Seckler684a4f72019-04-26 14:34:07 +010040#include "perfetto/trace/interned_data/interned_data.pbzero.h"
Florian Mayer5716fc12019-06-24 11:50:51 -070041#include "perfetto/trace/profiling/profile_common.pbzero.h"
Primiano Tuccic1678872019-03-20 11:30:54 +000042#include "perfetto/trace/trace.pbzero.h"
Nicolò Mazzucato85940b72019-07-18 10:32:39 +010043#include "perfetto/trace/track_event/source_location.pbzero.h"
Eric Seckler684a4f72019-04-26 14:34:07 +010044#include "perfetto/trace/track_event/task_execution.pbzero.h"
45#include "perfetto/trace/track_event/thread_descriptor.pbzero.h"
46#include "perfetto/trace/track_event/track_event.pbzero.h"
Primiano Tuccid933d912018-09-04 09:15:07 +010047
48namespace perfetto {
49namespace trace_processor {
50
51using protozero::ProtoDecoder;
Primiano Tuccid933d912018-09-04 09:15:07 +010052using protozero::proto_utils::MakeTagLengthDelimited;
53using protozero::proto_utils::MakeTagVarInt;
54using protozero::proto_utils::ParseVarInt;
55
Eric Seckler684a4f72019-04-26 14:34:07 +010056namespace {
57
Hector Dearman33610d22019-08-07 13:00:20 +010058constexpr uint8_t kTracePacketTag =
59 MakeTagLengthDelimited(protos::pbzero::Trace::kPacketFieldNumber);
60
Eric Seckler684a4f72019-04-26 14:34:07 +010061template <typename MessageType>
62void InternMessage(TraceProcessorContext* context,
63 ProtoIncrementalState::PacketSequenceState* state,
64 TraceBlobView message) {
65 constexpr auto kIidFieldNumber = MessageType::kIidFieldNumber;
66
Florian Mayer5716fc12019-06-24 11:50:51 -070067 uint64_t iid = 0;
Eric Seckler684a4f72019-04-26 14:34:07 +010068 auto message_start = message.data();
69 auto message_size = message.length();
70 protozero::ProtoDecoder decoder(message_start, message_size);
71
72 auto field = decoder.FindField(kIidFieldNumber);
73 if (PERFETTO_UNLIKELY(!field)) {
74 PERFETTO_ELOG("Interned message without interning_id");
75 context->storage->IncrementStats(stats::interned_data_tokenizer_errors);
76 return;
77 }
Florian Mayer5716fc12019-06-24 11:50:51 -070078 iid = field.as_uint64();
Eric Seckler684a4f72019-04-26 14:34:07 +010079
80 auto res = state->GetInternedDataMap<MessageType>()->emplace(
81 iid,
Eric Seckler56a007d2019-05-02 16:25:14 +010082 ProtoIncrementalState::InternedDataView<MessageType>(std::move(message)));
Eric Seckler684a4f72019-04-26 14:34:07 +010083 // If a message with this ID is already interned, its data should not have
84 // changed (this is forbidden by the InternedData proto).
85 // TODO(eseckler): This DCHECK assumes that the message is encoded the
86 // same way whenever it is re-emitted.
87 PERFETTO_DCHECK(res.second ||
88 (res.first->second.message.length() == message_size &&
89 memcmp(res.first->second.message.data(), message_start,
90 message_size) == 0));
91}
92
Hector Dearman33610d22019-08-07 13:00:20 +010093TraceBlobView Decompress(TraceBlobView input) {
94 uint8_t out[4096];
95 std::string s;
96
97 z_stream stream{};
98 stream.next_in = const_cast<uint8_t*>(input.data());
99 stream.avail_in = static_cast<unsigned int>(input.length());
100
101 if (inflateInit(&stream) != Z_OK)
102 return TraceBlobView(nullptr, 0, 0);
103
104 int ret;
105 do {
106 stream.next_out = out;
107 stream.avail_out = sizeof(out);
108 ret = inflate(&stream, Z_NO_FLUSH);
109 if (ret != Z_STREAM_END && ret != Z_OK)
110 return TraceBlobView(nullptr, 0, 0);
111 s.append(reinterpret_cast<char*>(out), sizeof(out) - stream.avail_out);
112 } while (ret != Z_STREAM_END);
113 inflateEnd(&stream);
114
115 std::unique_ptr<uint8_t[]> output(new uint8_t[s.size()]);
116 memcpy(output.get(), s.data(), s.size());
117 return TraceBlobView(std::move(output), 0, s.size());
118}
119
Eric Seckler684a4f72019-04-26 14:34:07 +0100120} // namespace
121
Primiano Tuccid933d912018-09-04 09:15:07 +0100122ProtoTraceTokenizer::ProtoTraceTokenizer(TraceProcessorContext* ctx)
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700123 : context_(ctx) {}
Primiano Tuccid933d912018-09-04 09:15:07 +0100124ProtoTraceTokenizer::~ProtoTraceTokenizer() = default;
125
Lalit Magantid71a9452019-05-09 15:13:24 +0100126util::Status ProtoTraceTokenizer::Parse(std::unique_ptr<uint8_t[]> owned_buf,
127 size_t size) {
Primiano Tuccid933d912018-09-04 09:15:07 +0100128 uint8_t* data = &owned_buf[0];
129 if (!partial_buf_.empty()) {
130 // It takes ~5 bytes for a proto preamble + the varint size.
131 const size_t kHeaderBytes = 5;
132 if (PERFETTO_UNLIKELY(partial_buf_.size() < kHeaderBytes)) {
133 size_t missing_len = std::min(kHeaderBytes - partial_buf_.size(), size);
134 partial_buf_.insert(partial_buf_.end(), &data[0], &data[missing_len]);
135 if (partial_buf_.size() < kHeaderBytes)
Lalit Magantid71a9452019-05-09 15:13:24 +0100136 return util::OkStatus();
Primiano Tuccid933d912018-09-04 09:15:07 +0100137 data += missing_len;
138 size -= missing_len;
139 }
140
Primiano Tuccic1678872019-03-20 11:30:54 +0000141 // At this point we have enough data in |partial_buf_| to read at least the
Primiano Tuccid933d912018-09-04 09:15:07 +0100142 // field header and know the size of the next TracePacket.
Primiano Tuccid933d912018-09-04 09:15:07 +0100143 const uint8_t* pos = &partial_buf_[0];
144 uint8_t proto_field_tag = *pos;
145 uint64_t field_size = 0;
146 const uint8_t* next = ParseVarInt(++pos, &*partial_buf_.end(), &field_size);
147 bool parse_failed = next == pos;
148 pos = next;
149 if (proto_field_tag != kTracePacketTag || field_size == 0 || parse_failed) {
Lalit Magantid71a9452019-05-09 15:13:24 +0100150 return util::ErrStatus(
151 "Failed parsing a TracePacket from the partial buffer");
Primiano Tuccid933d912018-09-04 09:15:07 +0100152 }
153
154 // At this point we know how big the TracePacket is.
155 size_t hdr_size = static_cast<size_t>(pos - &partial_buf_[0]);
156 size_t size_incl_header = static_cast<size_t>(field_size + hdr_size);
157 PERFETTO_DCHECK(size_incl_header > partial_buf_.size());
158
159 // There is a good chance that between the |partial_buf_| and the new |data|
160 // of the current call we have enough bytes to parse a TracePacket.
161 if (partial_buf_.size() + size >= size_incl_header) {
162 // Create a new buffer for the whole TracePacket and copy into that:
163 // 1) The beginning of the TracePacket (including the proto header) from
164 // the partial buffer.
165 // 2) The rest of the TracePacket from the current |data| buffer (note
166 // that we might have consumed already a few bytes form |data| earlier
167 // in this function, hence we need to keep |off| into account).
168 std::unique_ptr<uint8_t[]> buf(new uint8_t[size_incl_header]);
169 memcpy(&buf[0], partial_buf_.data(), partial_buf_.size());
170 // |size_missing| is the number of bytes for the rest of the TracePacket
171 // in |data|.
172 size_t size_missing = size_incl_header - partial_buf_.size();
173 memcpy(&buf[partial_buf_.size()], &data[0], size_missing);
174 data += size_missing;
175 size -= size_missing;
176 partial_buf_.clear();
177 uint8_t* buf_start = &buf[0]; // Note that buf is std::moved below.
Lalit Magantid71a9452019-05-09 15:13:24 +0100178 util::Status status =
179 ParseInternal(std::move(buf), buf_start, size_incl_header);
180 if (PERFETTO_UNLIKELY(!status.ok()))
181 return status;
Primiano Tuccid933d912018-09-04 09:15:07 +0100182 } else {
183 partial_buf_.insert(partial_buf_.end(), data, &data[size]);
Lalit Magantid71a9452019-05-09 15:13:24 +0100184 return util::OkStatus();
Primiano Tuccid933d912018-09-04 09:15:07 +0100185 }
186 }
Lalit Magantid71a9452019-05-09 15:13:24 +0100187 return ParseInternal(std::move(owned_buf), data, size);
Primiano Tuccid933d912018-09-04 09:15:07 +0100188}
189
Lalit Magantid71a9452019-05-09 15:13:24 +0100190util::Status ProtoTraceTokenizer::ParseInternal(
191 std::unique_ptr<uint8_t[]> owned_buf,
192 uint8_t* data,
193 size_t size) {
Primiano Tuccid933d912018-09-04 09:15:07 +0100194 PERFETTO_DCHECK(data >= &owned_buf[0]);
195 const uint8_t* start = &owned_buf[0];
196 const size_t data_off = static_cast<size_t>(data - start);
197 TraceBlobView whole_buf(std::move(owned_buf), data_off, size);
Primiano Tuccic1678872019-03-20 11:30:54 +0000198
199 protos::pbzero::Trace::Decoder decoder(data, size);
200 for (auto it = decoder.packet(); it; ++it) {
201 size_t field_offset = whole_buf.offset_of(it->data());
Lalit Magantid71a9452019-05-09 15:13:24 +0100202 util::Status status =
203 ParsePacket(whole_buf.slice(field_offset, it->size()));
204 if (PERFETTO_UNLIKELY(!status.ok()))
205 return status;
Primiano Tuccid933d912018-09-04 09:15:07 +0100206 }
207
Primiano Tuccic1678872019-03-20 11:30:54 +0000208 const size_t bytes_left = decoder.bytes_left();
209 if (bytes_left > 0) {
Primiano Tuccid933d912018-09-04 09:15:07 +0100210 PERFETTO_DCHECK(partial_buf_.empty());
Primiano Tuccic1678872019-03-20 11:30:54 +0000211 partial_buf_.insert(partial_buf_.end(), &data[decoder.read_offset()],
212 &data[decoder.read_offset() + bytes_left]);
Primiano Tuccid933d912018-09-04 09:15:07 +0100213 }
Lalit Magantid71a9452019-05-09 15:13:24 +0100214 return util::OkStatus();
Primiano Tuccid933d912018-09-04 09:15:07 +0100215}
216
Lalit Magantid71a9452019-05-09 15:13:24 +0100217util::Status ProtoTraceTokenizer::ParsePacket(TraceBlobView packet) {
Primiano Tuccic1678872019-03-20 11:30:54 +0000218 protos::pbzero::TracePacket::Decoder decoder(packet.data(), packet.length());
Lalit Maganti4b2b2532019-05-09 11:03:23 +0100219 if (PERFETTO_UNLIKELY(decoder.bytes_left()))
Lalit Magantid71a9452019-05-09 15:13:24 +0100220 return util::ErrStatus(
221 "Failed to parse proto packet fully; the trace is probably corrupt.");
Primiano Tuccid933d912018-09-04 09:15:07 +0100222
Primiano Tuccic1678872019-03-20 11:30:54 +0000223 auto timestamp = decoder.has_timestamp()
224 ? static_cast<int64_t>(decoder.timestamp())
225 : latest_timestamp_;
Primiano Tucci6756fb02019-08-14 15:49:18 +0200226
227 // If the TracePacket specifies a non-zero clock-id, translate the timestamp
228 // into the trace-time clock domain.
229 if (decoder.timestamp_clock_id()) {
230 PERFETTO_DCHECK(decoder.has_timestamp());
231 ClockTracker::ClockId clock_id = decoder.timestamp_clock_id();
232 const uint32_t seq_id = decoder.trusted_packet_sequence_id();
233 bool is_seq_scoped = ClockTracker::IsReservedSeqScopedClockId(clock_id);
234 if (is_seq_scoped) {
235 if (!seq_id) {
236 return util::ErrStatus(
237 "TracePacket specified a sequence-local clock id (%" PRIu32
238 ") but the TraceWriter's sequence_id is zero (the service is "
239 "probably too old)",
240 seq_id);
241 }
242 clock_id = ClockTracker::SeqScopedClockIdToGlobal(
243 seq_id, decoder.timestamp_clock_id());
244 }
245 auto trace_ts = context_->clock_tracker->ToTraceTime(clock_id, timestamp);
246 if (!trace_ts.has_value()) {
247 // ToTraceTime() will increase the |clock_sync_failure| stat on failure.
248 static const char seq_extra_err[] =
249 " Because the clock id is sequence-scoped, the ClockSnapshot must be "
250 "emitted on the same TraceWriter sequence of the packet that refers "
251 "to that clock id.";
252 return util::ErrStatus(
253 "Failed to convert TracePacket's timestamp from clock_id=%" PRIu32
254 " seq_id=%" PRIu32
255 ". This is usually due to the lack of a prior ClockSnapshot proto.%s",
256 decoder.timestamp_clock_id(), seq_id,
257 is_seq_scoped ? seq_extra_err : "");
258 }
259 timestamp = trace_ts.value();
260 }
Lalit Magantifa21a282019-01-17 19:03:04 +0000261 latest_timestamp_ = std::max(timestamp, latest_timestamp_);
Primiano Tuccid933d912018-09-04 09:15:07 +0100262
Eric Seckler684a4f72019-04-26 14:34:07 +0100263 if (decoder.incremental_state_cleared()) {
264 HandleIncrementalStateCleared(decoder);
265 } else if (decoder.previous_packet_dropped()) {
266 HandlePreviousPacketDropped(decoder);
267 }
268
Primiano Tucci6756fb02019-08-14 15:49:18 +0200269 if (decoder.has_clock_snapshot()) {
270 return ParseClockSnapshot(decoder.clock_snapshot(),
271 decoder.trusted_packet_sequence_id());
272 }
273
Eric Seckler684a4f72019-04-26 14:34:07 +0100274 if (decoder.has_interned_data()) {
275 auto field = decoder.interned_data();
276 const size_t offset = packet.offset_of(field.data);
277 ParseInternedData(decoder, packet.slice(offset, field.size));
278 }
279
Primiano Tuccic1678872019-03-20 11:30:54 +0000280 if (decoder.has_ftrace_events()) {
281 auto ftrace_field = decoder.ftrace_events();
282 const size_t fld_off = packet.offset_of(ftrace_field.data);
283 ParseFtraceBundle(packet.slice(fld_off, ftrace_field.size));
Lalit Magantid71a9452019-05-09 15:13:24 +0100284 return util::OkStatus();
Primiano Tuccid933d912018-09-04 09:15:07 +0100285 }
286
Eric Seckler684a4f72019-04-26 14:34:07 +0100287 if (decoder.has_track_event()) {
288 ParseTrackEventPacket(decoder, std::move(packet));
Lalit Magantid71a9452019-05-09 15:13:24 +0100289 return util::OkStatus();
Eric Seckler684a4f72019-04-26 14:34:07 +0100290 }
291
292 if (decoder.has_thread_descriptor()) {
293 ParseThreadDescriptorPacket(decoder);
Lalit Magantid71a9452019-05-09 15:13:24 +0100294 return util::OkStatus();
Eric Seckler684a4f72019-04-26 14:34:07 +0100295 }
296
Hector Dearman33610d22019-08-07 13:00:20 +0100297 if (decoder.has_compressed_packets()) {
298 protozero::ConstBytes field = decoder.compressed_packets();
299 const size_t field_off = packet.offset_of(field.data);
300 TraceBlobView compressed_packets = packet.slice(field_off, field.size);
301 TraceBlobView packets = Decompress(std::move(compressed_packets));
302
303 const uint8_t* start = packets.data();
304 const uint8_t* end = packets.data() + packets.length();
305 const uint8_t* ptr = start;
306 while ((end - ptr) > 2) {
307 const uint8_t* packet_start = ptr;
308 if (PERFETTO_UNLIKELY(*ptr != kTracePacketTag))
309 return util::ErrStatus("Expected TracePacket tag");
310 uint64_t packet_size = 0;
311 ptr = ParseVarInt(++ptr, end, &packet_size);
312 size_t packet_offset = static_cast<size_t>(ptr - start);
313 ptr += packet_size;
314 if (PERFETTO_UNLIKELY((ptr - packet_start) < 2 || ptr > end))
315 return util::ErrStatus("Invalid packet size");
316 util::Status status = ParsePacket(
317 packets.slice(packet_offset, static_cast<size_t>(packet_size)));
318 if (PERFETTO_UNLIKELY(!status.ok()))
319 return status;
320 }
321
322 return util::OkStatus();
323 }
324
Lalit Maganti295a8612019-05-21 13:57:42 +0100325 if (decoder.has_trace_config()) {
326 auto config = decoder.trace_config();
327 protos::pbzero::TraceConfig::Decoder trace_config(config.data, config.size);
328
329 if (trace_config.write_into_file()) {
330 int64_t window_size_ns;
331 if (trace_config.has_flush_period_ms() &&
332 trace_config.flush_period_ms() > 0) {
333 // We use 2x the flush period as a margin of error to allow for any
334 // late flush responses to still be sorted correctly.
Lalit Magantib2c2f562019-05-22 18:53:46 +0100335 window_size_ns = static_cast<int64_t>(trace_config.flush_period_ms()) *
336 2 * 1000 * 1000;
Lalit Maganti295a8612019-05-21 13:57:42 +0100337 } else {
338 constexpr uint64_t kDefaultWindowNs =
339 180 * 1000 * 1000 * 1000ULL; // 3 minutes.
340 PERFETTO_ELOG(
341 "It is strongly recommended to have flush_period_ms set when "
342 "write_into_file is turned on. You will likely have many dropped "
343 "events because of inability to sort the events correctly.");
344 window_size_ns = static_cast<int64_t>(kDefaultWindowNs);
345 }
346 context_->sorter->SetWindowSizeNs(window_size_ns);
347 }
348 }
349
Florian Mayer5716fc12019-06-24 11:50:51 -0700350 auto* state = GetIncrementalStateForPacketSequence(
351 decoder.trusted_packet_sequence_id());
352
Primiano Tuccid933d912018-09-04 09:15:07 +0100353 // Use parent data and length because we want to parse this again
354 // later to get the exact type of the packet.
Florian Mayer5716fc12019-06-24 11:50:51 -0700355 context_->sorter->PushTracePacket(timestamp, state, std::move(packet));
Lalit Maganti4b2b2532019-05-09 11:03:23 +0100356
Lalit Magantid71a9452019-05-09 15:13:24 +0100357 return util::OkStatus();
Eric Seckler684a4f72019-04-26 14:34:07 +0100358}
359
360void ProtoTraceTokenizer::HandleIncrementalStateCleared(
361 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
362 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
363 PERFETTO_ELOG(
364 "incremental_state_cleared without trusted_packet_sequence_id");
365 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
366 return;
367 }
368 GetIncrementalStateForPacketSequence(
369 packet_decoder.trusted_packet_sequence_id())
370 ->OnIncrementalStateCleared();
371}
372
373void ProtoTraceTokenizer::HandlePreviousPacketDropped(
374 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
375 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
376 PERFETTO_ELOG("previous_packet_dropped without trusted_packet_sequence_id");
377 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
378 return;
379 }
380 GetIncrementalStateForPacketSequence(
381 packet_decoder.trusted_packet_sequence_id())
382 ->OnPacketLoss();
383}
384
385void ProtoTraceTokenizer::ParseInternedData(
386 const protos::pbzero::TracePacket::Decoder& packet_decoder,
387 TraceBlobView interned_data) {
388 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
389 PERFETTO_ELOG("InternedData packet without trusted_packet_sequence_id");
390 context_->storage->IncrementStats(stats::interned_data_tokenizer_errors);
391 return;
392 }
393
394 auto* state = GetIncrementalStateForPacketSequence(
395 packet_decoder.trusted_packet_sequence_id());
396
397 protos::pbzero::InternedData::Decoder interned_data_decoder(
398 interned_data.data(), interned_data.length());
399
400 // Store references to interned data submessages into the sequence's state.
401 for (auto it = interned_data_decoder.event_categories(); it; ++it) {
402 size_t offset = interned_data.offset_of(it->data());
403 InternMessage<protos::pbzero::EventCategory>(
404 context_, state, interned_data.slice(offset, it->size()));
405 }
406
Eric Seckler0c460ef2019-08-14 15:42:36 +0100407 for (auto it = interned_data_decoder.event_names(); it; ++it) {
Eric Seckler684a4f72019-04-26 14:34:07 +0100408 size_t offset = interned_data.offset_of(it->data());
Eric Seckler0c460ef2019-08-14 15:42:36 +0100409 InternMessage<protos::pbzero::EventName>(
Eric Seckler684a4f72019-04-26 14:34:07 +0100410 context_, state, interned_data.slice(offset, it->size()));
411 }
412
413 for (auto it = interned_data_decoder.debug_annotation_names(); it; ++it) {
414 size_t offset = interned_data.offset_of(it->data());
415 InternMessage<protos::pbzero::DebugAnnotationName>(
416 context_, state, interned_data.slice(offset, it->size()));
417 }
418
419 for (auto it = interned_data_decoder.source_locations(); it; ++it) {
420 size_t offset = interned_data.offset_of(it->data());
421 InternMessage<protos::pbzero::SourceLocation>(
422 context_, state, interned_data.slice(offset, it->size()));
423 }
Florian Mayer5716fc12019-06-24 11:50:51 -0700424
425 for (auto it = interned_data_decoder.build_ids(); it; ++it) {
426 size_t offset = interned_data.offset_of(it->data());
427 InternMessage<protos::pbzero::InternedString>(
428 context_, state, interned_data.slice(offset, it->size()));
429 }
430 for (auto it = interned_data_decoder.mapping_paths(); it; ++it) {
431 size_t offset = interned_data.offset_of(it->data());
432 InternMessage<protos::pbzero::InternedString>(
433 context_, state, interned_data.slice(offset, it->size()));
434 }
435 for (auto it = interned_data_decoder.function_names(); it; ++it) {
436 size_t offset = interned_data.offset_of(it->data());
437 InternMessage<protos::pbzero::InternedString>(
438 context_, state, interned_data.slice(offset, it->size()));
439 }
440
441 for (auto it = interned_data_decoder.mappings(); it; ++it) {
442 size_t offset = interned_data.offset_of(it->data());
443 InternMessage<protos::pbzero::Mapping>(
444 context_, state, interned_data.slice(offset, it->size()));
445 }
446 for (auto it = interned_data_decoder.frames(); it; ++it) {
447 size_t offset = interned_data.offset_of(it->data());
448 InternMessage<protos::pbzero::Frame>(
449 context_, state, interned_data.slice(offset, it->size()));
450 }
451 for (auto it = interned_data_decoder.callstacks(); it; ++it) {
452 size_t offset = interned_data.offset_of(it->data());
453 InternMessage<protos::pbzero::Callstack>(
454 context_, state, interned_data.slice(offset, it->size()));
455 }
Nicolò Mazzucato8f75ede2019-08-12 17:36:36 +0100456
457 for (auto it = interned_data_decoder.log_message_body(); it; ++it) {
458 size_t offset = interned_data.offset_of(it->data());
459 InternMessage<protos::pbzero::LogMessageBody>(
460 context_, state, interned_data.slice(offset, it->size()));
461 }
Eric Seckler684a4f72019-04-26 14:34:07 +0100462}
463
464void ProtoTraceTokenizer::ParseThreadDescriptorPacket(
465 const protos::pbzero::TracePacket::Decoder& packet_decoder) {
466 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
467 PERFETTO_ELOG("ThreadDescriptor packet without trusted_packet_sequence_id");
468 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
469 return;
470 }
471
472 auto* state = GetIncrementalStateForPacketSequence(
473 packet_decoder.trusted_packet_sequence_id());
474
475 // TrackEvents will be ignored while incremental state is invalid. As a
476 // consequence, we should also ignore any ThreadDescriptors received in this
477 // state. Otherwise, any delta-encoded timestamps would be calculated
478 // incorrectly once we move out of the packet loss state. Instead, wait until
479 // the first subsequent descriptor after incremental state is cleared.
480 if (!state->IsIncrementalStateValid()) {
481 context_->storage->IncrementStats(
482 stats::track_event_tokenizer_skipped_packets);
483 return;
484 }
485
486 auto thread_descriptor_field = packet_decoder.thread_descriptor();
487 protos::pbzero::ThreadDescriptor::Decoder thread_descriptor_decoder(
488 thread_descriptor_field.data, thread_descriptor_field.size);
489
490 state->SetThreadDescriptor(
491 thread_descriptor_decoder.pid(), thread_descriptor_decoder.tid(),
492 thread_descriptor_decoder.reference_timestamp_us() * 1000,
Eric Seckler54f30a32019-07-19 15:10:29 +0100493 thread_descriptor_decoder.reference_thread_time_us() * 1000,
494 thread_descriptor_decoder.reference_thread_instruction_count());
Siddhartha Sd37e5662019-06-13 18:27:42 -0700495
496 base::StringView name;
497 if (thread_descriptor_decoder.has_thread_name()) {
498 name = thread_descriptor_decoder.thread_name();
499 } else if (thread_descriptor_decoder.has_chrome_thread_type()) {
500 using protos::pbzero::ThreadDescriptor;
501 switch (thread_descriptor_decoder.chrome_thread_type()) {
502 case ThreadDescriptor::CHROME_THREAD_MAIN:
503 name = "CrProcessMain";
504 break;
505 case ThreadDescriptor::CHROME_THREAD_IO:
506 name = "ChromeIOThread";
507 break;
508 case ThreadDescriptor::CHROME_THREAD_POOL_FG_WORKER:
509 name = "ThreadPoolForegroundWorker&";
510 break;
511 case ThreadDescriptor::CHROME_THREAD_POOL_BG_WORKER:
512 name = "ThreadPoolBackgroundWorker&";
513 break;
514 case ThreadDescriptor::CHROME_THREAD_POOL_FB_BLOCKING:
515 name = "ThreadPoolSingleThreadForegroundBlocking&";
516 break;
517 case ThreadDescriptor::CHROME_THREAD_POOL_BG_BLOCKING:
518 name = "ThreadPoolSingleThreadBackgroundBlocking&";
519 break;
520 case ThreadDescriptor::CHROME_THREAD_POOL_SERVICE:
521 name = "ThreadPoolService";
522 break;
523 case ThreadDescriptor::CHROME_THREAD_COMPOSITOR_WORKER:
524 name = "CompositorTileWorker&";
525 break;
526 case ThreadDescriptor::CHROME_THREAD_COMPOSITOR:
527 name = "Compositor";
528 break;
529 case ThreadDescriptor::CHROME_THREAD_VIZ_COMPOSITOR:
530 name = "VizCompositorThread";
531 break;
532 case ThreadDescriptor::CHROME_THREAD_SERVICE_WORKER:
533 name = "ServiceWorkerThread&";
534 break;
535 case ThreadDescriptor::CHROME_THREAD_MEMORY_INFRA:
536 name = "MemoryInfra";
537 break;
538 case ThreadDescriptor::CHROME_THREAD_SAMPLING_PROFILER:
539 name = "StackSamplingProfiler";
540 break;
541 case ThreadDescriptor::CHROME_THREAD_UNSPECIFIED:
542 name = "ChromeUnspecified";
543 break;
544 }
545 }
546
547 if (!name.empty()) {
548 auto thread_name_id = context_->storage->InternString(name);
549 ProcessTracker* procs = context_->process_tracker.get();
550 procs->UpdateThreadName(
551 static_cast<uint32_t>(thread_descriptor_decoder.tid()), thread_name_id);
552 }
Eric Seckler684a4f72019-04-26 14:34:07 +0100553}
554
Primiano Tucci6756fb02019-08-14 15:49:18 +0200555util::Status ProtoTraceTokenizer::ParseClockSnapshot(ConstBytes blob,
556 uint32_t seq_id) {
557 std::map<ClockTracker::ClockId, int64_t> clock_map;
558 protos::pbzero::ClockSnapshot::Decoder evt(blob.data, blob.size);
559 for (auto it = evt.clocks(); it; ++it) {
560 protos::pbzero::ClockSnapshot::Clock::Decoder clk(it->data(), it->size());
561 ClockTracker::ClockId clock_id = clk.clock_id();
562 if (ClockTracker::IsReservedSeqScopedClockId(clk.clock_id())) {
563 if (!seq_id) {
564 return util::ErrStatus(
565 "ClockSnapshot packet is specifying a sequence-scoped clock id "
566 "(%" PRIu64 ") but the TracePacket sequence_id is zero",
567 clock_id);
568 }
569 clock_id = ClockTracker::SeqScopedClockIdToGlobal(seq_id, clk.clock_id());
570 }
571 clock_map[clock_id] = static_cast<int64_t>(clk.timestamp());
572 }
573 context_->clock_tracker->AddSnapshot(clock_map);
574 return util::OkStatus();
575}
576
Eric Seckler684a4f72019-04-26 14:34:07 +0100577void ProtoTraceTokenizer::ParseTrackEventPacket(
578 const protos::pbzero::TracePacket::Decoder& packet_decoder,
579 TraceBlobView packet) {
580 constexpr auto kTimestampDeltaUsFieldNumber =
581 protos::pbzero::TrackEvent::kTimestampDeltaUsFieldNumber;
582 constexpr auto kTimestampAbsoluteUsFieldNumber =
583 protos::pbzero::TrackEvent::kTimestampAbsoluteUsFieldNumber;
584 constexpr auto kThreadTimeDeltaUsFieldNumber =
585 protos::pbzero::TrackEvent::kThreadTimeDeltaUsFieldNumber;
586 constexpr auto kThreadTimeAbsoluteUsFieldNumber =
587 protos::pbzero::TrackEvent::kThreadTimeAbsoluteUsFieldNumber;
Eric Seckler54f30a32019-07-19 15:10:29 +0100588 constexpr auto kThreadInstructionCountDeltaFieldNumber =
589 protos::pbzero::TrackEvent::kThreadInstructionCountDeltaFieldNumber;
590 constexpr auto kThreadInstructionCountAbsoluteFieldNumber =
591 protos::pbzero::TrackEvent::kThreadInstructionCountAbsoluteFieldNumber;
Eric Seckler684a4f72019-04-26 14:34:07 +0100592
593 if (PERFETTO_UNLIKELY(!packet_decoder.has_trusted_packet_sequence_id())) {
594 PERFETTO_ELOG("TrackEvent packet without trusted_packet_sequence_id");
595 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
596 return;
597 }
598
599 auto* state = GetIncrementalStateForPacketSequence(
600 packet_decoder.trusted_packet_sequence_id());
601
602 // TrackEvents can only be parsed correctly while incremental state for their
603 // sequence is valid and after a ThreadDescriptor has been parsed.
604 if (!state->IsTrackEventStateValid()) {
605 context_->storage->IncrementStats(
606 stats::track_event_tokenizer_skipped_packets);
607 return;
608 }
609
610 auto field = packet_decoder.track_event();
611 ProtoDecoder event_decoder(field.data, field.size);
612
613 int64_t timestamp;
614 int64_t thread_timestamp = 0;
Eric Seckler54f30a32019-07-19 15:10:29 +0100615 int64_t thread_instructions = 0;
Eric Seckler684a4f72019-04-26 14:34:07 +0100616
617 if (auto ts_delta_field =
618 event_decoder.FindField(kTimestampDeltaUsFieldNumber)) {
619 timestamp = state->IncrementAndGetTrackEventTimeNs(
620 ts_delta_field.as_int64() * 1000);
621 } else if (auto ts_absolute_field =
622 event_decoder.FindField(kTimestampAbsoluteUsFieldNumber)) {
623 // One-off absolute timestamps don't affect delta computation.
624 timestamp = ts_absolute_field.as_int64() * 1000;
625 } else {
626 PERFETTO_ELOG("TrackEvent without timestamp");
627 context_->storage->IncrementStats(stats::track_event_tokenizer_errors);
628 return;
629 }
630
631 if (auto tt_delta_field =
632 event_decoder.FindField(kThreadTimeDeltaUsFieldNumber)) {
633 thread_timestamp = state->IncrementAndGetTrackEventThreadTimeNs(
634 tt_delta_field.as_int64() * 1000);
635 } else if (auto tt_absolute_field =
636 event_decoder.FindField(kThreadTimeAbsoluteUsFieldNumber)) {
637 // One-off absolute timestamps don't affect delta computation.
638 thread_timestamp = tt_absolute_field.as_int64() * 1000;
639 }
640
Eric Seckler54f30a32019-07-19 15:10:29 +0100641 if (auto ti_delta_field =
642 event_decoder.FindField(kThreadInstructionCountDeltaFieldNumber)) {
643 thread_instructions =
644 state->IncrementAndGetTrackEventThreadInstructionCount(
645 ti_delta_field.as_int64());
646 } else if (auto ti_absolute_field = event_decoder.FindField(
647 kThreadInstructionCountAbsoluteFieldNumber)) {
648 // One-off absolute timestamps don't affect delta computation.
649 thread_instructions = ti_absolute_field.as_int64();
650 }
651
652 context_->sorter->PushTrackEventPacket(timestamp, thread_timestamp,
653 thread_instructions, state,
Eric Seckler684a4f72019-04-26 14:34:07 +0100654 std::move(packet));
Primiano Tuccid933d912018-09-04 09:15:07 +0100655}
656
657PERFETTO_ALWAYS_INLINE
658void ProtoTraceTokenizer::ParseFtraceBundle(TraceBlobView bundle) {
Primiano Tuccic1678872019-03-20 11:30:54 +0000659 protos::pbzero::FtraceEventBundle::Decoder decoder(bundle.data(),
660 bundle.length());
Primiano Tuccid933d912018-09-04 09:15:07 +0100661
Primiano Tuccic1678872019-03-20 11:30:54 +0000662 if (PERFETTO_UNLIKELY(!decoder.has_cpu())) {
663 PERFETTO_ELOG("CPU field not found in FtraceEventBundle");
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700664 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
Hector Dearman52642ce2019-03-07 15:31:11 +0000665 return;
666 }
667
Primiano Tuccic1678872019-03-20 11:30:54 +0000668 uint32_t cpu = decoder.cpu();
669 if (PERFETTO_UNLIKELY(cpu > base::kMaxCpus)) {
670 PERFETTO_ELOG("CPU larger than kMaxCpus (%u > %zu)", cpu, base::kMaxCpus);
671 return;
Primiano Tuccid933d912018-09-04 09:15:07 +0100672 }
Primiano Tuccic1678872019-03-20 11:30:54 +0000673
674 for (auto it = decoder.event(); it; ++it) {
675 size_t off = bundle.offset_of(it->data());
676 ParseFtraceEvent(cpu, bundle.slice(off, it->size()));
677 }
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700678 context_->sorter->FinalizeFtraceEventBatch(cpu);
Primiano Tuccid933d912018-09-04 09:15:07 +0100679}
680
681PERFETTO_ALWAYS_INLINE
682void ProtoTraceTokenizer::ParseFtraceEvent(uint32_t cpu, TraceBlobView event) {
683 constexpr auto kTimestampFieldNumber =
Primiano Tuccic1678872019-03-20 11:30:54 +0000684 protos::pbzero::FtraceEvent::kTimestampFieldNumber;
Primiano Tuccid933d912018-09-04 09:15:07 +0100685 const uint8_t* data = event.data();
686 const size_t length = event.length();
687 ProtoDecoder decoder(data, length);
Lalit Magantifa21a282019-01-17 19:03:04 +0000688 uint64_t raw_timestamp = 0;
Primiano Tuccid933d912018-09-04 09:15:07 +0100689 bool timestamp_found = false;
690
691 // Speculate on the fact that the timestamp is often the 1st field of the
692 // event.
693 constexpr auto timestampFieldTag = MakeTagVarInt(kTimestampFieldNumber);
694 if (PERFETTO_LIKELY(length > 10 && data[0] == timestampFieldTag)) {
695 // Fastpath.
Lalit Magantifa21a282019-01-17 19:03:04 +0000696 const uint8_t* next = ParseVarInt(data + 1, data + 11, &raw_timestamp);
Primiano Tuccid933d912018-09-04 09:15:07 +0100697 timestamp_found = next != data + 1;
698 decoder.Reset(next);
699 } else {
700 // Slowpath.
Primiano Tuccic1678872019-03-20 11:30:54 +0000701 if (auto ts_field = decoder.FindField(kTimestampFieldNumber)) {
702 timestamp_found = true;
703 raw_timestamp = ts_field.as_uint64();
704 }
Primiano Tuccid933d912018-09-04 09:15:07 +0100705 }
706
707 if (PERFETTO_UNLIKELY(!timestamp_found)) {
708 PERFETTO_ELOG("Timestamp field not found in FtraceEvent");
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700709 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
Primiano Tuccid933d912018-09-04 09:15:07 +0100710 return;
711 }
712
Lalit Magantifa21a282019-01-17 19:03:04 +0000713 int64_t timestamp = static_cast<int64_t>(raw_timestamp);
714 latest_timestamp_ = std::max(timestamp, latest_timestamp_);
Primiano Tuccid933d912018-09-04 09:15:07 +0100715
716 // We don't need to parse this packet, just push it to be sorted with
717 // the timestamp.
Deepanjan Roy01994ca2019-04-02 11:05:34 -0700718 context_->sorter->PushFtraceEvent(cpu, timestamp, std::move(event));
Primiano Tuccid933d912018-09-04 09:15:07 +0100719}
720
721} // namespace trace_processor
722} // namespace perfetto