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