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