CRAS: device_monitor - Close erroneous device in main thread

If an output device hit I/O error in audio thread, there was
no explicit code path to close it. So if application keeps
the audio output stream alive, the output device would keep the
same buffer playing forever.

This change adds below handling logic:
When EIO is received, check if it's within 10 seconds from the
last EIO error. If not, then reset this device(close and reopen).
Otherwise treat this as a non-stop error and close this device
to avoid audio looping.

BUG=b:170100252
TEST=Use code to fake EIO error after 5 seconds of playback,
verify the device receives a reset, and 5 more seconds later
it gets closed gracefully.

Change-Id: I5e491ea6c23e550012cd65c9b4d51281b7047972
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/2681863
Reviewed-by: Curtis Malainey <cujomalainey@chromium.org>
Reviewed-by: Cheng-Yi Chiang <cychiang@chromium.org>
Commit-Queue: Hsinyu Chao <hychao@chromium.org>
Tested-by: Hsinyu Chao <hychao@chromium.org>

5 files changed, 55 insertions, 0 deletions

diff --git a/cras/src/server/cras_device_monitor.c b/cras/src/server/cras_device_monitor.c
index 7dd0f5d7..e9730a0b 100644
--- a/cras/src/server/cras_device_monitor.c
+++ b/cras/src/server/cras_device_monitor.c
@@ -13,6 +13,7 @@
 enum CRAS_DEVICE_MONITOR_MSG_TYPE {
 	RESET_DEVICE,
 	SET_MUTE_STATE,
+	ERROR_CLOSE,
 };
 
 struct cras_device_monitor_message {
@@ -62,6 +63,21 @@ int cras_device_monitor_set_device_mute_state(unsigned int dev_idx)
 	return 0;
 }
 
+int cras_device_monitor_error_close(unsigned int dev_idx)
+{
+	struct cras_device_monitor_message msg;
+	int err;
+
+	init_device_msg(&msg, ERROR_CLOSE, dev_idx);
+	err = cras_main_message_send((struct cras_main_message *)&msg);
+	if (err < 0) {
+		syslog(LOG_ERR, "Failed to send device message %d",
+		       ERROR_CLOSE);
+		return err;
+	}
+	return 0;
+}
+
 /* When device is in a bad state, e.g. severe underrun,
  * it might break how audio thread works and cause busy wake up loop.
  * Resetting the device can bring device back to normal state.
@@ -84,6 +100,10 @@ static void handle_device_message(struct cras_main_message *msg, void *arg)
 	case SET_MUTE_STATE:
 		cras_iodev_list_set_dev_mute(device_msg->dev_idx);
 		break;
+	case ERROR_CLOSE:
+		syslog(LOG_ERR, "Close erroneous device in main thread");
+		cras_iodev_list_suspend_dev(device_msg->dev_idx);
+		break;
 	default:
 		syslog(LOG_ERR, "Unknown device message type %u",
 		       device_msg->message_type);
diff --git a/cras/src/server/cras_device_monitor.h b/cras/src/server/cras_device_monitor.h
index ac31adb9..eca2372b 100644
--- a/cras/src/server/cras_device_monitor.h
+++ b/cras/src/server/cras_device_monitor.h
@@ -15,4 +15,8 @@ int cras_device_monitor_set_device_mute_state(unsigned int dev_idx);
 /* Initializes device monitor and sets main thread callback. */
 int cras_device_monitor_init();
 
+/* Asks main thread to close device because error has occured in audio
+ * thread. */
+int cras_device_monitor_error_close(unsigned int dev_idx);
+
 #endif /* CRAS_DEVICE_MONITOR_H_ */
diff --git a/cras/src/server/dev_io.c b/cras/src/server/dev_io.c
index aea2244a..27c10c68 100644
--- a/cras/src/server/dev_io.c
+++ b/cras/src/server/dev_io.c
@@ -10,6 +10,7 @@
 #include "audio_thread_log.h"
 #include "cras_audio_area.h"
 #include "cras_audio_thread_monitor.h"
+#include "cras_device_monitor.h"
 #include "cras_iodev.h"
 #include "cras_non_empty_audio_handler.h"
 #include "cras_rstream.h"
@@ -47,6 +48,12 @@ static const int DROP_FRAMES_THRESHOLD_MS = 50;
 /* The number of devices playing/capturing non-empty stream(s). */
 static int non_empty_device_count = 0;
 
+/* The timestamp of last EIO error time. */
+static struct timespec last_io_err_time = { 0, 0 };
+
+/* The gap time to avoid repeated error close request to main thread. */
+static const int ERROR_CLOSE_GAP_TIME_SECS = 10;
+
 /* Gets the master device which the stream is attached to. */
 static inline struct cras_iodev *get_master_dev(const struct dev_stream *stream)
 {
@@ -934,12 +941,30 @@ int dev_io_send_captured_samples(struct open_dev *idev_list)
 static void handle_dev_err(int err_rc, struct open_dev **odevs,
 			   struct open_dev *adev)
 {
+	struct timespec diff, now;
 	if (err_rc == -EPIPE) {
 		/* Handle severe underrun. */
 		ATLOG(atlog, AUDIO_THREAD_SEVERE_UNDERRUN, adev->dev->info.idx,
 		      0, 0);
 		cras_iodev_reset_request(adev->dev);
 		cras_audio_thread_event_severe_underrun();
+	} else if (err_rc == -EIO) {
+		syslog(LOG_WARNING, "I/O err, reseting %s dev %s",
+		       adev->dev->direction == CRAS_STREAM_OUTPUT ? "output" :
+								    "input",
+		       adev->dev->info.name);
+		clock_gettime(CLOCK_REALTIME, &now);
+		subtract_timespecs(&now, &last_io_err_time, &diff);
+		if ((last_io_err_time.tv_sec == 0 &&
+		     last_io_err_time.tv_nsec == 0) ||
+		    diff.tv_sec > ERROR_CLOSE_GAP_TIME_SECS)
+			cras_iodev_reset_request(adev->dev);
+		else
+			cras_device_monitor_error_close(adev->dev->info.idx);
+
+		last_io_err_time = now;
+	} else {
+		syslog(LOG_ERR, "Dev %s err %d", adev->dev->info.name, err_rc);
 	}
 	/* Device error, remove it. */
 	dev_io_rm_open_dev(odevs, adev);
diff --git a/cras/src/tests/audio_thread_unittest.cc b/cras/src/tests/audio_thread_unittest.cc
index 6b78c696..14e98243 100644
--- a/cras/src/tests/audio_thread_unittest.cc
+++ b/cras/src/tests/audio_thread_unittest.cc
@@ -1409,6 +1409,9 @@ int cras_device_monitor_set_device_mute_state(unsigned int dev_idx) {
   cras_device_monitor_set_device_mute_state_called++;
   return 0;
 }
+int cras_device_monitor_error_close(unsigned int dev_idx) {
+  return 0;
+}
 
 int cras_iodev_drop_frames_by_time(struct cras_iodev* iodev,
                                    struct timespec ts) {
diff --git a/cras/src/tests/dev_io_unittest.cc b/cras/src/tests/dev_io_unittest.cc
index 096e3ed3..ab104aac 100644
--- a/cras/src/tests/dev_io_unittest.cc
+++ b/cras/src/tests/dev_io_unittest.cc
@@ -376,6 +376,9 @@ struct dev_stream* dev_stream_create(struct cras_rstream* stream,
                                      struct timespec* cb_ts) {
   return 0;
 }
+int cras_device_monitor_error_close(unsigned int dev_idx) {
+  return 0;
+}
 }  // extern "C"
 
 }  //  namespace