最近遇到了i2c传输慢的问题。正常的52字节的i2c传输应该在1ms以内返回，但是偶尔需要6~7ms才返回，不符合要求。因此研究ftrace工具，分析i2c传输慢。在哪里。疑点：同一个i2c总线上挂载了很多设备，可能同时发起传输，造成抢占。（解决办法：重要设备独占了一条i2c总线）i2c硬件传输慢。通常不太可能，因为这是硬件行为，除非从设备返回缓慢。（研究slave为什么慢）i2c传输完成后return，i2ccontroller向cpu发送传输完成信号，但是cpu忙于重载，没有及时调用i2c_reply通知调用者；或者i2c传输完成后，CPU处于休眠状态，由于i2c中断无法唤醒系统，唤醒后系统返回，导致速度慢。（提高用户线程优先级+让这个i2c总线持有锁，可以优化）1.简介strace：用于跟踪linux进程执行时的系统调用和接收信号，可以跟踪某个进程产生的系统调用过程。包括参数、返回值、执行时间。ftrace:ItisaLinuxkernelfunctiontracer,函数跟踪器，旨在帮助开发者和系统设计者发现内核内部发生了什么，从Linux-2.6内核开始支持。atrace：Androidtracer，使用ftrace跟踪Android上层的函数调用。systrace：Android的trace数据分析工具，将atrace采集到的数据以图形化的方式展示出来。systrace是分析Android设备性能的主要工具。然而，它实际上是其他几个工具的包装器：它是atrace的主机端包装器。atrace是一个设备端可执行文件，用于控制用户空间跟踪和设置ftrace，这是Linux内核中的主要跟踪机制。systrace使用atrace来启用跟踪，然后读取ftrace缓冲区并将其全部包装到一个独立的HTML查看器中。perfetto：新一代的systrace分析工具，使用perfetto工具，可以通过Android调试桥（ADB）收集Android设备的性能信息。perfetto使用多种来源从您的设备收集性能跟踪数据，例如：使用ftrace收集内核信息，使用atrace收集服务和应用程序中的用户空间注释，以及使用heapprofd收集服务和应用程序的本地内存使用信息。适用于Android9(P)及更高版本，但仅在Android11(R)及更高版本中默认启用。在Android9(P)和10(Q)上，您需要执行以下命令以确保跟踪服务在一切开始之前正常启动：#NeededonlyonAndroid9(P)and10(Q)onnon-Pixelphones.adbshellsetproppersist.traced.enable1LTR：LongTraceRecoder，最长可记录半小时的trace，主要用于分析游戏场景。因此，首先需要学习ftrace，它是其他trace的基础。2.宏定义在使用ftrace之前，需要确保内核配置已经编译了它的配置选项。CONFIG_FTRACE=yCONFIG_HAVE_FUNCTION_TRACER=yCONFIG_HAVE_FUNCTION_GRAPH_TRACER=yCONFIG_HAVE_DYNAMIC_FTRACE=yCONFIG_FUNCTION_TRACER=YCONFIG_IRQSOFF_TRACER=yCONFIG_SCHED_TRACER=yCONFIG_ENABLE_DEFAULT_TRACERS=yCONFIG_FTRACE_SYSCALLS=yCONFIG_PREEMPT_TRACER=y而后在/sys/kernel/debug/trace目录下提供了各种跟踪器(tracer)和event事件，一些常用的选项如下。available_tracers：列出系统当前支持的示踪剂。available_events：列出当前系统支持的event事件。current_tracer：设置并显示当前使用的示踪剂。使用echo命令将tracker的名称写入文件，即可以在不同的tracker之间切换。默认为nop，即不进行跟踪操作。trace：读取跟踪信息。使用cat命令查看ftrace记录的trace信息。tracing_on：用于开始或暂停跟踪。trace_options：设置ftrace的一些相关选项。nop：不跟踪任何信息。向current_tracer文件写入nop以清除之前收集的跟踪信息。function：跟踪内核函数的执行情况。function_graph：可以显示类似C语言的函数调用图，更直观。wakeup：跟踪进程唤醒信息。irqsoff：跟踪关机中断信息，记录关机的最长持续时间。preemptoff：跟踪shutdown禁止抢占信息，记录shutdown的最长持续时间。preemptirqsoff：结合了irqoff和preemptoff的功能。sched_switch：跟踪内核中的进程调度活动。3.Capturei2ctraceadbrootadbrootechonop>/sys/kernel/debug/tracing/current_tracer//清除之前的trace信息echo1>/sys/kernel/debug/tracing/events/i2c/enableecho1>/sys/kernel/debug/tracing/trasing_on//开启tracer操作设备，重现问题。echo0>/sys/kernel/debug/tracing/tracing_on//关闭trackeradbpull/sys/kernel/debug/tracing/trace下面目录也可以操作：/sys/kernel/tracing/adb拉出跟踪文件如下：#tracer:nop##entries-in-buffer/entries-written:1203/1087390#P:6##_------=>irqs-off#/_----=>需要重新安排#|/_---=>硬中断/软中断#||/_--=>抢占深度#|||/delay#TASK-PIDCPU#||||时间戳函数#|||||||||kworker/u12:0-6[003]...1253.195437:i2c_reply:i2c-1#1a=038f=0001l=63[00-00-01-81-68-03-72-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00]kworker/u12:0-6[003]...1253.195440:i2c_result:i2c-1n=2ret=2kworker/u12:0-6[003]...1253.257546:i2c_write:i2c-1#0a=038f=0000l=1[00]kworker/u12:0-6[003]...1253.257550:i2c_read:i2c-1#1a=038f=0001l=63kworker/u12:0-6[003]...1253.263708:i2c_reply:i2c-1#1a=038f=0001l=63[00-00-01-81-68-02-d0-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00]kworker/u12:0-6[003]...1253.263711:i2c_result:i2c-1n=2ret=2kworker/u12:5-223[003]...1254.632061:i2c_write:i2c-1#0a=038f=0000l=1[00]kworker/u12:5-223[003]...1254.632064:i2c_read:i2c-1#1a=038f=0001l=63kworker/u12:5-223[003]...1255.728473:i2c_result:i2c-1n=1ret=1kworker/u12:5-223[003]...1255.728499:i2c_write:i2c-1#0a=01af=0000l=3[63-a8-10]kworker/u12:4-222[003]...1266.944488:i2c_write:i2c-1#0a=038f=0000l=1[00]kworker/u12:4-222[003].n.1266.944492:i2c_read:i2c-1#1a=038f=0001l=63kworker/u12:1-53[003]...1268.822588:i2c_reply:i2c-1#1a=038f=0001l=63[00-00-00-40-00-01-c4-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-ff-ff-ff-ff-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00]kworker/u12:1-53[003]...1268.822591:i2c_result:i2c-1n=2ret=2kworker/u12:1-53[003]...1268.822650:i2c_write:i2c-1#0a=038f=0000l=1[00]kworker/u12:1-53[003]...1268.822651:i2c_read:i2c-1#1a=038f=0001l=63kworker/u12:0-6[003]...1271.457514:i2c_write:i2c-1#0a=038f=0000l=1[00]kworker/u12:0-6[003]...1271.457518:i2c_read:i2c-1#1a=038f=0001l=63这里可以看到那是哪个任务，PID是多少，I2C-1是用来通信的，传输过程是在CPU3上运行的，有内核时间戳传输，并且是r被CPU调度，返回调用线程的时间点，i2c_result为两次i2c传输的时间间隔。每个i2c传输的长度和内容也会被打印出来。因为博主一开始只在events中开启了i2c，所以只抓到了i2c部分，我们可以同时开启其他事件：如果同时开启i2c和irq，我们会在trace中看到更详细的内容，这足以分析i2c传输慢的问题。
