加入星計(jì)劃,您可以享受以下權(quán)益:

  • 創(chuàng)作內(nèi)容快速變現(xiàn)
  • 行業(yè)影響力擴(kuò)散
  • 作品版權(quán)保護(hù)
  • 300W+ 專業(yè)用戶
  • 1.5W+ 優(yōu)質(zhì)創(chuàng)作者
  • 5000+ 長(zhǎng)期合作伙伴
立即加入
  • 正文
    • 1、簡(jiǎn)介
    • 2、宏定義
    • 3、抓 i2c trace
  • 相關(guān)推薦
  • 電子產(chǎn)業(yè)圖譜
申請(qǐng)入駐 產(chǎn)業(yè)圖譜

手把手教你使用 ftrace

2022/10/31
3846
閱讀需 19 分鐘
加入交流群
掃碼加入
獲取工程師必備禮包
參與熱點(diǎn)資訊討論

最近遇到 i2c 傳輸慢的問題,正常一筆 i2c 傳輸 52 bytes 應(yīng)該在 1ms 內(nèi)返回,但是偶爾出現(xiàn) 6 ~ 7ms 才返回,不滿足要求,因此研究一下 ftrace 工具,分析 i2c 傳輸?shù)降茁谀睦铩岩桑?/p>

同一路 i2c bus 掛載設(shè)備多,可能同時(shí)發(fā)起傳輸,導(dǎo)致?lián)屨肌#ń鉀Q方法:重要器件獨(dú)占一路 i2c bus)

i2c 硬件傳輸慢。一般不太可能,因?yàn)檫@是硬件行為,除非從機(jī)返回慢。(研究從機(jī)為什么慢)

i2c 傳輸完成后返回,i2c 控制器發(fā)傳輸完成的信號(hào)給 cpu,但 cpu 忙 loading 重,沒有及時(shí)調(diào)用 i2c_reply 通知調(diào)用者;或者是 i2c 傳輸完成后,CPU 處于睡眠狀態(tài),由于 i2c 中斷無法喚醒系統(tǒng),系統(tǒng)醒了以后才返回,導(dǎo)致慢。(提升 user 線程優(yōu)先級(jí) + 讓這一路 i2c bus 持鎖,可以優(yōu)化)

1、簡(jiǎn)介

strace:用來跟蹤 Linux 進(jìn)程執(zhí)行時(shí)的系統(tǒng)調(diào)用和接收所接收的信號(hào),可以跟蹤到一個(gè)進(jìn)程產(chǎn)生的系統(tǒng)調(diào)用,包括參數(shù),返回值,執(zhí)行消耗的時(shí)間。

ftrace:是一個(gè) Linux 內(nèi)核函數(shù)跟蹤器,function tracer,旨在幫助開發(fā)人員和系統(tǒng)設(shè)計(jì)者可以找到內(nèi)核內(nèi)部發(fā)生的事情,從 Linux-2.6 內(nèi)核就支持了。

atrace:Android tracer,使用 ftrace 來跟蹤 Android 上層的函數(shù)調(diào)用。

systrace:Android 的 trace 數(shù)據(jù)分析工具,將 atrace 采集上來的數(shù)據(jù),以圖形化的方式展現(xiàn)出來。systrace 是分析 Android 設(shè)備性能的主要工具。不過,它實(shí)際上是多種其他工具的封裝容器:它是 atrace 的主機(jī)端封裝容器。atrace 是用于控制用戶空間跟蹤和設(shè)置 ftrace 的設(shè)備端可執(zhí)行文件,也是 Linux 內(nèi)核中的主要跟蹤機(jī)制。systrace 使用 atrace 來啟用跟蹤,然后讀取 ftrace 緩沖區(qū)并將其全部封裝到一個(gè)獨(dú)立的 HTML 查看器中。

perfetto:新一代 systrace 分析工具,使用 perfetto 工具,可以通過 Android 調(diào)試橋 (ADB) 在 Android 設(shè)備上收集性能信息。perfetto 從您的設(shè)備上收集性能跟蹤數(shù)據(jù)時(shí)會(huì)使用多種來源,例如:使用 ftrace 收集內(nèi)核信息、使用 atrace 收集服務(wù)和應(yīng)用中的用戶空間注釋、使用 heapprofd 收集服務(wù)和應(yīng)用的本地內(nèi)存使用情況信息。

