手把手教你分析 Trace,你学会了吗?

开发 前端
为了方便大家抓 trace,博主写了一个 bat 脚本,大家在 windows 环境下,直接双击运行,按照提示三次回车即可,抓到的 trace 会输出在当前文件,名字是 SYS_TRACE。

博主示例用的 RK3399,跑的 Android 8.1。

为了方便大家抓 trace,博主写了一个 bat 脚本,大家在 windows 环境下,直接双击运行,按照提示三次回车即可,抓到的 trace 会输出在当前文件,名字是 SYS_TRACE。

my_trace.bat

@echo off

rem in /sys/kernel/debug/tracing/ or /sys/kernel/tracing/ , please confirm by yourself

adb root

adb shell "echo 65536 > /sys/kernel/debug/tracing/buffer_size_kb"
echo "buffer_size_kb(per cpu): "
adb shell "cat /sys/kernel/debug/tracing/buffer_size_kb"

adb shell "echo nop > /sys/kernel/debug/tracing/current_tracer" >nul 2>&1
adb shell "echo 'noprint-tgid' > /sys/kernel/tracing/trace_options" >nul 2>&1

rem clear ftrace events
adb shell "echo > /sys/kernel/debug/tracing/set_event"

rem enable profiling events here,with loop
for %%x in (
sched_switch
sched_wakeup
sched_wakeup_new
sched_migrate_task
softirq_raise
softirq_entry
softirq_exit
ipi
irq
irq_handler_entry
irq_handler_exit
cpu_frequency
workqueue_execute_start
workqueue_execute_end
timer
clk
suspend_resume
device_pm_callback_start
device_pm_callback_end
cpu_idle
pm_qos_update_request
i2c
f2fs
suspend_resume
) do (
adb shell "echo %%x >> /sys/kernel/debug/tracing/set_event"
)

rem just in case tracing_enabled is disabled by user or other debugging tool
adb shell "echo 1 > /sys/kernel/debug/tracing/tracing_enabled" >nul 2>&1
adb shell "echo 0 > /sys/kernel/debug/tracing/tracing_on"

rem erase previous recorded trace
adb shell "echo > /sys/kernel/debug/tracing/trace"
echo press any key to start capturing...
pause

adb shell "echo 1 > /sys/kernel/debug/tracing/tracing_on"
echo "Start recordng ftrace data"
echo "Press any key to stop..."
pause

adb wait-for-device
adb shell "echo 0 > /sys/kernel/debug/tracing/tracing_on"
echo "Recording stopped..."

adb shell "ps -AT" > ps_1.txt
adb shell cat /sys/kernel/debug/tracing/trace > SYS_FTRACE
adb shell "ps -AT" > ps_2.txt
adb shell "echo noprint-tgid > /sys/kernel/debug/tracing/trace_options" >nul 2>&1

rem default size
adb shell "echo 4096 > /sys/kernel/debug/tracing/buffer_size_kb"
pause

这个脚本重要的地方都有注释,rem 开头的都是注释,请注意看第一个注释。

大概框架就是先把每个 CPU 的 buffer 设置为 65536,然后把想要抓取的 events 通过 for 循环设置进去,然后开启抓取,这时候你可以在设备上操作,复现问题,复现出来后,再停止抓取,并且把抓到的 trace 拉出来。

运行完毕后目录如下:

图片

SYS_TRACE 如下:

图片

本次我们只分析 i2c 问题,因此通过 grep 工具把 i2c 相关的提取出来。博主在 i2c4 上挂载了三个设备,通过 cat /proc/interrputs 确认 i2c4 的软件中断号是 41,则提取命令如下:

grep -e "irq=41" -e "i2c-4" SYS_FTRACE > i2c4-20221106.txt

则提取出来的内容只包含 i2c4 部分,截取一部分分析:

图片

i2c_read 到 irq_handler_entry 慢:

该路 I2C4 挂载设备过多,同时发起通信会抢占。

发起 i2c 传输的 user 线程优先级低,当多个设备同时发起 i2c 传输,或者前面已经有几个设备在等待,你的设备就拿不到锁,就一直排在后面。

硬件传输耗时久:比如从机有问题,或者 i2c 速率设置不对,用示波器可以抓到。

irq_handler_exit 到 i2c_reply 慢:

  1. 发起 i2c 传输的 user 线程优先级低,i2c 中断来了以后叫起 user 线程,但是被高优先级线程抢占,user 线程一直得不到 CPU 调度。
  2. 很多时候为了功耗,会设置 i2c 中断无法打醒 CPU。比如在 CPU0 发起一次 i2c 通信,CPU0 并没有等其返回,没事做就进入了 idle 状态,i2c 中断来了以后唤醒不了 CPU0,导致慢。【该原因和调度策略也有关系,当其他 CPU 空闲时候,user 线程应该调度到其他 CPU 处理才对】

总结来讲:

  1. 如果是 user 线程优先级低,则你观察到的 i2c 传输耗时是整体慢。
  2. 如果是 CPU 进入 idle 导致你的 i2c 传输耗时,则是概率性出现,并且耗时偶尔会出现 15-25ms 这种级别,无法忍受。
责任编辑:武晓燕 来源: 嵌入式Linux系统开发
相关推荐

2021-01-20 10:18:48

MySQL服务器配置

2022-10-30 10:31:42

i2ccpuftrace

2023-12-06 08:28:44

礼物系统用例图

2020-04-14 10:20:12

MySQL数据库死锁

2023-08-26 21:34:28

Spring源码自定义

2009-07-03 17:15:31

jsp上传文件

2010-08-09 09:25:23

SQL Server镜

2017-05-18 12:45:35

数据分析数据理解数据

2011-05-03 15:59:00

黑盒打印机

2011-01-10 14:41:26

2021-09-18 14:26:49

Linux Linux 启动流程Linux 系统

2023-06-27 07:21:51

前端开发坑点

2011-02-22 13:46:27

微软SQL.NET

2021-02-26 11:54:38

MyBatis 插件接口

2021-12-28 08:38:26

Linux 中断唤醒系统Linux 系统

2024-01-02 12:05:26

Java并发编程

2023-08-01 12:51:18

WebGPT机器学习模型

2022-10-18 17:59:46

Bootstrap源码父类

2023-03-08 08:42:55

MySQLcost量化

2015-10-26 09:24:30

微信公众号数据分析
点赞
收藏

51CTO技术栈公众号