CRAS: device_monitor - Add device monitor to handle device request

Use device monitor to handle message from audio thread.
When audio thread finds a device in bad state, it can send a message to
main thread to reset a device properly from iodev_list.

BUG=chromium:662786
TEST=make check
TEST=With hack patch of severe underrun, check device reset upon severe
     underrun. Also check audio thread log.

Signed-off-by: Cheng-Yi Chiang <cychiang@chromium.org>
Change-Id: Iac6d3f688f40cfe434002064407363151857ec6b
Reviewed-on: https://chromium-review.googlesource.com/411743
Commit-Ready: Nicolas Boichat <drinkcat@chromium.org>
Reviewed-by: Dylan Reid <dgreid@chromium.org>

10 files changed, 276 insertions, 2 deletions

diff --git a/cras/src/Makefile.am b/cras/src/Makefile.am
index 617065a5..ce49c70b 100644
--- a/cras/src/Makefile.am
+++ b/cras/src/Makefile.am
@@ -96,6 +96,7 @@ cras_SOURCES = \
 	server/cras_alsa_ucm.c \
 	server/cras_alsa_ucm_section.c \
 	server/cras_audio_area.c \
+	server/cras_device_monitor.c \
 	server/cras_dsp.c \
 	server/cras_dsp_ini.c \
 	server/cras_dsp_mod_builtin.c \
@@ -280,6 +281,7 @@ TESTS = \
 	checksum_unittest \
 	cras_client_unittest \
 	cras_tm_unittest \
+	device_monitor_unittest \
 	dev_stream_unittest \
 	device_blacklist_unittest \
 	dsp_core_unittest \
@@ -529,6 +531,11 @@ device_blacklist_unittest_CPPFLAGS = $(COMMON_CPPFLAGS) \
 	-I$(top_srcdir)/src/server/config $(CRAS_UT_TMPDIR_CFLAGS)
 device_blacklist_unittest_LDADD = -lgtest -liniparser -lpthread
 
+device_monitor_unittest_SOURCES = tests/device_monitor_unittest.cc
+device_monitor_unittest_CPPFLAGS = $(COMMON_CPPFLAGS) -I$(top_srcdir)/src/common \
+	-I$(top_srcdir)/src/server
+device_monitor_unittest_LDADD = -lgtest -lpthread
+
 dsp_core_unittest_SOURCES = tests/dsp_core_unittest.cc dsp/eq.c dsp/eq2.c \
 	dsp/biquad.c dsp/dsp_util.c dsp/crossover.c dsp/crossover2.c dsp/drc.c \
 	dsp/drc_kernel.c dsp/drc_math.c
diff --git a/cras/src/common/cras_types.h b/cras/src/common/cras_types.h
index 9ddde60d..522f001f 100644
--- a/cras/src/common/cras_types.h
+++ b/cras/src/common/cras_types.h
@@ -187,6 +187,7 @@ enum AUDIO_THREAD_LOG_EVENTS {
 	AUDIO_THREAD_ODEV_LEAVE_NO_STREAMS,
 	AUDIO_THREAD_ODEV_DEFAULT_NO_STREAMS,
 	AUDIO_THREAD_FILL_ODEV_ZEROS,
+	AUDIO_THREAD_SEVERE_UNDERRUN,
 };
 
 struct __attribute__ ((__packed__)) audio_thread_event {
diff --git a/cras/src/server/audio_thread.c b/cras/src/server/audio_thread.c
index 89f900ba..7fe4f7bd 100644
--- a/cras/src/server/audio_thread.c
+++ b/cras/src/server/audio_thread.c
@@ -15,6 +15,7 @@
 #include "cras_audio_area.h"
 #include "audio_thread_log.h"
 #include "cras_config.h"
+#include "cras_device_monitor.h"
 #include "cras_fmt_conv.h"
 #include "cras_iodev.h"
 #include "cras_rstream.h"
@@ -1204,8 +1205,15 @@ static int do_playback(struct audio_thread *thread)
 
 		rc = write_output_samples(thread, adev);
 		if (rc < 0) {
-			/* Device error, close it. */
-			thread_rm_open_adev(thread, adev);
+			if (rc == -EPIPE) {
+				/* Handle severe underrun. */
+				ATLOG(atlog, AUDIO_THREAD_SEVERE_UNDERRUN,
+				      adev->dev->info.idx, 0, 0);
+				cras_device_monitor_reset_device(adev->dev);
+			} else {
+				/* Device error, close it. */
+				thread_rm_open_adev(thread, adev);
+			}
 		}
 	}
 