在 Android 9 (P) 及以上版本平臺(tái)都可用,但只有在 Android 11 (R) 及以上的版本中才默認(rèn)啟用。在Android 9 (P) 和 10 (Q) 上,你需要執(zhí)行下面的命令,以確保在一切開始之前跟蹤服務(wù)正常啟動(dòng):

# Needed only on Android 9 (P) and 10 (Q) on non-Pixel phones.
adb shell setprop persist.traced.enable 1

conperf:CPU Freq 分析工具

LTR:Long Trace Recoder,可以錄制長(zhǎng)達(dá)半個(gè)小時(shí)的 trace,主要用于分析游戲場(chǎng)景。

因此,首先需要學(xué)習(xí) ftrace,它是其他 trace 的基礎(chǔ)。

2、宏定義

在使用 ftrace 之前,需要確保內(nèi)核配置編譯了其配置選項(xiàng)。

CONFIG_FTRACE=y
CONFIG_HAVE_FUNCTION_TRACER=y
CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
CONFIG_HAVE_DYNAMIC_FTRACE=y
CONFIG_FUNCTION_TRACER=Y
CONFIG_IRQSOFF_TRACER=y
CONFIG_SCHED_TRACER=y
CONFIG_ENABLE_DEFAULT_TRACERS=y
CONFIG_FTRACE_SYSCALLS=y
CONFIG_PREEMPT_TRACER=y

而后在 /sys/kernel/debug/trace 目錄下提供了各種跟蹤器(tracer)和 event 事件,一些常用的選項(xiàng)如下。

available_tracers:列出當(dāng)前系統(tǒng)支持的跟蹤器。

available_events:列出當(dāng)前系統(tǒng)支持的 event 事件。

current_tracer:設(shè)置和顯示當(dāng)前正在使用的跟蹤器。使用 echo 命令可以把跟蹤器的名字寫入該文件,即可以切換不同的跟蹤器。默認(rèn)為 nop,即不做任何跟蹤操作。

trace:讀取跟蹤信息。通過 cat 命令查看 ftrace 記錄下來的跟蹤信息。

tracing_on:用于開始或暫停跟蹤。

trace_options:設(shè)置 ftrace 的一些相關(guān)選項(xiàng)。

ftrace 當(dāng)前包含多個(gè)跟蹤器,很方便用戶用來跟蹤不同類型的信息,例如進(jìn)程睡眠喚醒、搶占延遲的信息。查看 available_tracers 可以知道當(dāng)前系統(tǒng)支持哪些跟蹤器,如果系統(tǒng)支持的跟蹤器上沒有用戶想要的,那就必須在配置內(nèi)核時(shí)自行打開,然后重新編譯內(nèi)核。常用的 ftrace 跟蹤器如下。

nop:不跟蹤任何信息。將 nop 寫入 current_tracer 文件可以清空之前收集到的跟蹤信息。

function:跟蹤內(nèi)核函數(shù)執(zhí)行情況。

function_graph:可以顯示類似 C 語言的函數(shù)調(diào)用關(guān)系圖,比較直觀。

wakeup:跟蹤進(jìn)程喚醒信息。

irqsoff:跟蹤關(guān)閉中斷信息,并記錄關(guān)閉的最大時(shí)長(zhǎng)。

preemptoff:跟蹤關(guān)閉禁止搶占信息,并記錄關(guān)閉的最大時(shí)長(zhǎng)。

preemptirqsoff:綜合了 irqoff 和 preemptoff 兩個(gè)功能。

sched_switch:對(duì)內(nèi)核中的進(jìn)程調(diào)度活動(dòng)進(jìn)行跟蹤。

 

3、抓 i2c trace

adb root

echo nop > /sys/kernel/debug/tracing/current_tracer  //清空以前的跟蹤信息
echo 1 > /sys/kernel/debug/tracing/events/i2c/enable
echo 1 > /sys/kernel/debug/tracing/trasing_on  //打開跟蹤器

操作設(shè)備,復(fù)現(xiàn)問題。

echo 0 > /sys/kernel/debug/tracing/tracing_on//關(guān)閉跟蹤器

adb pull /sys/kernel/debug/tracing/trace

