Track alsa buffer underruns
Test: audioflinger dumpsys with instrumented sleeps
Bug: 135729709
Bug: 124764221
Change-Id: I43e21c03320ec598d970914d4569e404878a7894
(cherry picked from commit 1f203ea4bfd70695a5d1f3794a8bff9448a4f40b)
Signed-off-by: Aniket Kumar Lata <alata@codeaurora.org>
diff --git a/hal/audio_hw.c b/hal/audio_hw.c
index bdc6971..8bd8992 100644
--- a/hal/audio_hw.c
+++ b/hal/audio_hw.c
@@ -65,6 +65,7 @@
#include <hardware/audio_alsaops.h>
#include <system/thread_defs.h>
#include <tinyalsa/asoundlib.h>
+#include <utils/Timers.h> // systemTime
#include <audio_effects/effect_aec.h>
#include <audio_effects/effect_ns.h>
#include <audio_utils/format.h>
@@ -4542,6 +4543,12 @@
dprintf(fd, " Standby: %s\n", out->standby ? "yes" : "no");
dprintf(fd, " Frames written: %lld\n", (long long)out->written);
+ char buffer[256]; // for statistics formatting
+ if (!is_offload_usecase(out->usecase)) {
+ simple_stats_to_string(&out->fifo_underruns, buffer, sizeof(buffer));
+ dprintf(fd, " Fifo frame underruns: %s\n", buffer);
+ }
+
if (locked) {
pthread_mutex_unlock(&out->lock);
}
@@ -5710,6 +5717,7 @@
goto exit;
}
out->started = 1;
+ out->last_fifo_valid = false; // we're coming out of standby, last_fifo isn't valid.
if (last_known_cal_step != -1) {
ALOGD("%s: retry previous failed cal level set", __func__);
audio_hw_send_gain_dep_calibration(last_known_cal_step);
@@ -5878,6 +5886,30 @@
bytes_to_write /= 2;
}
}
+
+ // Note: since out_get_presentation_position() is called alternating with out_write()
+ // by AudioFlinger, we can check underruns using the prior timestamp read.
+ // (Alternately we could check if the buffer is empty using pcm_get_htimestamp().
+ if (out->last_fifo_valid) {
+ // compute drain to see if there is an underrun.
+ const int64_t current_ns = systemTime(SYSTEM_TIME_MONOTONIC); // sys call
+ const int64_t frames_by_time =
+ (current_ns - out->last_fifo_time_ns) * out->config.rate / NANOS_PER_SECOND;
+ const int64_t underrun = frames_by_time - out->last_fifo_frames_remaining;
+
+ if (underrun > 0) {
+ simple_stats_log(&out->fifo_underruns, underrun);
+
+ ALOGW("%s: underrun(%lld) "
+ "frames_by_time(%lld) > out->last_fifo_frames_remaining(%lld)",
+ __func__,
+ (long long)out->fifo_underruns.n,
+ (long long)frames_by_time,
+ (long long)out->last_fifo_frames_remaining);
+ }
+ out->last_fifo_valid = false; // we're writing below, mark fifo info as stale.
+ }
+
ALOGVV("%s: writing buffer (%zu bytes) to pcm device", __func__, bytes);
long ns = 0;
@@ -6107,15 +6139,26 @@
if (out->pcm) {
unsigned int avail;
if (pcm_get_htimestamp(out->pcm, &avail, timestamp) == 0) {
- size_t kernel_buffer_size = out->config.period_size * out->config.period_count;
-
uint64_t signed_frames = 0;
uint64_t frames_temp = 0;
- frames_temp = (kernel_buffer_size > avail) ? (kernel_buffer_size - avail) : 0;
+ if (out->kernel_buffer_size > avail) {
+ frames_temp = out->last_fifo_frames_remaining = out->kernel_buffer_size - avail;
+ } else {
+ ALOGW("%s: avail:%u > kernel_buffer_size:%zu clamping!",
+ __func__, avail, out->kernel_buffer_size);
+ avail = out->kernel_buffer_size;
+ frames_temp = out->last_fifo_frames_remaining = 0;
+ }
+ out->last_fifo_valid = true;
+ out->last_fifo_time_ns = audio_utils_ns_from_timespec(timestamp);
+
if (out->written >= frames_temp)
signed_frames = out->written - frames_temp;
+ ALOGVV("%s: frames:%lld avail:%u kernel_buffer_size:%zu",
+ __func__, (long long)signed_frames, avail, out->kernel_buffer_size);
+
// This adjustment accounts for buffering after app processor.
// It is based on estimated DSP latency per use case, rather than exact.
frames_temp = platform_render_latency(out->usecase) * out->sample_rate / 1000000LL;
@@ -8251,6 +8294,8 @@
else
out->af_period_multiplier = 1;
+ out->kernel_buffer_size = out->config.period_size * out->config.period_count;
+
out->standby = 1;
/* out->muted = false; by calloc() */
/* out->written = 0; by calloc() */
diff --git a/hal/audio_hw.h b/hal/audio_hw.h
index cc9e602..bd88f86 100644
--- a/hal/audio_hw.h
+++ b/hal/audio_hw.h
@@ -48,6 +48,8 @@
#include <audio_route/audio_route.h>
#include <audio_utils/ErrorLog.h>
+#include <audio_utils/Statistics.h>
+#include <audio_utils/clock.h>
#include "audio_defs.h"
#include "voice.h"
#include "audio_hw_extn_api.h"
@@ -454,6 +456,15 @@
int stream;
} cs;
} extconn;
+
+ size_t kernel_buffer_size; // cached value of the alsa buffer size, const after open().
+
+ // last out_get_presentation_position() cached info.
+ bool last_fifo_valid;
+ unsigned int last_fifo_frames_remaining;
+ int64_t last_fifo_time_ns;
+
+ simple_stats_t fifo_underruns; // TODO: keep a list of the last N fifo underrun times.
};
struct stream_in {