diff --git a/cras/src/server/cras_device_monitor.c b/cras/src/server/cras_device_monitor.c
new file mode 100644
index 00000000..cd46a1bc
--- /dev/null
+++ b/cras/src/server/cras_device_monitor.c
@@ -0,0 +1,80 @@
+/* Copyright 2016 The Chromium OS Authors. All rights reserved.
+ * Use of this source code is governed by a BSD-style license that can be
+ * found in the LICENSE file.
+ */
+
+#include <syslog.h>
+
+#include "cras_device_monitor.h"
+#include "cras_iodev_list.h"
+#include "cras_main_message.h"
+
+enum CRAS_DEVICE_MONITOR_MSG_TYPE {
+	RESET_DEVICE,
+};
+
+struct cras_device_monitor_message {
+	struct cras_main_message header;
+	enum CRAS_DEVICE_MONITOR_MSG_TYPE message_type;
+	struct cras_iodev *iodev;
+};
+
+static void init_device_msg(
+		struct cras_device_monitor_message *msg,
+		enum CRAS_DEVICE_MONITOR_MSG_TYPE type,
+		struct cras_iodev *iodev)
+{
+	memset(msg, 0, sizeof(*msg));
+	msg->header.type = CRAS_MAIN_MONITOR_DEVICE;
+	msg->header.length = sizeof(*msg);
+	msg->message_type = type;
+	msg->iodev = iodev;
+}
+
+int cras_device_monitor_reset_device(struct cras_iodev *iodev)
+{
+	struct cras_device_monitor_message msg;
+	int err;
+
+	init_device_msg(&msg, RESET_DEVICE, iodev);
+	err = cras_main_message_send((struct cras_main_message *)&msg);
+	if (err < 0) {
+		syslog(LOG_ERR, "Failed to send device message");
+		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.
+ * Let main thread follow the disable/enable sequence in iodev_list
+ * to properly close/open the device while enabling/disabling fallback
+ * device.
+ */
+static void handle_device_message(struct cras_main_message *msg, void *arg)
+{
+	struct cras_device_monitor_message *device_msg =
+			(struct cras_device_monitor_message *)msg;
+	struct cras_iodev *iodev = device_msg->iodev;
+
+	switch (device_msg->message_type) {
+	case RESET_DEVICE:
+		syslog(LOG_ERR, "trying to recover device 0x%x by resetting it",
+		       iodev->info.idx);
+		cras_iodev_list_disable_dev(iodev);
+		cras_iodev_list_enable_dev(iodev);
+		break;
+	default:
+		syslog(LOG_ERR, "Unknown device message type %u",
+		       device_msg->message_type);
+		break;
+	}
+}
+
+int cras_device_monitor_init()
+{
+	cras_main_message_add_handler(CRAS_MAIN_MONITOR_DEVICE,
+				      handle_device_message, NULL);
+	return 0;
+}
diff --git a/cras/src/server/cras_device_monitor.h b/cras/src/server/cras_device_monitor.h
new file mode 100644
index 00000000..ceb94a36
--- /dev/null
+++ b/cras/src/server/cras_device_monitor.h
@@ -0,0 +1,17 @@
+/* Copyright 2016 The Chromium OS Authors. All rights reserved.
+ * Use of this source code is governed by a BSD-style license that can be
+ * found in the LICENSE file.
+ */
+
+#ifndef CRAS_DEVICE_MONITOR_H_
+#define CRAS_DEVICE_MONITOR_H_
+
+#include "cras_iodev.h"
+
+/* Asks main thread to reset a device */
+int cras_device_monitor_reset_device(struct cras_iodev *iodev);
+
+/* Initializes device monitor and sets main thread callback. */
+int cras_device_monitor_init();
+
+#endif /* CRAS_DEVICE_MONITOR_H_ */
diff --git a/cras/src/server/cras_main_message.h b/cras/src/server/cras_main_message.h
index f4267c1a..7475aaf6 100644
--- a/cras/src/server/cras_main_message.h
+++ b/cras/src/server/cras_main_message.h
@@ -16,6 +16,7 @@ enum CRAS_MAIN_MESSAGE_TYPE {
 	CRAS_MAIN_A2DP,
 	CRAS_MAIN_BT,
 	CRAS_MAIN_METRICS,
+	CRAS_MAIN_MONITOR_DEVICE,
 };
 
 /* Structure of the header of the message handled by main thread.
diff --git a/cras/src/server/cras_server.c b/cras/src/server/cras_server.c
index 52248fc8..ff5e601c 100644
--- a/cras/src/server/cras_server.c
+++ b/cras/src/server/cras_server.c
@@ -35,6 +35,7 @@
 #endif
 #include "cras_alert.h"
 #include "cras_config.h"
+#include "cras_device_monitor.h"
 #include "cras_iodev_list.h"
 #include "cras_main_message.h"
 #include "cras_messages.h"
@@ -424,6 +425,8 @@ int cras_server_run(unsigned int profile_disable_mask)
 
 	cras_server_metrics_init();
 
+	cras_device_monitor_init();
+
 #ifdef CRAS_DBUS
 	dbus_threads_init_default();
 	dbus_conn = cras_dbus_connect_system_bus();
diff --git a/cras/src/tests/audio_thread_unittest.cc b/cras/src/tests/audio_thread_unittest.cc
index 3b1c9207..c0cc919d 100644
--- a/cras/src/tests/audio_thread_unittest.cc
+++ b/cras/src/tests/audio_thread_unittest.cc
@@ -31,6 +31,8 @@ static unsigned int cras_iodev_prepare_output_before_write_samples_called;
 static enum CRAS_IODEV_STATE cras_iodev_prepare_output_before_write_samples_state;
 static unsigned int cras_iodev_get_output_buffer_called;
 static int cras_iodev_prepare_output_before_write_samples_ret;
+static int cras_device_monitor_reset_device_called;
+static struct cras_iodev *cras_device_monitor_reset_device_iodev;
 
 void ResetGlobalStubData() {
   cras_rstream_dev_offset_called = 0;
@@ -56,6 +58,8 @@ void ResetGlobalStubData() {
   cras_iodev_prepare_output_before_write_samples_state = CRAS_IODEV_STATE_OPEN;
   cras_iodev_get_output_buffer_called = 0;
   cras_iodev_prepare_output_before_write_samples_ret = 0;
+  cras_device_monitor_reset_device_called = 0;
+  cras_device_monitor_reset_device_iodev = NULL;
 }
 
 // Test streams and devices manipulation.
@@ -522,6 +526,40 @@ TEST_F(StreamDeviceSuite, WriteOutputSamplesUnderrun) {
   TearDownRstream(&rstream);
 }
 
+TEST_F(StreamDeviceSuite, DoPlaybackUnderrun) {
+  struct cras_iodev iodev, *piodev = &iodev;
+  struct cras_rstream rstream;
+
+  ResetGlobalStubData();
+
+  SetupDevice(&iodev, CRAS_STREAM_OUTPUT);
+  SetupRstream(&rstream, CRAS_STREAM_OUTPUT);
+
+  // Setup the output buffer for device.
+  cras_iodev_get_output_buffer_area = cras_audio_area_create(2);
+
+  // Add the device and add the stream.
+  thread_add_open_dev(thread_, &iodev);
+  thread_add_stream(thread_, &rstream, &piodev, 1);
+
+  // Assume device is running and there is a severe underrun.
+  iodev.state = CRAS_IODEV_STATE_NORMAL_RUN;
+  frames_queued_ = -EPIPE;
+
+  // Assume device in normal run stream state;
+  cras_iodev_prepare_output_before_write_samples_state = \
+      CRAS_IODEV_STATE_NORMAL_RUN;
+
+  do_playback(thread_);
+
+  // Audio thread should trigger device monitor to reset device.
+  EXPECT_EQ(1, cras_device_monitor_reset_device_called);
+  EXPECT_EQ(&iodev, cras_device_monitor_reset_device_iodev);
+
+  thread_rm_open_dev(thread_, &iodev);
+  TearDownRstream(&rstream);
+}
+
 TEST(AUdioThreadStreams, DrainStream) {
   struct cras_rstream rstream;
   struct cras_audio_shm_area shm_area;
@@ -901,6 +939,13 @@ unsigned int cras_iodev_get_num_underruns(const struct cras_iodev *iodev)
   return 0;
 }
 
+int cras_device_monitor_reset_device(struct cras_iodev *iodev)
+{
+  cras_device_monitor_reset_device_called++;
+  cras_device_monitor_reset_device_iodev = iodev;
+  return 0;
+}
+
 }  // extern "C"
 
 int main(int argc, char **argv) {
diff --git a/cras/src/tests/cras_test_client.c b/cras/src/tests/cras_test_client.c
index 9cd7ac55..da822a1e 100644
--- a/cras/src/tests/cras_test_client.c
+++ b/cras/src/tests/cras_test_client.c
@@ -529,6 +529,9 @@ static void show_alog_tag(const struct audio_thread_event_log *log,
 		printf("%-30s dev:%x hw_level:%u target:%u\n",
 		       "DEFAULT_NO_STREAMS", data1, data2, data3);
 		break;
+	case AUDIO_THREAD_SEVERE_UNDERRUN:
+		printf("%-30s dev:%x\n", "SEVERE_UNDERRUN", data1);
+		break;
 	default:
 		printf("%-30s tag:%u\n","UNKNOWN", tag);
 		break;
diff --git a/cras/src/tests/device_monitor_unittest.cc b/cras/src/tests/device_monitor_unittest.cc
new file mode 100644
index 00000000..15fc1b8e
--- /dev/null
+++ b/cras/src/tests/device_monitor_unittest.cc
@@ -0,0 +1,109 @@
+// Copyright 2016 The Chromium OS Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include <stdio.h>
+#include <gtest/gtest.h>
+
+extern "C" {
+#include "cras_device_monitor.c"
+#include "cras_iodev.h"
+#include "cras_main_message.h"
+}
+
+static enum CRAS_MAIN_MESSAGE_TYPE type_set;
+static struct cras_device_monitor_message *sent_msg;
+static int enable_dev_called;
+static cras_iodev *enable_dev;
+static int disable_dev_called;
+static cras_iodev *disable_dev;
+
+void ResetStubData() {
+  type_set = (enum CRAS_MAIN_MESSAGE_TYPE)0;
+  enable_dev_called = 0;
+  enable_dev = NULL;
+  disable_dev_called = 0;
+  disable_dev = NULL;
+}
+
+namespace {
+
+TEST(DeviceMonitorTestSuite, Init) {
+  ResetStubData();
+
+  cras_device_monitor_init();
+
+  EXPECT_EQ(type_set, CRAS_MAIN_MONITOR_DEVICE);
+}
+
+TEST(DeviceMonitorTestSuite, ResetDevice) {
+  struct cras_iodev dev;
+  ResetStubData();
+  // sent_msg will be filled with message content in cras_main_message_send.
+  sent_msg = (struct cras_device_monitor_message *)calloc(1, sizeof(*sent_msg));
+
+  cras_device_monitor_reset_device(&dev);
+
+  EXPECT_EQ(sent_msg->header.type, CRAS_MAIN_MONITOR_DEVICE);
+  EXPECT_EQ(sent_msg->header.length, sizeof(*sent_msg));
+  EXPECT_EQ(sent_msg->message_type, RESET_DEVICE);
+  EXPECT_EQ(sent_msg->iodev, &dev);
+
+  free(sent_msg);
+}
+
+TEST(DeviceMonitorTestSuite, HandleResetDevice) {
+  struct cras_iodev dev;
+  struct cras_device_monitor_message msg;
+  struct cras_main_message *main_message =
+      reinterpret_cast<struct cras_main_message *>(&msg);
+
+  ResetStubData();
+
+  // Filled msg with message content for resetting device.
+  init_device_msg(&msg, RESET_DEVICE, &dev);
+  // Assume the pipe works fine and main message handler receives the same
+  // message.
+  handle_device_message(main_message, NULL);
+
+  // Verify that disable/enable functions are called with correct device.
+  EXPECT_EQ(enable_dev_called, 1);
+  EXPECT_EQ(enable_dev, &dev);
+  EXPECT_EQ(disable_dev_called, 1);
+  EXPECT_EQ(disable_dev, &dev);
+}
+
+extern "C" {
+
+int cras_main_message_add_handler(enum CRAS_MAIN_MESSAGE_TYPE type,
+                                  cras_message_callback callback,
+                                  void *callback_data) {
+  type_set = type;
+  return 0;
+}
+
+int cras_main_message_send(struct cras_main_message *msg) {
+  // Copy the sent message so we can examine it in the test later.
+  memcpy(sent_msg, msg, sizeof(*sent_msg));
+  return 0;
+};
+
+void cras_iodev_list_enable_dev(struct cras_iodev *dev) {
+  enable_dev_called++;
+  enable_dev = dev;
+}
+
+void cras_iodev_list_disable_dev(struct cras_iodev *dev) {
+  disable_dev_called++;
+  disable_dev = dev;
+}
+
+}  // extern "C"
+}  // namespace
+
+int main(int argc, char **argv) {
+  ::testing::InitGoogleTest(&argc, argv);
+  int rc = RUN_ALL_TESTS();
+
+  return rc;
+}