如下目錄也可以操作:

/sys/kernel/tracing/

adb pull 出來的 trace 文件如下:

# tracer: nop
#
# entries-in-buffer/entries-written: 1203/1087390   #P:6
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
   kworker/u12:0-6     [003] ...1   253.195437: i2c_reply: i2c-1 #1 a=038 f=0001 l=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] ...1   253.195440: i2c_result: i2c-1 n=2 ret=2
   kworker/u12:0-6     [003] ...1   253.257546: i2c_write: i2c-1 #0 a=038 f=0000 l=1 [00]
   kworker/u12:0-6     [003] ...1   253.257550: i2c_read: i2c-1 #1 a=038 f=0001 l=63
   kworker/u12:0-6     [003] ...1   253.263708: i2c_reply: i2c-1 #1 a=038 f=0001 l=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] ...1   253.263711: i2c_result: i2c-1 n=2 ret=2
   kworker/u12:5-223   [003] ...1   254.632061: i2c_write: i2c-1 #0 a=038 f=0000 l=1 [00]
   kworker/u12:5-223   [003] ...1   254.632064: i2c_read: i2c-1 #1 a=038 f=0001 l=63
   kworker/u12:5-223   [003] ...1   255.728473: i2c_result: i2c-1 n=1 ret=1
   kworker/u12:5-223   [003] ...1   255.728499: i2c_write: i2c-1 #0 a=01a f=0000 l=3 [63-a8-10]
   kworker/u12:4-222   [003] ...1   266.944488: i2c_write: i2c-1 #0 a=038 f=0000 l=1 [00]
   kworker/u12:4-222   [003] .n.1   266.944492: i2c_read: i2c-1 #1 a=038 f=0001 l=63
   kworker/u12:1-53    [003] ...1   268.822588: i2c_reply: i2c-1 #1 a=038 f=0001 l=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] ...1   268.822591: i2c_result: i2c-1 n=2 ret=2
   kworker/u12:1-53    [003] ...1   268.822650: i2c_write: i2c-1 #0 a=038 f=0000 l=1 [00]
   kworker/u12:1-53    [003] ...1   268.822651: i2c_read: i2c-1 #1 a=038 f=0001 l=63
   kworker/u12:0-6     [003] ...1   271.457514: i2c_write: i2c-1 #0 a=038 f=0000 l=1 [00]
   kworker/u12:0-6     [003] ...1   271.457518: i2c_read: i2c-1 #1 a=038 f=0001 l=63

這里看出,是哪個(gè) task,PID 是多少,用的 I2C-1 進(jìn)行通信,傳輸過程是跑在 CPU3 上面,并且有 kernel 時(shí)間戳。

i2c_write、i2c_read、i2c_reply、i2c_result 是一個(gè)循環(huán),i2c_reply 是 i2c 傳輸完成,并且重新被 CPU 調(diào)度,返回到調(diào)用線程的時(shí)間點(diǎn),i2c_result 則是兩次 i2c 傳輸?shù)臅r(shí)間間隔。

每一筆 i2c 傳輸?shù)拈L(zhǎng)度,內(nèi)容,也都會(huì)打印出來。

因?yàn)椴┲饕婚_始只在 events 里面 enable 了 i2c,因此只抓除了 i2c 部分,我們可以同時(shí) enable 其他事件:

如果我們同時(shí) enable i2c 和 irq ,我們將在 trace 中看到更詳細(xì)的內(nèi)容,足夠分析 i2c 傳輸慢的問題。

詳細(xì)的 ftrace 原理和使用方法,請(qǐng)參考《奔跑吧 Linux 內(nèi)核 入門篇》11.3節(jié),或者《奔跑吧 Linux 內(nèi)核基于 Linux4.x 內(nèi)核源代碼問題分析》6.2節(jié)。

相關(guān)推薦

電子產(chǎn)業(yè)圖譜

研究生在讀,熟悉硬件、STM32單片機(jī)、嵌入式Linux。已收獲小米、聯(lián)發(fā)科、浙江大華、上能電氣、英威騰、匯川技術(shù)、格力、富士康等大廠offer。在這里分享求職經(jīng)驗(yàn)、嵌入式學(xué)習(xí)規(guī)劃、考研、嵌入式Linux技術(shù)文章等。