从Perfetto视角看Audio异常underrun问题的表现

原创于 2025-11-04 15:24:36 发布 · 801 阅读

17 ·

CC 4.0 BY-SA版权

文章标签：

#android #安卓framework开发 #framework #audio #Perfetto #systrace

audio 专栏收录该内容

23 篇文章

订阅专栏

背景

经常在会有测试会报一些app在某些时候会有声音卡顿，或者说录音的文件异常问题，这种情况下一般我们可以叫做Xrun

正常underrun & overrun定义

我们知道，在Audio模块中数据采用的是生产者-消费者模式，生产者负责生产数据，消费者用于消费数据，针对AudioTrack和AudioRecord，其对应的角色不同；

AudioTrack
生产者：AudioTrack，向sharedBuffer中添加数据；
消费者：PlaybackThread（AudioFlinger），从sharedBuffer中读取数据；
AudioRecord
生产者：AudioFlinger（输入设备），向指定sharedBuffer中添加数据；
消费者：AudioRecord，从sharedBuffer中读取数据；
欠载 ( UnderRun ) : 播放音频流时 , 如果当前现有数据已经播放完毕 , 新数据还没有来得及写入 , 此时会发生欠载情况，现象为断断续续，一卡一卡；
超限 ( OverRun ) : 录制音频流时 , 如果没有及时读取音频流数据 , 并且这些数据没有妥善保存 , 发生溢出 , 导致数据丢失 , 这种情况叫做超限，现象为“爆”音；
今天就以一个underrun的案例来展示一下这种underrun问题在Perfetto上的表现。

分析underrun方法

一般确定当前系统发出声音是否有underrun现象一般可以通过以下2种方式进行确定：
1、使用logcat抓日志方式，在日志中如果频繁出现大量的underrun关键字符就说明声音是underrun了。

adb logcat  | grep underrun

可以看到有频繁的underrun相关打印，而且是framesReady(192) < framesDesired(1090)即AudioTrack汇总准备好的buf数目远远小于预期的framesDesired数量。

V AudioFlinger: track(60) underrun, track state ACTIVE  framesReady(192) < framesDesired(1090)

在这里插入图片描述
看到上面的打印再结合听到的一卡一卡现象，就可以断定系统当前声音处于underrun状态。

2、可以采用音频课程中给大家讲解的teesink方式，导出系统各个阶段的音频，然后使用audacity软件进行播放查看。
去放开teesink，然后采用dumpsys media.audio_flinger命令进行导出相关过程的音频文件。
在这里插入图片描述

导出各个阶段的teesink音频文件进行确认underrun问题

在这里插入图片描述
然后把他们都导入到Audacity软件，展示相关的波形情况：

在这里插入图片描述
时间轴放大看更加清晰
上图明显可以看出AudioTrack的数据展示情况结论如下：
1、AudioTrack数据明显看波形和播放后都正常
2、MixerThread中写入hal的数据部分，明显看着波形间隔比较大，整个时间长也比AudioTrack大好多，而且听起来声音一卡一卡，没办法接受。

通过上面导出音频波形分析就可以直接确定声音一卡一卡问题其实是出在MixerThread的自身逻辑么？
哈哈，其实答案肯定不是出在MixerThread部分，具体答案继续看下面Perfetto部分对underrun的剖析及后续的文章或者课程的原因定位部分？

underrun情况下声音卡顿的Perfetto/systrace剖析

这块就需要结合源码和Perfetto systrace进行剖析
对比正常和异常情况播放声音抓取的Perfetto展示
正常模式下Perfetto展示：
在这里插入图片描述异常underrun情况下展示：

明显和正常情况一样时间内多了5ms左右sleep时间

在这里插入图片描述同样buf部分发现只有几百个，而且频繁变化，明显看出数据buf不足。
但是数据buf不足正常那就不足，正常我们想象就一直等待数据满足了后再进行thread_write写入数据到hal，那这样只是说数据要过一会才播放，能理解听到的效果一卡一卡，但是AudioTrack发送过来的数据应该是是按照顺序写入应该是要正常的，没有数据就不进行写入，这样来看那么MixerThread导出的wav文件也应该要正常？

那么为啥这里的MixerThread的数据导出的wav文件，发现数据就是一卡一卡，明显波形也是不对的。

这块就留给课程中马哥带大家进行剖析，具体关注马哥的这块讲解，或者大家也可以自行进行额外添加atrace打印进行Perfetto分析出原因。

当然这块马哥也加了大量的额外trace：

@@ -1473,12 +1473,14 @@ void AudioMixerBase::process__noResampleOneTrack()
     TO* out = reinterpret_cast<TO*>(t->mainBuffer);
     TA* aux = reinterpret_cast<TA*>(t->auxBuffer);
     const bool ramp = t->needsRamp();
