audio: add watchdog on buffer full condition

There have been several reports of devices losing audio
completely until rebooted.
The logs showed that the kernel buffer was steadily full
as if playback did not start or stopped and did not restart.

This change adds a watchdog to restart media server in case such
a condition persists.

Also add more log in case of errors reported by tinyalsa.

Bug 6699340.

Change-Id: Ie3e1565e1c1e6fd8581e6969343d481a63d5c880

1 files changed, 33 insertions, 8 deletions

diff --git a/audio/audio_hw.c b/audio/audio_hw.c
index 9a8330f..ff45acb 100644
--- a/audio/audio_hw.c
+++ b/audio/audio_hw.c
@@ -59,6 +59,7 @@
 #define MIN_WRITE_SLEEP_US 2000
 #define MAX_WRITE_SLEEP_US ((OUT_PERIOD_SIZE * OUT_SHORT_PERIOD_COUNT * 1000000) \
                                 / OUT_SAMPLING_RATE)
+#define MAX_SLEEP_LIMIT 100
 
 enum {
     OUT_BUFFER_TYPE_UNKNOWN,
@@ -123,6 +124,7 @@ struct stream_out {
     int write_threshold;
     int cur_write_threshold;
     int buffer_type;
+    int sleep_limit_count;
 
     struct audio_device *dev;
 };
@@ -264,6 +266,10 @@ static int start_output_stream(struct stream_out *out)
         device = PCM_DEVICE;
         out->pcm_config = &pcm_config_out;
         out->buffer_type = OUT_BUFFER_TYPE_UNKNOWN;
+        //FIXME: debug log for start failure issue
+        ALOGE_IF(out->pcm_config->start_threshold != OUT_PERIOD_SIZE * OUT_SHORT_PERIOD_COUNT,
+                 "start_output_stream(): corrupted start_threshold %d",
+                 out->pcm_config->start_threshold);
     }
 
     /*
@@ -308,6 +314,8 @@ static int start_output_stream(struct stream_out *out)
         out->buffer = malloc(pcm_frames_to_bytes(out->pcm, out->buffer_frames));
     }
 
+    out->sleep_limit_count = 0;
+
     adev->active_out = out;
 
     return 0;
@@ -610,7 +618,7 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
     size_t in_frames = bytes / frame_size;
     size_t out_frames;
     int buffer_type;
-    int kernel_frames;
+    unsigned int kernel_frames;
     bool sco_on;
 
     /*
@@ -684,12 +692,17 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
         do {
             struct timespec time_stamp;
             if (pcm_get_htimestamp(out->pcm,
-                                   (unsigned int *)&kernel_frames,
+                                   &kernel_frames,
                                    &time_stamp) < 0)
                 break;
+
+            if (kernel_frames > pcm_get_buffer_size(out->pcm)) {
+                ALOGW("out_write() invalid kernel frame count: %d", kernel_frames);
+                break;
+            }
             kernel_frames = pcm_get_buffer_size(out->pcm) - kernel_frames;
 
-            if (kernel_frames > out->cur_write_threshold) {
+            if ((int)kernel_frames > out->cur_write_threshold) {
                 int sleep_time_us =
                     (int)(((int64_t)(kernel_frames - out->cur_write_threshold)
                                     * 1000000) / out->pcm_config->rate);
@@ -697,15 +710,25 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
                     break;
                 total_sleep_time_us += sleep_time_us;
                 if (total_sleep_time_us > MAX_WRITE_SLEEP_US) {
-                    ALOGW("out_write() limiting sleep time %d to %d",
-                          total_sleep_time_us, MAX_WRITE_SLEEP_US);
+                    ALOGW_IF(out->sleep_limit_count == 0,
+                             "out_write() limiting total sleep time %d to %d, cur sleep time us %d",
+                          total_sleep_time_us, MAX_WRITE_SLEEP_US,
+                          sleep_time_us);
                     sleep_time_us = MAX_WRITE_SLEEP_US -
                                         (total_sleep_time_us - sleep_time_us);
+                    LOG_ALWAYS_FATAL_IF(out->sleep_limit_count++ >= MAX_SLEEP_LIMIT,
+                                        "out_write() limit sleep max count exceeded, "
+                                        "kernel frames %d, cur_write_threshold %d, "
+                                        "total_sleep_time_us %d, sleep_time_us %d",
+                                        kernel_frames, out->cur_write_threshold,
+                                        total_sleep_time_us, sleep_time_us);
+                } else {
+                    out->sleep_limit_count = 0;
                 }
                 usleep(sleep_time_us);
             }
 
-        } while ((kernel_frames > out->cur_write_threshold) &&
+        } while (((int)kernel_frames > out->cur_write_threshold) &&
                 (total_sleep_time_us <= MAX_WRITE_SLEEP_US));
 
         /* do not allow abrupt changes on buffer size. Increasing/decreasing
@@ -725,8 +748,8 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
             if (out->cur_write_threshold > out->write_threshold) {
                 out->cur_write_threshold = out->write_threshold;
             }
-        } else if ((kernel_frames < out->write_threshold) &&
-            ((out->write_threshold - kernel_frames) >
+        } else if (((int)kernel_frames < out->write_threshold) &&
+            ((out->write_threshold - (int)kernel_frames) >
                 (int)(period_size * OUT_SHORT_PERIOD_COUNT))) {
             out->cur_write_threshold = (kernel_frames / period_size + 1) * period_size;
             out->cur_write_threshold += period_size / 4;
@@ -737,6 +760,7 @@ static ssize_t out_write(struct audio_stream_out *stream, const void* buffer,
     if (ret == -EPIPE) {
         /* In case of underrun, don't sleep since we want to catch up asap */
         pthread_mutex_unlock(&out->lock);
+        ALOGE("out_write() error EPIPE");
         return ret;
     }
 
@@ -744,6 +768,7 @@ exit:
     pthread_mutex_unlock(&out->lock);
 
     if (ret != 0) {
+        ALOGE("out_write() error %s", pcm_get_error(out->pcm));
         usleep(bytes * 1000000 / audio_stream_frame_size(&stream->common) /
                out_get_sample_rate(&stream->common));
     }