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_parser.h"
18
19 #include <algorithm>
20 #include <array>
21 #include <cinttypes>
22 #include <cstddef>
23 #include <cstdint>
24 #include <limits>
25 #include <optional>
26 #include <string>
27 #include <utility>
28 #include <vector>
29
30 #include "perfetto/base/compiler.h"
31 #include "perfetto/base/logging.h"
32 #include "perfetto/base/status.h"
33 #include "perfetto/ext/base/string_utils.h"
34 #include "perfetto/ext/base/string_view.h"
35 #include "perfetto/ext/base/utils.h"
36 #include "perfetto/protozero/field.h"
37 #include "perfetto/protozero/proto_decoder.h"
38 #include "perfetto/protozero/proto_utils.h"
39 #include "perfetto/public/compiler.h"
40 #include "perfetto/trace_processor/basic_types.h"
41 #include "perfetto/trace_processor/trace_blob_view.h"
42 #include "src/trace_processor/importers/common/args_tracker.h"
43 #include "src/trace_processor/importers/common/cpu_tracker.h"
44 #include "src/trace_processor/importers/common/event_tracker.h"
45 #include "src/trace_processor/importers/common/metadata_tracker.h"
46 #include "src/trace_processor/importers/common/parser_types.h"
47 #include "src/trace_processor/importers/common/process_tracker.h"
48 #include "src/trace_processor/importers/common/system_info_tracker.h"
49 #include "src/trace_processor/importers/common/thread_state_tracker.h"
50 #include "src/trace_processor/importers/common/track_compressor.h"
51 #include "src/trace_processor/importers/common/track_tracker.h"
52 #include "src/trace_processor/importers/common/tracks.h"
53 #include "src/trace_processor/importers/common/tracks_common.h"
54 #include "src/trace_processor/importers/common/tracks_internal.h"
55 #include "src/trace_processor/importers/ftrace/binder_tracker.h"
56 #include "src/trace_processor/importers/ftrace/ftrace_descriptors.h"
57 #include "src/trace_processor/importers/ftrace/ftrace_sched_event_tracker.h"
58 #include "src/trace_processor/importers/ftrace/pkvm_hyp_cpu_tracker.h"
59 #include "src/trace_processor/importers/ftrace/v4l2_tracker.h"
60 #include "src/trace_processor/importers/ftrace/virtio_video_tracker.h"
61 #include "src/trace_processor/importers/i2c/i2c_tracker.h"
62 #include "src/trace_processor/importers/proto/packet_sequence_state_generation.h"
63 #include "src/trace_processor/importers/syscalls/syscall_tracker.h"
64 #include "src/trace_processor/importers/systrace/systrace_parser.h"
65 #include "src/trace_processor/storage/metadata.h"
66 #include "src/trace_processor/storage/stats.h"
67 #include "src/trace_processor/storage/trace_storage.h"
68 #include "src/trace_processor/tables/metadata_tables_py.h"
69 #include "src/trace_processor/types/softirq_action.h"
70 #include "src/trace_processor/types/tcp_state.h"
71 #include "src/trace_processor/types/variadic.h"
72 #include "src/trace_processor/types/version_number.h"
73
74 #include "protos/perfetto/trace/ftrace/android_fs.pbzero.h"
75 #include "protos/perfetto/trace/ftrace/bcl_exynos.pbzero.h"
76 #include "protos/perfetto/trace/ftrace/binder.pbzero.h"
77 #include "protos/perfetto/trace/ftrace/block.pbzero.h"
78 #include "protos/perfetto/trace/ftrace/cma.pbzero.h"
79 #include "protos/perfetto/trace/ftrace/cpm_trace.pbzero.h"
80 #include "protos/perfetto/trace/ftrace/cpuhp.pbzero.h"
81 #include "protos/perfetto/trace/ftrace/cros_ec.pbzero.h"
82 #include "protos/perfetto/trace/ftrace/dcvsh.pbzero.h"
83 #include "protos/perfetto/trace/ftrace/devfreq.pbzero.h"
84 #include "protos/perfetto/trace/ftrace/dmabuf_heap.pbzero.h"
85 #include "protos/perfetto/trace/ftrace/dpu.pbzero.h"
86 #include "protos/perfetto/trace/ftrace/fastrpc.pbzero.h"
87 #include "protos/perfetto/trace/ftrace/ftrace.pbzero.h"
88 #include "protos/perfetto/trace/ftrace/ftrace_event.pbzero.h"
89 #include "protos/perfetto/trace/ftrace/ftrace_stats.pbzero.h"
90 #include "protos/perfetto/trace/ftrace/g2d.pbzero.h"
91 #include "protos/perfetto/trace/ftrace/generic.pbzero.h"
92 #include "protos/perfetto/trace/ftrace/google_icc_trace.pbzero.h"
93 #include "protos/perfetto/trace/ftrace/google_irm_trace.pbzero.h"
94 #include "protos/perfetto/trace/ftrace/gpu_mem.pbzero.h"
95 #include "protos/perfetto/trace/ftrace/i2c.pbzero.h"
96 #include "protos/perfetto/trace/ftrace/ion.pbzero.h"
97 #include "protos/perfetto/trace/ftrace/irq.pbzero.h"
98 #include "protos/perfetto/trace/ftrace/kgsl.pbzero.h"
99 #include "protos/perfetto/trace/ftrace/kmem.pbzero.h"
100 #include "protos/perfetto/trace/ftrace/lwis.pbzero.h"
101 #include "protos/perfetto/trace/ftrace/mali.pbzero.h"
102 #include "protos/perfetto/trace/ftrace/mdss.pbzero.h"
103 #include "protos/perfetto/trace/ftrace/mm_event.pbzero.h"
104 #include "protos/perfetto/trace/ftrace/net.pbzero.h"
105 #include "protos/perfetto/trace/ftrace/oom.pbzero.h"
106 #include "protos/perfetto/trace/ftrace/panel.pbzero.h"
107 #include "protos/perfetto/trace/ftrace/power.pbzero.h"
108 #include "protos/perfetto/trace/ftrace/raw_syscalls.pbzero.h"
109 #include "protos/perfetto/trace/ftrace/rpm.pbzero.h"
110 #include "protos/perfetto/trace/ftrace/samsung.pbzero.h"
111 #include "protos/perfetto/trace/ftrace/sched.pbzero.h"
112 #include "protos/perfetto/trace/ftrace/scm.pbzero.h"
113 #include "protos/perfetto/trace/ftrace/sde.pbzero.h"
114 #include "protos/perfetto/trace/ftrace/signal.pbzero.h"
115 #include "protos/perfetto/trace/ftrace/skb.pbzero.h"
116 #include "protos/perfetto/trace/ftrace/sock.pbzero.h"
117 #include "protos/perfetto/trace/ftrace/synthetic.pbzero.h"
118 #include "protos/perfetto/trace/ftrace/systrace.pbzero.h"
119 #include "protos/perfetto/trace/ftrace/task.pbzero.h"
120 #include "protos/perfetto/trace/ftrace/tcp.pbzero.h"
121 #include "protos/perfetto/trace/ftrace/trusty.pbzero.h"
122 #include "protos/perfetto/trace/ftrace/ufs.pbzero.h"
123 #include "protos/perfetto/trace/ftrace/vmscan.pbzero.h"
124 #include "protos/perfetto/trace/ftrace/workqueue.pbzero.h"
125 #include "protos/perfetto/trace/interned_data/interned_data.pbzero.h"
126 #include "protos/perfetto/trace/profiling/profile_common.pbzero.h"
127
128 namespace perfetto::trace_processor {
129
130 namespace {
131
132 using protos::pbzero::perfetto_pbzero_enum_KprobeEvent::KprobeType;
133 using protozero::ConstBytes;
134 using protozero::ProtoDecoder;
135
136 struct FtraceEventAndFieldId {
137 uint32_t event_id;
138 uint32_t field_id;
139 };
140
141 // Contains a list of all the proto fields in ftrace events which represent
142 // kernel functions. This list is used to convert the iids in these fields to
143 // proper kernel symbols.
144 // TODO(lalitm): going through this array is O(n) on a hot-path (see
145 // ParseTypedFtraceToRaw). Consider changing this if we end up adding a lot of
146 // events here.
147 constexpr auto kKernelFunctionFields = std::array<FtraceEventAndFieldId, 6>{
148 FtraceEventAndFieldId{
149 protos::pbzero::FtraceEvent::kSchedBlockedReasonFieldNumber,
150 protos::pbzero::SchedBlockedReasonFtraceEvent::kCallerFieldNumber},
151 FtraceEventAndFieldId{
152 protos::pbzero::FtraceEvent::kWorkqueueExecuteStartFieldNumber,
153 protos::pbzero::WorkqueueExecuteStartFtraceEvent::kFunctionFieldNumber},
154 FtraceEventAndFieldId{
155 protos::pbzero::FtraceEvent::kWorkqueueQueueWorkFieldNumber,
156 protos::pbzero::WorkqueueQueueWorkFtraceEvent::kFunctionFieldNumber},
157 FtraceEventAndFieldId{
158 protos::pbzero::FtraceEvent::kFuncgraphEntryFieldNumber,
159 protos::pbzero::FuncgraphEntryFtraceEvent::kFuncFieldNumber},
160 FtraceEventAndFieldId{
161 protos::pbzero::FtraceEvent::kFuncgraphExitFieldNumber,
162 protos::pbzero::FuncgraphExitFtraceEvent::kFuncFieldNumber},
163 FtraceEventAndFieldId{
164 protos::pbzero::FtraceEvent::kMmShrinkSlabStartFieldNumber,
165 protos::pbzero::MmShrinkSlabStartFtraceEvent::kShrinkFieldNumber}};
166
GetUfsCmdString(uint32_t ufsopcode,uint32_t gid)167 std::string GetUfsCmdString(uint32_t ufsopcode, uint32_t gid) {
168 std::string buffer;
169 switch (ufsopcode) {
170 case 4:
171 buffer = "FORMAT UNIT";
172 break;
173 case 18:
174 buffer = "INQUIRY";
175 break;
176 case 85:
177 buffer = "MODE SELECT (10)";
178 break;
179 case 90:
180 buffer = "MODE SENSE (10)";
181 break;
182 case 52:
183 buffer = "PRE-FETCH (10)";
184 break;
185 case 144:
186 buffer = "PRE-FETCH (16)";
187 break;
188 case 8:
189 buffer = "READ (6)";
190 break;
191 case 40:
192 buffer = "READ (10)";
193 break;
194 case 136:
195 buffer = "READ (16)";
196 break;
197 case 60:
198 buffer = "READ BUFFER";
199 break;
200 case 37:
201 buffer = "READ CAPACITY (10)";
202 break;
203 case 158:
204 buffer = "READ CAPACITY (16)";
205 break;
206 case 160:
207 buffer = "REPORT LUNS";
208 break;
209 case 3:
210 buffer = "REQUEST SENSE";
211 break;
212 case 162:
213 buffer = "SECURITY PROTOCOL IN";
214 break;
215 case 181:
216 buffer = "SECURITY PROTOCOL OUT";
217 break;
218 case 29:
219 buffer = "SEND DIAGNOSTIC";
220 break;
221 case 27:
222 buffer = "START STOP UNIT";
223 break;
224 case 53:
225 buffer = "SYNCHRONIZE CACHE (10)";
226 break;
227 case 145:
228 buffer = "SYNCHRONIZE CACHE (16)";
229 break;
230 case 0:
231 buffer = "TEST UNIT READY";
232 break;
233 case 66:
234 buffer = "UNMAP";
235 break;
236 case 47:
237 buffer = "VERIFY";
238 break;
239 case 10:
240 buffer = "WRITE (6)";
241 break;
242 case 42:
243 buffer = "WRITE (10)";
244 break;
245 case 138:
246 buffer = "WRITE (16)";
247 break;
248 case 59:
249 buffer = "WRITE BUFFER";
250 break;
251 default:
252 buffer = "UNDEFINED";
253 break;
254 }
255 if (gid > 0) {
256 base::StackString<32> gid_str(" (GID=0x%x)", gid);
257 buffer = buffer + gid_str.c_str();
258 }
259 return buffer;
260 }
261
262 enum RpmStatus {
263 RPM_INVALID = -1,
264 RPM_ACTIVE = 0,
265 RPM_RESUMING,
266 RPM_SUSPENDED,
267 RPM_SUSPENDING,
268 };
269
270 // Obtain the string corresponding to the event code (`event` field) in the
271 // `device_pm_callback_start` tracepoint.
GetDpmCallbackEventString(int64_t event)272 std::string GetDpmCallbackEventString(int64_t event) {
273 // This mapping order is obtained directly from the Linux kernel code.
274 switch (event) {
275 case 0x2:
276 return "suspend";
277 case 0x10:
278 return "resume";
279 case 0x1:
280 return "freeze";
281 case 0x8:
282 return "quiesce";
283 case 0x4:
284 return "hibernate";
285 case 0x20:
286 return "thaw";
287 case 0x40:
288 return "restore";
289 case 0x80:
290 return "recover";
291 default:
292 return "(unknown PM event)";
293 }
294 }
295
StrStartsWith(const std::string & str,const std::string & prefix)296 bool StrStartsWith(const std::string& str, const std::string& prefix) {
297 return str.size() >= prefix.size() &&
298 str.compare(0, prefix.size(), prefix) == 0;
299 }
300
301 // Constructs the callback phase name for device PM callback slices.
302 //
303 // Format: "<event type>[:<callback phase>]"
304 // Examples: suspend, suspend:late, resume:noirq etc.
ConstructCallbackPhaseName(const std::string & pm_ops,const std::string & event_type)305 std::string ConstructCallbackPhaseName(const std::string& pm_ops,
306 const std::string& event_type) {
307 std::string callback_phase = event_type;
308
309 // The Linux kernel has a limitation where the `pm_ops` field in the
310 // tracepoint is left empty if the phase is either prepare/complete.
311 if (pm_ops == "") {
312 if (event_type == "suspend") {
313 return callback_phase + ":prepare";
314 }
315 if (event_type == "resume") {
316 return callback_phase + ":complete";
317 }
318 }
319
320 // Extract phase (if present) for slice details.
321 //
322 // The `pm_ops` string may contain both callback phase and callback type, but
323 // only phase is needed. A prefix match is used due to potential absence of
324 // either/both phase or type in `pm_ops`.
325 const std::vector<std::string> valid_phases = {"early", "late", "noirq"};
326 for (const std::string& valid_phase : valid_phases) {
327 if (StrStartsWith(pm_ops, valid_phase)) {
328 return callback_phase + ":" + valid_phase;
329 }
330 }
331 return callback_phase;
332 }
333
GetMmEventTypeStr(uint32_t type)334 const char* GetMmEventTypeStr(uint32_t type) {
335 switch (type) {
336 case 0:
337 return "min_flt";
338 case 1:
339 return "maj_flt";
340 case 2:
341 return "read_io";
342 case 3:
343 return "compaction";
344 case 4:
345 return "reclaim";
346 case 5:
347 return "swp_flt";
348 case 6:
349 return "kern_alloc";
350 default:
351 return nullptr;
352 }
353 }
354
355 } // namespace
356
FtraceParser(TraceProcessorContext * context)357 FtraceParser::FtraceParser(TraceProcessorContext* context)
358 : context_(context),
359 rss_stat_tracker_(context),
360 drm_tracker_(context),
361 iostat_tracker_(context),
362 virtio_gpu_tracker_(context),
363 mali_gpu_event_tracker_(context),
364 pkvm_hyp_cpu_tracker_(context),
365 gpu_work_period_tracker_(context),
366 thermal_tracker_(context),
367 pixel_mm_kswapd_event_tracker_(context),
368 sched_wakeup_name_id_(context->storage->InternString("sched_wakeup")),
369 sched_waking_name_id_(context->storage->InternString("sched_waking")),
370 cpu_id_(context->storage->InternString("cpu")),
371 suspend_resume_minimal_slice_name_id_(
372 context->storage->InternString("Suspended")),
373 inode_arg_id_(context->storage->InternString("inode")),
374 signal_generate_id_(context->storage->InternString("signal_generate")),
375 signal_deliver_id_(context->storage->InternString("signal_deliver")),
376 lmk_id_(context->storage->InternString("mem.lmk")),
377 comm_name_id_(context->storage->InternString("comm")),
378 signal_name_id_(context_->storage->InternString("signal.sig")),
379 oom_kill_id_(context_->storage->InternString("mem.oom_kill")),
380 workqueue_id_(context_->storage->InternString("workqueue")),
381 irq_id_(context_->storage->InternString("irq")),
382 tcp_state_id_(context_->storage->InternString("tcp_state")),
383 tcp_event_id_(context_->storage->InternString("tcp_event")),
384 protocol_arg_id_(context_->storage->InternString("protocol")),
385 napi_gro_id_(context_->storage->InternString("napi_gro")),
386 ret_arg_id_(context_->storage->InternString("ret")),
387 len_arg_id_(context->storage->InternString("len")),
388 direct_reclaim_nr_reclaimed_id_(
389 context->storage->InternString("direct_reclaim_nr_reclaimed")),
390 direct_reclaim_order_id_(
391 context->storage->InternString("direct_reclaim_order")),
392 direct_reclaim_may_writepage_id_(
393 context->storage->InternString("direct_reclaim_may_writepage")),
394 direct_reclaim_gfp_flags_id_(
395 context->storage->InternString("direct_reclaim_gfp_flags")),
396 vec_arg_id_(context->storage->InternString("vec")),
397 io_wait_id_(context->storage->InternString("io_wait")),
398 function_id_(context->storage->InternString("function")),
399 waker_utid_id_(context->storage->InternString("waker_utid")),
400 cros_ec_arg_num_id_(context->storage->InternString("ec_num")),
401 cros_ec_arg_ec_id_(context->storage->InternString("ec_delta")),
402 cros_ec_arg_sample_ts_id_(context->storage->InternString("sample_ts")),
403 shrink_slab_id_(context_->storage->InternString("mm_vmscan_shrink_slab")),
404 shrink_name_id_(context->storage->InternString("shrink_name")),
405 shrink_total_scan_id_(context->storage->InternString("total_scan")),
406 shrink_freed_id_(context->storage->InternString("freed")),
407 shrink_priority_id_(context->storage->InternString("priority")),
408 trusty_category_id_(context_->storage->InternString("tipc")),
409 trusty_name_trusty_std_id_(context_->storage->InternString("trusty_std")),
410 trusty_name_tipc_rx_id_(context_->storage->InternString("tipc_rx")),
411 cma_alloc_id_(context_->storage->InternString("mm_cma_alloc")),
412 cma_name_id_(context_->storage->InternString("cma_name")),
413 cma_pfn_id_(context_->storage->InternString("cma_pfn")),
414 cma_req_pages_id_(context_->storage->InternString("cma_req_pages")),
415 cma_nr_migrated_id_(context_->storage->InternString("cma_nr_migrated")),
416 cma_nr_reclaimed_id_(context_->storage->InternString("cma_nr_reclaimed")),
417 cma_nr_mapped_id_(context_->storage->InternString("cma_nr_mapped")),
418 cma_nr_isolate_fail_id_(
419 context_->storage->InternString("cma_nr_isolate_fail")),
420 cma_nr_migrate_fail_id_(
421 context_->storage->InternString("cma_nr_migrate_fail")),
422 cma_nr_test_fail_id_(context_->storage->InternString("cma_nr_test_fail")),
423 syscall_ret_id_(context->storage->InternString("ret")),
424 syscall_args_id_(context->storage->InternString("args")),
425 replica_slice_id_(context->storage->InternString("replica_slice")),
426 file_path_id_(context_->storage->InternString("file_path")),
427 offset_id_start_(context_->storage->InternString("offset_start")),
428 offset_id_end_(context_->storage->InternString("offset_end")),
429 bytes_read_id_start_(context_->storage->InternString("bytes_read_start")),
430 bytes_read_id_end_(context_->storage->InternString("bytes_read_end")),
431 android_fs_data_read_id_(
432 context_->storage->InternString("android_fs_data_read")),
433 google_icc_event_id_(context->storage->InternString("google_icc_event")),
434 google_irm_event_id_(context->storage->InternString("google_irm_event")),
435 runtime_status_invalid_id_(
436 context->storage->InternString("Invalid State")),
437 runtime_status_active_id_(context->storage->InternString("Active")),
438 runtime_status_suspending_id_(
439 context->storage->InternString("Suspending")),
440 runtime_status_resuming_id_(context->storage->InternString("Resuming")),
441 suspend_resume_main_event_id_(
442 context->storage->InternString("Main Kernel Suspend Event")),
443 suspend_resume_device_pm_event_id_(
444 context->storage->InternString("Device PM Suspend Event")),
445 suspend_resume_utid_arg_name_(context->storage->InternString("utid")),
446 suspend_resume_device_arg_name_(
447 context->storage->InternString("device_name")),
448 suspend_resume_driver_arg_name_(
449 context->storage->InternString("driver_name")),
450 suspend_resume_callback_phase_arg_name_(
451 context->storage->InternString("callback_phase")),
452 suspend_resume_event_type_arg_name_(
453 context->storage->InternString("event_type")),
454 device_name_id_(context->storage->InternString("device_name")),
455 block_io_id_(context->storage->InternString("block_io")),
456 block_io_arg_sector_id_(context->storage->InternString("sector")),
457 cpuhp_action_cpu_id_(context->storage->InternString("action_cpu")),
458 cpuhp_idx_id_(context->storage->InternString("cpuhp_idx")),
459 disp_vblank_irq_enable_id_(
460 context_->storage->InternString("disp_vblank_irq_enable")),
461 disp_vblank_irq_enable_output_id_arg_name_(
462 context_->storage->InternString("output_id")) {
463 // Build the lookup table for the strings inside ftrace events (e.g. the
464 // name of ftrace event fields and the names of their args).
465 for (size_t i = 0; i < GetDescriptorsSize(); i++) {
466 auto* descriptor = GetMessageDescriptorForId(i);
467 if (!descriptor->name) {
468 ftrace_message_strings_.emplace_back();
469 continue;
470 }
471
472 FtraceMessageStrings ftrace_strings;
473 ftrace_strings.message_name_id =
474 context->storage->InternString(descriptor->name);
475
476 for (size_t fid = 0; fid <= descriptor->max_field_id; fid++) {
477 const auto& field = descriptor->fields[fid];
478 if (!field.name)
479 continue;
480 ftrace_strings.field_name_ids[fid] =
481 context->storage->InternString(field.name);
482 }
483 ftrace_message_strings_.emplace_back(ftrace_strings);
484 }
485
486 mm_event_counter_names_ = {
487 {MmEventCounterNames(
488 context->storage->InternString("mem.mm.min_flt.count"),
489 context->storage->InternString("mem.mm.min_flt.max_lat"),
490 context->storage->InternString("mem.mm.min_flt.avg_lat")),
491 MmEventCounterNames(
492 context->storage->InternString("mem.mm.maj_flt.count"),
493 context->storage->InternString("mem.mm.maj_flt.max_lat"),
494 context->storage->InternString("mem.mm.maj_flt.avg_lat")),
495 MmEventCounterNames(
496 context->storage->InternString("mem.mm.read_io.count"),
497 context->storage->InternString("mem.mm.read_io.max_lat"),
498 context->storage->InternString("mem.mm.read_io.avg_lat")),
499 MmEventCounterNames(
500 context->storage->InternString("mem.mm.compaction.count"),
501 context->storage->InternString("mem.mm.compaction.max_lat"),
502 context->storage->InternString("mem.mm.compaction.avg_lat")),
503 MmEventCounterNames(
504 context->storage->InternString("mem.mm.reclaim.count"),
505 context->storage->InternString("mem.mm.reclaim.max_lat"),
506 context->storage->InternString("mem.mm.reclaim.avg_lat")),
507 MmEventCounterNames(
508 context->storage->InternString("mem.mm.swp_flt.count"),
509 context->storage->InternString("mem.mm.swp_flt.max_lat"),
510 context->storage->InternString("mem.mm.swp_flt.avg_lat")),
511 MmEventCounterNames(
512 context->storage->InternString("mem.mm.kern_alloc.count"),
513 context->storage->InternString("mem.mm.kern_alloc.max_lat"),
514 context->storage->InternString("mem.mm.kern_alloc.avg_lat"))}};
515 }
516
ParseFtraceStats(ConstBytes blob,uint32_t packet_sequence_id)517 base::Status FtraceParser::ParseFtraceStats(ConstBytes blob,
518 uint32_t packet_sequence_id) {
519 protos::pbzero::FtraceStats::Decoder evt(blob);
520 bool is_start =
521 evt.phase() == protos::pbzero::FtraceStats::Phase::START_OF_TRACE;
522 bool is_end = evt.phase() == protos::pbzero::FtraceStats::Phase::END_OF_TRACE;
523 if (!is_start && !is_end) {
524 return base::ErrStatus("Ignoring unknown ftrace stats phase %d",
525 evt.phase());
526 }
527 size_t phase = is_end ? 1 : 0;
528
529 // This code relies on the fact that each ftrace_cpu_XXX_end event is
530 // just after the corresponding ftrace_cpu_XXX_begin event.
531 static_assert(
532 stats::ftrace_cpu_read_events_end - stats::ftrace_cpu_read_events_begin ==
533 1 &&
534 stats::ftrace_cpu_entries_end - stats::ftrace_cpu_entries_begin == 1,
535 "ftrace_cpu_XXX stats definition are messed up");
536
537 auto* storage = context_->storage.get();
538 for (auto it = evt.cpu_stats(); it; ++it) {
539 protos::pbzero::FtraceCpuStats::Decoder cpu_stats(*it);
540 int cpu = static_cast<int>(cpu_stats.cpu());
541
542 int64_t entries = static_cast<int64_t>(cpu_stats.entries());
543 int64_t overrun = static_cast<int64_t>(cpu_stats.overrun());
544 int64_t commit_overrun = static_cast<int64_t>(cpu_stats.commit_overrun());
545 int64_t bytes = static_cast<int64_t>(cpu_stats.bytes_read());
546 int64_t dropped_events = static_cast<int64_t>(cpu_stats.dropped_events());
547 int64_t read_events = static_cast<int64_t>(cpu_stats.read_events());
548 int64_t now_ts = static_cast<int64_t>(cpu_stats.now_ts() * 1e9);
549
550 storage->SetIndexedStats(stats::ftrace_cpu_entries_begin + phase, cpu,
551 entries);
552 storage->SetIndexedStats(stats::ftrace_cpu_overrun_begin + phase, cpu,
553 overrun);
554 storage->SetIndexedStats(stats::ftrace_cpu_commit_overrun_begin + phase,
555 cpu, commit_overrun);
556 storage->SetIndexedStats(stats::ftrace_cpu_bytes_begin + phase, cpu, bytes);
557 storage->SetIndexedStats(stats::ftrace_cpu_dropped_events_begin + phase,
558 cpu, dropped_events);
559 storage->SetIndexedStats(stats::ftrace_cpu_read_events_begin + phase, cpu,
560 read_events);
561 storage->SetIndexedStats(stats::ftrace_cpu_now_ts_begin + phase, cpu,
562 now_ts);
563
564 if (is_end) {
565 auto opt_entries_begin =
566 storage->GetIndexedStats(stats::ftrace_cpu_entries_begin, cpu);
567 if (opt_entries_begin) {
568 int64_t delta_entries = entries - opt_entries_begin.value();
569 storage->SetIndexedStats(stats::ftrace_cpu_entries_delta, cpu,
570 delta_entries);
571 }
572
573 auto opt_overrun_begin =
574 storage->GetIndexedStats(stats::ftrace_cpu_overrun_begin, cpu);
575 if (opt_overrun_begin) {
576 int64_t delta_overrun = overrun - opt_overrun_begin.value();
577 storage->SetIndexedStats(stats::ftrace_cpu_overrun_delta, cpu,
578 delta_overrun);
579 }
580
581 auto opt_commit_overrun_begin =
582 storage->GetIndexedStats(stats::ftrace_cpu_commit_overrun_begin, cpu);
583 if (opt_commit_overrun_begin) {
584 int64_t delta_commit_overrun =
585 commit_overrun - opt_commit_overrun_begin.value();
586 storage->SetIndexedStats(stats::ftrace_cpu_commit_overrun_delta, cpu,
587 delta_commit_overrun);
588 }
589
590 auto opt_bytes_begin =
591 storage->GetIndexedStats(stats::ftrace_cpu_bytes_begin, cpu);
592 if (opt_bytes_begin) {
593 int64_t delta_bytes = bytes - opt_bytes_begin.value();
594 storage->SetIndexedStats(stats::ftrace_cpu_bytes_delta, cpu,
595 delta_bytes);
596 }
597
598 auto opt_dropped_events_begin =
599 storage->GetIndexedStats(stats::ftrace_cpu_dropped_events_begin, cpu);
600 if (opt_dropped_events_begin) {
601 int64_t delta_dropped_events =
602 dropped_events - opt_dropped_events_begin.value();
603 storage->SetIndexedStats(stats::ftrace_cpu_dropped_events_delta, cpu,
604 delta_dropped_events);
605 }
606
607 auto opt_read_events_begin =
608 storage->GetIndexedStats(stats::ftrace_cpu_read_events_begin, cpu);
609 if (opt_read_events_begin) {
610 int64_t delta_read_events = read_events - opt_read_events_begin.value();
611 storage->SetIndexedStats(stats::ftrace_cpu_read_events_delta, cpu,
612 delta_read_events);
613 }
614 }
615
616 // oldest_event_ts can often be set to very high values, possibly because
617 // of wrapping. Ensure that we are not overflowing to avoid ubsan
618 // complaining.
619 double oldest_event_ts = cpu_stats.oldest_event_ts() * 1e9;
620 // NB: This comparison is correct only because of the >=, it would be
621 // incorrect with >. std::numeric_limits<int64_t>::max() converted to
622 // a double is the next value representable as a double that is *larger*
623 // than std::numeric_limits<int64_t>::max(). All values that are
624 // representable as doubles and < than that value are thus representable
625 // as int64_t.
626 if (oldest_event_ts >=
627 static_cast<double>(std::numeric_limits<int64_t>::max())) {
628 storage->SetIndexedStats(stats::ftrace_cpu_oldest_event_ts_begin + phase,
629 cpu, std::numeric_limits<int64_t>::max());
630 } else {
631 storage->SetIndexedStats(stats::ftrace_cpu_oldest_event_ts_begin + phase,
632 cpu, static_cast<int64_t>(oldest_event_ts));
633 }
634 }
635
636 protos::pbzero::FtraceKprobeStats::Decoder kprobe_stats(evt.kprobe_stats());
637 storage->SetStats(stats::ftrace_kprobe_hits_begin + phase,
638 kprobe_stats.hits());
639 storage->SetStats(stats::ftrace_kprobe_misses_begin + phase,
640 kprobe_stats.misses());
641 if (is_end) {
642 auto kprobe_hits_begin = storage->GetStats(stats::ftrace_kprobe_hits_begin);
643 auto kprobe_hits_end = kprobe_stats.hits();
644 if (kprobe_hits_begin) {
645 int64_t delta_hits = kprobe_hits_end - kprobe_hits_begin;
646 storage->SetStats(stats::ftrace_kprobe_hits_delta, delta_hits);
647 }
648
649 auto kprobe_misses_begin =
650 storage->GetStats(stats::ftrace_kprobe_misses_begin);
651 auto kprobe_misses_end = kprobe_stats.misses();
652 if (kprobe_misses_begin) {
653 int64_t delta_misses = kprobe_misses_end - kprobe_misses_begin;
654 storage->SetStats(stats::ftrace_kprobe_misses_delta, delta_misses);
655 }
656 }
657
658 // Compute atrace + ftrace setup errors. We do two things here:
659 // 1. We add up all the errors and put the counter in the stats table (which
660 // can hold only numerals).
661 // 2. We concatenate together all the errors in a string and put that in the
662 // medatata table.
663 // Both will be reported in the 'Info & stats' page in the UI.
664 if (is_start) {
665 if (seen_errors_for_sequence_id_.count(packet_sequence_id) == 0) {
666 std::string error_str;
667 for (auto it = evt.failed_ftrace_events(); it; ++it) {
668 storage->IncrementStats(stats::ftrace_setup_errors, 1);
669 error_str += "Ftrace event failed: " + it->as_std_string() + "\n";
670 }
671 for (auto it = evt.unknown_ftrace_events(); it; ++it) {
672 storage->IncrementStats(stats::ftrace_setup_errors, 1);
673 error_str += "Ftrace event unknown: " + it->as_std_string() + "\n";
674 }
675 if (evt.atrace_errors().size > 0) {
676 storage->IncrementStats(stats::ftrace_setup_errors, 1);
677 error_str += "Atrace failures: " + evt.atrace_errors().ToStdString();
678 }
679 if (!error_str.empty()) {
680 auto error_str_id = storage->InternString(base::StringView(error_str));
681 context_->metadata_tracker->AppendMetadata(
682 metadata::ftrace_setup_errors, Variadic::String(error_str_id));
683 seen_errors_for_sequence_id_.insert(packet_sequence_id);
684 }
685 }
686 if (evt.preserve_ftrace_buffer()) {
687 preserve_ftrace_buffer_ = true;
688 }
689 }
690
691 // Check for parsing errors such as our understanding of the ftrace ring
692 // buffer ABI not matching the data read out of the kernel (while the trace
693 // was being recorded). Reject such traces altogether as we need to make such
694 // errors hard to ignore (most likely it's a bug in perfetto or the kernel).
695 using protos::pbzero::FtraceParseStatus;
696 auto error_it = evt.ftrace_parse_errors();
697 if (error_it) {
698 auto dev_flag =
699 context_->config.dev_flags.find("ignore-ftrace-parse-errors");
700 bool dev_skip_errors = dev_flag != context_->config.dev_flags.end() &&
701 dev_flag->second == "true";
702 if (!dev_skip_errors) {
703 std::string msg =
704 "Trace was recorded with critical ftrace parsing errors, indicating "
705 "a bug in Perfetto or the kernel. Please report "
706 "the trace to Perfetto. If you really need to load this trace, use a "
707 "native trace_processor_shell as an accelerator with these flags: "
708 "\"trace_processor_shell --httpd --dev --dev-flag "
709 "ignore-ftrace-parse-errors=true <trace_file.pb>\". Errors: ";
710 size_t error_count = 0;
711 for (; error_it; ++error_it) {
712 auto error_code = static_cast<FtraceParseStatus>(*error_it);
713 // Relax the strictness of zero-padded page errors, they're prevalent
714 // but also do not affect the actual ftrace payload.
715 // See b/329396486#comment6, b/204564312#comment20.
716 if (error_code ==
717 FtraceParseStatus::FTRACE_STATUS_ABI_ZERO_DATA_LENGTH) {
718 context_->storage->IncrementStats(
719 stats::ftrace_abi_errors_skipped_zero_data_length);
720 continue;
721 }
722 error_count += 1;
723 msg += protos::pbzero::FtraceParseStatus_Name(error_code);
724 msg += ", ";
725 }
726 msg += "(ERR:ftrace_parse)"; // special marker for UI
727 if (error_count > 0) {
728 return base::Status(msg);
729 }
730 }
731 }
732
733 return base::OkStatus();
734 }
735
ParseFtraceEvent(uint32_t cpu,int64_t ts,const TracePacketData & data)736 base::Status FtraceParser::ParseFtraceEvent(uint32_t cpu,
737 int64_t ts,
738 const TracePacketData& data) {
739 MaybeOnFirstFtraceEvent();
740 if (PERFETTO_UNLIKELY(ts < drop_ftrace_data_before_ts_)) {
741 context_->storage->IncrementStats(
742 stats::ftrace_packet_before_tracing_start);
743 return base::OkStatus();
744 }
745 using protos::pbzero::FtraceEvent;
746 const TraceBlobView& event = data.packet;
747 PacketSequenceStateGeneration* seq_state = data.sequence_state.get();
748 ProtoDecoder decoder(event.data(), event.length());
749 uint64_t raw_pid = 0;
750 bool no_pid = false;
751 if (auto pid_field = decoder.FindField(FtraceEvent::kPidFieldNumber)) {
752 raw_pid = pid_field.as_uint64();
753 } else {
754 no_pid = true;
755 }
756 uint32_t pid = static_cast<uint32_t>(raw_pid);
757
758 for (auto fld = decoder.ReadField(); fld.valid(); fld = decoder.ReadField()) {
759 bool is_metadata_field = fld.id() == FtraceEvent::kPidFieldNumber ||
760 fld.id() == FtraceEvent::kTimestampFieldNumber;
761 if (is_metadata_field)
762 continue;
763
764 // pKVM hypervisor events are recorded as ftrace events, however they are
765 // not associated with any pid. The rest of trace parsing logic for
766 // hypervisor events will use the pid 0.
767 if (no_pid && !PkvmHypervisorCpuTracker::IsPkvmHypervisorEvent(fld.id())) {
768 return base::ErrStatus("Pid field not found in ftrace packet");
769 }
770
771 ConstBytes fld_bytes = fld.as_bytes();
772 if (fld.id() == FtraceEvent::kGenericFieldNumber) {
773 ParseGenericFtrace(ts, cpu, pid, fld_bytes);
774 } else if (fld.id() != FtraceEvent::kSchedSwitchFieldNumber) {
775 // sched_switch parsing populates the raw table by itself
776 ParseTypedFtraceToRaw(fld.id(), ts, cpu, pid, fld_bytes, seq_state);
777 }
778
779 // Skip everything besides the |raw| write if we're at the start of the
780 // trace and not all per-cpu buffers cover this region yet. Otherwise if
781 // this event signifies a beginning of an operation that can end on a
782 // different cpu, we could conclude that the operation never ends.
783 // See b/192586066.
784 if (PERFETTO_UNLIKELY(ts < soft_drop_ftrace_data_before_ts_)) {
785 return base::OkStatus();
786 }
787
788 if (PkvmHypervisorCpuTracker::IsPkvmHypervisorEvent(fld.id())) {
789 pkvm_hyp_cpu_tracker_.ParseHypEvent(cpu, ts, fld.id(), fld_bytes);
790 }
791
792 switch (fld.id()) {
793 case FtraceEvent::kSchedSwitchFieldNumber: {
794 ParseSchedSwitch(cpu, ts, fld_bytes);
795 break;
796 }
797 case FtraceEvent::kSchedWakingFieldNumber: {
798 ParseSchedWaking(ts, pid, fld_bytes);
799 break;
800 }
801 case FtraceEvent::kSchedProcessFreeFieldNumber: {
802 ParseSchedProcessFree(ts, fld_bytes);
803 break;
804 }
805 case FtraceEvent::kCpuFrequencyFieldNumber: {
806 ParseCpuFreq(ts, fld_bytes);
807 break;
808 }
809 case FtraceEvent::kDcvshFreqFieldNumber: {
810 ParseCpuFreqThrottle(ts, fld_bytes);
811 break;
812 }
813 case FtraceEvent::kGpuFrequencyFieldNumber: {
814 ParseGpuFreq(ts, fld_bytes);
815 break;
816 }
817 case FtraceEvent::kKgslGpuFrequencyFieldNumber: {
818 ParseKgslGpuFreq(ts, fld_bytes);
819 break;
820 }
821 case FtraceEvent::kCpuIdleFieldNumber: {
822 ParseCpuIdle(ts, fld_bytes);
823 break;
824 }
825 case FtraceEvent::kPrintFieldNumber: {
826 ParsePrint(ts, pid, fld_bytes);
827 break;
828 }
829 case FtraceEvent::kZeroFieldNumber: {
830 ParseZero(ts, pid, fld_bytes);
831 break;
832 }
833 case FtraceEvent::kRssStatThrottledFieldNumber:
834 case FtraceEvent::kRssStatFieldNumber: {
835 rss_stat_tracker_.ParseRssStat(ts, fld.id(), pid, fld_bytes);
836 break;
837 }
838 case FtraceEvent::kIonHeapGrowFieldNumber: {
839 ParseIonHeapGrowOrShrink(ts, pid, fld_bytes, true);
840 break;
841 }
842 case FtraceEvent::kIonHeapShrinkFieldNumber: {
843 ParseIonHeapGrowOrShrink(ts, pid, fld_bytes, false);
844 break;
845 }
846 case FtraceEvent::kIonStatFieldNumber: {
847 ParseIonStat(ts, pid, fld_bytes);
848 break;
849 }
850 case FtraceEvent::kDmaHeapStatFieldNumber: {
851 ParseDmaHeapStat(ts, pid, fld_bytes);
852 break;
853 }
854 case FtraceEvent::kSignalGenerateFieldNumber: {
855 ParseSignalGenerate(ts, fld_bytes);
856 break;
857 }
858 case FtraceEvent::kSignalDeliverFieldNumber: {
859 ParseSignalDeliver(ts, pid, fld_bytes);
860 break;
861 }
862 case FtraceEvent::kOomScoreAdjUpdateFieldNumber: {
863 ParseOOMScoreAdjUpdate(ts, fld_bytes);
864 break;
865 }
866 case FtraceEvent::kMarkVictimFieldNumber: {
867 ParseOOMKill(ts, fld_bytes);
868 break;
869 }
870 case FtraceEvent::kMmEventRecordFieldNumber: {
871 ParseMmEventRecord(ts, pid, fld_bytes);
872 break;
873 }
874 case FtraceEvent::kSysEnterFieldNumber: {
875 ParseSysEnterEvent(ts, pid, fld_bytes);
876 break;
877 }
878 case FtraceEvent::kSysExitFieldNumber: {
879 ParseSysExitEvent(ts, pid, fld_bytes);
880 break;
881 }
882 case FtraceEvent::kTaskNewtaskFieldNumber: {
883 ParseTaskNewTask(ts, pid, fld_bytes);
884 break;
885 }
886 case FtraceEvent::kTaskRenameFieldNumber: {
887 ParseTaskRename(fld_bytes);
888 break;
889 }
890 case FtraceEvent::kBinderTransactionFieldNumber: {
891 ParseBinderTransaction(ts, pid, fld_bytes);
892 break;
893 }
894 case FtraceEvent::kBinderTransactionReceivedFieldNumber: {
895 ParseBinderTransactionReceived(ts, pid, fld_bytes);
896 break;
897 }
898 case FtraceEvent::kBinderCommandFieldNumber: {
899 ParseBinderCommand(ts, pid, fld_bytes);
900 break;
901 }
902 case FtraceEvent::kBinderReturnFieldNumber: {
903 ParseBinderReturn(ts, pid, fld_bytes);
904 break;
905 }
906 case FtraceEvent::kBinderTransactionAllocBufFieldNumber: {
907 ParseBinderTransactionAllocBuf(ts, pid, fld_bytes);
908 break;
909 }
910 case FtraceEvent::kBinderLockFieldNumber: {
911 ParseBinderLock(ts, pid, fld_bytes);
912 break;
913 }
914 case FtraceEvent::kBinderUnlockFieldNumber: {
915 ParseBinderUnlock(ts, pid, fld_bytes);
916 break;
917 }
918 case FtraceEvent::kBinderLockedFieldNumber: {
919 ParseBinderLocked(ts, pid, fld_bytes);
920 break;
921 }
922 case FtraceEvent::kSdeTracingMarkWriteFieldNumber: {
923 ParseSdeTracingMarkWrite(ts, pid, fld_bytes);
924 break;
925 }
926 case FtraceEvent::kClockSetRateFieldNumber: {
927 ParseClockSetRate(ts, fld_bytes);
928 break;
929 }
930 case FtraceEvent::kClockEnableFieldNumber: {
931 ParseClockEnable(ts, fld_bytes);
932 break;
933 }
934 case FtraceEvent::kClockDisableFieldNumber: {
935 ParseClockDisable(ts, fld_bytes);
936 break;
937 }
938 case FtraceEvent::kScmCallStartFieldNumber: {
939 ParseScmCallStart(ts, pid, fld_bytes);
940 break;
941 }
942 case FtraceEvent::kScmCallEndFieldNumber: {
943 ParseScmCallEnd(ts, pid, fld_bytes);
944 break;
945 }
946 case FtraceEvent::kCmaAllocStartFieldNumber: {
947 ParseCmaAllocStart(ts, pid);
948 break;
949 }
950 case FtraceEvent::kCmaAllocInfoFieldNumber: {
951 ParseCmaAllocInfo(ts, pid, fld_bytes);
952 break;
953 }
954 case FtraceEvent::kMmVmscanDirectReclaimBeginFieldNumber: {
955 ParseDirectReclaimBegin(ts, pid, fld_bytes);
956 break;
957 }
958 case FtraceEvent::kMmVmscanDirectReclaimEndFieldNumber: {
959 ParseDirectReclaimEnd(ts, pid, fld_bytes);
960 break;
961 }
962 case FtraceEvent::kMmShrinkSlabStartFieldNumber: {
963 ParseShrinkSlabStart(ts, pid, fld_bytes, seq_state);
964 break;
965 }
966 case FtraceEvent::kMmShrinkSlabEndFieldNumber: {
967 ParseShrinkSlabEnd(ts, pid, fld_bytes);
968 break;
969 }
970 case FtraceEvent::kWorkqueueExecuteStartFieldNumber: {
971 ParseWorkqueueExecuteStart(cpu, ts, pid, fld_bytes, seq_state);
972 break;
973 }
974 case FtraceEvent::kWorkqueueExecuteEndFieldNumber: {
975 ParseWorkqueueExecuteEnd(ts, pid, fld_bytes);
976 break;
977 }
978 case FtraceEvent::kIrqHandlerEntryFieldNumber: {
979 ParseIrqHandlerEntry(cpu, ts, fld_bytes);
980 break;
981 }
982 case FtraceEvent::kIrqHandlerExitFieldNumber: {
983 ParseIrqHandlerExit(cpu, ts, fld_bytes);
984 break;
985 }
986 case FtraceEvent::kSoftirqEntryFieldNumber: {
987 ParseSoftIrqEntry(cpu, ts, fld_bytes);
988 break;
989 }
990 case FtraceEvent::kSoftirqExitFieldNumber: {
991 ParseSoftIrqExit(cpu, ts, fld_bytes);
992 break;
993 }
994 case FtraceEvent::kGpuMemTotalFieldNumber: {
995 ParseGpuMemTotal(ts, fld_bytes);
996 break;
997 }
998 case FtraceEvent::kThermalTemperatureFieldNumber: {
999 thermal_tracker_.ParseThermalTemperature(ts, fld_bytes);
1000 break;
1001 }
1002 case FtraceEvent::kThermalExynosAcpmBulkFieldNumber: {
1003 thermal_tracker_.ParseThermalExynosAcpmBulk(fld_bytes);
1004 break;
1005 }
1006 case FtraceEvent::kThermalExynosAcpmHighOverheadFieldNumber: {
1007 thermal_tracker_.ParseThermalExynosAcpmHighOverhead(ts, fld_bytes);
1008 break;
1009 }
1010 case FtraceEvent::kCdevUpdateFieldNumber: {
1011 thermal_tracker_.ParseCdevUpdate(ts, fld_bytes);
1012 break;
1013 }
1014 case FtraceEvent::kSchedBlockedReasonFieldNumber: {
1015 ParseSchedBlockedReason(fld_bytes, seq_state);
1016 break;
1017 }
1018 case FtraceEvent::kFastrpcDmaStatFieldNumber: {
1019 ParseFastRpcDmaStat(ts, pid, fld_bytes);
1020 break;
1021 }
1022 case FtraceEvent::kG2dTracingMarkWriteFieldNumber: {
1023 ParseG2dTracingMarkWrite(ts, pid, fld_bytes);
1024 break;
1025 }
1026 case FtraceEvent::kSamsungTracingMarkWriteFieldNumber: {
1027 ParseSamsungTracingMarkWrite(ts, pid, fld_bytes);
1028 break;
1029 }
1030 case FtraceEvent::kDpuTracingMarkWriteFieldNumber: {
1031 ParseDpuTracingMarkWrite(ts, pid, fld_bytes);
1032 break;
1033 }
1034 case FtraceEvent::kDpuDispDpuUnderrunFieldNumber: {
1035 ParseDpuDispDpuUnderrun(ts, fld_bytes);
1036 break;
1037 }
1038 case FtraceEvent::kDpuDispVblankIrqEnableFieldNumber: {
1039 ParseDpuDispVblankIrqEnable(ts, fld_bytes);
1040 break;
1041 }
1042 case FtraceEvent::kMaliTracingMarkWriteFieldNumber: {
1043 ParseMaliTracingMarkWrite(ts, pid, fld_bytes);
1044 break;
1045 }
1046 case FtraceEvent::kLwisTracingMarkWriteFieldNumber: {
1047 ParseLwisTracingMarkWrite(ts, pid, fld_bytes);
1048 break;
1049 }
1050 case FtraceEvent::kVirtioGpuCmdQueueFieldNumber:
1051 case FtraceEvent::kVirtioGpuCmdResponseFieldNumber: {
1052 virtio_gpu_tracker_.ParseVirtioGpu(ts, fld.id(), pid, fld_bytes);
1053 break;
1054 }
1055 case FtraceEvent::kCpuhpPauseFieldNumber: {
1056 ParseCpuhpPause(ts, pid, fld_bytes);
1057 break;
1058 }
1059 case FtraceEvent::kNetifReceiveSkbFieldNumber: {
1060 ParseNetifReceiveSkb(cpu, ts, fld_bytes);
1061 break;
1062 }
1063 case FtraceEvent::kNetDevXmitFieldNumber: {
1064 ParseNetDevXmit(cpu, ts, fld_bytes);
1065 break;
1066 }
1067 case FtraceEvent::kInetSockSetStateFieldNumber: {
1068 ParseInetSockSetState(ts, pid, fld_bytes);
1069 break;
1070 }
1071 case FtraceEvent::kTcpRetransmitSkbFieldNumber: {
1072 ParseTcpRetransmitSkb(ts, fld_bytes);
1073 break;
1074 }
1075 case FtraceEvent::kNapiGroReceiveEntryFieldNumber: {
1076 ParseNapiGroReceiveEntry(cpu, ts, fld_bytes);
1077 break;
1078 }
1079 case FtraceEvent::kNapiGroReceiveExitFieldNumber: {
1080 ParseNapiGroReceiveExit(cpu, ts, fld_bytes);
1081 break;
1082 }
1083 case FtraceEvent::kCpuFrequencyLimitsFieldNumber: {
1084 ParseCpuFrequencyLimits(ts, fld_bytes);
1085 break;
1086 }
1087 case FtraceEvent::kKfreeSkbFieldNumber: {
1088 ParseKfreeSkb(ts, fld_bytes);
1089 break;
1090 }
1091 case FtraceEvent::kCrosEcSensorhubDataFieldNumber: {
1092 ParseCrosEcSensorhubData(ts, fld_bytes);
1093 break;
1094 }
1095 case FtraceEvent::kUfshcdCommandFieldNumber: {
1096 ParseUfshcdCommand(ts, fld_bytes);
1097 break;
1098 }
1099 case FtraceEvent::kWakeupSourceActivateFieldNumber: {
1100 ParseWakeSourceActivate(ts, fld_bytes);
1101 break;
1102 }
1103 case FtraceEvent::kWakeupSourceDeactivateFieldNumber: {
1104 ParseWakeSourceDeactivate(ts, fld_bytes);
1105 break;
1106 }
1107 case FtraceEvent::kUfshcdClkGatingFieldNumber: {
1108 ParseUfshcdClkGating(ts, fld_bytes);
1109 break;
1110 }
1111 case FtraceEvent::kSuspendResumeFieldNumber: {
1112 ParseSuspendResume(ts, cpu, pid, fld_bytes);
1113 break;
1114 }
1115 case FtraceEvent::kSuspendResumeMinimalFieldNumber: {
1116 ParseSuspendResumeMinimal(ts, fld_bytes);
1117 break;
1118 }
1119 case FtraceEvent::kDrmVblankEventFieldNumber:
1120 case FtraceEvent::kDrmVblankEventDeliveredFieldNumber:
1121 case FtraceEvent::kDrmSchedJobFieldNumber:
1122 case FtraceEvent::kDrmRunJobFieldNumber:
1123 case FtraceEvent::kDrmSchedProcessJobFieldNumber:
1124 case FtraceEvent::kDmaFenceInitFieldNumber:
1125 case FtraceEvent::kDmaFenceEmitFieldNumber:
1126 case FtraceEvent::kDmaFenceSignaledFieldNumber:
1127 case FtraceEvent::kDmaFenceWaitStartFieldNumber:
1128 case FtraceEvent::kDmaFenceWaitEndFieldNumber: {
1129 drm_tracker_.ParseDrm(ts, fld.id(), pid, fld_bytes);
1130 break;
1131 }
1132 case FtraceEvent::kF2fsIostatFieldNumber: {
1133 iostat_tracker_.ParseF2fsIostat(ts, fld_bytes);
1134 break;
1135 }
1136 case FtraceEvent::kF2fsIostatLatencyFieldNumber: {
1137 iostat_tracker_.ParseF2fsIostatLatency(ts, fld_bytes);
1138 break;
1139 }
1140 case FtraceEvent::kSchedCpuUtilCfsFieldNumber: {
1141 ParseSchedCpuUtilCfs(ts, fld_bytes);
1142 break;
1143 }
1144 case FtraceEvent::kI2cReadFieldNumber: {
1145 ParseI2cReadEvent(ts, pid, fld_bytes);
1146 break;
1147 }
1148 case FtraceEvent::kI2cWriteFieldNumber: {
1149 ParseI2cWriteEvent(ts, pid, fld_bytes);
1150 break;
1151 }
1152 case FtraceEvent::kI2cResultFieldNumber: {
1153 ParseI2cResultEvent(ts, pid, fld_bytes);
1154 break;
1155 }
1156 case FtraceEvent::kFuncgraphEntryFieldNumber: {
1157 ParseFuncgraphEntry(ts, cpu, pid, fld_bytes, seq_state);
1158 break;
1159 }
1160 case FtraceEvent::kFuncgraphExitFieldNumber: {
1161 ParseFuncgraphExit(ts, cpu, pid, fld_bytes, seq_state);
1162 break;
1163 }
1164 case FtraceEvent::kV4l2QbufFieldNumber:
1165 case FtraceEvent::kV4l2DqbufFieldNumber:
1166 case FtraceEvent::kVb2V4l2BufQueueFieldNumber:
1167 case FtraceEvent::kVb2V4l2BufDoneFieldNumber:
1168 case FtraceEvent::kVb2V4l2QbufFieldNumber:
1169 case FtraceEvent::kVb2V4l2DqbufFieldNumber: {
1170 V4l2Tracker::GetOrCreate(context_)->ParseV4l2Event(fld.id(), ts, pid,
1171 fld_bytes);
1172 break;
1173 }
1174 case FtraceEvent::kVirtioVideoCmdFieldNumber:
1175 case FtraceEvent::kVirtioVideoCmdDoneFieldNumber:
1176 case FtraceEvent::kVirtioVideoResourceQueueFieldNumber:
1177 case FtraceEvent::kVirtioVideoResourceQueueDoneFieldNumber: {
1178 VirtioVideoTracker::GetOrCreate(context_)->ParseVirtioVideoEvent(
1179 fld.id(), ts, fld_bytes);
1180 break;
1181 }
1182 case FtraceEvent::kTrustySmcFieldNumber: {
1183 ParseTrustySmc(pid, ts, fld_bytes);
1184 break;
1185 }
1186 case FtraceEvent::kTrustySmcDoneFieldNumber: {
1187 ParseTrustySmcDone(pid, ts, fld_bytes);
1188 break;
1189 }
1190 case FtraceEvent::kTrustyStdCall32FieldNumber: {
1191 ParseTrustyStdCall32(pid, ts, fld_bytes);
1192 break;
1193 }
1194 case FtraceEvent::kTrustyStdCall32DoneFieldNumber: {
1195 ParseTrustyStdCall32Done(pid, ts, fld_bytes);
1196 break;
1197 }
1198 case FtraceEvent::kTrustyShareMemoryFieldNumber: {
1199 ParseTrustyShareMemory(pid, ts, fld_bytes);
1200 break;
1201 }
1202 case FtraceEvent::kTrustyShareMemoryDoneFieldNumber: {
1203 ParseTrustyShareMemoryDone(pid, ts, fld_bytes);
1204 break;
1205 }
1206 case FtraceEvent::kTrustyReclaimMemoryFieldNumber: {
1207 ParseTrustyReclaimMemory(pid, ts, fld_bytes);
1208 break;
1209 }
1210 case FtraceEvent::kTrustyReclaimMemoryDoneFieldNumber: {
1211 ParseTrustyReclaimMemoryDone(pid, ts, fld_bytes);
1212 break;
1213 }
1214 case FtraceEvent::kTrustyIrqFieldNumber: {
1215 ParseTrustyIrq(pid, ts, fld_bytes);
1216 break;
1217 }
1218 case FtraceEvent::kTrustyIpcHandleEventFieldNumber: {
1219 ParseTrustyIpcHandleEvent(pid, ts, fld_bytes);
1220 break;
1221 }
1222 case FtraceEvent::kTrustyIpcConnectFieldNumber: {
1223 ParseTrustyIpcConnect(pid, ts, fld_bytes);
1224 break;
1225 }
1226 case FtraceEvent::kTrustyIpcConnectEndFieldNumber: {
1227 ParseTrustyIpcConnectEnd(pid, ts, fld_bytes);
1228 break;
1229 }
1230 case FtraceEvent::kTrustyIpcWriteFieldNumber: {
1231 ParseTrustyIpcWrite(pid, ts, fld_bytes);
1232 break;
1233 }
1234 case FtraceEvent::kTrustyIpcReadFieldNumber: {
1235 ParseTrustyIpcRead(pid, ts, fld_bytes);
1236 break;
1237 }
1238 case FtraceEvent::kTrustyIpcReadEndFieldNumber: {
1239 ParseTrustyIpcReadEnd(pid, ts, fld_bytes);
1240 break;
1241 }
1242 case FtraceEvent::kTrustyIpcPollFieldNumber: {
1243 ParseTrustyIpcPoll(pid, ts, fld_bytes);
1244 break;
1245 }
1246 case FtraceEvent::kTrustyIpcRxFieldNumber: {
1247 ParseTrustyIpcRx(pid, ts, fld_bytes);
1248 break;
1249 }
1250 case FtraceEvent::kTrustyEnqueueNopFieldNumber: {
1251 ParseTrustyEnqueueNop(pid, ts, fld_bytes);
1252 break;
1253 }
1254 case FtraceEvent::kDevfreqFrequencyFieldNumber: {
1255 ParseDeviceFrequency(ts, fld_bytes);
1256 break;
1257 }
1258 case FtraceEvent::kMaliMaliCSFINTERRUPTSTARTFieldNumber:
1259 case FtraceEvent::kMaliMaliCSFINTERRUPTENDFieldNumber: {
1260 mali_gpu_event_tracker_.ParseMaliGpuIrqEvent(ts, fld.id(), cpu,
1261 fld_bytes);
1262 break;
1263 }
1264 case FtraceEvent::kMaliMaliPMMCUHCTLCORESDOWNSCALENOTIFYPENDFieldNumber:
1265 case FtraceEvent::kMaliMaliPMMCUHCTLCORESNOTIFYPENDFieldNumber:
1266 case FtraceEvent::kMaliMaliPMMCUHCTLCOREINACTIVEPENDFieldNumber:
1267 case FtraceEvent::kMaliMaliPMMCUHCTLMCUONRECHECKFieldNumber:
1268 case FtraceEvent::kMaliMaliPMMCUHCTLSHADERSCOREOFFPENDFieldNumber:
1269 case FtraceEvent::kMaliMaliPMMCUHCTLSHADERSPENDOFFFieldNumber:
1270 case FtraceEvent::kMaliMaliPMMCUHCTLSHADERSPENDONFieldNumber:
1271 case FtraceEvent::kMaliMaliPMMCUHCTLSHADERSREADYOFFFieldNumber:
1272 case FtraceEvent::kMaliMaliPMMCUINSLEEPFieldNumber:
1273 case FtraceEvent::kMaliMaliPMMCUOFFFieldNumber:
1274 case FtraceEvent::kMaliMaliPMMCUONFieldNumber:
1275 case FtraceEvent::kMaliMaliPMMCUONCOREATTRUPDATEPENDFieldNumber:
1276 case FtraceEvent::kMaliMaliPMMCUONGLBREINITPENDFieldNumber:
1277 case FtraceEvent::kMaliMaliPMMCUONHALTFieldNumber:
1278 case FtraceEvent::kMaliMaliPMMCUONHWCNTDISABLEFieldNumber:
1279 case FtraceEvent::kMaliMaliPMMCUONHWCNTENABLEFieldNumber:
1280 case FtraceEvent::kMaliMaliPMMCUONPENDHALTFieldNumber:
1281 case FtraceEvent::kMaliMaliPMMCUONPENDSLEEPFieldNumber:
1282 case FtraceEvent::kMaliMaliPMMCUONSLEEPINITIATEFieldNumber:
1283 case FtraceEvent::kMaliMaliPMMCUPENDOFFFieldNumber:
1284 case FtraceEvent::kMaliMaliPMMCUPENDONRELOADFieldNumber:
1285 case FtraceEvent::kMaliMaliPMMCUPOWERDOWNFieldNumber:
1286 case FtraceEvent::kMaliMaliPMMCURESETWAITFieldNumber: {
1287 mali_gpu_event_tracker_.ParseMaliGpuMcuStateEvent(ts, fld.id());
1288 break;
1289 }
1290 case FtraceEvent::kTracingMarkWriteFieldNumber: {
1291 ParseMdssTracingMarkWrite(ts, pid, fld_bytes);
1292 break;
1293 }
1294 case FtraceEvent::kAndroidFsDatareadEndFieldNumber: {
1295 ParseAndroidFsDatareadEnd(ts, fld_bytes);
1296 break;
1297 }
1298 case FtraceEvent::kAndroidFsDatareadStartFieldNumber: {
1299 ParseAndroidFsDatareadStart(ts, pid, fld_bytes);
1300 break;
1301 }
1302 case FtraceEvent::kGpuWorkPeriodFieldNumber: {
1303 gpu_work_period_tracker_.ParseGpuWorkPeriodEvent(ts, fld_bytes);
1304 break;
1305 }
1306 case FtraceEvent::kRpmStatusFieldNumber: {
1307 ParseRpmStatus(ts, fld_bytes);
1308 break;
1309 }
1310 case FtraceEvent::kPanelWriteGenericFieldNumber: {
1311 ParsePanelWriteGeneric(ts, pid, fld_bytes);
1312 break;
1313 }
1314 case FtraceEvent::kGoogleIccEventFieldNumber: {
1315 ParseGoogleIccEvent(ts, fld_bytes);
1316 break;
1317 }
1318 case FtraceEvent::kGoogleIrmEventFieldNumber: {
1319 ParseGoogleIrmEvent(ts, fld_bytes);
1320 break;
1321 }
1322 case FtraceEvent::kDevicePmCallbackStartFieldNumber: {
1323 ParseDevicePmCallbackStart(ts, cpu, pid, fld_bytes);
1324 break;
1325 }
1326 case FtraceEvent::kDevicePmCallbackEndFieldNumber: {
1327 ParseDevicePmCallbackEnd(ts, fld_bytes);
1328 break;
1329 }
1330 case FtraceEvent::kBclIrqTriggerFieldNumber: {
1331 ParseBclIrq(ts, fld_bytes);
1332 break;
1333 }
1334 case FtraceEvent::kPixelMmKswapdWakeFieldNumber: {
1335 pixel_mm_kswapd_event_tracker_.ParsePixelMmKswapdWake(ts, pid);
1336 break;
1337 }
1338 case FtraceEvent::kPixelMmKswapdDoneFieldNumber: {
1339 pixel_mm_kswapd_event_tracker_.ParsePixelMmKswapdDone(ts, pid,
1340 fld_bytes);
1341 break;
1342 }
1343 case FtraceEvent::kKprobeEventFieldNumber: {
1344 ParseKprobe(ts, pid, fld_bytes);
1345 break;
1346 }
1347 case FtraceEvent::kParamSetValueCpmFieldNumber: {
1348 ParseParamSetValueCpm(fld_bytes);
1349 break;
1350 }
1351 case FtraceEvent::kBlockIoStartFieldNumber: {
1352 ParseBlockIoStart(ts, fld_bytes);
1353 break;
1354 }
1355 case FtraceEvent::kBlockIoDoneFieldNumber: {
1356 ParseBlockIoDone(ts, fld_bytes);
1357 break;
1358 }
1359 // Intentional fallthrough for Cpuhp multienter/enter, since they both
1360 // have same fields and require identical processing.
1361 case FtraceEvent::kCpuhpMultiEnterFieldNumber:
1362 case FtraceEvent::kCpuhpEnterFieldNumber: {
1363 ParseCpuhpEnter(fld.id(), ts, cpu, fld_bytes);
1364 break;
1365 }
1366 case FtraceEvent::kCpuhpExitFieldNumber: {
1367 ParseCpuhpExit(ts, fld_bytes);
1368 break;
1369 }
1370 default:
1371 break;
1372 }
1373 }
1374
1375 PERFETTO_DCHECK(!decoder.bytes_left());
1376 return base::OkStatus();
1377 }
1378
ParseInlineSchedSwitch(uint32_t cpu,int64_t ts,const InlineSchedSwitch & data)1379 base::Status FtraceParser::ParseInlineSchedSwitch(
1380 uint32_t cpu,
1381 int64_t ts,
1382 const InlineSchedSwitch& data) {
1383 MaybeOnFirstFtraceEvent();
1384 bool parse_only_into_raw = false;
1385 if (PERFETTO_UNLIKELY(ts < soft_drop_ftrace_data_before_ts_)) {
1386 parse_only_into_raw = true;
1387 if (ts < drop_ftrace_data_before_ts_) {
1388 context_->storage->IncrementStats(
1389 stats::ftrace_packet_before_tracing_start);
1390 return base::OkStatus();
1391 }
1392 }
1393
1394 using protos::pbzero::FtraceEvent;
1395 FtraceSchedEventTracker* ftrace_sched_tracker =
1396 FtraceSchedEventTracker::GetOrCreate(context_);
1397 ftrace_sched_tracker->PushSchedSwitchCompact(
1398 cpu, ts, data.prev_state, static_cast<uint32_t>(data.next_pid),
1399 data.next_prio, data.next_comm, parse_only_into_raw);
1400 return base::OkStatus();
1401 }
1402
ParseInlineSchedWaking(uint32_t cpu,int64_t ts,const InlineSchedWaking & data)1403 base::Status FtraceParser::ParseInlineSchedWaking(
1404 uint32_t cpu,
1405 int64_t ts,
1406 const InlineSchedWaking& data) {
1407 MaybeOnFirstFtraceEvent();
1408 bool parse_only_into_raw = false;
1409 if (PERFETTO_UNLIKELY(ts < soft_drop_ftrace_data_before_ts_)) {
1410 parse_only_into_raw = true;
1411 if (ts < drop_ftrace_data_before_ts_) {
1412 context_->storage->IncrementStats(
1413 stats::ftrace_packet_before_tracing_start);
1414 return base::OkStatus();
1415 }
1416 }
1417
1418 using protos::pbzero::FtraceEvent;
1419 FtraceSchedEventTracker* ftrace_sched_tracker =
1420 FtraceSchedEventTracker::GetOrCreate(context_);
1421 ftrace_sched_tracker->PushSchedWakingCompact(
1422 cpu, ts, static_cast<uint32_t>(data.pid), data.target_cpu, data.prio,
1423 data.comm, data.common_flags, parse_only_into_raw);
1424 return base::OkStatus();
1425 }
1426
MaybeOnFirstFtraceEvent()1427 void FtraceParser::MaybeOnFirstFtraceEvent() {
1428 if (PERFETTO_LIKELY(has_seen_first_ftrace_packet_)) {
1429 return;
1430 }
1431
1432 // Calculate the timestamp used to skip events that predate the time when
1433 // tracing started.
1434 DropFtraceDataBefore drop_before =
1435 preserve_ftrace_buffer_ ? DropFtraceDataBefore::kNoDrop
1436 : context_->config.drop_ftrace_data_before;
1437 switch (drop_before) {
1438 case DropFtraceDataBefore::kNoDrop: {
1439 drop_ftrace_data_before_ts_ = 0;
1440 break;
1441 }
1442 case DropFtraceDataBefore::kAllDataSourcesStarted:
1443 case DropFtraceDataBefore::kTracingStarted: {
1444 metadata::KeyId event_key =
1445 drop_before == DropFtraceDataBefore::kAllDataSourcesStarted
1446 ? metadata::all_data_source_started_ns
1447 : metadata::tracing_started_ns;
1448
1449 drop_ftrace_data_before_ts_ =
1450 context_->metadata_tracker->GetMetadata(event_key)
1451 .value_or(SqlValue::Long(0))
1452 .AsLong();
1453 break;
1454 }
1455 }
1456
1457 // Calculate the timestamp used to skip early events, while still populating
1458 // the |ftrace_events| table.
1459 SoftDropFtraceDataBefore soft_drop_before =
1460 context_->config.soft_drop_ftrace_data_before;
1461
1462 // TODO(b/344969928): Workaround, can be removed when perfetto v47+ traces are
1463 // the norm in Android.
1464 base::StringView unique_session_name =
1465 context_->metadata_tracker->GetMetadata(metadata::unique_session_name)
1466 .value_or(SqlValue::String(""))
1467 .AsString();
1468 if (unique_session_name ==
1469 base::StringView("session_with_lightweight_battery_tracing")) {
1470 soft_drop_before = SoftDropFtraceDataBefore::kNoDrop;
1471 }
1472
1473 switch (soft_drop_before) {
1474 case SoftDropFtraceDataBefore::kNoDrop: {
1475 soft_drop_ftrace_data_before_ts_ = 0;
1476 break;
1477 }
1478 case SoftDropFtraceDataBefore::kAllPerCpuBuffersValid: {
1479 soft_drop_ftrace_data_before_ts_ =
1480 context_->metadata_tracker
1481 ->GetMetadata(metadata::ftrace_latest_data_start_ns)
1482 .value_or(SqlValue::Long(0))
1483 .AsLong();
1484 break;
1485 }
1486 }
1487 soft_drop_ftrace_data_before_ts_ =
1488 std::max(soft_drop_ftrace_data_before_ts_, drop_ftrace_data_before_ts_);
1489
1490 has_seen_first_ftrace_packet_ = true;
1491 }
1492
ParseGenericFtrace(int64_t ts,uint32_t cpu,uint32_t tid,ConstBytes blob)1493 void FtraceParser::ParseGenericFtrace(int64_t ts,
1494 uint32_t cpu,
1495 uint32_t tid,
1496 ConstBytes blob) {
1497 protos::pbzero::GenericFtraceEvent::Decoder evt(blob);
1498 StringId event_id = context_->storage->InternString(evt.event_name());
1499 UniqueTid utid = context_->process_tracker->GetOrCreateThread(tid);
1500 auto ucpu = context_->cpu_tracker->GetOrCreateCpu(cpu);
1501 tables::FtraceEventTable::Id id =
1502 context_->storage->mutable_ftrace_event_table()
1503 ->Insert({ts, event_id, utid, {}, {}, ucpu})
1504 .id;
1505 auto inserter = context_->args_tracker->AddArgsTo(id);
1506
1507 for (auto it = evt.field(); it; ++it) {
1508 protos::pbzero::GenericFtraceEvent::Field::Decoder fld(*it);
1509 auto field_name_id = context_->storage->InternString(fld.name());
1510 if (fld.has_int_value()) {
1511 inserter.AddArg(field_name_id, Variadic::Integer(fld.int_value()));
1512 } else if (fld.has_uint_value()) {
1513 inserter.AddArg(
1514 field_name_id,
1515 Variadic::Integer(static_cast<int64_t>(fld.uint_value())));
1516 } else if (fld.has_str_value()) {
1517 StringId str_value = context_->storage->InternString(fld.str_value());
1518 inserter.AddArg(field_name_id, Variadic::String(str_value));
1519 }
1520 }
1521 }
1522
ParseTypedFtraceToRaw(uint32_t ftrace_id,int64_t timestamp,uint32_t cpu,uint32_t tid,ConstBytes blob,PacketSequenceStateGeneration * seq_state)1523 void FtraceParser::ParseTypedFtraceToRaw(
1524 uint32_t ftrace_id,
1525 int64_t timestamp,
1526 uint32_t cpu,
1527 uint32_t tid,
1528 ConstBytes blob,
1529 PacketSequenceStateGeneration* seq_state) {
1530 if (PERFETTO_UNLIKELY(!context_->config.ingest_ftrace_in_raw_table))
1531 return;
1532
1533 ProtoDecoder decoder(blob);
1534 if (ftrace_id >= GetDescriptorsSize()) {
1535 PERFETTO_DLOG("Event with id: %d does not exist and cannot be parsed.",
1536 ftrace_id);
1537 return;
1538 }
1539
1540 FtraceMessageDescriptor* m = GetMessageDescriptorForId(ftrace_id);
1541 const auto& message_strings = ftrace_message_strings_[ftrace_id];
1542 UniqueTid utid = context_->process_tracker->GetOrCreateThread(tid);
1543 auto ucpu = context_->cpu_tracker->GetOrCreateCpu(cpu);
1544 tables::FtraceEventTable::Id id =
1545 context_->storage->mutable_ftrace_event_table()
1546 ->Insert(
1547 {timestamp, message_strings.message_name_id, utid, {}, {}, ucpu})
1548 .id;
1549 auto inserter = context_->args_tracker->AddArgsTo(id);
1550
1551 for (auto fld = decoder.ReadField(); fld.valid(); fld = decoder.ReadField()) {
1552 uint32_t field_id = fld.id();
1553 if (PERFETTO_UNLIKELY(field_id >= kMaxFtraceEventFields)) {
1554 PERFETTO_DLOG(
1555 "Skipping ftrace arg - proto field id is too large (%" PRIu32 ")",
1556 field_id);
1557 continue;
1558 }
1559
1560 ProtoSchemaType type = m->fields[field_id].type;
1561 StringId name_id = message_strings.field_name_ids[field_id];
1562
1563 // Check if this field represents a kernel function.
1564 const auto it = std::find_if(
1565 kKernelFunctionFields.begin(), kKernelFunctionFields.end(),
1566 [ftrace_id, field_id](const FtraceEventAndFieldId& ev) {
1567 return ev.event_id == ftrace_id && ev.field_id == field_id;
1568 });
1569 if (it != kKernelFunctionFields.end()) {
1570 PERFETTO_CHECK(type == ProtoSchemaType::kUint64);
1571
1572 auto* interned_string = seq_state->LookupInternedMessage<
1573 protos::pbzero::InternedData::kKernelSymbolsFieldNumber,
1574 protos::pbzero::InternedString>(fld.as_uint64());
1575
1576 // If we don't have the string for this field (can happen if
1577 // symbolization wasn't enabled, if reading the symbols errored out or
1578 // on legacy traces) then just add the field as a normal arg.
1579 if (interned_string) {
1580 protozero::ConstBytes str = interned_string->str();
1581 StringId str_id = context_->storage->InternString(base::StringView(
1582 reinterpret_cast<const char*>(str.data), str.size));
1583 inserter.AddArg(name_id, Variadic::String(str_id));
1584 continue;
1585 }
1586 }
1587
1588 switch (type) {
1589 case ProtoSchemaType::kInt32:
1590 case ProtoSchemaType::kInt64:
1591 case ProtoSchemaType::kSfixed32:
1592 case ProtoSchemaType::kSfixed64:
1593 case ProtoSchemaType::kBool:
1594 case ProtoSchemaType::kEnum: {
1595 inserter.AddArg(name_id, Variadic::Integer(fld.as_int64()));
1596 break;
1597 }
1598 case ProtoSchemaType::kUint32:
1599 case ProtoSchemaType::kUint64:
1600 case ProtoSchemaType::kFixed32:
1601 case ProtoSchemaType::kFixed64: {
1602 // Note that SQLite functions will still treat unsigned values
1603 // as a signed 64 bit integers (but the translation back to ftrace
1604 // refers to this storage directly).
1605 inserter.AddArg(name_id, Variadic::UnsignedInteger(fld.as_uint64()));
1606 break;
1607 }
1608 case ProtoSchemaType::kSint32:
1609 case ProtoSchemaType::kSint64: {
1610 inserter.AddArg(name_id, Variadic::Integer(fld.as_sint64()));
1611 break;
1612 }
1613 case ProtoSchemaType::kString:
1614 case ProtoSchemaType::kBytes: {
1615 StringId value = context_->storage->InternString(fld.as_string());
1616 inserter.AddArg(name_id, Variadic::String(value));
1617 break;
1618 }
1619 case ProtoSchemaType::kDouble: {
1620 inserter.AddArg(name_id, Variadic::Real(fld.as_double()));
1621 break;
1622 }
1623 case ProtoSchemaType::kFloat: {
1624 inserter.AddArg(name_id,
1625 Variadic::Real(static_cast<double>(fld.as_float())));
1626 break;
1627 }
1628 case ProtoSchemaType::kUnknown:
1629 case ProtoSchemaType::kGroup:
1630 case ProtoSchemaType::kMessage:
1631 PERFETTO_DLOG("Could not store %s as a field in args table.",
1632 ProtoSchemaToString(type));
1633 break;
1634 }
1635 }
1636 }
1637
1638 PERFETTO_ALWAYS_INLINE
ParseSchedSwitch(uint32_t cpu,int64_t timestamp,ConstBytes blob)1639 void FtraceParser::ParseSchedSwitch(uint32_t cpu,
1640 int64_t timestamp,
1641 ConstBytes blob) {
1642 protos::pbzero::SchedSwitchFtraceEvent::Decoder ss(blob);
1643 uint32_t prev_pid = static_cast<uint32_t>(ss.prev_pid());
1644 uint32_t next_pid = static_cast<uint32_t>(ss.next_pid());
1645 FtraceSchedEventTracker::GetOrCreate(context_)->PushSchedSwitch(
1646 cpu, timestamp, prev_pid, ss.prev_comm(), ss.prev_prio(), ss.prev_state(),
1647 next_pid, ss.next_comm(), ss.next_prio());
1648 }
1649
ParseKprobe(int64_t timestamp,uint32_t pid,ConstBytes blob)1650 void FtraceParser::ParseKprobe(int64_t timestamp,
1651 uint32_t pid,
1652 ConstBytes blob) {
1653 protos::pbzero::KprobeEvent::Decoder kp(blob);
1654
1655 auto kprobe_type = static_cast<KprobeType>(kp.type());
1656 StringId name_id = context_->storage->InternString(kp.name());
1657 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
1658 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
1659 switch (kprobe_type) {
1660 case KprobeType::KPROBE_TYPE_BEGIN:
1661 context_->slice_tracker->Begin(timestamp, track_id,
1662 kNullStringId /* cat */, name_id);
1663 break;
1664 case KprobeType::KPROBE_TYPE_END:
1665 context_->slice_tracker->End(timestamp, track_id, kNullStringId /* cat */,
1666 name_id);
1667 break;
1668 case KprobeType::KPROBE_TYPE_INSTANT:
1669 context_->slice_tracker->Scoped(timestamp, track_id, kNullStringId,
1670 name_id, 0);
1671 break;
1672 case KprobeType::KPROBE_TYPE_UNKNOWN:
1673 break;
1674 }
1675 }
1676
ParseSchedWaking(int64_t timestamp,uint32_t pid,ConstBytes blob)1677 void FtraceParser::ParseSchedWaking(int64_t timestamp,
1678 uint32_t pid,
1679 ConstBytes blob) {
1680 protos::pbzero::SchedWakingFtraceEvent::Decoder sw(blob);
1681 uint32_t wakee_pid = static_cast<uint32_t>(sw.pid());
1682 StringId name_id = context_->storage->InternString(sw.comm());
1683 auto wakee_utid = context_->process_tracker->UpdateThreadName(
1684 wakee_pid, name_id, ThreadNamePriority::kFtrace);
1685 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
1686 ThreadStateTracker::GetOrCreate(context_)->PushWakingEvent(timestamp,
1687 wakee_utid, utid);
1688 }
1689
ParseSchedProcessFree(int64_t timestamp,ConstBytes blob)1690 void FtraceParser::ParseSchedProcessFree(int64_t timestamp, ConstBytes blob) {
1691 protos::pbzero::SchedProcessFreeFtraceEvent::Decoder ex(blob);
1692 uint32_t pid = static_cast<uint32_t>(ex.pid());
1693 context_->process_tracker->EndThread(timestamp, pid);
1694 }
1695
ParseCpuFreq(int64_t timestamp,ConstBytes blob)1696 void FtraceParser::ParseCpuFreq(int64_t timestamp, ConstBytes blob) {
1697 protos::pbzero::CpuFrequencyFtraceEvent::Decoder freq(blob);
1698 TrackId track = context_->track_tracker->InternTrack(
1699 tracks::kCpuFrequencyBlueprint, tracks::Dimensions(freq.cpu_id()));
1700 context_->event_tracker->PushCounter(timestamp, freq.state(), track);
1701 }
1702
ParseCpuFreqThrottle(int64_t timestamp,ConstBytes blob)1703 void FtraceParser::ParseCpuFreqThrottle(int64_t timestamp, ConstBytes blob) {
1704 static constexpr auto kBlueprint = tracks::CounterBlueprint(
1705 "cpu_frequency_throttle", tracks::UnknownUnitBlueprint(),
1706 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
1707 tracks::StaticNameBlueprint("cpufreq_throttle"));
1708 protos::pbzero::DcvshFreqFtraceEvent::Decoder freq(blob);
1709 TrackId track = context_->track_tracker->InternTrack(
1710 kBlueprint, tracks::Dimensions(static_cast<uint32_t>(freq.cpu())));
1711 context_->event_tracker->PushCounter(timestamp,
1712 static_cast<double>(freq.freq()), track);
1713 }
1714
ParseGpuFreq(int64_t timestamp,ConstBytes blob)1715 void FtraceParser::ParseGpuFreq(int64_t timestamp, ConstBytes blob) {
1716 protos::pbzero::GpuFrequencyFtraceEvent::Decoder freq(blob);
1717 TrackId track = context_->track_tracker->InternTrack(
1718 tracks::kGpuFrequencyBlueprint, tracks::Dimensions(freq.gpu_id()));
1719 context_->event_tracker->PushCounter(timestamp, freq.state(), track);
1720 }
1721
ParseKgslGpuFreq(int64_t timestamp,ConstBytes blob)1722 void FtraceParser::ParseKgslGpuFreq(int64_t timestamp, ConstBytes blob) {
1723 protos::pbzero::KgslGpuFrequencyFtraceEvent::Decoder freq(blob);
1724 // Source data is frequency / 1000, so we correct that here:
1725 double new_freq = static_cast<double>(freq.gpu_freq()) * 1000.0;
1726 TrackId track = context_->track_tracker->InternTrack(
1727 tracks::kGpuFrequencyBlueprint, tracks::Dimensions(freq.gpu_id()));
1728 context_->event_tracker->PushCounter(timestamp, new_freq, track);
1729 }
1730
ParseCpuIdle(int64_t timestamp,ConstBytes blob)1731 void FtraceParser::ParseCpuIdle(int64_t timestamp, ConstBytes blob) {
1732 protos::pbzero::CpuIdleFtraceEvent::Decoder idle(blob);
1733 TrackId track = context_->track_tracker->InternTrack(
1734 tracks::kCpuIdleBlueprint, tracks::Dimensions(idle.cpu_id()));
1735 context_->event_tracker->PushCounter(timestamp, idle.state(), track);
1736 }
1737
ParsePrint(int64_t timestamp,uint32_t pid,ConstBytes blob)1738 void FtraceParser::ParsePrint(int64_t timestamp,
1739 uint32_t pid,
1740 ConstBytes blob) {
1741 // Atrace slices are emitted as begin/end events written into the tracefs
1742 // trace_marker. If we're tracing syscalls, the reconstructed atrace slice
1743 // would start and end in the middle of different sys_write slices (on the
1744 // same track). Since trace_processor enforces strict slice nesting, we need
1745 // to resolve this conflict. The chosen approach is to distort the data, and
1746 // pretend that the write syscall ended at the atrace slice's boundary.
1747 //
1748 // In other words, this true structure:
1749 // [write...].....[write...]
1750 // ....[atrace_slice..].....
1751 //
1752 // Is turned into:
1753 // [wr][atrace_slice..]
1754 // ...............[wri]
1755 //
1756 std::optional<UniqueTid> opt_utid =
1757 context_->process_tracker->GetThreadOrNull(pid);
1758 if (opt_utid) {
1759 SyscallTracker::GetOrCreate(context_)->MaybeTruncateOngoingWriteSlice(
1760 timestamp, *opt_utid);
1761 }
1762
1763 protos::pbzero::PrintFtraceEvent::Decoder evt(blob);
1764 SystraceParser::GetOrCreate(context_)->ParsePrintEvent(timestamp, pid,
1765 evt.buf());
1766 }
1767
ParseZero(int64_t timestamp,uint32_t pid,ConstBytes blob)1768 void FtraceParser::ParseZero(int64_t timestamp, uint32_t pid, ConstBytes blob) {
1769 protos::pbzero::ZeroFtraceEvent::Decoder evt(blob);
1770 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1771 SystraceParser::GetOrCreate(context_)->ParseZeroEvent(
1772 timestamp, pid, evt.flag(), evt.name(), tgid, evt.value());
1773 }
1774
ParseMdssTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1775 void FtraceParser::ParseMdssTracingMarkWrite(int64_t timestamp,
1776 uint32_t pid,
1777 ConstBytes blob) {
1778 protos::pbzero::TracingMarkWriteFtraceEvent::Decoder evt(blob);
1779 if (!evt.has_trace_begin()) {
1780 context_->storage->IncrementStats(stats::systrace_parse_failure);
1781 return;
1782 }
1783
1784 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1785 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1786 timestamp, pid, 0, evt.trace_begin(), evt.trace_name(), tgid, 0);
1787 }
1788
ParseSdeTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1789 void FtraceParser::ParseSdeTracingMarkWrite(int64_t timestamp,
1790 uint32_t pid,
1791 ConstBytes blob) {
1792 protos::pbzero::SdeTracingMarkWriteFtraceEvent::Decoder evt(blob);
1793 if (!evt.has_trace_type() && !evt.has_trace_begin()) {
1794 context_->storage->IncrementStats(stats::systrace_parse_failure);
1795 return;
1796 }
1797
1798 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1799 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1800 timestamp, pid, static_cast<char>(evt.trace_type()), evt.trace_begin(),
1801 evt.trace_name(), tgid, evt.value());
1802 }
1803
ParseSamsungTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1804 void FtraceParser::ParseSamsungTracingMarkWrite(int64_t timestamp,
1805 uint32_t pid,
1806 ConstBytes blob) {
1807 protos::pbzero::SamsungTracingMarkWriteFtraceEvent::Decoder evt(blob);
1808 if (!evt.has_trace_type()) {
1809 context_->storage->IncrementStats(stats::systrace_parse_failure);
1810 return;
1811 }
1812
1813 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1814 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1815 timestamp, pid, static_cast<char>(evt.trace_type()),
1816 false /*trace_begin*/, evt.trace_name(), tgid, evt.value());
1817 }
1818
ParseDpuTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1819 void FtraceParser::ParseDpuTracingMarkWrite(int64_t timestamp,
1820 uint32_t pid,
1821 ConstBytes blob) {
1822 protos::pbzero::DpuTracingMarkWriteFtraceEvent::Decoder evt(blob);
1823 if (!evt.type()) {
1824 context_->storage->IncrementStats(stats::systrace_parse_failure);
1825 return;
1826 }
1827
1828 // b/395779936: there are drivers emitting events that pretend that the
1829 // emitting thread is part of a different process, while using B/E/I/C events.
1830 // We cannot trust those tid<->tgid associations, so override the tgid to 0 to
1831 // rely on the existing swapper workarounds. Counter event parsing has
1832 // existing workarounds for this scenario, so keep their tgid for backwards
1833 // compatibility with existing queries.
1834 char evt_type = static_cast<char>(evt.type());
1835 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1836 if (evt_type != 'C')
1837 tgid = 0;
1838
1839 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1840 timestamp, pid, evt_type, false /*trace_begin*/, evt.name(), tgid,
1841 evt.value());
1842 }
1843
ParseDpuDispDpuUnderrun(int64_t timestamp,ConstBytes blob)1844 void FtraceParser::ParseDpuDispDpuUnderrun(int64_t timestamp,
1845 ConstBytes blob) {
1846 protos::pbzero::DpuDispDpuUnderrunFtraceEvent::Decoder ex(blob);
1847 static constexpr auto kBluePrint = tracks::SliceBlueprint(
1848 "disp_dpu_underrun",
1849 tracks::DimensionBlueprints(
1850 tracks::UintDimensionBlueprint("display_id")
1851 ),
1852 tracks::FnNameBlueprint([](uint32_t display_id) {
1853 return base::StackString<256>("underrun[%u]", display_id);
1854 }));
1855
1856 TrackId track_id =
1857 context_->track_tracker->InternTrack(kBluePrint, tracks::Dimensions(ex.id()));
1858 StringId slice_name_id =
1859 context_->storage->InternString(base::StringView("disp_dpu_underrun"));
1860
1861 context_->slice_tracker->Scoped(timestamp, track_id, kNullStringId,
1862 slice_name_id, 0,
1863 [&](ArgsTracker::BoundInserter* inserter) {
1864 inserter->AddArg(
1865 context_->storage->InternString(base::StringView("vsync_count")),
1866 Variadic::Integer(ex.vsync_count()));
1867 inserter->AddArg(
1868 context_->storage->InternString(base::StringView("pending_frame")),
1869 Variadic::Integer(ex.frames_pending()));
1870 });
1871 }
1872
ParseDpuDispVblankIrqEnable(int64_t timestamp,ConstBytes blob)1873 void FtraceParser::ParseDpuDispVblankIrqEnable(int64_t timestamp,
1874 ConstBytes blob) {
1875 protos::pbzero::DpuDispVblankIrqEnableFtraceEvent::Decoder ex(blob);
1876
1877 static constexpr auto kBlueprint = tracks::SliceBlueprint(
1878 "disp_vblank_irq_enable",
1879 tracks::DimensionBlueprints(tracks::UintDimensionBlueprint("display_id")),
1880 tracks::FnNameBlueprint([](uint32_t display_id) {
1881 return base::StackString<256>("vblank_irq_en[%u]", display_id);
1882 }));
1883
1884 TrackId track_id = context_->track_tracker->InternTrack(
1885 kBlueprint, tracks::Dimensions(ex.id()));
1886 if (ex.enable()) {
1887 context_->slice_tracker->Begin(
1888 timestamp, track_id, kNullStringId, disp_vblank_irq_enable_id_,
1889 [&](ArgsTracker::BoundInserter* inserter) {
1890 inserter->AddArg(disp_vblank_irq_enable_output_id_arg_name_,
1891 Variadic::Integer(ex.output_id()));
1892 });
1893 } else {
1894 context_->slice_tracker->End(timestamp, track_id);
1895 }
1896 }
1897
ParseG2dTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1898 void FtraceParser::ParseG2dTracingMarkWrite(int64_t timestamp,
1899 uint32_t pid,
1900 ConstBytes blob) {
1901 protos::pbzero::G2dTracingMarkWriteFtraceEvent::Decoder evt(blob);
1902 if (!evt.type()) {
1903 context_->storage->IncrementStats(stats::systrace_parse_failure);
1904 return;
1905 }
1906
1907 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1908 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1909 timestamp, pid, static_cast<char>(evt.type()), false /*trace_begin*/,
1910 evt.name(), tgid, evt.value());
1911 }
1912
ParseMaliTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1913 void FtraceParser::ParseMaliTracingMarkWrite(int64_t timestamp,
1914 uint32_t pid,
1915 ConstBytes blob) {
1916 protos::pbzero::MaliTracingMarkWriteFtraceEvent::Decoder evt(blob);
1917 if (!evt.type()) {
1918 context_->storage->IncrementStats(stats::systrace_parse_failure);
1919 return;
1920 }
1921
1922 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1923 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1924 timestamp, pid, static_cast<char>(evt.type()), false /*trace_begin*/,
1925 evt.name(), tgid, evt.value());
1926 }
1927
ParseLwisTracingMarkWrite(int64_t timestamp,uint32_t pid,ConstBytes blob)1928 void FtraceParser::ParseLwisTracingMarkWrite(int64_t timestamp,
1929 uint32_t pid,
1930 ConstBytes blob) {
1931 protos::pbzero::LwisTracingMarkWriteFtraceEvent::Decoder evt(blob);
1932 if (!evt.type()) {
1933 context_->storage->IncrementStats(stats::systrace_parse_failure);
1934 return;
1935 }
1936
1937 uint32_t tgid = static_cast<uint32_t>(evt.pid());
1938 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
1939 timestamp, pid, static_cast<char>(evt.type()), false /*trace_begin*/,
1940 evt.func_name(), tgid, evt.value());
1941 }
1942
1943 namespace {
1944
1945 constexpr auto kInterconnectTrackBlueprint =
1946 tracks::SliceBlueprint("interconnect_events",
1947 tracks::DimensionBlueprints(),
1948 tracks::StaticNameBlueprint("Interconnect Events"));
1949
1950 } // namespace
1951
ParseGoogleIccEvent(int64_t timestamp,ConstBytes blob)1952 void FtraceParser::ParseGoogleIccEvent(int64_t timestamp, ConstBytes blob) {
1953 protos::pbzero::GoogleIccEventFtraceEvent::Decoder evt(blob);
1954 TrackId track_id =
1955 context_->track_tracker->InternTrack(kInterconnectTrackBlueprint);
1956 StringId slice_name_id =
1957 context_->storage->InternString(base::StringView(evt.event()));
1958 context_->slice_tracker->Scoped(timestamp, track_id, google_icc_event_id_,
1959 slice_name_id, 0);
1960 }
1961
ParseGoogleIrmEvent(int64_t timestamp,ConstBytes blob)1962 void FtraceParser::ParseGoogleIrmEvent(int64_t timestamp, ConstBytes blob) {
1963 protos::pbzero::GoogleIrmEventFtraceEvent::Decoder evt(blob);
1964 TrackId track_id =
1965 context_->track_tracker->InternTrack(kInterconnectTrackBlueprint);
1966 StringId slice_name_id =
1967 context_->storage->InternString(base::StringView(evt.event()));
1968 context_->slice_tracker->Scoped(timestamp, track_id, google_irm_event_id_,
1969 slice_name_id, 0);
1970 }
1971
1972 namespace {
1973
1974 constexpr auto kIonBlueprint = tracks::CounterBlueprint(
1975 "ion",
1976 tracks::UnknownUnitBlueprint(),
1977 tracks::DimensionBlueprints(tracks::StringDimensionBlueprint("heap_name")),
__anone76f5f400902(base::StringView heap_name) 1978 tracks::FnNameBlueprint([](base::StringView heap_name) {
1979 if (heap_name.size() > 0) {
1980 return base::StackString<255>("mem.ion.%.*s", int(heap_name.size()),
1981 heap_name.data());
1982 }
1983 return base::StackString<255>("mem.ion");
1984 }));
1985
1986 constexpr auto kIonChangeBlueprint = tracks::CounterBlueprint(
1987 "ion_change",
1988 tracks::UnknownUnitBlueprint(),
1989 tracks::DimensionBlueprints(tracks::StringDimensionBlueprint("heap_name"),
1990 tracks::kThreadDimensionBlueprint),
__anone76f5f400a02(base::StringView heap_name, uint32_t) 1991 tracks::FnNameBlueprint([](base::StringView heap_name, uint32_t) {
1992 if (heap_name.size() > 0) {
1993 return base::StackString<255>("mem.ion_change.%.*s",
1994 int(heap_name.size()), heap_name.data());
1995 }
1996 return base::StackString<255>("mem.ion_change");
1997 }));
1998
1999 } // namespace
2000
2001 /** Parses ion heap events present in Pixel kernels. */
ParseIonHeapGrowOrShrink(int64_t timestamp,uint32_t pid,ConstBytes blob,bool grow)2002 void FtraceParser::ParseIonHeapGrowOrShrink(int64_t timestamp,
2003 uint32_t pid,
2004 ConstBytes blob,
2005 bool grow) {
2006 protos::pbzero::IonHeapGrowFtraceEvent::Decoder ion(blob);
2007
2008 // The total_allocated ftrace event reports the value before the
2009 // atomic_long_add / sub takes place.
2010 int64_t change_bytes = static_cast<int64_t>(ion.len()) * (grow ? 1 : -1);
2011 int64_t total_bytes = ion.total_allocated() + change_bytes;
2012
2013 base::StringView heap =
2014 ion.has_heap_name() ? base::StringView(ion.heap_name()) : "unknown";
2015
2016 // Push the global counter.
2017 TrackId track = context_->track_tracker->InternTrack(
2018 kIonBlueprint, tracks::Dimensions(heap));
2019 context_->event_tracker->PushCounter(timestamp,
2020 static_cast<double>(total_bytes), track);
2021
2022 // Push the change counter.
2023 // TODO(b/121331269): these should really be instant events.
2024 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2025 track = context_->track_tracker->InternTrack(kIonChangeBlueprint,
2026 tracks::Dimensions(heap, utid));
2027 context_->event_tracker->PushCounter(
2028 timestamp, static_cast<double>(change_bytes), track);
2029
2030 // We are reusing the same function for ion_heap_grow and ion_heap_shrink.
2031 // It is fine as the arguments are the same, but we need to be sure that the
2032 // protobuf field id for both are the same.
2033 static_assert(
2034 static_cast<int>(
2035 protos::pbzero::IonHeapGrowFtraceEvent::kTotalAllocatedFieldNumber) ==
2036 static_cast<int>(protos::pbzero::IonHeapShrinkFtraceEvent::
2037 kTotalAllocatedFieldNumber) &&
2038 static_cast<int>(
2039 protos::pbzero::IonHeapGrowFtraceEvent::kLenFieldNumber) ==
2040 static_cast<int>(
2041 protos::pbzero::IonHeapShrinkFtraceEvent::kLenFieldNumber) &&
2042 static_cast<int>(
2043 protos::pbzero::IonHeapGrowFtraceEvent::kHeapNameFieldNumber) ==
2044 static_cast<int>(protos::pbzero::IonHeapShrinkFtraceEvent::
2045 kHeapNameFieldNumber),
2046 "ION field mismatch");
2047 }
2048
2049 /** Parses ion heap events (introduced in 4.19 kernels). */
ParseIonStat(int64_t timestamp,uint32_t pid,protozero::ConstBytes data)2050 void FtraceParser::ParseIonStat(int64_t timestamp,
2051 uint32_t pid,
2052 protozero::ConstBytes data) {
2053 protos::pbzero::IonStatFtraceEvent::Decoder ion(data);
2054
2055 // Push the global counter.
2056 TrackId track = context_->track_tracker->InternTrack(
2057 kIonBlueprint, tracks::Dimensions(base::StringView()));
2058 context_->event_tracker->PushCounter(
2059 timestamp, static_cast<double>(ion.total_allocated()), track);
2060
2061 // Push the change counter.
2062 // TODO(b/121331269): these should really be instant events.
2063 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2064 track = context_->track_tracker->InternTrack(
2065 kIonChangeBlueprint, tracks::Dimensions(base::StringView(), utid));
2066 context_->event_tracker->PushCounter(timestamp,
2067 static_cast<double>(ion.len()), track);
2068
2069 static constexpr auto kBlueprint = TrackCompressor::SliceBlueprint(
2070 "android_ion_allocations", tracks::DimensionBlueprints(),
2071 tracks::StaticNameBlueprint("mem.ion_buffer"));
2072
2073 // Global track for individual buffer tracking
2074 if (ion.len() > 0) {
2075 TrackId id = context_->track_compressor->InternBegin(
2076 kBlueprint, tracks::Dimensions(), ion.buffer_id());
2077 std::string buf = std::to_string(ion.len() / 1024) + " kB";
2078 context_->slice_tracker->Begin(
2079 timestamp, id, kNullStringId,
2080 context_->storage->InternString(base::StringView(buf)));
2081 } else {
2082 TrackId id = context_->track_compressor->InternEnd(
2083 kBlueprint, tracks::Dimensions(), ion.buffer_id());
2084 context_->slice_tracker->End(timestamp, id);
2085 }
2086 }
2087
ParseBclIrq(int64_t ts,protozero::ConstBytes data)2088 void FtraceParser::ParseBclIrq(int64_t ts, protozero::ConstBytes data) {
2089 protos::pbzero::BclIrqTriggerFtraceEvent::Decoder bcl(data);
2090 int throttle = bcl.throttle();
2091
2092 static constexpr auto kBlueprint = tracks::CounterBlueprint(
2093 "bcl_irq", tracks::UnknownUnitBlueprint(),
2094 tracks::DimensionBlueprints(tracks::StringDimensionBlueprint("bcl_key")),
2095 tracks::FnNameBlueprint([](base::StringView key) {
2096 return base::StackString<1024>("%.*s", int(key.size()), key.data());
2097 }));
2098
2099 // id
2100 TrackId track = context_->track_tracker->InternTrack(
2101 kBlueprint, tracks::Dimensions("bcl_irq_id"));
2102 context_->event_tracker->PushCounter(ts, throttle ? bcl.id() : -1, track);
2103 // throttle
2104 track = context_->track_tracker->InternTrack(
2105 kBlueprint, tracks::Dimensions("bcl_irq_throttle"));
2106 context_->event_tracker->PushCounter(ts, throttle, track);
2107 // cpu0_limit
2108 track = context_->track_tracker->InternTrack(
2109 kBlueprint, tracks::Dimensions("bcl_irq_cpu0"));
2110 context_->event_tracker->PushCounter(ts, throttle ? bcl.cpu0_limit() : 0,
2111 track);
2112 // cpu1_limit
2113 track = context_->track_tracker->InternTrack(
2114 kBlueprint, tracks::Dimensions("bcl_irq_cpu1"));
2115 context_->event_tracker->PushCounter(ts, throttle ? bcl.cpu1_limit() : 0,
2116 track);
2117 // cpu2_limit
2118 track = context_->track_tracker->InternTrack(
2119 kBlueprint, tracks::Dimensions("bcl_irq_cpu2"));
2120 context_->event_tracker->PushCounter(ts, throttle ? bcl.cpu2_limit() : 0,
2121 track);
2122 // tpu_limit
2123 track = context_->track_tracker->InternTrack(
2124 kBlueprint, tracks::Dimensions("bcl_irq_tpu"));
2125 context_->event_tracker->PushCounter(ts, throttle ? bcl.tpu_limit() : 0,
2126 track);
2127 // gpu_limit
2128 track = context_->track_tracker->InternTrack(
2129 kBlueprint, tracks::Dimensions("bcl_irq_gpu"));
2130 context_->event_tracker->PushCounter(ts, throttle ? bcl.gpu_limit() : 0,
2131 track);
2132 // voltage
2133 track = context_->track_tracker->InternTrack(
2134 kBlueprint, tracks::Dimensions("bcl_irq_voltage"));
2135 context_->event_tracker->PushCounter(ts, bcl.voltage(), track);
2136 // capacity
2137 track = context_->track_tracker->InternTrack(
2138 kBlueprint, tracks::Dimensions("bcl_irq_capacity"));
2139 context_->event_tracker->PushCounter(ts, bcl.capacity(), track);
2140 }
2141
ParseDmaHeapStat(int64_t timestamp,uint32_t pid,protozero::ConstBytes data)2142 void FtraceParser::ParseDmaHeapStat(int64_t timestamp,
2143 uint32_t pid,
2144 protozero::ConstBytes data) {
2145 protos::pbzero::DmaHeapStatFtraceEvent::Decoder dma_heap(data);
2146
2147 static constexpr auto kBlueprint = tracks::CounterBlueprint(
2148 "android_dma_heap", tracks::UnknownUnitBlueprint(),
2149 tracks::DimensionBlueprints(),
2150 tracks::StaticNameBlueprint("mem.dma_heap"));
2151
2152 // Push the global counter.
2153 TrackId track = context_->track_tracker->InternTrack(kBlueprint);
2154 context_->event_tracker->PushCounter(
2155 timestamp, static_cast<double>(dma_heap.total_allocated()), track);
2156
2157 static constexpr auto kChangeBlueprint = tracks::CounterBlueprint(
2158 "android_dma_heap_change", tracks::UnknownUnitBlueprint(),
2159 tracks::Dimensions(tracks::kThreadDimensionBlueprint),
2160 tracks::StaticNameBlueprint("mem.dma_heap_change"));
2161
2162 // Push the change counter.
2163 // TODO(b/121331269): these should really be instant events.
2164 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2165 track = context_->track_tracker->InternTrack(kChangeBlueprint,
2166 tracks::Dimensions(utid));
2167
2168 context_->event_tracker->PushCounter(
2169 timestamp, static_cast<double>(dma_heap.len()), track,
2170 [&, this](ArgsTracker::BoundInserter* inserter) {
2171 inserter->AddArg(inode_arg_id_,
2172 Variadic::UnsignedInteger(dma_heap.inode()));
2173 });
2174
2175 static constexpr auto kAllocsBlueprint = TrackCompressor::SliceBlueprint(
2176 "android_dma_allocations", tracks::DimensionBlueprints(),
2177 tracks::StaticNameBlueprint("mem.dma_buffer"));
2178
2179 // Global track for individual buffer tracking
2180 if (dma_heap.len() > 0) {
2181 TrackId id = context_->track_compressor->InternBegin(
2182 kAllocsBlueprint, tracks::Dimensions(),
2183 static_cast<int64_t>(dma_heap.inode()));
2184 std::string buf = std::to_string(dma_heap.len() / 1024) + " kB";
2185 context_->slice_tracker->Begin(
2186 timestamp, id, kNullStringId,
2187 context_->storage->InternString(base::StringView(buf)));
2188 } else {
2189 TrackId id = context_->track_compressor->InternEnd(
2190 kAllocsBlueprint, tracks::Dimensions(),
2191 static_cast<int64_t>(dma_heap.inode()));
2192 context_->slice_tracker->End(timestamp, id);
2193 }
2194 }
2195
2196 // This event has both the pid of the thread that sent the signal and the
2197 // destination of the signal. Currently storing the pid of the destination.
ParseSignalGenerate(int64_t timestamp,ConstBytes blob)2198 void FtraceParser::ParseSignalGenerate(int64_t timestamp, ConstBytes blob) {
2199 protos::pbzero::SignalGenerateFtraceEvent::Decoder sig(blob);
2200
2201 UniqueTid utid = context_->process_tracker->GetOrCreateThread(
2202 static_cast<uint32_t>(sig.pid()));
2203 int signal = sig.sig();
2204 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2205 context_->slice_tracker->Scoped(
2206 timestamp, track, kNullStringId, signal_generate_id_, 0,
2207 [this, signal](ArgsTracker::BoundInserter* inserter) {
2208 inserter->AddArg(signal_name_id_, Variadic::Integer(signal));
2209 });
2210 }
2211
ParseSignalDeliver(int64_t timestamp,uint32_t pid,ConstBytes blob)2212 void FtraceParser::ParseSignalDeliver(int64_t timestamp,
2213 uint32_t pid,
2214 ConstBytes blob) {
2215 protos::pbzero::SignalDeliverFtraceEvent::Decoder sig(blob);
2216 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2217 int signal = sig.sig();
2218 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2219 context_->slice_tracker->Scoped(
2220 timestamp, track, kNullStringId, signal_deliver_id_, 0,
2221 [this, signal](ArgsTracker::BoundInserter* inserter) {
2222 inserter->AddArg(signal_name_id_, Variadic::Integer(signal));
2223 });
2224 }
2225
ParseOOMScoreAdjUpdate(int64_t timestamp,ConstBytes blob)2226 void FtraceParser::ParseOOMScoreAdjUpdate(int64_t timestamp, ConstBytes blob) {
2227 protos::pbzero::OomScoreAdjUpdateFtraceEvent::Decoder evt(blob);
2228 // The int16_t static cast is because older version of the on-device tracer
2229 // had a bug on negative varint encoding (b/120618641).
2230 auto oom_adj = static_cast<int16_t>(evt.oom_score_adj());
2231 auto tid = static_cast<uint32_t>(evt.pid());
2232 UniqueTid utid = context_->process_tracker->GetOrCreateThread(tid);
2233 context_->event_tracker->PushProcessCounterForThread(
2234 EventTracker::OomScoreAdj(), timestamp, oom_adj, utid);
2235 }
2236
ParseOOMKill(int64_t timestamp,ConstBytes blob)2237 void FtraceParser::ParseOOMKill(int64_t timestamp, ConstBytes blob) {
2238 protos::pbzero::MarkVictimFtraceEvent::Decoder evt(blob);
2239 UniqueTid utid = context_->process_tracker->GetOrCreateThread(
2240 static_cast<uint32_t>(evt.pid()));
2241 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2242 context_->slice_tracker->Scoped(timestamp, track, kNullStringId, oom_kill_id_,
2243 0);
2244 }
2245
ParseMmEventRecord(int64_t timestamp,uint32_t pid,ConstBytes blob)2246 void FtraceParser::ParseMmEventRecord(int64_t timestamp,
2247 uint32_t pid,
2248 ConstBytes blob) {
2249 protos::pbzero::MmEventRecordFtraceEvent::Decoder evt(blob);
2250
2251 uint32_t type = evt.type();
2252 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2253
2254 const char* type_str = GetMmEventTypeStr(type);
2255 if (!type_str) {
2256 context_->storage->IncrementStats(stats::mm_unknown_type);
2257 return;
2258 }
2259 context_->event_tracker->PushProcessCounterForThread(
2260 EventTracker::MmEvent{type_str, "count"}, timestamp, evt.count(), utid);
2261 context_->event_tracker->PushProcessCounterForThread(
2262 EventTracker::MmEvent{type_str, "max_lat"}, timestamp, evt.max_lat(),
2263 utid);
2264 context_->event_tracker->PushProcessCounterForThread(
2265 EventTracker::MmEvent{type_str, "avg_lat"}, timestamp, evt.avg_lat(),
2266 utid);
2267 }
2268
ParseSysEnterEvent(int64_t timestamp,uint32_t pid,ConstBytes blob)2269 void FtraceParser::ParseSysEnterEvent(int64_t timestamp,
2270 uint32_t pid,
2271 ConstBytes blob) {
2272 protos::pbzero::SysEnterFtraceEvent::Decoder evt(blob);
2273 uint32_t syscall_num = static_cast<uint32_t>(evt.id());
2274 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2275
2276 SyscallTracker* syscall_tracker = SyscallTracker::GetOrCreate(context_);
2277 auto args_callback = [this, &evt](ArgsTracker::BoundInserter* inserter) {
2278 // process all syscall arguments
2279 uint32_t count = 0;
2280 for (auto it = evt.args(); it; ++it) {
2281 if (syscall_arg_name_ids_.size() == count) {
2282 base::StackString<32> string_arg("args[%u]", count);
2283 auto string_id =
2284 context_->storage->InternString(string_arg.string_view());
2285 syscall_arg_name_ids_.emplace_back(string_id);
2286 }
2287 inserter->AddArg(syscall_args_id_, syscall_arg_name_ids_[count],
2288 Variadic::UnsignedInteger(*it));
2289 ++count;
2290 }
2291 };
2292 syscall_tracker->Enter(timestamp, utid, syscall_num, args_callback);
2293 }
2294
ParseSysExitEvent(int64_t timestamp,uint32_t pid,ConstBytes blob)2295 void FtraceParser::ParseSysExitEvent(int64_t timestamp,
2296 uint32_t pid,
2297 ConstBytes blob) {
2298 // Note: Although this seems duplicated to ParseSysEnterEvent, it is
2299 // not. We decode SysExitFtraceEvent here to handle the return
2300 // value of a syscall whereas SysEnterFtraceEvent is decoded
2301 // above to handle the syscall arguments.
2302 protos::pbzero::SysExitFtraceEvent::Decoder evt(blob);
2303 uint32_t syscall_num = static_cast<uint32_t>(evt.id());
2304 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2305
2306 SyscallTracker* syscall_tracker = SyscallTracker::GetOrCreate(context_);
2307 auto args_callback = [this, &evt](ArgsTracker::BoundInserter* inserter) {
2308 if (evt.has_ret()) {
2309 const auto ret = evt.ret();
2310 inserter->AddArg(syscall_ret_id_, Variadic::Integer(ret));
2311 }
2312 };
2313 syscall_tracker->Exit(timestamp, utid, syscall_num, args_callback);
2314 }
2315
ParseI2cReadEvent(int64_t timestamp,uint32_t pid,protozero::ConstBytes blob)2316 void FtraceParser::ParseI2cReadEvent(int64_t timestamp,
2317 uint32_t pid,
2318 protozero::ConstBytes blob) {
2319 protos::pbzero::I2cReadFtraceEvent::Decoder evt(blob);
2320 uint32_t adapter_nr = static_cast<uint32_t>(evt.adapter_nr());
2321 uint32_t msg_nr = static_cast<uint32_t>(evt.msg_nr());
2322 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2323
2324 I2cTracker* i2c_tracker = I2cTracker::GetOrCreate(context_);
2325 i2c_tracker->Enter(timestamp, utid, adapter_nr, msg_nr);
2326 }
2327
ParseI2cWriteEvent(int64_t timestamp,uint32_t pid,protozero::ConstBytes blob)2328 void FtraceParser::ParseI2cWriteEvent(int64_t timestamp,
2329 uint32_t pid,
2330 protozero::ConstBytes blob) {
2331 protos::pbzero::I2cWriteFtraceEvent::Decoder evt(blob);
2332 uint32_t adapter_nr = static_cast<uint32_t>(evt.adapter_nr());
2333 uint32_t msg_nr = static_cast<uint32_t>(evt.msg_nr());
2334 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2335
2336 I2cTracker* i2c_tracker = I2cTracker::GetOrCreate(context_);
2337 i2c_tracker->Enter(timestamp, utid, adapter_nr, msg_nr);
2338 }
2339
ParseI2cResultEvent(int64_t timestamp,uint32_t pid,protozero::ConstBytes blob)2340 void FtraceParser::ParseI2cResultEvent(int64_t timestamp,
2341 uint32_t pid,
2342 protozero::ConstBytes blob) {
2343 protos::pbzero::I2cResultFtraceEvent::Decoder evt(blob);
2344 uint32_t adapter_nr = static_cast<uint32_t>(evt.adapter_nr());
2345 uint32_t nr_msgs = static_cast<uint32_t>(evt.nr_msgs());
2346 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2347
2348 I2cTracker* i2c_tracker = I2cTracker::GetOrCreate(context_);
2349 i2c_tracker->Exit(timestamp, utid, adapter_nr, nr_msgs);
2350 }
2351
ParseTaskNewTask(int64_t timestamp,uint32_t source_tid,ConstBytes blob)2352 void FtraceParser::ParseTaskNewTask(int64_t timestamp,
2353 uint32_t source_tid,
2354 ConstBytes blob) {
2355 protos::pbzero::TaskNewtaskFtraceEvent::Decoder evt(blob);
2356 uint32_t clone_flags = static_cast<uint32_t>(evt.clone_flags());
2357 uint32_t new_tid = static_cast<uint32_t>(evt.pid());
2358 StringId new_comm = context_->storage->InternString(evt.comm());
2359 auto* proc_tracker = context_->process_tracker.get();
2360
2361 // task_newtask is raised both in the case of a new process creation (fork()
2362 // family) and thread creation (clone(CLONE_THREAD, ...)).
2363 static const uint32_t kCloneThread = 0x00010000; // From kernel's sched.h.
2364
2365 if (PERFETTO_UNLIKELY(new_tid == 0)) {
2366 // In the case of boot-time tracing (kernel is started with tracing
2367 // enabled), the ftrace buffer will see /bin/init creating swapper/0
2368 // tasks: event {
2369 // pid: 1
2370 // task_newtask {
2371 // pid: 0
2372 // comm: "swapper/0"
2373 // }
2374 // }
2375 // Skip these task_newtask events since they are kernel idle tasks.
2376 PERFETTO_DCHECK(source_tid == 1);
2377 PERFETTO_DCHECK(base::StartsWith(evt.comm().ToStdString(), "swapper"));
2378 return;
2379 }
2380
2381 // If the process is a fork, start a new process.
2382 if ((clone_flags & kCloneThread) == 0) {
2383 // This is a plain-old fork() or equivalent.
2384 proc_tracker->StartNewProcess(timestamp, source_tid, new_tid, new_comm,
2385 ThreadNamePriority::kFtrace);
2386
2387 auto source_utid = proc_tracker->GetOrCreateThread(source_tid);
2388 auto new_utid = proc_tracker->GetOrCreateThread(new_tid);
2389
2390 ThreadStateTracker::GetOrCreate(context_)->PushNewTaskEvent(
2391 timestamp, new_utid, source_utid);
2392 return;
2393 }
2394
2395 // This is a pthread_create or similar. Bind the two threads together, so
2396 // they get resolved to the same process.
2397 auto source_utid = proc_tracker->GetOrCreateThread(source_tid);
2398 auto new_utid = proc_tracker->StartNewThread(timestamp, new_tid);
2399 proc_tracker->UpdateThreadNameByUtid(new_utid, new_comm,
2400 ThreadNamePriority::kFtrace);
2401 proc_tracker->AssociateThreads(source_utid, new_utid);
2402
2403 ThreadStateTracker::GetOrCreate(context_)->PushNewTaskEvent(
2404 timestamp, new_utid, source_utid);
2405 }
2406
ParseTaskRename(ConstBytes blob)2407 void FtraceParser::ParseTaskRename(ConstBytes blob) {
2408 protos::pbzero::TaskRenameFtraceEvent::Decoder evt(blob);
2409 uint32_t tid = static_cast<uint32_t>(evt.pid());
2410 StringId comm = context_->storage->InternString(evt.newcomm());
2411 context_->process_tracker->UpdateThreadNameAndMaybeProcessName(
2412 tid, comm, ThreadNamePriority::kFtrace);
2413 }
2414
ParseBinderTransaction(int64_t timestamp,uint32_t pid,ConstBytes blob)2415 void FtraceParser::ParseBinderTransaction(int64_t timestamp,
2416 uint32_t pid,
2417 ConstBytes blob) {
2418 protos::pbzero::BinderTransactionFtraceEvent::Decoder evt(blob);
2419 int32_t dest_node = static_cast<int32_t>(evt.target_node());
2420 uint32_t dest_tgid = static_cast<uint32_t>(evt.to_proc());
2421 uint32_t dest_tid = static_cast<uint32_t>(evt.to_thread());
2422 int32_t transaction_id = static_cast<int32_t>(evt.debug_id());
2423 bool is_reply = static_cast<int32_t>(evt.reply()) == 1;
2424 uint32_t flags = static_cast<uint32_t>(evt.flags());
2425 auto code_str = base::IntToHexString(evt.code()) + " Java Layer Dependent";
2426 StringId code = context_->storage->InternString(base::StringView(code_str));
2427 BinderTracker::GetOrCreate(context_)->Transaction(
2428 timestamp, pid, transaction_id, dest_node, dest_tgid, dest_tid, is_reply,
2429 flags, code);
2430 }
2431
ParseBinderTransactionReceived(int64_t timestamp,uint32_t pid,ConstBytes blob)2432 void FtraceParser::ParseBinderTransactionReceived(int64_t timestamp,
2433 uint32_t pid,
2434 ConstBytes blob) {
2435 protos::pbzero::BinderTransactionReceivedFtraceEvent::Decoder evt(blob);
2436 int32_t transaction_id = static_cast<int32_t>(evt.debug_id());
2437 BinderTracker::GetOrCreate(context_)->TransactionReceived(timestamp, pid,
2438 transaction_id);
2439 }
2440
ParseBinderCommand(int64_t timestamp,uint32_t pid,ConstBytes blob)2441 void FtraceParser::ParseBinderCommand(int64_t timestamp,
2442 uint32_t pid,
2443 ConstBytes blob) {
2444 protos::pbzero::BinderCommandFtraceEvent::Decoder evt(blob);
2445 BinderTracker::GetOrCreate(context_)->CommandToKernel(timestamp, pid,
2446 evt.cmd());
2447 }
2448
ParseBinderReturn(int64_t timestamp,uint32_t pid,ConstBytes blob)2449 void FtraceParser::ParseBinderReturn(int64_t timestamp,
2450 uint32_t pid,
2451 ConstBytes blob) {
2452 protos::pbzero::BinderReturnFtraceEvent::Decoder evt(blob);
2453 BinderTracker::GetOrCreate(context_)->ReturnFromKernel(timestamp, pid,
2454 evt.cmd());
2455 }
2456
ParseBinderTransactionAllocBuf(int64_t timestamp,uint32_t pid,ConstBytes blob)2457 void FtraceParser::ParseBinderTransactionAllocBuf(int64_t timestamp,
2458 uint32_t pid,
2459 ConstBytes blob) {
2460 protos::pbzero::BinderTransactionAllocBufFtraceEvent::Decoder evt(blob);
2461 uint64_t data_size = static_cast<uint64_t>(evt.data_size());
2462 uint64_t offsets_size = static_cast<uint64_t>(evt.offsets_size());
2463
2464 BinderTracker::GetOrCreate(context_)->TransactionAllocBuf(
2465 timestamp, pid, data_size, offsets_size);
2466 }
2467
ParseBinderLocked(int64_t timestamp,uint32_t pid,ConstBytes blob)2468 void FtraceParser::ParseBinderLocked(int64_t timestamp,
2469 uint32_t pid,
2470 ConstBytes blob) {
2471 protos::pbzero::BinderLockedFtraceEvent::Decoder evt(blob);
2472 BinderTracker::GetOrCreate(context_)->Locked(timestamp, pid);
2473 }
2474
ParseBinderLock(int64_t timestamp,uint32_t pid,ConstBytes blob)2475 void FtraceParser::ParseBinderLock(int64_t timestamp,
2476 uint32_t pid,
2477 ConstBytes blob) {
2478 protos::pbzero::BinderLockFtraceEvent::Decoder evt(blob);
2479 BinderTracker::GetOrCreate(context_)->Lock(timestamp, pid);
2480 }
2481
ParseBinderUnlock(int64_t timestamp,uint32_t pid,ConstBytes blob)2482 void FtraceParser::ParseBinderUnlock(int64_t timestamp,
2483 uint32_t pid,
2484 ConstBytes blob) {
2485 protos::pbzero::BinderUnlockFtraceEvent::Decoder evt(blob);
2486 BinderTracker::GetOrCreate(context_)->Unlock(timestamp, pid);
2487 }
2488
ParseClockSetRate(int64_t timestamp,ConstBytes blob)2489 void FtraceParser::ParseClockSetRate(int64_t timestamp, ConstBytes blob) {
2490 protos::pbzero::ClockSetRateFtraceEvent::Decoder evt(blob);
2491 TrackId track = context_->track_tracker->InternTrack(
2492 tracks::kClockFrequencyBlueprint, tracks::Dimensions(evt.name()));
2493 context_->event_tracker->PushCounter(timestamp,
2494 static_cast<double>(evt.state()), track);
2495 }
2496
ParseClockEnable(int64_t timestamp,ConstBytes blob)2497 void FtraceParser::ParseClockEnable(int64_t timestamp, ConstBytes blob) {
2498 protos::pbzero::ClockEnableFtraceEvent::Decoder evt(blob);
2499 TrackId track = context_->track_tracker->InternTrack(
2500 tracks::kClockStateBlueprint, tracks::Dimensions(evt.name()));
2501 context_->event_tracker->PushCounter(timestamp,
2502 static_cast<double>(evt.state()), track);
2503 }
2504
ParseClockDisable(int64_t timestamp,ConstBytes blob)2505 void FtraceParser::ParseClockDisable(int64_t timestamp, ConstBytes blob) {
2506 protos::pbzero::ClockDisableFtraceEvent::Decoder evt(blob);
2507 TrackId track = context_->track_tracker->InternTrack(
2508 tracks::kClockStateBlueprint, tracks::Dimensions(evt.name()));
2509 context_->event_tracker->PushCounter(timestamp,
2510 static_cast<double>(evt.state()), track);
2511 }
2512
ParseScmCallStart(int64_t timestamp,uint32_t pid,ConstBytes blob)2513 void FtraceParser::ParseScmCallStart(int64_t timestamp,
2514 uint32_t pid,
2515 ConstBytes blob) {
2516 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2517 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2518 protos::pbzero::ScmCallStartFtraceEvent::Decoder evt(blob);
2519
2520 base::StackString<64> str("scm id=%#" PRIx64, evt.x0());
2521 StringId name_id = context_->storage->InternString(str.string_view());
2522 context_->slice_tracker->Begin(timestamp, track_id, kNullStringId, name_id);
2523 }
2524
ParseScmCallEnd(int64_t timestamp,uint32_t pid,ConstBytes blob)2525 void FtraceParser::ParseScmCallEnd(int64_t timestamp,
2526 uint32_t pid,
2527 ConstBytes blob) {
2528 protos::pbzero::ScmCallEndFtraceEvent::Decoder evt(blob);
2529 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2530 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2531 context_->slice_tracker->End(timestamp, track_id);
2532 }
2533
ParseCmaAllocStart(int64_t timestamp,uint32_t pid)2534 void FtraceParser::ParseCmaAllocStart(int64_t timestamp, uint32_t pid) {
2535 std::optional<VersionNumber> kernel_version =
2536 SystemInfoTracker::GetOrCreate(context_)->GetKernelVersion();
2537 // CmaAllocInfo event only exists after 5.10
2538 if (kernel_version < VersionNumber{5, 10})
2539 return;
2540
2541 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2542 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2543
2544 context_->slice_tracker->Begin(timestamp, track_id, kNullStringId,
2545 cma_alloc_id_);
2546 }
2547
ParseCmaAllocInfo(int64_t timestamp,uint32_t pid,ConstBytes blob)2548 void FtraceParser::ParseCmaAllocInfo(int64_t timestamp,
2549 uint32_t pid,
2550 ConstBytes blob) {
2551 std::optional<VersionNumber> kernel_version =
2552 SystemInfoTracker::GetOrCreate(context_)->GetKernelVersion();
2553 // CmaAllocInfo event only exists after 5.10
2554 if (kernel_version < VersionNumber{5, 10})
2555 return;
2556
2557 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2558 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2559 protos::pbzero::CmaAllocInfoFtraceEvent::Decoder cma_alloc_info(blob);
2560 auto args_inserter = [this,
2561 &cma_alloc_info](ArgsTracker::BoundInserter* inserter) {
2562 inserter->AddArg(cma_name_id_,
2563 Variadic::String(context_->storage->InternString(
2564 cma_alloc_info.name())));
2565 inserter->AddArg(cma_pfn_id_,
2566 Variadic::UnsignedInteger(cma_alloc_info.pfn()));
2567 inserter->AddArg(cma_req_pages_id_,
2568 Variadic::UnsignedInteger(cma_alloc_info.count()));
2569 inserter->AddArg(cma_nr_migrated_id_,
2570 Variadic::UnsignedInteger(cma_alloc_info.nr_migrated()));
2571 inserter->AddArg(cma_nr_reclaimed_id_,
2572 Variadic::UnsignedInteger(cma_alloc_info.nr_reclaimed()));
2573 inserter->AddArg(cma_nr_mapped_id_,
2574 Variadic::UnsignedInteger(cma_alloc_info.nr_mapped()));
2575 inserter->AddArg(cma_nr_isolate_fail_id_,
2576 Variadic::UnsignedInteger(cma_alloc_info.err_iso()));
2577 inserter->AddArg(cma_nr_migrate_fail_id_,
2578 Variadic::UnsignedInteger(cma_alloc_info.err_mig()));
2579 inserter->AddArg(cma_nr_test_fail_id_,
2580 Variadic::UnsignedInteger(cma_alloc_info.err_test()));
2581 };
2582 context_->slice_tracker->End(timestamp, track_id, kNullStringId,
2583 kNullStringId, args_inserter);
2584 }
2585
ParseDirectReclaimBegin(int64_t timestamp,uint32_t pid,ConstBytes blob)2586 void FtraceParser::ParseDirectReclaimBegin(int64_t timestamp,
2587 uint32_t pid,
2588 ConstBytes blob) {
2589 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2590 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2591 protos::pbzero::MmVmscanDirectReclaimBeginFtraceEvent::Decoder
2592 direct_reclaim_begin(blob);
2593
2594 StringId name_id =
2595 context_->storage->InternString("mm_vmscan_direct_reclaim");
2596
2597 auto args_inserter = [this, &direct_reclaim_begin](
2598 ArgsTracker::BoundInserter* inserter) {
2599 inserter->AddArg(direct_reclaim_order_id_,
2600 Variadic::Integer(direct_reclaim_begin.order()));
2601 inserter->AddArg(direct_reclaim_may_writepage_id_,
2602 Variadic::Integer(direct_reclaim_begin.may_writepage()));
2603 inserter->AddArg(
2604 direct_reclaim_gfp_flags_id_,
2605 Variadic::UnsignedInteger(direct_reclaim_begin.gfp_flags()));
2606 };
2607 context_->slice_tracker->Begin(timestamp, track_id, kNullStringId, name_id,
2608 args_inserter);
2609 }
2610
ParseDirectReclaimEnd(int64_t timestamp,uint32_t pid,ConstBytes blob)2611 void FtraceParser::ParseDirectReclaimEnd(int64_t timestamp,
2612 uint32_t pid,
2613 ConstBytes blob) {
2614 protos::pbzero::ScmCallEndFtraceEvent::Decoder evt(blob);
2615 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2616 TrackId track_id = context_->track_tracker->InternThreadTrack(utid);
2617 protos::pbzero::MmVmscanDirectReclaimEndFtraceEvent::Decoder
2618 direct_reclaim_end(blob);
2619
2620 auto args_inserter =
2621 [this, &direct_reclaim_end](ArgsTracker::BoundInserter* inserter) {
2622 inserter->AddArg(
2623 direct_reclaim_nr_reclaimed_id_,
2624 Variadic::UnsignedInteger(direct_reclaim_end.nr_reclaimed()));
2625 };
2626 context_->slice_tracker->End(timestamp, track_id, kNullStringId,
2627 kNullStringId, args_inserter);
2628 }
2629
ParseShrinkSlabStart(int64_t timestamp,uint32_t pid,ConstBytes blob,PacketSequenceStateGeneration * seq_state)2630 void FtraceParser::ParseShrinkSlabStart(
2631 int64_t timestamp,
2632 uint32_t pid,
2633 ConstBytes blob,
2634 PacketSequenceStateGeneration* seq_state) {
2635 protos::pbzero::MmShrinkSlabStartFtraceEvent::Decoder shrink_slab_start(blob);
2636
2637 StringId shrink_name =
2638 InternedKernelSymbolOrFallback(shrink_slab_start.shrink(), seq_state);
2639
2640 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2641 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2642 context_->slice_tracker->Begin(
2643 timestamp, track, kNullStringId, shrink_slab_id_,
2644 [&, this](ArgsTracker::BoundInserter* inserter) {
2645 inserter->AddArg(shrink_name_id_, Variadic::String(shrink_name));
2646 inserter->AddArg(
2647 shrink_total_scan_id_,
2648 Variadic::UnsignedInteger(shrink_slab_start.total_scan()));
2649 inserter->AddArg(shrink_priority_id_,
2650 Variadic::Integer(shrink_slab_start.priority()));
2651 });
2652 }
2653
ParseShrinkSlabEnd(int64_t timestamp,uint32_t pid,ConstBytes blob)2654 void FtraceParser::ParseShrinkSlabEnd(int64_t timestamp,
2655 uint32_t pid,
2656 ConstBytes blob) {
2657 protos::pbzero::MmShrinkSlabEndFtraceEvent::Decoder shrink_slab_end(blob);
2658 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2659 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2660
2661 context_->slice_tracker->End(
2662 timestamp, track, kNullStringId, kNullStringId,
2663 [&, this](ArgsTracker::BoundInserter* inserter) {
2664 inserter->AddArg(shrink_freed_id_,
2665 Variadic::Integer(shrink_slab_end.retval()));
2666 });
2667 }
2668
ParseWorkqueueExecuteStart(uint32_t cpu,int64_t timestamp,uint32_t pid,ConstBytes blob,PacketSequenceStateGeneration * seq_state)2669 void FtraceParser::ParseWorkqueueExecuteStart(
2670 uint32_t cpu,
2671 int64_t timestamp,
2672 uint32_t pid,
2673 ConstBytes blob,
2674 PacketSequenceStateGeneration* seq_state) {
2675 protos::pbzero::WorkqueueExecuteStartFtraceEvent::Decoder evt(blob);
2676 StringId name_id = InternedKernelSymbolOrFallback(evt.function(), seq_state);
2677
2678 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2679 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2680
2681 context_->slice_tracker->Begin(
2682 timestamp, track, workqueue_id_, name_id,
2683 [&, this](ArgsTracker::BoundInserter* inserter) {
2684 inserter->AddArg(cpu_id_, Variadic::Integer(cpu));
2685 });
2686 }
2687
ParseWorkqueueExecuteEnd(int64_t timestamp,uint32_t pid,ConstBytes blob)2688 void FtraceParser::ParseWorkqueueExecuteEnd(int64_t timestamp,
2689 uint32_t pid,
2690 ConstBytes blob) {
2691 protos::pbzero::WorkqueueExecuteEndFtraceEvent::Decoder evt(blob);
2692 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2693 TrackId track = context_->track_tracker->InternThreadTrack(utid);
2694 context_->slice_tracker->End(timestamp, track, workqueue_id_);
2695 }
2696
2697 namespace {
2698
2699 constexpr auto kIrqBlueprint = tracks::SliceBlueprint(
2700 "cpu_irq",
2701 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
__anone76f5f401802(uint32_t cpu) 2702 tracks::FnNameBlueprint([](uint32_t cpu) {
2703 return base::StackString<255>("Irq Cpu %u", cpu);
2704 }));
2705
2706 } // namespace
2707
ParseIrqHandlerEntry(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2708 void FtraceParser::ParseIrqHandlerEntry(uint32_t cpu,
2709 int64_t timestamp,
2710 protozero::ConstBytes blob) {
2711 protos::pbzero::IrqHandlerEntryFtraceEvent::Decoder evt(blob);
2712
2713 TrackId track = context_->track_tracker->InternTrack(kIrqBlueprint,
2714 tracks::Dimensions(cpu));
2715
2716 base::StringView irq_name = evt.name();
2717 base::StackString<255> slice_name("IRQ (%.*s)", int(irq_name.size()),
2718 irq_name.data());
2719 StringId slice_name_id =
2720 context_->storage->InternString(slice_name.string_view());
2721 context_->slice_tracker->Begin(timestamp, track, irq_id_, slice_name_id);
2722 }
2723
ParseIrqHandlerExit(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2724 void FtraceParser::ParseIrqHandlerExit(uint32_t cpu,
2725 int64_t timestamp,
2726 protozero::ConstBytes blob) {
2727 protos::pbzero::IrqHandlerExitFtraceEvent::Decoder evt(blob);
2728
2729 TrackId track = context_->track_tracker->InternTrack(kIrqBlueprint,
2730 tracks::Dimensions(cpu));
2731 context_->slice_tracker->End(
2732 timestamp, track, irq_id_, {},
2733 [&, this](ArgsTracker::BoundInserter* inserter) {
2734 inserter->AddArg(ret_arg_id_,
2735 Variadic::String(context_->storage->InternString(
2736 evt.ret() == 1 ? "handled" : "unhandled")));
2737 });
2738 }
2739
2740 namespace {
2741
2742 constexpr auto kSoftIrqBlueprint = tracks::SliceBlueprint(
2743 "cpu_softirq",
2744 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
__anone76f5f401b02(uint32_t cpu) 2745 tracks::FnNameBlueprint([](uint32_t cpu) {
2746 return base::StackString<255>("SoftIrq Cpu %u", cpu);
2747 }));
2748
2749 } // namespace
2750
ParseSoftIrqEntry(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2751 void FtraceParser::ParseSoftIrqEntry(uint32_t cpu,
2752 int64_t timestamp,
2753 protozero::ConstBytes blob) {
2754 protos::pbzero::SoftirqEntryFtraceEvent::Decoder evt(blob);
2755 if (evt.vec() >= base::ArraySize(kActionNames)) {
2756 PERFETTO_DFATAL("No action name at index %d for softirq event.", evt.vec());
2757 return;
2758 }
2759
2760 TrackId track = context_->track_tracker->InternTrack(kSoftIrqBlueprint,
2761 tracks::Dimensions(cpu));
2762 StringId slice_name_id =
2763 context_->storage->InternString(kActionNames[evt.vec()]);
2764 context_->slice_tracker->Begin(timestamp, track, irq_id_, slice_name_id);
2765 }
2766
ParseSoftIrqExit(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2767 void FtraceParser::ParseSoftIrqExit(uint32_t cpu,
2768 int64_t timestamp,
2769 protozero::ConstBytes blob) {
2770 protos::pbzero::SoftirqExitFtraceEvent::Decoder evt(blob);
2771
2772 TrackId track = context_->track_tracker->InternTrack(kSoftIrqBlueprint,
2773 tracks::Dimensions(cpu));
2774 context_->slice_tracker->End(timestamp, track, irq_id_, {},
2775 [&, this](ArgsTracker::BoundInserter* inserter) {
2776 inserter->AddArg(vec_arg_id_,
2777 Variadic::Integer(evt.vec()));
2778 });
2779 }
2780
ParseGpuMemTotal(int64_t timestamp,protozero::ConstBytes data)2781 void FtraceParser::ParseGpuMemTotal(int64_t timestamp,
2782 protozero::ConstBytes data) {
2783 protos::pbzero::GpuMemTotalFtraceEvent::Decoder gpu_mem_total(data);
2784
2785 TrackId track;
2786 const uint32_t pid = gpu_mem_total.pid();
2787 if (pid == 0) {
2788 // Pid 0 is used to indicate the global total
2789 track =
2790 context_->track_tracker->InternTrack(tracks::kGlobalGpuMemoryBlueprint);
2791 } else {
2792 // It's possible for GpuMemTotal ftrace events to be emitted by kworker
2793 // threads *after* process death. In this case, we simply want to discard
2794 // the event as otherwise we would create fake processes which we
2795 // definitely want to avoid.
2796 // See b/192274404 for more info.
2797 std::optional<UniqueTid> opt_utid =
2798 context_->process_tracker->GetThreadOrNull(pid);
2799 if (!opt_utid)
2800 return;
2801
2802 // If the thread does exist, the |pid| in gpu_mem_total events is always a
2803 // true process id (and not a thread id) so ensure there is an association
2804 // between the tid and pid.
2805 UniqueTid updated_utid = context_->process_tracker->UpdateThread(pid, pid);
2806 PERFETTO_DCHECK(updated_utid == *opt_utid);
2807
2808 // UpdateThread above should ensure this is always set.
2809 UniquePid upid = *context_->storage->thread_table()[*opt_utid].upid();
2810 PERFETTO_DCHECK(context_->storage->process_table()[upid].pid() == pid);
2811 track = context_->track_tracker->InternTrack(
2812 tracks::kProcessGpuMemoryBlueprint, tracks::Dimensions(upid));
2813 }
2814 context_->event_tracker->PushCounter(
2815 timestamp, static_cast<double>(gpu_mem_total.size()), track);
2816 }
2817
ParseSchedBlockedReason(protozero::ConstBytes blob,PacketSequenceStateGeneration * seq_state)2818 void FtraceParser::ParseSchedBlockedReason(
2819 protozero::ConstBytes blob,
2820 PacketSequenceStateGeneration* seq_state) {
2821 protos::pbzero::SchedBlockedReasonFtraceEvent::Decoder event(blob);
2822 uint32_t pid = static_cast<uint32_t>(event.pid());
2823 auto utid = context_->process_tracker->GetOrCreateThread(pid);
2824 uint32_t caller_iid = static_cast<uint32_t>(event.caller());
2825 auto* interned_string = seq_state->LookupInternedMessage<
2826 protos::pbzero::InternedData::kKernelSymbolsFieldNumber,
2827 protos::pbzero::InternedString>(caller_iid);
2828
2829 std::optional<StringId> blocked_function_str_id = std::nullopt;
2830 if (interned_string) {
2831 protozero::ConstBytes str = interned_string->str();
2832 blocked_function_str_id = context_->storage->InternString(
2833 base::StringView(reinterpret_cast<const char*>(str.data), str.size));
2834 }
2835
2836 ThreadStateTracker::GetOrCreate(context_)->PushBlockedReason(
2837 utid, event.io_wait(), blocked_function_str_id);
2838 }
2839
ParseFastRpcDmaStat(int64_t timestamp,uint32_t pid,protozero::ConstBytes blob)2840 void FtraceParser::ParseFastRpcDmaStat(int64_t timestamp,
2841 uint32_t pid,
2842 protozero::ConstBytes blob) {
2843 protos::pbzero::FastrpcDmaStatFtraceEvent::Decoder event(blob);
2844
2845 static constexpr auto kDimensionBlueprint =
2846 tracks::UintDimensionBlueprint("cid");
2847
2848 static constexpr auto kBlueprint = tracks::CounterBlueprint(
2849 "fastrpc", tracks::UnknownUnitBlueprint(),
2850 tracks::DimensionBlueprints(kDimensionBlueprint),
2851 tracks::FnNameBlueprint([](uint32_t cid) {
2852 switch (cid) {
2853 case 0:
2854 return base::StackString<128>("mem.fastrpc[ASDP]");
2855 case 1:
2856 return base::StackString<128>("mem.fastrpc[MDSP]");
2857 case 2:
2858 return base::StackString<128>("mem.fastrpc[SDSP]");
2859 case 3:
2860 return base::StackString<128>("mem.fastrpc[CDSP]");
2861 default:
2862 return base::StackString<128>("mem.fastrpc[%" PRIu32 "]", cid);
2863 }
2864 }));
2865
2866 // Push the global counter.
2867 TrackId track = context_->track_tracker->InternTrack(
2868 kBlueprint, tracks::Dimensions(event.cid()));
2869 context_->event_tracker->PushCounter(
2870 timestamp, static_cast<double>(event.total_allocated()), track);
2871
2872 static constexpr auto kChangeBlueprint = tracks::CounterBlueprint(
2873 "fastrpc_change", tracks::UnknownUnitBlueprint(),
2874 tracks::DimensionBlueprints(kDimensionBlueprint,
2875 tracks::kThreadDimensionBlueprint),
2876 tracks::FnNameBlueprint([](uint32_t cid, uint32_t) {
2877 switch (cid) {
2878 case 0:
2879 return base::StackString<128>("mem.fastrpc_change[ASDP]");
2880 case 1:
2881 return base::StackString<128>("mem.fastrpc_change[MDSP]");
2882 case 2:
2883 return base::StackString<128>("mem.fastrpc_change[SDSP]");
2884 case 3:
2885 return base::StackString<128>("mem.fastrpc_change[CDSP]");
2886 default:
2887 return base::StackString<128>("mem.fastrpc_change[%" PRIu32 "]",
2888 cid);
2889 }
2890 }));
2891
2892 // Push the change counter.
2893 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
2894 TrackId delta_track = context_->track_tracker->InternTrack(
2895 kChangeBlueprint, tracks::Dimensions(event.cid(), utid));
2896 context_->event_tracker->PushCounter(
2897 timestamp, static_cast<double>(event.len()), delta_track);
2898 }
2899
ParseCpuhpPause(int64_t,uint32_t,protozero::ConstBytes blob)2900 void FtraceParser::ParseCpuhpPause(int64_t,
2901 uint32_t,
2902 protozero::ConstBytes blob) {
2903 protos::pbzero::CpuhpPauseFtraceEvent::Decoder evt(blob);
2904 // TODO(b/183110813): Parse and visualize this event.
2905 }
2906
ParseNetifReceiveSkb(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2907 void FtraceParser::ParseNetifReceiveSkb(uint32_t cpu,
2908 int64_t timestamp,
2909 protozero::ConstBytes blob) {
2910 static constexpr auto kBlueprint = tracks::CounterBlueprint(
2911 "net_receive", tracks::UnknownUnitBlueprint(),
2912 tracks::DimensionBlueprints(tracks::kNetworkInterfaceDimensionBlueprint),
2913 tracks::FnNameBlueprint([](base::StringView net_device) {
2914 return base::StackString<255>("%.*s Received KB",
2915 static_cast<int>(net_device.size()),
2916 net_device.data());
2917 }));
2918
2919 protos::pbzero::NetifReceiveSkbFtraceEvent::Decoder event(blob);
2920 base::StringView net_device = event.name();
2921
2922 TrackId track = context_->track_tracker->InternTrack(
2923 kBlueprint, tracks::Dimensions(net_device));
2924
2925 uint64_t& received = nic_received_bytes_[net_device.ToStdString()];
2926 received += event.len();
2927
2928 uint64_t nic_received_kb = received / 1024;
2929 context_->event_tracker->PushCounter(
2930 timestamp, static_cast<double>(nic_received_kb), track,
2931 [&, this](ArgsTracker::BoundInserter* inserter) {
2932 StringId cpu_key = context_->storage->InternString("cpu");
2933 StringId len_key = context_->storage->InternString("len");
2934 inserter->AddArg(cpu_key, Variadic::UnsignedInteger(cpu));
2935 inserter->AddArg(len_key, Variadic::UnsignedInteger(event.len()));
2936 });
2937 }
2938
ParseNetDevXmit(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)2939 void FtraceParser::ParseNetDevXmit(uint32_t cpu,
2940 int64_t timestamp,
2941 protozero::ConstBytes blob) {
2942 protos::pbzero::NetDevXmitFtraceEvent::Decoder evt(blob);
2943
2944 // Make sure driver took care of packet.
2945 if (evt.rc() != 0) {
2946 return;
2947 }
2948
2949 base::StringView net_device = evt.name();
2950
2951 static constexpr auto kBlueprint = tracks::CounterBlueprint(
2952 "net_transmit", tracks::UnknownUnitBlueprint(),
2953 tracks::DimensionBlueprints(tracks::kNetworkInterfaceDimensionBlueprint),
2954 tracks::FnNameBlueprint([](base::StringView net_device) {
2955 return base::StackString<255>("%.*s Transmitted KB",
2956 static_cast<int>(net_device.size()),
2957 net_device.data());
2958 }));
2959 TrackId track = context_->track_tracker->InternTrack(
2960 kBlueprint, tracks::Dimensions(net_device));
2961
2962 uint64_t& transmitted = nic_transmitted_bytes_[net_device.ToStdString()];
2963 transmitted += evt.len();
2964
2965 uint64_t nic_transmitted_kilobytes = transmitted / 1024;
2966 context_->event_tracker->PushCounter(
2967 timestamp, static_cast<double>(nic_transmitted_kilobytes), track,
2968 [&, this](ArgsTracker::BoundInserter* inserter) {
2969 inserter->AddArg(cpu_id_, Variadic::UnsignedInteger(cpu));
2970 inserter->AddArg(len_arg_id_, Variadic::UnsignedInteger(evt.len()));
2971 });
2972 }
2973
ParseInetSockSetState(int64_t timestamp,uint32_t pid,protozero::ConstBytes blob)2974 void FtraceParser::ParseInetSockSetState(int64_t timestamp,
2975 uint32_t pid,
2976 protozero::ConstBytes blob) {
2977 protos::pbzero::InetSockSetStateFtraceEvent::Decoder evt(blob);
2978
2979 // Skip non TCP protocol.
2980 if (evt.protocol() != kIpprotoTcp) {
2981 PERFETTO_ELOG("skip non tcp protocol");
2982 return;
2983 }
2984
2985 // Skip non IP protocol.
2986 if (evt.family() != kAfNet && evt.family() != kAfNet6) {
2987 PERFETTO_ELOG("skip non IP protocol");
2988 return;
2989 }
2990
2991 // Skip invalid TCP state.
2992 if (evt.newstate() >= TCP_MAX_STATES || evt.oldstate() >= TCP_MAX_STATES) {
2993 PERFETTO_ELOG("skip invalid tcp state");
2994 return;
2995 }
2996
2997 auto got = skaddr_to_stream_.find(evt.skaddr());
2998 if (got == skaddr_to_stream_.end()) {
2999 skaddr_to_stream_[evt.skaddr()] = ++num_of_tcp_stream_;
3000 }
3001 StringId slice_name_id;
3002 if (evt.newstate() == TCP_SYN_SENT) {
3003 base::StackString<32> str("%s(pid=%" PRIu32 ")",
3004 kTcpStateNames[evt.newstate()], pid);
3005 slice_name_id = context_->storage->InternString(str.string_view());
3006 } else if (evt.newstate() == TCP_ESTABLISHED) {
3007 base::StackString<64> str("%s(sport=%" PRIu32 ",dport=%" PRIu32 ")",
3008 kTcpStateNames[evt.newstate()], evt.sport(),
3009 evt.dport());
3010 slice_name_id = context_->storage->InternString(str.string_view());
3011 } else {
3012 base::StringView slice_name = kTcpStateNames[evt.newstate()];
3013 slice_name_id = context_->storage->InternString(slice_name);
3014 }
3015
3016 static constexpr auto kBlueprint = tracks::SliceBlueprint(
3017 "net_socket_set_state",
3018 tracks::DimensionBlueprints(
3019 tracks::UintDimensionBlueprint("tcp_stream_idx")),
3020 tracks::FnNameBlueprint([](uint32_t stream_idx) {
3021 return base::StackString<64>("TCP stream#%" PRIu32 "", stream_idx);
3022 }));
3023
3024 uint32_t stream = skaddr_to_stream_[evt.skaddr()];
3025 TrackId id = context_->track_tracker->InternTrack(kBlueprint,
3026 tracks::Dimensions(stream));
3027 context_->slice_tracker->End(timestamp, id);
3028 context_->slice_tracker->Begin(timestamp, id, tcp_state_id_, slice_name_id);
3029 }
3030
ParseTcpRetransmitSkb(int64_t timestamp,protozero::ConstBytes blob)3031 void FtraceParser::ParseTcpRetransmitSkb(int64_t timestamp,
3032 protozero::ConstBytes blob) {
3033 protos::pbzero::TcpRetransmitSkbFtraceEvent::Decoder evt(blob);
3034
3035 static constexpr auto kBlueprint = tracks::SliceBlueprint(
3036 "net_tcp_retransmit_skb", tracks::DimensionBlueprints(),
3037 tracks::StaticNameBlueprint("TCP Retransmit Skb"));
3038
3039 base::StackString<64> str("sport=%" PRIu32 ",dport=%" PRIu32 "", evt.sport(),
3040 evt.dport());
3041 StringId slice_name_id = context_->storage->InternString(str.string_view());
3042 TrackId track_id = context_->track_tracker->InternTrack(kBlueprint);
3043 context_->slice_tracker->Scoped(timestamp, track_id, tcp_event_id_,
3044 slice_name_id, 0);
3045 }
3046
3047 namespace {
3048
3049 constexpr auto kNapiGroBlueprint = tracks::SliceBlueprint(
3050 "cpu_napi_gro",
3051 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
__anone76f5f402502(uint32_t cpu) 3052 tracks::FnNameBlueprint([](uint32_t cpu) {
3053 return base::StackString<255>("Napi Gro Cpu %u", cpu);
3054 }));
3055
3056 } // namespace
3057
ParseNapiGroReceiveEntry(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)3058 void FtraceParser::ParseNapiGroReceiveEntry(uint32_t cpu,
3059 int64_t timestamp,
3060 protozero::ConstBytes blob) {
3061 protos::pbzero::NapiGroReceiveEntryFtraceEvent::Decoder evt(blob);
3062
3063 TrackId track = context_->track_tracker->InternTrack(kNapiGroBlueprint,
3064 tracks::Dimensions(cpu));
3065 StringId slice_name_id = context_->storage->InternString(evt.name());
3066 context_->slice_tracker->Begin(
3067 timestamp, track, napi_gro_id_, slice_name_id,
3068 [&, this](ArgsTracker::BoundInserter* inserter) {
3069 inserter->AddArg(len_arg_id_, Variadic::Integer(evt.len()));
3070 });
3071 }
3072
ParseNapiGroReceiveExit(uint32_t cpu,int64_t timestamp,protozero::ConstBytes blob)3073 void FtraceParser::ParseNapiGroReceiveExit(uint32_t cpu,
3074 int64_t timestamp,
3075 protozero::ConstBytes blob) {
3076 protos::pbzero::NapiGroReceiveExitFtraceEvent::Decoder evt(blob);
3077
3078 TrackId track = context_->track_tracker->InternTrack(kNapiGroBlueprint,
3079 tracks::Dimensions(cpu));
3080 context_->slice_tracker->End(timestamp, track, napi_gro_id_, {},
3081 [&, this](ArgsTracker::BoundInserter* inserter) {
3082 inserter->AddArg(ret_arg_id_,
3083 Variadic::Integer(evt.ret()));
3084 });
3085 }
3086
ParseCpuFrequencyLimits(int64_t timestamp,protozero::ConstBytes blob)3087 void FtraceParser::ParseCpuFrequencyLimits(int64_t timestamp,
3088 protozero::ConstBytes blob) {
3089 protos::pbzero::CpuFrequencyLimitsFtraceEvent::Decoder evt(blob);
3090
3091 static constexpr auto kMaxBlueprint = tracks::CounterBlueprint(
3092 "cpu_max_frequency_limit", tracks::UnknownUnitBlueprint(),
3093 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
3094 tracks::FnNameBlueprint([](uint32_t cpu) {
3095 return base::StackString<255>("Cpu %u Max Freq Limit", cpu);
3096 }));
3097
3098 TrackId max_track = context_->track_tracker->InternTrack(
3099 kMaxBlueprint, tracks::Dimensions(evt.cpu_id()));
3100 context_->event_tracker->PushCounter(
3101 timestamp, static_cast<double>(evt.max_freq()), max_track);
3102
3103 static constexpr auto kMinBlueprint = tracks::CounterBlueprint(
3104 "cpu_min_frequency_limit", tracks::UnknownUnitBlueprint(),
3105 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
3106 tracks::FnNameBlueprint([](uint32_t cpu) {
3107 return base::StackString<255>("Cpu %u Min Freq Limit", cpu);
3108 }));
3109
3110 TrackId min_track = context_->track_tracker->InternTrack(
3111 kMinBlueprint, tracks::Dimensions(evt.cpu_id()));
3112 context_->event_tracker->PushCounter(
3113 timestamp, static_cast<double>(evt.min_freq()), min_track);
3114 }
3115
ParseKfreeSkb(int64_t timestamp,protozero::ConstBytes blob)3116 void FtraceParser::ParseKfreeSkb(int64_t timestamp,
3117 protozero::ConstBytes blob) {
3118 protos::pbzero::KfreeSkbFtraceEvent::Decoder evt(blob);
3119
3120 // Skip non IP & IPV6 protocol.
3121 if (evt.protocol() != kEthPIp && evt.protocol() != kEthPIp6) {
3122 return;
3123 }
3124 num_of_kfree_skb_ip_prot += 1;
3125
3126 static constexpr auto kBlueprint = tracks::CounterBlueprint(
3127 "net_kfree_skb", tracks::UnknownUnitBlueprint(),
3128 tracks::DimensionBlueprints(),
3129 tracks::StaticNameBlueprint("Kfree Skb IP Prot"));
3130
3131 TrackId track = context_->track_tracker->InternTrack(kBlueprint);
3132 context_->event_tracker->PushCounter(
3133 timestamp, static_cast<double>(num_of_kfree_skb_ip_prot), track,
3134 [&, this](ArgsTracker::BoundInserter* inserter) {
3135 base::StackString<255> prot("%s",
3136 evt.protocol() == kEthPIp ? "IP" : "IPV6");
3137 StringId prot_id = context_->storage->InternString(prot.string_view());
3138 // Store protocol as args for metrics computation.
3139 inserter->AddArg(protocol_arg_id_, Variadic::String(prot_id));
3140 });
3141 }
3142
ParseCrosEcSensorhubData(int64_t timestamp,protozero::ConstBytes blob)3143 void FtraceParser::ParseCrosEcSensorhubData(int64_t timestamp,
3144 protozero::ConstBytes blob) {
3145 protos::pbzero::CrosEcSensorhubDataFtraceEvent::Decoder evt(blob);
3146
3147 // Push the global counter.
3148 static constexpr auto kBlueprint = tracks::CounterBlueprint(
3149 "cros_ec_sensorhub_data", tracks::UnknownUnitBlueprint(),
3150 tracks::DimensionBlueprints(
3151 tracks::UintDimensionBlueprint("ec_sensor_num")),
3152 tracks::FnNameBlueprint([](uint32_t sensor) {
3153 return base::StackString<255>("cros_ec.cros_ec_sensorhub_data.%u",
3154 sensor);
3155 }));
3156
3157 TrackId track = context_->track_tracker->InternTrack(
3158 kBlueprint, tracks::Dimensions(evt.ec_sensor_num()));
3159 context_->event_tracker->PushCounter(
3160 timestamp,
3161 static_cast<double>(evt.current_time() - evt.current_timestamp()), track,
3162 [&, this](ArgsTracker::BoundInserter* inserter) {
3163 inserter->AddArg(cros_ec_arg_num_id_,
3164 Variadic::Integer(evt.ec_sensor_num()));
3165 inserter->AddArg(
3166 cros_ec_arg_ec_id_,
3167 Variadic::Integer(evt.fifo_timestamp() - evt.current_timestamp()));
3168 inserter->AddArg(cros_ec_arg_sample_ts_id_,
3169 Variadic::Integer(evt.current_timestamp()));
3170 });
3171 }
3172
ParseUfshcdClkGating(int64_t timestamp,protozero::ConstBytes blob)3173 void FtraceParser::ParseUfshcdClkGating(int64_t timestamp,
3174 protozero::ConstBytes blob) {
3175 protos::pbzero::UfshcdClkGatingFtraceEvent::Decoder evt(blob);
3176 uint32_t clk_state = 0;
3177 switch (evt.state()) {
3178 case 1:
3179 // Change ON state to 3
3180 clk_state = 3;
3181 break;
3182 case 2:
3183 // Change REQ_OFF state to 1
3184 clk_state = 1;
3185 break;
3186 case 3:
3187 // Change REQ_ON state to 2
3188 clk_state = 2;
3189 break;
3190 }
3191 static constexpr auto kBlueprint = tracks::CounterBlueprint(
3192 "ufs_clkgating", tracks::UnknownUnitBlueprint(),
3193 tracks::DimensionBlueprints(),
3194 tracks::StaticNameBlueprint(
3195 "io.ufs.clkgating (OFF:0/REQ_OFF/REQ_ON/ON:3)"));
3196 TrackId track = context_->track_tracker->InternTrack(kBlueprint);
3197 context_->event_tracker->PushCounter(timestamp,
3198 static_cast<double>(clk_state), track);
3199 }
3200
ParseTrustySmc(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3201 void FtraceParser::ParseTrustySmc(uint32_t pid,
3202 int64_t timestamp,
3203 protozero::ConstBytes blob) {
3204 protos::pbzero::TrustySmcFtraceEvent::Decoder evt(blob);
3205
3206 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3207 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3208
3209 base::StackString<48> name("trusty_smc:r0= %" PRIu64, evt.r0());
3210 StringId name_generic = context_->storage->InternString(name.string_view());
3211
3212 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3213 name_generic);
3214 }
3215
ParseTrustySmcDone(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3216 void FtraceParser::ParseTrustySmcDone(uint32_t pid,
3217 int64_t timestamp,
3218 protozero::ConstBytes blob) {
3219 protos::pbzero::TrustySmcDoneFtraceEvent::Decoder evt(blob);
3220
3221 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3222 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3223
3224 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3225 base::StackString<256> name("trusty_smc_done:r0= %" PRIu64, evt.ret());
3226 StringId name_generic = context_->storage->InternString(name.string_view());
3227 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3228 name_generic, 0);
3229 }
3230
ParseTrustyStdCall32(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3231 void FtraceParser::ParseTrustyStdCall32(uint32_t pid,
3232 int64_t timestamp,
3233 protozero::ConstBytes blob) {
3234 protos::pbzero::TrustyStdCall32FtraceEvent::Decoder evt(blob);
3235
3236 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3237 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3238
3239 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3240 trusty_name_trusty_std_id_);
3241 }
3242
ParseTrustyStdCall32Done(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3243 void FtraceParser::ParseTrustyStdCall32Done(uint32_t pid,
3244 int64_t timestamp,
3245 protozero::ConstBytes blob) {
3246 protos::pbzero::TrustyStdCall32DoneFtraceEvent::Decoder evt(blob);
3247
3248 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3249 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3250
3251 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3252 if (evt.ret() < 0) {
3253 base::StackString<256> name("trusty_err_std: err= %" PRIi64, evt.ret());
3254 StringId name_generic = context_->storage->InternString(name.string_view());
3255 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3256 name_generic, 0);
3257 }
3258 }
3259
ParseTrustyShareMemory(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3260 void FtraceParser::ParseTrustyShareMemory(uint32_t pid,
3261 int64_t timestamp,
3262 protozero::ConstBytes blob) {
3263 protos::pbzero::TrustyShareMemoryFtraceEvent::Decoder evt(blob);
3264
3265 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3266 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3267
3268 base::StackString<256> name(
3269 "trusty_share_mem: len= %" PRIu64 " nents= %" PRIu32 " lend= %" PRIu32,
3270 static_cast<uint64_t>(evt.len()), evt.nents(), evt.lend());
3271 StringId name_generic = context_->storage->InternString(name.string_view());
3272
3273 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3274 name_generic);
3275 }
3276
ParseTrustyShareMemoryDone(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3277 void FtraceParser::ParseTrustyShareMemoryDone(uint32_t pid,
3278 int64_t timestamp,
3279 protozero::ConstBytes blob) {
3280 protos::pbzero::TrustyShareMemoryDoneFtraceEvent::Decoder evt(blob);
3281
3282 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3283 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3284 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3285
3286 base::StackString<256> name("trusty_share_mem: handle= %" PRIu64
3287 " ret= %" PRIi32,
3288 evt.handle(), evt.ret());
3289 StringId name_generic = context_->storage->InternString(name.string_view());
3290 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3291 name_generic, 0);
3292 }
3293
ParseTrustyReclaimMemory(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3294 void FtraceParser::ParseTrustyReclaimMemory(uint32_t pid,
3295 int64_t timestamp,
3296 protozero::ConstBytes blob) {
3297 protos::pbzero::TrustyReclaimMemoryFtraceEvent::Decoder evt(blob);
3298
3299 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3300 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3301
3302 base::StackString<256> name("trusty_reclaim_mem: id=%" PRIu64, evt.id());
3303 StringId name_generic = context_->storage->InternString(name.string_view());
3304
3305 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3306 name_generic);
3307 }
3308
ParseTrustyReclaimMemoryDone(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3309 void FtraceParser::ParseTrustyReclaimMemoryDone(uint32_t pid,
3310 int64_t timestamp,
3311 protozero::ConstBytes blob) {
3312 protos::pbzero::TrustyReclaimMemoryDoneFtraceEvent::Decoder evt(blob);
3313
3314 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3315 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3316 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3317
3318 if (evt.ret() < 0) {
3319 base::StackString<256> name("trusty_reclaim_mem_err: err= %" PRIi32,
3320 evt.ret());
3321 StringId name_generic = context_->storage->InternString(name.string_view());
3322 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3323 name_generic, 0);
3324 }
3325 }
3326
ParseTrustyIrq(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3327 void FtraceParser::ParseTrustyIrq(uint32_t pid,
3328 int64_t timestamp,
3329 protozero::ConstBytes blob) {
3330 protos::pbzero::TrustyIrqFtraceEvent::Decoder evt(blob);
3331
3332 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3333 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3334
3335 base::StackString<256> name("trusty_irq: irq= %" PRIi32, evt.irq());
3336 StringId name_generic = context_->storage->InternString(name.string_view());
3337
3338 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3339 name_generic, 0);
3340 }
3341
ParseTrustyIpcHandleEvent(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3342 void FtraceParser::ParseTrustyIpcHandleEvent(uint32_t pid,
3343 int64_t timestamp,
3344 protozero::ConstBytes blob) {
3345 protos::pbzero::TrustyIpcHandleEventFtraceEvent::Decoder evt(blob);
3346
3347 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3348 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3349
3350 base::StackString<256> name(
3351 "trusty_ipc_handle_event: chan=%" PRIu32 " srv_name=%s event=%" PRIu32,
3352 evt.chan(), evt.srv_name().ToStdString().c_str(), evt.event_id());
3353 StringId name_generic = context_->storage->InternString(name.string_view());
3354
3355 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3356 name_generic, 0);
3357 }
3358
ParseTrustyEnqueueNop(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3359 void FtraceParser::ParseTrustyEnqueueNop(uint32_t pid,
3360 int64_t timestamp,
3361 protozero::ConstBytes blob) {
3362 protos::pbzero::TrustyEnqueueNopFtraceEvent::Decoder evt(blob);
3363
3364 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3365 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3366
3367 base::StackString<256> name("trusty_enqueue_nop: arg1= %" PRIu32
3368 " arg2= %" PRIu32 " arg3=%" PRIu32,
3369 evt.arg1(), evt.arg2(), evt.arg3());
3370 StringId name_generic = context_->storage->InternString(name.string_view());
3371 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3372 name_generic, 0);
3373 }
3374
ParseTrustyIpcConnect(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3375 void FtraceParser::ParseTrustyIpcConnect(uint32_t pid,
3376 int64_t timestamp,
3377 protozero::ConstBytes blob) {
3378 protos::pbzero::TrustyIpcConnectFtraceEvent::Decoder evt(blob);
3379
3380 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3381 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3382
3383 base::StackString<256> name("tipc_connect: %s",
3384 evt.port().ToStdString().c_str());
3385 StringId name_generic = context_->storage->InternString(name.string_view());
3386
3387 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3388 name_generic);
3389 }
3390
ParseTrustyIpcConnectEnd(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3391 void FtraceParser::ParseTrustyIpcConnectEnd(uint32_t pid,
3392 int64_t timestamp,
3393 protozero::ConstBytes blob) {
3394 protos::pbzero::TrustyIpcConnectEndFtraceEvent::Decoder evt(blob);
3395
3396 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3397 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3398
3399 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3400 if (evt.err()) {
3401 base::StackString<256> name("tipc_err_connect:err= %" PRIi32, evt.err());
3402 StringId name_generic = context_->storage->InternString(name.string_view());
3403 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3404 name_generic, 0);
3405 }
3406 }
3407
ParseTrustyIpcWrite(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3408 void FtraceParser::ParseTrustyIpcWrite(uint32_t pid,
3409 int64_t timestamp,
3410 protozero::ConstBytes blob) {
3411 protos::pbzero::TrustyIpcWriteFtraceEvent::Decoder evt(blob);
3412
3413 StringId name_generic = kNullStringId;
3414 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3415 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3416
3417 if (evt.shm_cnt() > 0) {
3418 base::StackString<256> name("tipc_write: %s shm_cnt:[%" PRIu64 "]",
3419 evt.srv_name().ToStdString().c_str(),
3420 evt.shm_cnt());
3421 name_generic = context_->storage->InternString(name.string_view());
3422 } else {
3423 base::StackString<256> name("tipc_write: %s",
3424 evt.srv_name().ToStdString().c_str());
3425 name_generic = context_->storage->InternString(name.string_view());
3426 }
3427 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3428 name_generic, 0);
3429
3430 if (evt.len_or_err() < 0) {
3431 base::StackString<256> name("tipc_err_write:len_or_err= %" PRIi32,
3432 evt.len_or_err());
3433 name_generic = context_->storage->InternString(name.string_view());
3434 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3435 name_generic, 0);
3436 }
3437 }
3438
ParseTrustyIpcRead(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3439 void FtraceParser::ParseTrustyIpcRead(uint32_t pid,
3440 int64_t timestamp,
3441 protozero::ConstBytes blob) {
3442 protos::pbzero::TrustyIpcReadFtraceEvent::Decoder evt(blob);
3443
3444 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3445 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3446
3447 base::StackString<256> name("tipc_read: %s",
3448 evt.srv_name().ToStdString().c_str());
3449 StringId name_generic = context_->storage->InternString(name.string_view());
3450 context_->slice_tracker->Begin(timestamp, track, trusty_category_id_,
3451 name_generic);
3452 }
3453
ParseTrustyIpcReadEnd(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3454 void FtraceParser::ParseTrustyIpcReadEnd(uint32_t pid,
3455 int64_t timestamp,
3456 protozero::ConstBytes blob) {
3457 protos::pbzero::TrustyIpcReadEndFtraceEvent::Decoder evt(blob);
3458
3459 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3460 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3461 context_->slice_tracker->End(timestamp, track, trusty_category_id_);
3462
3463 if (evt.len_or_err() <= 0) {
3464 base::StackString<256> name("tipc_err_read:len_or_err= %" PRIi32,
3465 evt.len_or_err());
3466 StringId name_generic = context_->storage->InternString(name.string_view());
3467 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3468 name_generic, 0);
3469 }
3470 }
3471
ParseTrustyIpcPoll(uint32_t pid,int64_t timestamp,protozero::ConstBytes blob)3472 void FtraceParser::ParseTrustyIpcPoll(uint32_t pid,
3473 int64_t timestamp,
3474 protozero::ConstBytes blob) {
3475 protos::pbzero::TrustyIpcPollFtraceEvent::Decoder evt(blob);
3476
3477 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3478 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3479
3480 base::StackString<256> name("tipc_poll: %s",
3481 evt.srv_name().ToStdString().c_str());
3482 StringId name_generic = context_->storage->InternString(name.string_view());
3483 context_->slice_tracker->Scoped(timestamp, track, trusty_category_id_,
3484 name_generic, 0);
3485 }
3486
ParseTrustyIpcRx(uint32_t pid,int64_t ts,protozero::ConstBytes blob)3487 void FtraceParser::ParseTrustyIpcRx(uint32_t pid,
3488 int64_t ts,
3489 protozero::ConstBytes blob) {
3490 protos::pbzero::TrustyIpcRxFtraceEvent::Decoder evt(blob);
3491
3492 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3493 TrackId track = context_->track_tracker->InternThreadTrack(utid);
3494
3495 context_->slice_tracker->Scoped(ts, track, trusty_category_id_,
3496 trusty_name_tipc_rx_id_, 0);
3497 }
3498
ParseUfshcdCommand(int64_t timestamp,protozero::ConstBytes blob)3499 void FtraceParser::ParseUfshcdCommand(int64_t timestamp,
3500 protozero::ConstBytes blob) {
3501 protos::pbzero::UfshcdCommandFtraceEvent::Decoder evt(blob);
3502
3503 static constexpr auto kCounterBlueprint = tracks::CounterBlueprint(
3504 "ufs_command_count", tracks::UnknownUnitBlueprint(),
3505 tracks::DimensionBlueprints(),
3506 tracks::StaticNameBlueprint("io.ufs.command.count"));
3507
3508 // Parse occupied ufs command queue
3509 uint32_t num = evt.doorbell() > 0
3510 ? static_cast<uint32_t>(PERFETTO_POPCOUNT(evt.doorbell()))
3511 : (evt.str_t() == 1 ? 0 : 1);
3512 TrackId track = context_->track_tracker->InternTrack(kCounterBlueprint);
3513 context_->event_tracker->PushCounter(timestamp, static_cast<double>(num),
3514 track);
3515
3516 static constexpr auto kTagBlueprint = tracks::SliceBlueprint(
3517 "ufs_command_tag",
3518 tracks::DimensionBlueprints(tracks::UintDimensionBlueprint("ufs_tag")),
3519 tracks::FnNameBlueprint([](uint32_t tag) {
3520 return base::StackString<32>("io.ufs.command.tag[%03u]", tag);
3521 }));
3522
3523 // Parse ufs command tag
3524 TrackId tag_track_id = context_->track_tracker->InternTrack(
3525 kTagBlueprint, tracks::Dimensions(evt.tag()));
3526 if (evt.str_t() == 0) {
3527 std::string ufs_op_str = GetUfsCmdString(evt.opcode(), evt.group_id());
3528 StringId ufs_slice_name =
3529 context_->storage->InternString(base::StringView(ufs_op_str));
3530 context_->slice_tracker->Begin(timestamp, tag_track_id, kNullStringId,
3531 ufs_slice_name);
3532 } else {
3533 context_->slice_tracker->End(timestamp, tag_track_id);
3534 }
3535 }
3536
3537 namespace {
3538
3539 constexpr auto kWakesourceBlueprint = tracks::SliceBlueprint(
3540 "wakesource_wakelock",
3541 tracks::DimensionBlueprints(
3542 tracks::StringDimensionBlueprint("wakelock_event")),
__anone76f5f402f02(base::StringView event_name) 3543 tracks::FnNameBlueprint([](base::StringView event_name) {
3544 return base::StackString<32>("Wakelock(%.*s)", int(event_name.size()),
3545 event_name.data());
3546 }));
3547
3548 } // namespace
3549
ParseWakeSourceActivate(int64_t timestamp,protozero::ConstBytes blob)3550 void FtraceParser::ParseWakeSourceActivate(int64_t timestamp,
3551 protozero::ConstBytes blob) {
3552 protos::pbzero::WakeupSourceActivateFtraceEvent::Decoder evt(blob);
3553
3554 std::string event_name = evt.name().ToStdString();
3555 uint32_t count = active_wakelock_to_count_[event_name];
3556 active_wakelock_to_count_[event_name] += 1;
3557
3558 // There is already an active slice with this name, don't create another.
3559 if (count > 0) {
3560 return;
3561 }
3562
3563 TrackId track_id = context_->track_tracker->InternTrack(
3564 kWakesourceBlueprint, tracks::Dimensions(evt.name()));
3565 base::StackString<32> str("Wakelock(%s)", event_name.c_str());
3566 StringId stream_id = context_->storage->InternString(str.string_view());
3567 context_->slice_tracker->Begin(timestamp, track_id, kNullStringId, stream_id);
3568 }
3569
ParseWakeSourceDeactivate(int64_t timestamp,protozero::ConstBytes blob)3570 void FtraceParser::ParseWakeSourceDeactivate(int64_t timestamp,
3571 protozero::ConstBytes blob) {
3572 protos::pbzero::WakeupSourceDeactivateFtraceEvent::Decoder evt(blob);
3573
3574 std::string event_name = evt.name().ToStdString();
3575 uint32_t count = active_wakelock_to_count_[event_name];
3576 active_wakelock_to_count_[event_name] = count > 0 ? count - 1 : 0;
3577 if (count != 1) {
3578 return;
3579 }
3580
3581 TrackId track_id = context_->track_tracker->InternTrack(
3582 kWakesourceBlueprint, tracks::Dimensions(evt.name()));
3583 context_->slice_tracker->End(timestamp, track_id);
3584 }
3585
3586 namespace {
3587
3588 constexpr auto kSuspendResumeBlueprint = TrackCompressor::SliceBlueprint(
3589 "suspend_resume",
3590 tracks::Dimensions(),
3591 tracks::StaticNameBlueprint("Suspend/Resume Latency"));
3592
3593 } // namespace
3594
ParseSuspendResume(int64_t timestamp,uint32_t cpu,uint32_t tid,protozero::ConstBytes blob)3595 void FtraceParser::ParseSuspendResume(int64_t timestamp,
3596 uint32_t cpu,
3597 uint32_t tid,
3598 protozero::ConstBytes blob) {
3599 protos::pbzero::SuspendResumeFtraceEvent::Decoder evt(blob);
3600
3601 std::string action_name = evt.action().ToStdString();
3602
3603 // Hard code fix the timekeeping_freeze action's value to zero, the value is
3604 // processor_id and device could enter suspend/resume from different
3605 // processor.
3606 auto val = (action_name == "timekeeping_freeze") ? 0 : evt.val();
3607
3608 base::StackString<64> str("%s(%d)", action_name.c_str(), val);
3609 std::string current_action = str.ToStdString();
3610
3611 StringId slice_name_id = context_->storage->InternString(str.string_view());
3612 int64_t cookie = slice_name_id.raw_id();
3613 if (!evt.start()) {
3614 TrackId end_id = context_->track_compressor->InternEnd(
3615 kSuspendResumeBlueprint, tracks::Dimensions(), cookie);
3616 context_->slice_tracker->End(timestamp, end_id);
3617
3618 if (action_name == "suspend_enter") {
3619 suspend_state_ = SUSPEND_STATE_INITIAL;
3620 } else if (action_name == "thaw_processes" &&
3621 suspend_state_ == SUSPEND_STATE_FREEZE) {
3622 // We encountered the bug. Close the suspend_enter slice.
3623 end_id = context_->track_compressor->InternEnd(
3624 kSuspendResumeBlueprint, tracks::Dimensions(),
3625 suspend_enter_slice_cookie_);
3626 context_->slice_tracker->End(timestamp, end_id);
3627
3628 suspend_state_ = SUSPEND_STATE_INITIAL;
3629 }
3630 return;
3631 }
3632
3633 // Work around bug where the suspend_enter() slice never terminates if we
3634 // see an error in suspend_prepare().
3635 //
3636 // We can detect this state if we
3637 // a) End thaw_processes()
3638 // b) While in freeze_processes()
3639 // c) And in suspend_enter()
3640 //
3641 // since thaw_processes() is only called *from within freeze_processes()*
3642 // in the error case, and should never overlap with suspend_enter().
3643 //
3644 // See b/381039361.
3645 if (action_name == "suspend_enter") {
3646 suspend_state_ = SUSPEND_STATE_ENTER;
3647 suspend_enter_slice_cookie_ = cookie;
3648 } else if (action_name == "freeze_processes" &&
3649 suspend_state_ == SUSPEND_STATE_ENTER) {
3650 suspend_state_ = SUSPEND_STATE_FREEZE;
3651 }
3652
3653 TrackId start_id = context_->track_compressor->InternBegin(
3654 kSuspendResumeBlueprint, tracks::Dimensions(), cookie);
3655 auto args_inserter = [&](ArgsTracker::BoundInserter* inserter) {
3656 inserter->AddArg(suspend_resume_utid_arg_name_,
3657 Variadic::UnsignedInteger(
3658 context_->process_tracker->GetOrCreateThread(tid)));
3659 inserter->AddArg(suspend_resume_event_type_arg_name_,
3660 Variadic::String(suspend_resume_main_event_id_));
3661 inserter->AddArg(cpu_id_, Variadic::UnsignedInteger(cpu));
3662
3663 // These fields are set to null as this is not a device PM callback event.
3664 inserter->AddArg(suspend_resume_device_arg_name_,
3665 Variadic::String(kNullStringId));
3666 inserter->AddArg(suspend_resume_driver_arg_name_,
3667 Variadic::String(kNullStringId));
3668 inserter->AddArg(suspend_resume_callback_phase_arg_name_,
3669 Variadic::String(kNullStringId));
3670 };
3671 context_->slice_tracker->Begin(timestamp, start_id, kNullStringId,
3672 slice_name_id, args_inserter);
3673 }
3674
ParseSuspendResumeMinimal(int64_t timestamp,protozero::ConstBytes blob)3675 void FtraceParser::ParseSuspendResumeMinimal(int64_t timestamp,
3676 protozero::ConstBytes blob) {
3677 protos::pbzero::SuspendResumeMinimalFtraceEvent::Decoder evt(blob);
3678
3679 static constexpr auto kBlueprint = tracks::SliceBlueprint(
3680 "suspend_resume_minimal", tracks::DimensionBlueprints(),
3681 tracks::StaticNameBlueprint("Suspend/Resume Minimal"));
3682 TrackId track_id = context_->track_tracker->InternTrack(kBlueprint);
3683 if (evt.start()) {
3684 context_->slice_tracker->Begin(timestamp, track_id, kNullStringId,
3685 suspend_resume_minimal_slice_name_id_);
3686 } else {
3687 context_->slice_tracker->End(timestamp, track_id);
3688 }
3689 }
3690
ParseSchedCpuUtilCfs(int64_t timestamp,protozero::ConstBytes blob)3691 void FtraceParser::ParseSchedCpuUtilCfs(int64_t timestamp,
3692 protozero::ConstBytes blob) {
3693 protos::pbzero::SchedCpuUtilCfsFtraceEvent::Decoder evt(blob);
3694
3695 static constexpr auto kUtilBlueprint = tracks::CounterBlueprint(
3696 "cpu_utilization", tracks::UnknownUnitBlueprint(),
3697 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
3698 tracks::FnNameBlueprint([](uint32_t cpu) {
3699 return base::StackString<255>("Cpu %u Util", cpu);
3700 }));
3701 TrackId util_track = context_->track_tracker->InternTrack(
3702 kUtilBlueprint, tracks::Dimensions(evt.cpu()));
3703 context_->event_tracker->PushCounter(
3704 timestamp, static_cast<double>(evt.cpu_util()), util_track);
3705
3706 static constexpr auto kCapBlueprint = tracks::CounterBlueprint(
3707 "cpu_capacity", tracks::UnknownUnitBlueprint(),
3708 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
3709 tracks::FnNameBlueprint([](uint32_t cpu) {
3710 return base::StackString<255>("Cpu %u Cap", cpu);
3711 }));
3712 TrackId cap_track = context_->track_tracker->InternTrack(
3713 kCapBlueprint, tracks::Dimensions(evt.cpu()));
3714 context_->event_tracker->PushCounter(
3715 timestamp, static_cast<double>(evt.capacity()), cap_track);
3716
3717 static constexpr auto kNrRunningBlueprint = tracks::CounterBlueprint(
3718 "cpu_nr_running", tracks::UnknownUnitBlueprint(),
3719 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
3720 tracks::FnNameBlueprint([](uint32_t cpu) {
3721 return base::StackString<255>("Cpu %u Nr Running", cpu);
3722 }));
3723 TrackId nr_track = context_->track_tracker->InternTrack(
3724 kNrRunningBlueprint, tracks::Dimensions(evt.cpu()));
3725 context_->event_tracker->PushCounter(
3726 timestamp, static_cast<double>(evt.nr_running()), nr_track);
3727 }
3728
3729 namespace {
3730
3731 constexpr auto kThreadFuncgraphBlueprint = tracks::SliceBlueprint(
3732 "thread_funcgraph",
3733 tracks::DimensionBlueprints(tracks::kThreadDimensionBlueprint),
3734 tracks::StaticNameBlueprint("Funcgraph"));
3735
3736 constexpr auto kCpuFuncgraphBlueprint = tracks::SliceBlueprint(
3737 "cpu_funcgraph",
3738 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
__anone76f5f403602(uint32_t cpu) 3739 tracks::FnNameBlueprint([](uint32_t cpu) {
3740 return base::StackString<255>("swapper%u -funcgraph", cpu);
3741 }));
3742
3743 } // namespace
3744
ParseFuncgraphEntry(int64_t timestamp,uint32_t cpu,uint32_t pid,protozero::ConstBytes blob,PacketSequenceStateGeneration * seq_state)3745 void FtraceParser::ParseFuncgraphEntry(
3746 int64_t timestamp,
3747 uint32_t cpu,
3748 uint32_t pid,
3749 protozero::ConstBytes blob,
3750 PacketSequenceStateGeneration* seq_state) {
3751 protos::pbzero::FuncgraphEntryFtraceEvent::Decoder evt(blob);
3752 StringId name_id = InternedKernelSymbolOrFallback(evt.func(), seq_state);
3753
3754 TrackId track = {};
3755 if (pid != 0) {
3756 // common case: normal thread
3757 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3758 track = context_->track_tracker->InternTrack(kThreadFuncgraphBlueprint,
3759 tracks::Dimensions(utid));
3760 } else {
3761 // Idle threads (swapper) are implicit, and all share the same thread id
3762 // 0. Therefore we cannot use a thread-scoped track because many instances
3763 // of swapper might be running concurrently. Fall back onto global tracks
3764 // (one per cpu).
3765 track = context_->track_tracker->InternTrack(kCpuFuncgraphBlueprint,
3766 tracks::Dimensions(cpu));
3767 }
3768 context_->slice_tracker->Begin(timestamp, track, kNullStringId, name_id);
3769 }
3770
ParseFuncgraphExit(int64_t timestamp,uint32_t cpu,uint32_t pid,protozero::ConstBytes blob,PacketSequenceStateGeneration * seq_state)3771 void FtraceParser::ParseFuncgraphExit(
3772 int64_t timestamp,
3773 uint32_t cpu,
3774 uint32_t pid,
3775 protozero::ConstBytes blob,
3776 PacketSequenceStateGeneration* seq_state) {
3777 protos::pbzero::FuncgraphExitFtraceEvent::Decoder evt(blob);
3778 StringId name_id = InternedKernelSymbolOrFallback(evt.func(), seq_state);
3779
3780 TrackId track = {};
3781 if (pid != 0) {
3782 // common case: normal thread
3783 UniqueTid utid = context_->process_tracker->GetOrCreateThread(pid);
3784 track = context_->track_tracker->InternTrack(kThreadFuncgraphBlueprint,
3785 tracks::Dimensions(utid));
3786 } else {
3787 // special case: see |ParseFuncgraphEntry|
3788 track = context_->track_tracker->InternTrack(kCpuFuncgraphBlueprint,
3789 tracks::Dimensions(cpu));
3790 }
3791 context_->slice_tracker->End(timestamp, track, kNullStringId, name_id);
3792 }
3793
3794 namespace {
3795
3796 constexpr auto kAndroidFsBlueprint =
3797 TrackCompressor::SliceBlueprint("android_fs",
3798 tracks::Dimensions(),
3799 tracks::StaticNameBlueprint("android_fs"));
3800
3801 } // namespace
3802
ParseAndroidFsDatareadStart(int64_t ts,uint32_t pid,ConstBytes data)3803 void FtraceParser::ParseAndroidFsDatareadStart(int64_t ts,
3804 uint32_t pid,
3805 ConstBytes data) {
3806 protos::pbzero::AndroidFsDatareadStartFtraceEvent::Decoder decoder(data);
3807 inode_offset_thread_map_.Insert({decoder.ino(), decoder.offset()}, pid);
3808
3809 TrackId track_id = context_->track_compressor->InternBegin(
3810 kAndroidFsBlueprint, tracks::Dimensions(), pid);
3811 context_->slice_tracker->Begin(
3812 ts, track_id, kNullStringId, android_fs_data_read_id_,
3813 [&, this](ArgsTracker::BoundInserter* inserter) {
3814 inserter->AddArg(file_path_id_,
3815 Variadic::String(context_->storage->InternString(
3816 base::StringView(decoder.pathbuf()))));
3817 inserter->AddArg(offset_id_start_, Variadic::Integer(decoder.offset()));
3818 inserter->AddArg(bytes_read_id_start_,
3819 Variadic::Integer(decoder.bytes()));
3820 });
3821 }
3822
ParseAndroidFsDatareadEnd(int64_t ts,ConstBytes data)3823 void FtraceParser::ParseAndroidFsDatareadEnd(int64_t ts, ConstBytes data) {
3824 protos::pbzero::AndroidFsDatareadEndFtraceEvent::Decoder decoder(data);
3825 auto* it = inode_offset_thread_map_.Find({decoder.ino(), decoder.offset()});
3826 if (!it) {
3827 return;
3828 }
3829 uint32_t start_event_tid = *it;
3830 inode_offset_thread_map_.Erase({decoder.ino(), decoder.offset()});
3831
3832 TrackId track_id = context_->track_compressor->InternEnd(
3833 kAndroidFsBlueprint, tracks::Dimensions(), start_event_tid);
3834 context_->slice_tracker->End(
3835 ts, track_id, kNullStringId, kNullStringId,
3836 [&, this](ArgsTracker::BoundInserter* inserter) {
3837 inserter->AddArg(offset_id_end_, Variadic::Integer(decoder.offset()));
3838 inserter->AddArg(bytes_read_id_end_,
3839 Variadic::Integer(decoder.bytes()));
3840 });
3841 }
3842
GetRpmStatusStringId(int32_t rpm_status_val)3843 StringId FtraceParser::GetRpmStatusStringId(int32_t rpm_status_val) {
3844 // `RPM_SUSPENDED` is omitted from this list as it would never be used as a
3845 // slice label.
3846 switch (rpm_status_val) {
3847 case RPM_INVALID:
3848 return runtime_status_invalid_id_;
3849 case RPM_SUSPENDING:
3850 return runtime_status_suspending_id_;
3851 case RPM_RESUMING:
3852 return runtime_status_resuming_id_;
3853 case RPM_ACTIVE:
3854 return runtime_status_active_id_;
3855 }
3856
3857 PERFETTO_DLOG(
3858 "Invalid runtime status value obtained from rpm_status ftrace event");
3859 return runtime_status_invalid_id_;
3860 }
3861
ParseRpmStatus(int64_t ts,protozero::ConstBytes blob)3862 void FtraceParser::ParseRpmStatus(int64_t ts, protozero::ConstBytes blob) {
3863 protos::pbzero::RpmStatusFtraceEvent::Decoder rpm_event(blob);
3864
3865 // Device here refers to anything managed by a Linux kernel driver.
3866 static constexpr auto kBlueprint = tracks::CounterBlueprint(
3867 "linux_rpm", tracks::UnknownUnitBlueprint(),
3868 tracks::DimensionBlueprints(tracks::kLinuxDeviceDimensionBlueprint));
3869 TrackId track_id =
3870 context_->track_tracker->InternTrack(kBlueprint, {rpm_event.name()});
3871
3872 // A `runtime_status` event implies a potential change in state. Hence, if
3873 // an active slice exists for this device, end that slice.
3874 if (active_rpm_tracks_.find(track_id) != active_rpm_tracks_.end()) {
3875 context_->slice_tracker->End(ts, track_id);
3876 }
3877
3878 // To reduce visual clutter, the "SUSPENDED" state will be omitted from the
3879 // visualization, as devices typically spend the majority of their time in
3880 // this state.
3881 int32_t rpm_status = rpm_event.status();
3882 if (rpm_status == RPM_SUSPENDED) {
3883 active_rpm_tracks_.erase(track_id);
3884 return;
3885 }
3886
3887 context_->slice_tracker->Begin(ts, track_id, /*category=*/kNullStringId,
3888 /*raw_name=*/GetRpmStatusStringId(rpm_status));
3889 active_rpm_tracks_.insert(track_id);
3890 }
3891
3892 // Parses `device_pm_callback_start` events and begins corresponding slices in
3893 // the suspend / resume latency UI track.
ParseDevicePmCallbackStart(int64_t ts,uint32_t cpu,uint32_t tid,protozero::ConstBytes blob)3894 void FtraceParser::ParseDevicePmCallbackStart(int64_t ts,
3895 uint32_t cpu,
3896 uint32_t tid,
3897 protozero::ConstBytes blob) {
3898 protos::pbzero::DevicePmCallbackStartFtraceEvent::Decoder dpm_event(blob);
3899
3900 // Device here refers to anything managed by a Linux kernel driver.
3901 std::string device_name = dpm_event.device().ToStdString();
3902 std::string driver_name = dpm_event.driver().ToStdString();
3903
3904 std::string slice_name = device_name + " " + driver_name;
3905 StringId slice_name_id = context_->storage->InternString(slice_name.c_str());
3906 int64_t cookie = slice_name_id.raw_id();
3907
3908 std::string callback_phase = ConstructCallbackPhaseName(
3909 /*pm_ops=*/dpm_event.pm_ops().ToStdString(),
3910 /*event_type=*/GetDpmCallbackEventString(dpm_event.event()));
3911
3912 TrackId track_id = context_->track_compressor->InternBegin(
3913 kSuspendResumeBlueprint, tracks::Dimensions(), cookie);
3914 context_->slice_tracker->Begin(
3915 ts, track_id, kNullStringId, slice_name_id,
3916 [&](ArgsTracker::BoundInserter* inserter) {
3917 inserter->AddArg(
3918 suspend_resume_utid_arg_name_,
3919 Variadic::UnsignedInteger(
3920 context_->process_tracker->GetOrCreateThread(tid)));
3921 inserter->AddArg(suspend_resume_event_type_arg_name_,
3922 Variadic::String(suspend_resume_device_pm_event_id_));
3923 inserter->AddArg(cpu_id_, Variadic::UnsignedInteger(cpu));
3924 inserter->AddArg(suspend_resume_device_arg_name_,
3925 Variadic::String(context_->storage->InternString(
3926 device_name.c_str())));
3927 inserter->AddArg(suspend_resume_driver_arg_name_,
3928 Variadic::String(context_->storage->InternString(
3929 driver_name.c_str())));
3930 inserter->AddArg(suspend_resume_callback_phase_arg_name_,
3931 Variadic::String(context_->storage->InternString(
3932 callback_phase.c_str())));
3933 });
3934 }
3935
3936 // Parses `device_pm_callback_end` events and ends corresponding slices in the
3937 // suspend / resume latency UI track.
ParseDevicePmCallbackEnd(int64_t ts,protozero::ConstBytes blob)3938 void FtraceParser::ParseDevicePmCallbackEnd(int64_t ts,
3939 protozero::ConstBytes blob) {
3940 protos::pbzero::DevicePmCallbackEndFtraceEvent::Decoder dpm_event(blob);
3941
3942 // Device here refers to anything managed by a Linux kernel driver.
3943 std::string device_name = dpm_event.device().ToStdString();
3944 std::string driver_name = dpm_event.driver().ToStdString();
3945
3946 std::string slice_name = device_name + " " + driver_name;
3947 StringId slice_name_id = context_->storage->InternString(slice_name.c_str());
3948 int64_t cookie = slice_name_id.raw_id();
3949
3950 TrackId track_id = context_->track_compressor->InternEnd(
3951 kSuspendResumeBlueprint, tracks::Dimensions(), cookie);
3952 context_->slice_tracker->End(ts, track_id);
3953 }
3954
ParsePanelWriteGeneric(int64_t timestamp,uint32_t pid,ConstBytes blob)3955 void FtraceParser::ParsePanelWriteGeneric(int64_t timestamp,
3956 uint32_t pid,
3957 ConstBytes blob) {
3958 protos::pbzero::PanelWriteGenericFtraceEvent::Decoder evt(blob);
3959 if (!evt.type()) {
3960 context_->storage->IncrementStats(stats::systrace_parse_failure);
3961 return;
3962 }
3963
3964 auto tgid = static_cast<uint32_t>(evt.pid());
3965 SystraceParser::GetOrCreate(context_)->ParseKernelTracingMarkWrite(
3966 timestamp, pid, static_cast<char>(evt.type()), false /*trace_begin*/,
3967 evt.name(), tgid, evt.value());
3968 }
3969
InternedKernelSymbolOrFallback(uint64_t key,PacketSequenceStateGeneration * seq_state)3970 StringId FtraceParser::InternedKernelSymbolOrFallback(
3971 uint64_t key,
3972 PacketSequenceStateGeneration* seq_state) {
3973 auto* interned_string = seq_state->LookupInternedMessage<
3974 protos::pbzero::InternedData::kKernelSymbolsFieldNumber,
3975 protos::pbzero::InternedString>(key);
3976 StringId name_id;
3977 if (interned_string) {
3978 protozero::ConstBytes str = interned_string->str();
3979 name_id = context_->storage->InternString(
3980 base::StringView(reinterpret_cast<const char*>(str.data), str.size));
3981 } else {
3982 base::StackString<255> slice_name("%#" PRIx64, key);
3983 name_id = context_->storage->InternString(slice_name.string_view());
3984 }
3985 return name_id;
3986 }
3987
ParseDeviceFrequency(int64_t ts,protozero::ConstBytes blob)3988 void FtraceParser::ParseDeviceFrequency(int64_t ts,
3989 protozero::ConstBytes blob) {
3990
3991 static constexpr auto kBlueprint = tracks::CounterBlueprint(
3992 "linux_device_frequency", tracks::UnknownUnitBlueprint(),
3993 tracks::DimensionBlueprints(tracks::kLinuxDeviceDimensionBlueprint),
3994 tracks::FnNameBlueprint([](base::StringView dev_name) {
3995 // The dev_name as is is prepended with an address (e.g. 17000000a), so
3996 // truncate that by searching for "devfreq_". This ensures that in all
3997 // cases, the track name is prefixed with "devfreq_", such that track
3998 // names will be in the form of "devfreq_bci", "devfreq_dsu", etc.
3999 std::string device = dev_name.ToStdString();
4000 auto position = device.find("devfreq_");
4001 return (position == std::string::npos)
4002 ? base::StackString<255>("devfreq_%s", device.c_str())
4003 : base::StackString<255>("%s", device.substr(position).c_str());
4004
4005 }));
4006 protos::pbzero::DevfreqFrequencyFtraceEvent::Decoder event(blob);
4007 TrackId track_id = context_->track_tracker->InternTrack(
4008 kBlueprint, tracks::Dimensions(event.dev_name()));
4009 context_->event_tracker->PushCounter(ts, static_cast<double>(event.freq()),
4010 track_id);
4011 }
4012
ParseParamSetValueCpm(protozero::ConstBytes blob)4013 void FtraceParser::ParseParamSetValueCpm(protozero::ConstBytes blob) {
4014 static constexpr auto kBlueprint = tracks::CounterBlueprint(
4015 "pixel_cpm_counters", tracks::UnknownUnitBlueprint(),
4016 tracks::DimensionBlueprints(tracks::kNameFromTraceDimensionBlueprint),
4017 tracks::FnNameBlueprint([](base::StringView body) {
4018 return base::StackString<255>("%.*s", int(body.size()), body.data());
4019 }));
4020 protos::pbzero::ParamSetValueCpmFtraceEvent::Decoder event(blob);
4021 TrackId track_id = context_->track_tracker->InternTrack(
4022 kBlueprint, tracks::Dimensions(event.body()));
4023 context_->event_tracker->PushCounter(static_cast<int64_t>(event.timestamp()),
4024 event.value(), track_id);
4025 }
4026
4027 namespace {
4028 constexpr auto kBlockTrackBlueprint = tracks::CounterBlueprint(
4029 "block_io",
4030 tracks::UnknownUnitBlueprint(),
4031 tracks::DimensionBlueprints(
4032 tracks::UintDimensionBlueprint("block_device")));
4033 }
4034
ParseBlockIoStart(int64_t ts,protozero::ConstBytes blob)4035 void FtraceParser::ParseBlockIoStart(int64_t ts, protozero::ConstBytes blob) {
4036 protos::pbzero::BlockIoStartFtraceEvent::Decoder event(blob);
4037 TrackId track_id =
4038 context_->track_tracker->InternTrack(kBlockTrackBlueprint, {event.dev()});
4039 context_->slice_tracker->Begin(
4040 ts, track_id, kNullStringId, block_io_id_,
4041 [this, &event](ArgsTracker::BoundInserter* inserter) {
4042 inserter->AddArg(block_io_arg_sector_id_,
4043 Variadic::UnsignedInteger(event.sector()));
4044 });
4045 }
4046
ParseBlockIoDone(int64_t ts,protozero::ConstBytes blob)4047 void FtraceParser::ParseBlockIoDone(int64_t ts, protozero::ConstBytes blob) {
4048 protos::pbzero::BlockIoDoneFtraceEvent::Decoder event(blob);
4049 TrackId track_id =
4050 context_->track_tracker->InternTrack(kBlockTrackBlueprint, {event.dev()});
4051 context_->slice_tracker->End(
4052 ts, track_id, kNullStringId, block_io_id_,
4053 [this, &event](ArgsTracker::BoundInserter* inserter) {
4054 inserter->AddArg(block_io_arg_sector_id_,
4055 Variadic::UnsignedInteger(event.sector()));
4056 });
4057 }
4058
4059 namespace {
4060 constexpr auto kCpuHpBlueprint = tracks::SliceBlueprint(
4061 "cpu_hotplug",
4062 tracks::DimensionBlueprints(tracks::kCpuDimensionBlueprint),
__anone76f5f404102(uint32_t cpu) 4063 tracks::FnNameBlueprint([](uint32_t cpu) {
4064 return base::StackString<255>("CPU Hotplug %u", cpu);
4065 }));
4066 }
4067
ParseCpuhpEnter(uint32_t fld_id,int64_t ts,uint32_t action_cpu,protozero::ConstBytes blob)4068 void FtraceParser::ParseCpuhpEnter(uint32_t fld_id,
4069 int64_t ts,
4070 uint32_t action_cpu,
4071 protozero::ConstBytes blob) {
4072 uint32_t hp_cpu = UINT32_MAX;
4073 int32_t idx = INT32_MAX;
4074 switch (fld_id) {
4075 case protos::pbzero::FtraceEvent::kCpuhpEnterFieldNumber: {
4076 protos::pbzero::CpuhpEnterFtraceEvent::Decoder cpuhp_event(blob);
4077 hp_cpu = cpuhp_event.cpu();
4078 idx = cpuhp_event.idx();
4079 break;
4080 }
4081 case protos::pbzero::FtraceEvent::kCpuhpMultiEnterFieldNumber: {
4082 protos::pbzero::CpuhpMultiEnterFtraceEvent::Decoder cpuhp_event(blob);
4083 hp_cpu = cpuhp_event.cpu();
4084 idx = cpuhp_event.idx();
4085 break;
4086 }
4087 default:
4088 // Only support hotplug_enter and hotplug_multi_enter
4089 return;
4090 }
4091
4092 // hp_cpu, the CPU being hotplugged, is stored in track dimension. action_cpu
4093 // is the CPU assisting hp_cpu in the hotplug operation. action_cpu could be
4094 // the hp_cpu itself or a different CPU, but the distinction is important
4095 // since it helps indicate when exactly the hp_cpu is powered off.
4096 StringId slice_name_id = context_->storage->InternString(
4097 base::StackString<32>("cpuhp(%d)", idx).string_view());
4098 TrackId track_id = context_->track_tracker->InternTrack(
4099 kCpuHpBlueprint, tracks::Dimensions(hp_cpu));
4100 context_->slice_tracker->Begin(
4101 ts, track_id, cpu_id_, slice_name_id,
4102 [&](ArgsTracker::BoundInserter* inserter) {
4103 inserter->AddArg(cpuhp_action_cpu_id_,
4104 Variadic::UnsignedInteger(action_cpu));
4105 inserter->AddArg(cpuhp_idx_id_, Variadic::Integer(idx));
4106 });
4107 }
4108
ParseCpuhpExit(int64_t ts,protozero::ConstBytes blob)4109 void FtraceParser::ParseCpuhpExit(int64_t ts, protozero::ConstBytes blob) {
4110 protos::pbzero::CpuhpExitFtraceEvent::Decoder cpuhp_event(blob);
4111 TrackId track_id = context_->track_tracker->InternTrack(
4112 kCpuHpBlueprint, tracks::Dimensions(cpuhp_event.cpu()));
4113 context_->slice_tracker->End(ts, track_id);
4114 }
4115 } // namespace perfetto::trace_processor
4116