-
+    {
+    }
     for (size_t numFrames = mFrameCount; numFrames > 0; ) {
         AudioBufferProvider::Buffer& b(t->buffer);
         // get input buffer
         b.frameCount = numFrames;
         t->bufferProvider->getNextBuffer(&b);
+        ATRACE_FORMAT("process__noResampleOneTrack mFrameCount %d  b.frameCount %d",mFrameCount, b.frameCount);
         const TI *in = reinterpret_cast<TI*>(b.raw);
 
         // in == NULL can happen if the track was flushed just after having
@@ -1489,6 +1491,7 @@ void AudioMixerBase::process__noResampleOneTrack()
             ALOGE_IF((((uintptr_t)in) & 3), "process__noResampleOneTrack: bus error: "
                     "buffer %p track %p, channels %d, needs %#x",
                     in, &t, t->channelCount, t->needs);
+            ATRACE_NAME("process__noResampleOneTrack in == NULL || (((uintptr_t)in) & 3)");
             return;
         }
 
diff --git a/services/audioflinger/Configuration.h b/services/audioflinger/Configuration.h
index 845697a38c..1f8276c02d 100644
--- a/services/audioflinger/Configuration.h
+++ b/services/audioflinger/Configuration.h
@@ -36,7 +36,7 @@
 //#define STATE_QUEUE_DUMP
 
 // uncomment to allow tee sink debugging to be enabled by property
-//#define TEE_SINK
+#define TEE_SINK
 
 // uncomment to log CPU statistics every n wall clock seconds
 //#define DEBUG_CPU_USAGE 10
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index c525c4a874..9daf1f9825 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -3595,6 +3595,9 @@ ssize_t PlaybackThread::threadLoop_write()
 #ifdef TEE_SINK
             mTee.write((char *)mSinkBuffer + offset, framesWritten);
 #endif
+        {
+                    ATRACE_FORMAT(" mTee.write %d",framesWritten);
+        }
         } else {
             bytesWritten = framesWritten;
         }
@@ -5937,11 +5940,13 @@ PlaybackThread::mixer_state MixerThread::prepareTracks_l(
             std::string traceName("nRdy");
             traceName += std::to_string(trackId);
             ATRACE_INT(traceName.c_str(), framesReady);
+            ATRACE_FORMAT("framesReady %d minFrames %d",(int)framesReady,minFrames);
         }
         if ((framesReady >= minFrames) && track->isReady() &&
                 !track->isPaused() && !track->isTerminated())
         {
             ALOGVV("track(%d) s=%08x [OK] on thread %p", trackId, cblk->mServer, this);
+            ATRACE_FORMAT("track(%d) s=%08x [OK] on thread %p", trackId, cblk->mServer, this);
 
             mixedTracks++;
 
@@ -6211,6 +6216,8 @@ PlaybackThread::mixer_state MixerThread::prepareTracks_l(
         } else {
             size_t underrunFrames = 0;
             if (framesReady < desiredFrames && !track->isStopped() && !track->isPaused()) {
+                 ATRACE_FORMAT("track(%d) underrun, track state %s  framesReady(%zu) < framesDesired(%zd)",
+                        trackId, track->getTrackStateAsString(), framesReady, desiredFrames);
                 ALOGV("track(%d) underrun, track state %s  framesReady(%zu) < framesDesired(%zd)",
                         trackId, track->getTrackStateAsString(), framesReady, desiredFrames);
                 underrunFrames = desiredFrames;
@@ -6223,6 +6230,7 @@ PlaybackThread::mixer_state MixerThread::prepareTracks_l(
             if (chain != 0) {
                 chain->clearInputBuffer();
             }
+            ATRACE_FORMAT("track(%d) s=%08x [NOT READY] on thread %p", trackId, cblk->mServer, this);
 
             ALOGVV("track(%d) s=%08x [NOT READY] on thread %p", trackId, cblk->mServer, this);
             if ((track->sharedBuffer() != 0) || track->isTerminated() ||
diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp
index f5d72e32cd..26858f5ad5 100644
--- a/services/audioflinger/Tracks.cpp
+++ b/services/audioflinger/Tracks.cpp
@@ -1063,6 +1063,7 @@ uint32_t Track::sampleRate() const {
 // AudioBufferProvider interface
 status_t Track::getNextBuffer(AudioBufferProvider::Buffer* buffer)
 {
+    ATRACE_NAME("Track::getNextBuffer");
     ServerProxy::Buffer buf;
     size_t desiredFrames = buffer->frameCount;
     buf.mFrameCount = desiredFrames;
@@ -1072,8 +1073,12 @@ status_t Track::getNextBuffer(AudioBufferProvider::Buffer* buffer)
     if (buf.mFrameCount == 0 && !isStopping() && !isStopped() && !isPaused() && !isOffloaded()) {
         ALOGV("%s(%d): underrun,  framesReady(%zu) < framesDesired(%zd), state: %d",
                 __func__, mId, buf.mFrameCount, desiredFrames, (int)mState);
+            ATRACE_FORMAT("%s(%d): underrun,  framesReady(%zu) < framesDesired(%zd), state: %d",
+                __func__, mId, buf.mFrameCount, desiredFrames, (int)mState);
+
         mAudioTrackServerProxy->tallyUnderrunFrames(desiredFrames);
     } else {
+            ATRACE_NAME("mAudioTrackServerProxy->tallyUnderrunFrames(0)");
         mAudioTrackServerProxy->tallyUnderrunFrames(0);
     }
     return status;