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/ftrace/ftrace_tokenizer.h"
18
19 #include "perfetto/base/logging.h"
20 #include "perfetto/protozero/proto_decoder.h"
21 #include "perfetto/protozero/proto_utils.h"
22 #include "src/trace_processor/importers/proto/packet_sequence_state.h"
23 #include "src/trace_processor/sorter/trace_sorter.h"
24 #include "src/trace_processor/storage/stats.h"
25 #include "src/trace_processor/storage/trace_storage.h"
26
27 #include "protos/perfetto/common/builtin_clock.pbzero.h"
28 #include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
29 #include "protos/perfetto/trace/ftrace/ftrace_event_bundle.pbzero.h"
30
31 namespace perfetto {
32 namespace trace_processor {
33
34 using protozero::ProtoDecoder;
35 using protozero::proto_utils::MakeTagVarInt;
36 using protozero::proto_utils::ParseVarInt;
37
38 using protos::pbzero::BuiltinClock;
39 using protos::pbzero::FtraceClock;
40 using protos::pbzero::FtraceEventBundle;
41
42 namespace {
43
44 static constexpr uint32_t kFtraceGlobalClockIdForOldKernels = 64;
45
ResolveTraceTime(TraceProcessorContext * context,ClockTracker::ClockId clock_id,int64_t ts)46 PERFETTO_ALWAYS_INLINE base::StatusOr<int64_t> ResolveTraceTime(
47 TraceProcessorContext* context,
48 ClockTracker::ClockId clock_id,
49 int64_t ts) {
50 // On most traces (i.e. P+), the clock should be BOOTTIME.
51 if (PERFETTO_LIKELY(clock_id == BuiltinClock::BUILTIN_CLOCK_BOOTTIME))
52 return ts;
53 return context->clock_tracker->ToTraceTime(clock_id, ts);
54 }
55
56 } // namespace
57
58 PERFETTO_ALWAYS_INLINE
TokenizeFtraceBundle(TraceBlobView bundle,PacketSequenceState * state,uint32_t packet_sequence_id)59 base::Status FtraceTokenizer::TokenizeFtraceBundle(
60 TraceBlobView bundle,
61 PacketSequenceState* state,
62 uint32_t packet_sequence_id) {
63 protos::pbzero::FtraceEventBundle::Decoder decoder(bundle.data(),
64 bundle.length());
65
66 if (PERFETTO_UNLIKELY(!decoder.has_cpu())) {
67 PERFETTO_ELOG("CPU field not found in FtraceEventBundle");
68 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
69 return base::OkStatus();
70 }
71
72 uint32_t cpu = decoder.cpu();
73 static constexpr uint32_t kMaxCpuCount = 1024;
74 if (PERFETTO_UNLIKELY(cpu >= kMaxCpuCount)) {
75 return base::ErrStatus(
76 "CPU %u is greater than maximum allowed of %u. This is likely because "
77 "of trace corruption",
78 cpu, kMaxCpuCount);
79 }
80
81 ClockTracker::ClockId clock_id;
82 switch (decoder.ftrace_clock()) {
83 case FtraceClock::FTRACE_CLOCK_UNSPECIFIED:
84 clock_id = BuiltinClock::BUILTIN_CLOCK_BOOTTIME;
85 break;
86 case FtraceClock::FTRACE_CLOCK_GLOBAL:
87 clock_id = ClockTracker::SeqenceToGlobalClock(
88 packet_sequence_id, kFtraceGlobalClockIdForOldKernels);
89 break;
90 case FtraceClock::FTRACE_CLOCK_MONO_RAW:
91 clock_id = BuiltinClock::BUILTIN_CLOCK_MONOTONIC_RAW;
92 break;
93 case FtraceClock::FTRACE_CLOCK_LOCAL:
94 return base::ErrStatus("Unable to parse ftrace packets with local clock");
95 default:
96 return base::ErrStatus(
97 "Unable to parse ftrace packets with unknown clock");
98 }
99
100 if (decoder.has_ftrace_timestamp()) {
101 PERFETTO_DCHECK(clock_id != BuiltinClock::BUILTIN_CLOCK_BOOTTIME);
102 HandleFtraceClockSnapshot(decoder.ftrace_timestamp(),
103 decoder.boot_timestamp(), packet_sequence_id);
104 }
105
106 if (decoder.has_compact_sched()) {
107 TokenizeFtraceCompactSched(cpu, clock_id, decoder.compact_sched());
108 }
109
110 for (auto it = decoder.event(); it; ++it) {
111 TokenizeFtraceEvent(cpu, clock_id, bundle.slice(it->data(), it->size()),
112 state);
113 }
114 return base::OkStatus();
115 }
116
117 PERFETTO_ALWAYS_INLINE
TokenizeFtraceEvent(uint32_t cpu,ClockTracker::ClockId clock_id,TraceBlobView event,PacketSequenceState * state)118 void FtraceTokenizer::TokenizeFtraceEvent(uint32_t cpu,
119 ClockTracker::ClockId clock_id,
120 TraceBlobView event,
121 PacketSequenceState* state) {
122 constexpr auto kTimestampFieldNumber =
123 protos::pbzero::FtraceEvent::kTimestampFieldNumber;
124 constexpr auto kTimestampFieldTag = MakeTagVarInt(kTimestampFieldNumber);
125
126 const uint8_t* data = event.data();
127 const size_t length = event.length();
128 ProtoDecoder decoder(data, length);
129
130 // Speculate on the fact that the timestamp is often the 1st field of the
131 // event.
132 uint64_t raw_timestamp = 0;
133 bool timestamp_found = false;
134 if (PERFETTO_LIKELY(length > 10 && data[0] == kTimestampFieldTag)) {
135 // Fastpath.
136 const uint8_t* next = ParseVarInt(data + 1, data + 11, &raw_timestamp);
137 timestamp_found = next != data + 1;
138 decoder.Reset(next);
139 } else {
140 // Slowpath.
141 if (auto ts_field = decoder.FindField(kTimestampFieldNumber)) {
142 timestamp_found = true;
143 raw_timestamp = ts_field.as_uint64();
144 }
145 }
146
147 if (PERFETTO_UNLIKELY(!timestamp_found)) {
148 PERFETTO_ELOG("Timestamp field not found in FtraceEvent");
149 context_->storage->IncrementStats(stats::ftrace_bundle_tokenizer_errors);
150 return;
151 }
152
153 // ClockTracker will increment some error stats if it failed to convert the
154 // timestamp so just return.
155 int64_t int64_timestamp = static_cast<int64_t>(raw_timestamp);
156 base::StatusOr<int64_t> timestamp =
157 ResolveTraceTime(context_, clock_id, int64_timestamp);
158 if (!timestamp.ok()) {
159 DlogWithLimit(timestamp.status());
160 return;
161 }
162 context_->sorter->PushFtraceEvent(cpu, *timestamp, std::move(event),
163 state->current_generation());
164 }
165
166 PERFETTO_ALWAYS_INLINE
TokenizeFtraceCompactSched(uint32_t cpu,ClockTracker::ClockId clock_id,protozero::ConstBytes packet)167 void FtraceTokenizer::TokenizeFtraceCompactSched(uint32_t cpu,
168 ClockTracker::ClockId clock_id,
169 protozero::ConstBytes packet) {
170 FtraceEventBundle::CompactSched::Decoder compact_sched(packet);
171
172 // Build the interning table for comm fields.
173 std::vector<StringId> string_table;
174 string_table.reserve(512);
175 for (auto it = compact_sched.intern_table(); it; it++) {
176 StringId value = context_->storage->InternString(*it);
177 string_table.push_back(value);
178 }
179
180 TokenizeFtraceCompactSchedSwitch(cpu, clock_id, compact_sched, string_table);
181 TokenizeFtraceCompactSchedWaking(cpu, clock_id, compact_sched, string_table);
182 }
183
TokenizeFtraceCompactSchedSwitch(uint32_t cpu,ClockTracker::ClockId clock_id,const FtraceEventBundle::CompactSched::Decoder & compact,const std::vector<StringId> & string_table)184 void FtraceTokenizer::TokenizeFtraceCompactSchedSwitch(
185 uint32_t cpu,
186 ClockTracker::ClockId clock_id,
187 const FtraceEventBundle::CompactSched::Decoder& compact,
188 const std::vector<StringId>& string_table) {
189 // Accumulator for timestamp deltas.
190 int64_t timestamp_acc = 0;
191
192 // The events' fields are stored in a structure-of-arrays style, using packed
193 // repeated fields. Walk each repeated field in step to recover individual
194 // events.
195 bool parse_error = false;
196 auto timestamp_it = compact.switch_timestamp(&parse_error);
197 auto pstate_it = compact.switch_prev_state(&parse_error);
198 auto npid_it = compact.switch_next_pid(&parse_error);
199 auto nprio_it = compact.switch_next_prio(&parse_error);
200 auto comm_it = compact.switch_next_comm_index(&parse_error);
201 for (; timestamp_it && pstate_it && npid_it && nprio_it && comm_it;
202 ++timestamp_it, ++pstate_it, ++npid_it, ++nprio_it, ++comm_it) {
203 InlineSchedSwitch event{};
204
205 // delta-encoded timestamp
206 timestamp_acc += static_cast<int64_t>(*timestamp_it);
207 int64_t event_timestamp = timestamp_acc;
208
209 // index into the interned string table
210 PERFETTO_DCHECK(*comm_it < string_table.size());
211 event.next_comm = string_table[*comm_it];
212
213 event.prev_state = *pstate_it;
214 event.next_pid = *npid_it;
215 event.next_prio = *nprio_it;
216
217 base::StatusOr<int64_t> timestamp =
218 ResolveTraceTime(context_, clock_id, event_timestamp);
219 if (!timestamp.ok()) {
220 DlogWithLimit(timestamp.status());
221 return;
222 }
223 context_->sorter->PushInlineFtraceEvent(cpu, *timestamp, event);
224 }
225
226 // Check that all packed buffers were decoded correctly, and fully.
227 bool sizes_match =
228 !timestamp_it && !pstate_it && !npid_it && !nprio_it && !comm_it;
229 if (parse_error || !sizes_match)
230 context_->storage->IncrementStats(stats::compact_sched_has_parse_errors);
231 }
232
TokenizeFtraceCompactSchedWaking(uint32_t cpu,ClockTracker::ClockId clock_id,const FtraceEventBundle::CompactSched::Decoder & compact,const std::vector<StringId> & string_table)233 void FtraceTokenizer::TokenizeFtraceCompactSchedWaking(
234 uint32_t cpu,
235 ClockTracker::ClockId clock_id,
236 const FtraceEventBundle::CompactSched::Decoder& compact,
237 const std::vector<StringId>& string_table) {
238 // Accumulator for timestamp deltas.
239 int64_t timestamp_acc = 0;
240
241 // The events' fields are stored in a structure-of-arrays style, using packed
242 // repeated fields. Walk each repeated field in step to recover individual
243 // events.
244 bool parse_error = false;
245 auto timestamp_it = compact.waking_timestamp(&parse_error);
246 auto pid_it = compact.waking_pid(&parse_error);
247 auto tcpu_it = compact.waking_target_cpu(&parse_error);
248 auto prio_it = compact.waking_prio(&parse_error);
249 auto comm_it = compact.waking_comm_index(&parse_error);
250
251 for (; timestamp_it && pid_it && tcpu_it && prio_it && comm_it;
252 ++timestamp_it, ++pid_it, ++tcpu_it, ++prio_it, ++comm_it) {
253 InlineSchedWaking event{};
254
255 // delta-encoded timestamp
256 timestamp_acc += static_cast<int64_t>(*timestamp_it);
257 int64_t event_timestamp = timestamp_acc;
258
259 // index into the interned string table
260 PERFETTO_DCHECK(*comm_it < string_table.size());
261 event.comm = string_table[*comm_it];
262
263 event.pid = *pid_it;
264 event.target_cpu = *tcpu_it;
265 event.prio = *prio_it;
266
267 base::StatusOr<int64_t> timestamp =
268 ResolveTraceTime(context_, clock_id, event_timestamp);
269 if (!timestamp.ok()) {
270 DlogWithLimit(timestamp.status());
271 return;
272 }
273 context_->sorter->PushInlineFtraceEvent(cpu, *timestamp, event);
274 }
275
276 // Check that all packed buffers were decoded correctly, and fully.
277 bool sizes_match =
278 !timestamp_it && !pid_it && !tcpu_it && !prio_it && !comm_it;
279 if (parse_error || !sizes_match)
280 context_->storage->IncrementStats(stats::compact_sched_has_parse_errors);
281 }
282
HandleFtraceClockSnapshot(int64_t ftrace_ts,int64_t boot_ts,uint32_t packet_sequence_id)283 void FtraceTokenizer::HandleFtraceClockSnapshot(int64_t ftrace_ts,
284 int64_t boot_ts,
285 uint32_t packet_sequence_id) {
286 // If we've already seen a snapshot at this timestamp, don't unnecessarily
287 // add another entry to the clock tracker.
288 if (latest_ftrace_clock_snapshot_ts_ == ftrace_ts)
289 return;
290 latest_ftrace_clock_snapshot_ts_ = ftrace_ts;
291
292 ClockTracker::ClockId global_id = ClockTracker::SeqenceToGlobalClock(
293 packet_sequence_id, kFtraceGlobalClockIdForOldKernels);
294 context_->clock_tracker->AddSnapshot(
295 {ClockTracker::ClockTimestamp(global_id, ftrace_ts),
296 ClockTracker::ClockTimestamp(BuiltinClock::BUILTIN_CLOCK_BOOTTIME,
297 boot_ts)});
298 }
299
300 } // namespace trace_processor
301 } // namespace perfetto
302