通过 Perfetto 工具快速定位到audio卡顿杂音/Binder阻塞简单分析

sssyyxx

已于 2024-08-29 12:24:08 修改

阅读量3.1k

点赞数 46

文章标签： java 开发语言 android c++ 驱动开发音视频

于 2024-08-26 11:36:44 首次发布

本文链接：https://blog.youkuaiyun.com/qq_53303957/article/details/138602207

版权

本文主要通过 Perfetto 工具快速定位到audio卡顿杂音位置。并确认导致audio卡顿的大概原因。这里只关注audio卡顿的原因，不涉及触摸啊生命周期啊这类的东西。其实只算是一个简单的介绍，整个流程下基本也只能知道卡顿的问题，具体怎么解决卡顿还是需要自己根据实际情况去处理的。

一、准备

Chrome浏览器
trace文件
最好是一个竖着摆放的显示屏

将Chrome 浏览器放在竖屏显示器部分。打开网址 https://ui.perfetto.dev/#!/。将侧边菜单栏收起，我们用不到。然后将trace文件拖入网页内的任意区域。我们得到一个如下图的界面。那准备工作就完成。如果有报错，那说明你的trace文件需要做转换。可以自行百度一下。

CPU架构

简单来说目前的手机 CPU 按照核心数和架构来说，可以分为下面三类：

非大小核架构（正常所有核一样）
大小核架构（正常0-3小核，4-7大核）
大中小核架构（正常0-3小核，4-6中核，7超大核）

二、界面介绍

从上到下依次是

1.搜索栏

用pefetto自带的搜索框需要4个字符以上，搜出来的数据会比较详细，可以配合Ctrl+F一起使用，有时候Ctrl+F搜索不到的数据，需要自带的Search搜索

2.时间轴

3.CPU区

4.进程信息区

5.详细信息区

如果没有这个也没关系后面随便点个方块就有了。显示的就是点击方块的具体信息。

优先级：数字越大优先级越小

三、操作介绍

W	放大
S	缩小
D	右移
A	左移
F	精确定位	需要选中一个格子
M	框选	需要选中一个格子，或者在时间轴拖动一个范围。下面有一处会具体介绍。

基本操作还有疑问，可以在页面中shift+/ ，也就是“？”，通过官方提供的操作指南可以学习基本操作。

左键单击某个线程，既可看到详细信息，例如耗时等。再shift+M，可以精准标注该线程，使用鼠标左键长按整个区间，选择在需要分析的部分长按，既可获取在此期间的各个进程的操作，可以尝试一下各个操作。

shift+M:

四、查看线程状态

Perfetto 会用不同的颜色来标识不同的线程状态, 在每个方法上面都会有对应的线程状态来标识目前线程所处的状态，通过查看线程状态我们可以知道目前的瓶颈是什么, 是 cpu 执行慢还是因为 Binder 调用, 又或是进行 io 操作, 又或是拿不到 cpu 时间片，线程状态主要有下面几个：

绿色 : 运行中（Running）

只有在该状态的线程才可能在 cpu 上运行。而同一时刻可能有多个线程处于可执行状态，这些线程的task_struct 结构（线程所有信息）被放入对应 cpu 的可执行队列中（一个线程最多只能出现在一个 cpu 的可执行队列中）。调度器的任务就是从各个 cpu 的可执行队列中分别选择一个线程在该cpu 上运行。

浅绿色 : 可运行（Runnable）

线程可以运行但当前没有安排，在等待 cpu 调度

作用：Runnable 状态的线程状态持续时间越长，则表示 cpu 的调度越忙，没有及时处理到这个任务。

白色 : 休眠中（Sleep）

线程没有工作要做，可能是因为线程在互斥锁上被阻塞，也可能等待某个线程返回，可以看是被谁唤醒，去查看是等待哪个线程。

作用：这里一般是在等事件驱动。

橘色 : 不可中断的睡眠态（Uninterruptible Sleep - IO Block）

