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_sched_event_tracker.h"
18
19 #include <limits>
20
21 #include "perfetto/ext/base/string_view.h"
22 #include "src/trace_processor/importers/common/args_tracker.h"
23 #include "src/trace_processor/importers/common/event_tracker.h"
24 #include "src/trace_processor/importers/common/process_tracker.h"
25 #include "src/trace_processor/importers/common/sched_event_state.h"
26 #include "src/trace_processor/importers/common/sched_event_tracker.h"
27 #include "src/trace_processor/importers/common/system_info_tracker.h"
28 #include "src/trace_processor/importers/common/thread_state_tracker.h"
29 #include "src/trace_processor/importers/ftrace/ftrace_descriptors.h"
30 #include "src/trace_processor/storage/stats.h"
31 #include "src/trace_processor/types/task_state.h"
32 #include "src/trace_processor/types/trace_processor_context.h"
33 #include "src/trace_processor/types/variadic.h"
34
35 #include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
36 #include "protos/perfetto/trace/ftrace/sched.pbzero.h"
37
38 namespace perfetto {
39 namespace trace_processor {
40
FtraceSchedEventTracker(TraceProcessorContext * context)41 FtraceSchedEventTracker::FtraceSchedEventTracker(TraceProcessorContext* context)
42 : context_(context) {
43 // pre-parse sched_switch
44 auto* switch_descriptor = GetMessageDescriptorForId(
45 protos::pbzero::FtraceEvent::kSchedSwitchFieldNumber);
46 PERFETTO_CHECK(switch_descriptor->max_field_id == kSchedSwitchMaxFieldId);
47
48 for (size_t i = 1; i <= kSchedSwitchMaxFieldId; i++) {
49 sched_switch_field_ids_[i] =
50 context->storage->InternString(switch_descriptor->fields[i].name);
51 }
52 sched_switch_id_ = context->storage->InternString(switch_descriptor->name);
53
54 // pre-parse sched_waking
55 auto* waking_descriptor = GetMessageDescriptorForId(
56 protos::pbzero::FtraceEvent::kSchedWakingFieldNumber);
57 PERFETTO_CHECK(waking_descriptor->max_field_id == kSchedWakingMaxFieldId);
58
59 for (size_t i = 1; i <= kSchedWakingMaxFieldId; i++) {
60 sched_waking_field_ids_[i] =
61 context->storage->InternString(waking_descriptor->fields[i].name);
62 }
63 sched_waking_id_ = context->storage->InternString(waking_descriptor->name);
64 }
65
66 FtraceSchedEventTracker::~FtraceSchedEventTracker() = default;
67
PushSchedSwitch(uint32_t cpu,int64_t ts,uint32_t prev_pid,base::StringView prev_comm,int32_t prev_prio,int64_t prev_state,uint32_t next_pid,base::StringView next_comm,int32_t next_prio)68 void FtraceSchedEventTracker::PushSchedSwitch(uint32_t cpu,
69 int64_t ts,
70 uint32_t prev_pid,
71 base::StringView prev_comm,
72 int32_t prev_prio,
73 int64_t prev_state,
74 uint32_t next_pid,
75 base::StringView next_comm,
76 int32_t next_prio) {
77 if (!context_->sched_event_tracker->UpdateEventTrackerTimestamp(
78 ts, "sched_switch", stats::sched_switch_out_of_order)) {
79 return;
80 }
81
82 StringId next_comm_id = context_->storage->InternString(next_comm);
83 UniqueTid next_utid = context_->process_tracker->UpdateThreadName(
84 next_pid, next_comm_id, ThreadNamePriority::kFtrace);
85
86 // First use this data to close the previous slice.
87 bool prev_pid_match_prev_next_pid = false;
88 auto* pending_sched = sched_event_state_.GetPendingSchedInfoForCpu(cpu);
89 uint32_t pending_slice_idx = pending_sched->pending_slice_storage_idx;
90 StringId prev_state_string_id = TaskStateToStringId(prev_state);
91 if (prev_state_string_id == kNullStringId) {
92 context_->storage->IncrementStats(stats::task_state_invalid);
93 }
94 if (pending_slice_idx < std::numeric_limits<uint32_t>::max()) {
95 prev_pid_match_prev_next_pid = prev_pid == pending_sched->last_pid;
96 if (PERFETTO_LIKELY(prev_pid_match_prev_next_pid)) {
97 context_->sched_event_tracker->ClosePendingSlice(pending_slice_idx, ts,
98 prev_state_string_id);
99 } else {
100 // If the pids are not consistent, make a note of this.
101 context_->storage->IncrementStats(stats::mismatched_sched_switch_tids);
102 }
103 }
104
105 // We have to intern prev_comm again because our assumption that
106 // this event's |prev_comm| == previous event's |next_comm| does not hold
107 // if the thread changed its name while scheduled.
108 StringId prev_comm_id = context_->storage->InternString(prev_comm);
109 UniqueTid prev_utid = context_->process_tracker->UpdateThreadName(
110 prev_pid, prev_comm_id, ThreadNamePriority::kFtrace);
111
112 AddRawSchedSwitchEvent(cpu, ts, prev_utid, prev_pid, prev_comm_id, prev_prio,
113 prev_state, next_pid, next_comm_id, next_prio);
114
115 auto new_slice_idx = context_->sched_event_tracker
116 ->AddStartSlice(cpu, ts, next_utid, next_prio);
117
118 // Finally, update the info for the next sched switch on this CPU.
119 pending_sched->pending_slice_storage_idx = new_slice_idx;
120 pending_sched->last_pid = next_pid;
121 pending_sched->last_utid = next_utid;
122 pending_sched->last_prio = next_prio;
123
124 // Update the ThreadState table.
125 ThreadStateTracker::GetOrCreate(context_)->PushSchedSwitchEvent(
126 ts, cpu, prev_utid, prev_state_string_id, next_utid);
127 }
128
PushSchedSwitchCompact(uint32_t cpu,int64_t ts,int64_t prev_state,uint32_t next_pid,int32_t next_prio,StringId next_comm_id,bool parse_only_into_raw)129 void FtraceSchedEventTracker::PushSchedSwitchCompact(uint32_t cpu,
130 int64_t ts,
131 int64_t prev_state,
132 uint32_t next_pid,
133 int32_t next_prio,
134 StringId next_comm_id,
135 bool parse_only_into_raw) {
136 if (!context_->sched_event_tracker->UpdateEventTrackerTimestamp(
137 ts, "sched_switch", stats::sched_switch_out_of_order)) {
138 return;
139 }
140
141 UniqueTid next_utid = context_->process_tracker->UpdateThreadName(
142 next_pid, next_comm_id, ThreadNamePriority::kFtrace);
143
144 // If we're processing the first compact event for this cpu, don't start a
145 // slice since we're missing the "prev_*" fields. The successive events will
146 // create slices as normal, but the first per-cpu switch is effectively
147 // discarded.
148 auto* pending_sched = sched_event_state_.GetPendingSchedInfoForCpu(cpu);
149 if (pending_sched->last_utid == std::numeric_limits<UniqueTid>::max()) {
150 context_->storage->IncrementStats(stats::compact_sched_switch_skipped);
151
152 pending_sched->last_pid = next_pid;
153 pending_sched->last_utid = next_utid;
154 pending_sched->last_prio = next_prio;
155 // Note: no pending slice, so leave |pending_slice_storage_idx| in its
156 // invalid state.
157 return;
158 }
159
160 // Close the pending slice if any (we won't have one when processing the first
161 // two compact events for a given cpu).
162 uint32_t pending_slice_idx = pending_sched->pending_slice_storage_idx;
163 StringId prev_state_str_id = TaskStateToStringId(prev_state);
164 if (prev_state_str_id == kNullStringId) {
165 context_->storage->IncrementStats(stats::task_state_invalid);
166 }
167 if (pending_slice_idx != std::numeric_limits<uint32_t>::max()) {
168 context_->sched_event_tracker->ClosePendingSlice(pending_slice_idx, ts,
169 prev_state_str_id);
170 }
171
172 // Use the previous event's values to infer this event's "prev_*" fields.
173 // There are edge cases, but this assumption should still produce sensible
174 // results in the absence of data loss.
175 UniqueTid prev_utid = pending_sched->last_utid;
176 uint32_t prev_pid = pending_sched->last_pid;
177 int32_t prev_prio = pending_sched->last_prio;
178
179 // Do a fresh task name lookup in case it was updated by a task_rename while
180 // scheduled.
181 StringId prev_comm_id =
182 context_->storage->thread_table().name()[prev_utid].value_or(
183 kNullStringId);
184
185 AddRawSchedSwitchEvent(cpu, ts, prev_utid, prev_pid, prev_comm_id, prev_prio,
186 prev_state, next_pid, next_comm_id, next_prio);
187
188 // Update the info for the next sched switch on this CPU.
189 pending_sched->last_pid = next_pid;
190 pending_sched->last_utid = next_utid;
191 pending_sched->last_prio = next_prio;
192
193 // Subtle: if only inserting into raw, we're ending with:
194 // * updated |pending_sched->last_*| fields
195 // * still-defaulted |pending_slice_storage_idx|
196 // This is similar to the first compact_sched_switch per cpu.
197 if (PERFETTO_UNLIKELY(parse_only_into_raw))
198 return;
199
200 // Update per-cpu Sched table.
201 auto new_slice_idx = context_->sched_event_tracker->AddStartSlice(
202 cpu, ts, next_utid, next_prio);
203 pending_sched->pending_slice_storage_idx = new_slice_idx;
204
205 // Update the per-thread ThreadState table.
206 ThreadStateTracker::GetOrCreate(context_)->PushSchedSwitchEvent(
207 ts, cpu, prev_utid, prev_state_str_id, next_utid);
208 }
209
210 // Processes a sched_waking that was decoded from a compact representation,
211 // adding to the raw and instants tables.
PushSchedWakingCompact(uint32_t cpu,int64_t ts,uint32_t wakee_pid,uint16_t target_cpu,uint16_t prio,StringId comm_id,uint16_t common_flags,bool parse_only_into_raw)212 void FtraceSchedEventTracker::PushSchedWakingCompact(uint32_t cpu,
213 int64_t ts,
214 uint32_t wakee_pid,
215 uint16_t target_cpu,
216 uint16_t prio,
217 StringId comm_id,
218 uint16_t common_flags,
219 bool parse_only_into_raw) {
220 if (!context_->sched_event_tracker->UpdateEventTrackerTimestamp(
221 ts, "sched_waking", stats::sched_waking_out_of_order)) {
222 return;
223 }
224
225 // We infer the task that emitted the event (i.e. common_pid) from the
226 // scheduling slices. Drop the event if we haven't seen any sched_switch
227 // events for this cpu yet.
228 // Note that if sched_switch wasn't enabled, we will have to skip all
229 // compact waking events.
230 auto* pending_sched = sched_event_state_.GetPendingSchedInfoForCpu(cpu);
231 if (pending_sched->last_utid == std::numeric_limits<UniqueTid>::max()) {
232 context_->storage->IncrementStats(stats::compact_sched_waking_skipped);
233 return;
234 }
235 auto curr_utid = pending_sched->last_utid;
236
237 if (PERFETTO_LIKELY(context_->config.ingest_ftrace_in_raw_table)) {
238 tables::FtraceEventTable::Row row;
239 row.ts = ts;
240 row.name = sched_waking_id_;
241 row.utid = curr_utid;
242 row.common_flags = common_flags;
243 row.ucpu = context_->cpu_tracker->GetOrCreateCpu(cpu);
244
245 // Add an entry to the raw table.
246 RawId id = context_->storage->mutable_ftrace_event_table()->Insert(row).id;
247
248 using SW = protos::pbzero::SchedWakingFtraceEvent;
249 auto inserter = context_->args_tracker->AddArgsTo(id);
250 auto add_raw_arg = [this, &inserter](int field_num, Variadic var) {
251 StringId key = sched_waking_field_ids_[static_cast<size_t>(field_num)];
252 inserter.AddArg(key, var);
253 };
254 add_raw_arg(SW::kCommFieldNumber, Variadic::String(comm_id));
255 add_raw_arg(SW::kPidFieldNumber, Variadic::Integer(wakee_pid));
256 add_raw_arg(SW::kPrioFieldNumber, Variadic::Integer(prio));
257 add_raw_arg(SW::kTargetCpuFieldNumber, Variadic::Integer(target_cpu));
258 }
259
260 if (PERFETTO_UNLIKELY(parse_only_into_raw))
261 return;
262
263 // Add a waking entry to the ThreadState table.
264 auto wakee_utid = context_->process_tracker->GetOrCreateThread(wakee_pid);
265 ThreadStateTracker::GetOrCreate(context_)->PushWakingEvent(
266 ts, wakee_utid, curr_utid, common_flags);
267 }
268
AddRawSchedSwitchEvent(uint32_t cpu,int64_t ts,UniqueTid prev_utid,uint32_t prev_pid,StringId prev_comm_id,int32_t prev_prio,int64_t prev_state,uint32_t next_pid,StringId next_comm_id,int32_t next_prio)269 void FtraceSchedEventTracker::AddRawSchedSwitchEvent(uint32_t cpu,
270 int64_t ts,
271 UniqueTid prev_utid,
272 uint32_t prev_pid,
273 StringId prev_comm_id,
274 int32_t prev_prio,
275 int64_t prev_state,
276 uint32_t next_pid,
277 StringId next_comm_id,
278 int32_t next_prio) {
279 if (PERFETTO_LIKELY(context_->config.ingest_ftrace_in_raw_table)) {
280 // Push the raw event - this is done as the raw ftrace event codepath does
281 // not insert sched_switch.
282 auto ucpu = context_->cpu_tracker->GetOrCreateCpu(cpu);
283 RawId id = context_->storage->mutable_ftrace_event_table()
284 ->Insert({ts, sched_switch_id_, prev_utid, {}, {}, ucpu})
285 .id;
286
287 // Note: this ordering is important. The events should be pushed in the same
288 // order as the order of fields in the proto; this is used by the raw table
289 // to index these events using the field ids.
290 using SS = protos::pbzero::SchedSwitchFtraceEvent;
291
292 auto inserter = context_->args_tracker->AddArgsTo(id);
293 auto add_raw_arg = [this, &inserter](int field_num, Variadic var) {
294 StringId key = sched_switch_field_ids_[static_cast<size_t>(field_num)];
295 inserter.AddArg(key, var);
296 };
297 add_raw_arg(SS::kPrevCommFieldNumber, Variadic::String(prev_comm_id));
298 add_raw_arg(SS::kPrevPidFieldNumber, Variadic::Integer(prev_pid));
299 add_raw_arg(SS::kPrevPrioFieldNumber, Variadic::Integer(prev_prio));
300 add_raw_arg(SS::kPrevStateFieldNumber, Variadic::Integer(prev_state));
301 add_raw_arg(SS::kNextCommFieldNumber, Variadic::String(next_comm_id));
302 add_raw_arg(SS::kNextPidFieldNumber, Variadic::Integer(next_pid));
303 add_raw_arg(SS::kNextPrioFieldNumber, Variadic::Integer(next_prio));
304 }
305 }
306
TaskStateToStringId(int64_t task_state_int)307 StringId FtraceSchedEventTracker::TaskStateToStringId(int64_t task_state_int) {
308 using ftrace_utils::TaskState;
309 std::optional<VersionNumber> kernel_version =
310 SystemInfoTracker::GetOrCreate(context_)->GetKernelVersion();
311
312 TaskState task_state = TaskState::FromRawPrevState(
313 static_cast<uint16_t>(task_state_int), kernel_version);
314 return task_state.is_valid()
315 ? context_->storage->InternString(task_state.ToString().data())
316 : kNullStringId;
317 }
318
319 } // namespace trace_processor
320 } // namespace perfetto
321