线程在I / O上被阻塞或等待磁盘操作完成，一般底线都会标识出此时的blocked function

作用：正常遇到的都是由于IO阻塞导致的。如果是大段的这个可以给性能组看一看。

棕色 : 不可中断的睡眠态（ Uninterruptible Sleep (non-IO)）

线程在另一个内核操作（通常是内存管理）上被阻塞。

作用：一般是陷入了内核态，有些情况下是正常的，有些情况下是不正常的，如果是大段的这个也可以给性能组看一看。

五、问题的修复节奏

以MTK平台为例，查看framework里服务层要往HAL写的数据的dump，也就是write.wav，未发现异常，说明上层服务传下来的音源数据是正常的。

再次查看HAL往kernel写的数据的dump，如果也是正常的，说明音源没问题。

那么总归就两种情祝:

1.overrun:写数据快，播数据慢，导致buffer满了，导致卡顿。

2.underrun:写数据慢，播数据快，导致buffer空了，无数据可播，出现卡顿。

此时咱们可以搜索以下log打印：get null buffer|underrun|buffer overflow|timeout

确认当前CPU loading状况

CPU Loading计算： Totals time/(Selection extent time*Online CPU Number）*100%

框选runnable 时间段的CPU各task的状况，然后查看CPU负载情况。

一般loading达到85%以上可以确认有loading 重的嫌疑。然后再查看CPU loading 排序，找出loading 排名前五的process，check是否有异常。

如果有异常背景进程（如JIT/heaptaskdaemon/kswapd等等），请先排除此类进程的影响后复测。

Low Memory

方法一：查看CPU占用率排名，如果kswapd0(内存置换)排CPU TOP3，很有可能发生Low memory issue。

方法二：检查debuglogger里面是否有low memory问题，搜索关键字“lowmemorykiller”

After kernel-4.14

lowmemorykiller: Kill 'com.google.android.apps.wellbeing' (17392), uid 10155, oom_adj 945 to free 11248kB

lowmemorykiller: Reclaimed 11248kB, cache(220756kB) and free(140600kB)-reserved(95248kB) below min(221184kB) for oom_adj 900

log说明：

adj越小说明系统lowmemory越严重

方法三：Trace中“Uninterruptible Sleep”状态 block 在如下几个地方： “do_page_fault balance_dirty_pages_ratelimited wait_on_page_bit_killable __lock_page_or_retry __lock_page wait_on_page_bit”等

添加systrace方法

native层用法

#define ATRACE_TAG ATRACE_TAG_ALWAYS

#include <utils/Trace.h> // for c++

#include <cutils/trace.h> // for c

ATRACE_CALL();

ATRACE_BEGIN();

ATRACE_END();

定义ATRACE_TAG：如使用了ATRACE_TAG_GRAPHICS，表示它和Graphics相关。

ATRACE_INIT：用于统计某个变量使用的情况。ATRACE_INIT(“变量TAG”，变量名)

ATRACE_CALL：用于统计函数的调用情况ATRACE_CALL()

app层

Trace.beginSection(“Fragement_onCreateView”);

// … 其他代码

// …

// … 结束处

Trace.endSection()

然后通过指令：python systrace.py --app=sectionName 指定APK，或者通过DDMS选择指定APK，抓取systrace分析

Java framework层

import android.os.Trace;

Trace.traceBegin(Trace.TRACE_TAG_VIEW, “Activity:setContentView”); //choose one tag from Trace.java

Trace.traceEnd(Trace.TRACE_TAG_VIEW);

Kernel

#define ATRACE_END() trace_printk(“tracing_mark_write: E\n”)

#define ATRACE_BEGIN(name) trace_printk(“tracing_mark_write: B|%d|%s\n”, current->tgid, name)

#define ATRACE_FUNC() ATRACE_BEGIN(func)

#define ATRACE_INT(name, value) trace_printk(“tracing_mark_write: C|%d|%s|%d\n”, current->tgid, name, (int)(value))

在audio中，可在

AudioFlinger::PlaybackThread::threadLoop_write()，

AudioPlayer::fillBuffer()，

OMXCodec::read()，

OMXCodec::drainInputBuffer()，

FileSource::readapt()

这几个函数中添加trace point，然后抓取systrace，看出现卡音时这些函数执行是否有异常（有没有被其他线程长时间block或者主动sleep很久），如果发现某个函数sleep很久，可以在该函数中继续添加trace point不断细化直到找出某一个具体的代码来（比如一直在某处等待lock）。

如果被其他线程block很久，则可以找对应模块owner一起check。

添加trace point方法如下：

1.在*.cpp文件顶部添加”#define ATRACE_TAG ATRACE_TAG_AUDIO”，接着下面添加”#include <utils/Trace.h>”

2.在你需要监控的代码段前后添加ATRACE_BEGIN(“XXX”);和ATRACE_END();，其中XXX是你自己需要定义的名字。具体实例可参看函数：“AudioFlinger::PlaybackThread::threadLoop_write()”

例子：

代码中audioflinger中write mixer线程中的trace位置：frameworks/av/services/audioflinger/Threads.cpp

疑问：在systrace中，如何通过log确认线程ID？

在systrace中，直接通过日志确认线程ID可能会有些困难，因为systrace主要是用来分析Android系统的性能，它收集并展示各种系统事件，如CPU使用情况、进程调度、线程状态等，而不是用来直接查看或解析日志的。

但是可以通过一些间接的方式在systrace中找到与线程相关的信息：

查看进程和线程活动：在systrace中，可以看到各个进程的CPU使用情况以及线程的调度情况。通过观察这些图形，可以大致了解哪些线程在何时处于活动状态。
使用标签：在代码中，可以使用Trace.beginSection()和Trace.endSection()来标记代码块，这样这些代码块在systrace中就会有明显的标识。
结合日志分析：虽然systrace本身不直接解析日志，但可以将systrace的数据与Logcat结合起来分析。首先，通过Logcat找到你感兴趣的线程ID或相关日志信息，然后在systrace中查找对应时间段内的活动线程。

任务唤醒信息分析

以上为分析整机性能问题导致audio出现问题的大致流程，接下来看看audio的trace分析

分别星标nRdy(服务层传下的要播放的数据)、AudioOut、mix、write这几个线程：

nRdy线程：这个线程可能与音频数据的非就绪状态（not ready）有关。它可能负责监视音频数据的准备情况，或者在数据到达之前执行一些预处理任务。当音频数据准备好播放或处理时，该线程可能会触发相应的操作。
fRdy0线程：这个线程可能表示与音频数据相关的某种特定类型的就绪状态（for ready）。它可能负责处理已经准备好的音频数据，或者执行与音频播放或录制相关的任务。

例：

如果发现AudioOut线程有一大段空白,没有被正常调度,说明上层write线程没有被正常调度,导致上层没有数据写下来,mix就没数据处理了,HAL里就就没数据write到kernel了,所以也就卡顿了。

audio主要关注AudioOut和FastMixer，检查write区间异常点，正常FastMixer写一次4ms，AudioOut写一次19ms（可以观察正常时间段）

一般情况下，audioflinger节点出现写0数据为AudioOut写异常，ADSP中节点出现mute数据为FastMixer写异常

可以使用下面的命令查看机器当前温度，看看是不是温度过高导致限频从而出现的杂音：

adb shell cat /sys/class/thermal/thermal_message/board_sensor_temp

确认问题时间点

通过log打印确认问题时间，也可以通过录屏，截图，测试描述等

还可以通过InputEvent用户交互事件和screen截图事件进行搜索

分析例：

搜索surfaceflinger ，查看时间点，看到包含问题时间点：

之后分别星标nRdy、AudioOut、write这几个线程：

nRdy是服务层传下的要播放的数据，可以看到，再HAL层的write线程，出现了一个橙色的长条和文章开头的拍照音卡顿的间隔时间差不多一样，就是这里出了问题。

这个橙色是Uninterruptible Sleep状态，看起来是卡IO了，从perfetto看，没有写non-IO或者IO，也不太确定是什么引起的，看唤醒关系的话，往后找running状态，找它是被谁唤醒的。

一般有Uninterruptible Sleep就可以找性能团队协助分析了。

绑核

如果是在kernel space 可以使用如下的api的方式去绑核。

1 int set_cpus_allowed_ptr(struct task_struct *p, const struct cpumask *new_mask)

2 如果是native的话用syscall的方式调用sched_setaffinity ,可以参考taskset.c 文件。

3 adb shell 方式

(1)adb shell taskset -ap f 1865 ap：1865 进程下的所有线程都绑核

f：绑的cpu是：0 -3 表示这个task允许被摆放的cpu，其每一个bit位代表一个cpu，如果为1表示允许摆放在当前cpu，否表示不允许。

如：0xf对应的二进制为：0000 1111;表示可以被摆放到cpu 0 1 2 3 ,不允许被摆放到cpu4 cpu5 cpu6 cpu7

(2)adb shell taskset -p f 1865 p：跟ap相比较，只绑定特定的线程1865

Binder

在systrace中，Binder Transaction是进程间发送请求或数据的操作，而Binder Reply则是对这些请求的响应。

很多卡顿问题和响应速度的问题，是因为跨进程 binder 通信的时候，锁竞争导致 binder 通信事件变长，影响了调用端。

Binder 主要是用来跨进程进行通信，可以看下面这张图，简单显示了在 Perfetto 中，Binder 通信是如何显示的

点击 Binder 可以查看其详细信息

争夺(contention)意思是这里由于在和目前对象的锁正被其他对象（Owner）所持有，所以没法得到该对象的锁的拥有权，所以进入该对象的锁池。

Owner : 指的是当前拥有这个对象的锁的对象，后面是其线程 ID。

monitor contention with owner binder:2069_1E (10742) at boolean android.os.MessageQueue.enqueueMessage(android.os.Message, long)(MessageQueue.java:583) waiters=0

Monitor 指的是当前锁对象的池，在 Java 中，每个对象都有两个池，锁(monitor)池和等待池：

锁池（同步队列 SynchronizedQueue ）：假设线程 A 已经拥有了某个对象(注意:不是类 )的锁，而其它的线程想要调用这个对象的某个 synchronized 方法(或者 synchronized 块)，由于这些线程在进入对象的 synchronized 方法之前必须先获得该对象的锁的拥有权，但是该对象的锁目前正被线程 A 拥有，所以这些线程就进入了该对象的锁池中。

Owner : 指的是当前拥有这个对象的锁的对象。这里是 binder:2069_1E ,10742 是其线程 ID。

at 后面跟的是拥有这个对象的锁的对象正在做什么。这里是在执行 boolean android.os.MessageQueue.enqueueMessage 这个方法，其代码位置是：MessageQueue.java:583

详细解释：

monitor contention：监视器争用。在多线程环境中，当多个线程尝试同时访问一个同步块或对象时，但一次只能有一个线程能够访问它，就会发生监视器争用。这通常发生在对象上的同步方法或同步块中。
with owner binder:2069_1E (10742)：这表示当前持有监视器（即锁）的线程与某个Binder对象（在Android中用于进程间通信）相关联，其标识符为2069_1E，并且该线程的ID是10742。
at boolean android.os.MessageQueue.enqueueMessage(android.os.Message, long)(MessageQueue.java:583)：这指出争用发生在MessageQueue类的enqueueMessage方法上，位于MessageQueue.java文件的第583行。enqueueMessage方法用于向消息队列中添加一个消息。
waiters=0：表示当前没有线程在等待获取这个监视器锁。
blocking from android.os.Message android.os.MessageQueue.next()(MessageQueue.java:346)：这表示有一个线程被阻塞在MessageQueue类的next方法上，该方法试图从消息队列中获取下一个消息。它位于MessageQueue.java文件的第346行。