CRAS: metrics - Refactor logging stream function

1. Use cras_server_metrics_stream_create and
cras_server_metrics_stream_destroy function instead of logging metrics
seperately when streams create and destroy.

2. Move cras_server_metrics_stream_create from
rclient_handle_client_stream_connect to cras_rstream_create so that we
can log streams created by CRAS server.

BUG=b:144819087
TEST=Server stream can be recorded correctly.

Change-Id: Ib6888f541a9e78af9d3db668766d3c05e699ae90
Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/third_party/adhd/+/1925946
Reviewed-by: Cheng-Yi Chiang <cychiang@chromium.org>
Tested-by: Yu-Hsuan Hsu <yuhsuan@chromium.org>
Commit-Queue: Yu-Hsuan Hsu <yuhsuan@chromium.org>

5 files changed, 60 insertions, 113 deletions

diff --git a/cras/src/tests/capture_rclient_unittest.cc b/cras/src/tests/capture_rclient_unittest.cc
index 8abdbe48..709b5022 100644
--- a/cras/src/tests/capture_rclient_unittest.cc
+++ b/cras/src/tests/capture_rclient_unittest.cc
@@ -20,7 +20,6 @@ extern "C" {
 }
 static unsigned int cras_make_fd_nonblocking_called;
 static unsigned int cras_observer_remove_called;
-static unsigned int cras_server_metrics_stream_config_called;
 static int stream_list_add_called;
 static int stream_list_add_return;
 static unsigned int stream_list_rm_called;
@@ -31,7 +30,6 @@ static unsigned int cras_rstream_config_init_with_message_called;
 void ResetStubData() {
   cras_make_fd_nonblocking_called = 0;
   cras_observer_remove_called = 0;
-  cras_server_metrics_stream_config_called = 0;
   stream_list_add_called = 0;
   stream_list_add_return = 0;
   stream_list_rm_called = 0;
@@ -269,11 +267,6 @@ unsigned int cras_rstream_get_effects(const struct cras_rstream* stream) {
   return 0;
 }
 
-int cras_server_metrics_stream_config(struct cras_rstream_config* config) {
-  cras_server_metrics_stream_config_called++;
-  return 0;
-}
-
 int cras_send_with_fds(int sockfd,
                        const void* buf,
                        size_t len,
diff --git a/cras/src/tests/control_rclient_unittest.cc b/cras/src/tests/control_rclient_unittest.cc
index 9349c8d1..f0c3437f 100644
--- a/cras/src/tests/control_rclient_unittest.cc
+++ b/cras/src/tests/control_rclient_unittest.cc
@@ -45,7 +45,6 @@ static unsigned int stream_list_add_stream_called;
 static unsigned int stream_list_disconnect_stream_called;
 static unsigned int cras_iodev_list_rm_input_called;
 static unsigned int cras_iodev_list_rm_output_called;
-static unsigned int cras_server_metrics_stream_config_called;
 static struct cras_audio_shm dummy_shm;
 static struct cras_rstream dummy_rstream;
 static size_t cras_observer_num_ops_registered;
@@ -65,7 +64,6 @@ void ResetStubData() {
   cras_rstream_create_return = 0;
   cras_rstream_create_stream_out = (struct cras_rstream*)NULL;
   cras_iodev_attach_stream_retval = 0;
-  cras_server_metrics_stream_config_called = 0;
   cras_system_set_volume_value = 0;
   cras_system_set_volume_called = 0;
   cras_system_set_capture_gain_value = 0;
@@ -204,7 +202,6 @@ TEST_F(RClientMessagesSuite, AudThreadAttachFail) {
   EXPECT_EQ(1, cras_rstream_config_init_with_message_called);
   EXPECT_EQ(1, stream_list_add_stream_called);
   EXPECT_EQ(0, stream_list_disconnect_stream_called);
-  EXPECT_EQ(0, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, ConnectMsgWithBadFd) {
@@ -221,7 +218,6 @@ TEST_F(RClientMessagesSuite, ConnectMsgWithBadFd) {
   EXPECT_NE(0, out_msg.err);
   EXPECT_EQ(stream_list_add_stream_called,
             stream_list_disconnect_stream_called);
-  EXPECT_EQ(0, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, ConnectMsgFromOldClient) {
@@ -247,7 +243,6 @@ TEST_F(RClientMessagesSuite, ConnectMsgFromOldClient) {
   EXPECT_EQ(1, cras_rstream_config_init_with_message_called);
   EXPECT_EQ(1, stream_list_add_stream_called);
   EXPECT_EQ(0, stream_list_disconnect_stream_called);
-  EXPECT_EQ(1, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, StreamConnectMessageValidDirection) {
@@ -276,7 +271,6 @@ TEST_F(RClientMessagesSuite, StreamConnectMessageValidDirection) {
     EXPECT_EQ(called, cras_rstream_config_init_with_message_called);
     EXPECT_EQ(called, stream_list_add_stream_called);
     EXPECT_EQ(0, stream_list_disconnect_stream_called);
-    EXPECT_EQ(called, cras_server_metrics_stream_config_called);
   }
 }
 
@@ -300,7 +294,6 @@ TEST_F(RClientMessagesSuite, StreamConnectMessageInvalidDirection) {
   EXPECT_EQ(-EINVAL, out_msg.err);
   EXPECT_EQ(0, stream_list_add_stream_called);
   EXPECT_EQ(0, stream_list_disconnect_stream_called);
-  EXPECT_EQ(0, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, StreamConnectMessageInvalidClientId) {
@@ -344,7 +337,6 @@ TEST_F(RClientMessagesSuite, SuccessReply) {
   EXPECT_EQ(1, cras_rstream_config_init_with_message_called);
   EXPECT_EQ(1, stream_list_add_stream_called);
   EXPECT_EQ(0, stream_list_disconnect_stream_called);
-  EXPECT_EQ(1, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, SuccessCreateThreadReply) {
@@ -367,7 +359,6 @@ TEST_F(RClientMessagesSuite, SuccessCreateThreadReply) {
   EXPECT_EQ(1, cras_rstream_config_init_with_message_called);
   EXPECT_EQ(1, stream_list_add_stream_called);
   EXPECT_EQ(0, stream_list_disconnect_stream_called);
-  EXPECT_EQ(1, cras_server_metrics_stream_config_called);
 }
 
 TEST_F(RClientMessagesSuite, SetVolume) {
@@ -1009,11 +1000,6 @@ void cras_observer_remove(struct cras_observer_client* client) {
   cras_observer_remove_called++;
 }
 
-int cras_server_metrics_stream_config(struct cras_rstream_config* config) {
-  cras_server_metrics_stream_config_called++;
-  return 0;
-}
-
 void cras_rstream_config_init_with_message(
     struct cras_rclient* client,
     const struct cras_connect_message* msg,
diff --git a/cras/src/tests/playback_rclient_unittest.cc b/cras/src/tests/playback_rclient_unittest.cc
index 316eb1d8..53fbf95c 100644
--- a/cras/src/tests/playback_rclient_unittest.cc
+++ b/cras/src/tests/playback_rclient_unittest.cc
@@ -20,7 +20,6 @@ extern "C" {
 }
 static unsigned int cras_make_fd_nonblocking_called;
 static unsigned int cras_observer_remove_called;
-static unsigned int cras_server_metrics_stream_config_called;
 static int stream_list_add_called;
 static int stream_list_add_return;
 static unsigned int stream_list_rm_called;
@@ -31,7 +30,6 @@ static unsigned int cras_rstream_config_init_with_message_called;
 void ResetStubData() {
   cras_make_fd_nonblocking_called = 0;
   cras_observer_remove_called = 0;
-  cras_server_metrics_stream_config_called = 0;
   stream_list_add_called = 0;
   stream_list_add_return = 0;
   stream_list_rm_called = 0;
@@ -269,11 +267,6 @@ unsigned int cras_rstream_get_effects(const struct cras_rstream* stream) {
   return 0;
 }
 
-int cras_server_metrics_stream_config(struct cras_rstream_config* config) {
-  cras_server_metrics_stream_config_called++;
-  return 0;
-}
-
 int cras_send_with_fds(int sockfd,
                        const void* buf,
                        size_t len,
diff --git a/cras/src/tests/rstream_unittest.cc b/cras/src/tests/rstream_unittest.cc
index 69523f5f..f5487a93 100644
--- a/cras/src/tests/rstream_unittest.cc
+++ b/cras/src/tests/rstream_unittest.cc
@@ -16,6 +16,8 @@ extern "C" {
 #include "cras_shm.h"
 }
 
+#include "metrics_stub.h"
+
 namespace {
 
 class RstreamTestSuite : public testing::Test {
@@ -392,6 +394,15 @@ unsigned int buffer_share_id_offset(const struct buffer_share* mix,
 void cras_system_state_stream_added(enum CRAS_STREAM_DIRECTION direction) {}
 
 void cras_system_state_stream_removed(enum CRAS_STREAM_DIRECTION direction) {}
+
+int cras_server_metrics_stream_create(const struct cras_rstream* stream) {
+  return 0;
+}
+
+int cras_server_metrics_stream_destroy(const struct cras_rstream* stream) {
+  return 0;
+}
+
 #ifdef HAVE_WEBRTC_APM
 struct cras_apm_list* cras_apm_list_create(void* stream_ptr, uint64_t effects) {
   return NULL;
@@ -409,8 +420,4 @@ struct cras_audio_format* cras_apm_list_get_format(struct cras_apm* apm) {
   return NULL;
 }
 #endif
-
-int cras_server_metrics_missed_cb_frequency(const struct cras_rstream* stream) {
-  return 0;
-}
 }
diff --git a/cras/src/tests/server_metrics_unittest.cc b/cras/src/tests/server_metrics_unittest.cc
index 94a689c5..3bfb879f 100644
--- a/cras/src/tests/server_metrics_unittest.cc
+++ b/cras/src/tests/server_metrics_unittest.cc
@@ -160,79 +160,6 @@ TEST(ServerMetricsTestSuite, SetMetricsNumUnderruns) {
   EXPECT_EQ(sent_msgs[0].data.value, underrun);
 }
 
-TEST(ServerMetricsTestSuite, SetMetricsMissedCallbackFrequencyInputStream) {
-  ResetStubData();
-  struct cras_rstream stream;
-  struct timespec diff_ts;
-
-  stream.flags = 0;
-  stream.start_ts.tv_sec = 0;
-  stream.start_ts.tv_nsec = 0;
-  clock_gettime_retspec.tv_sec = 1000;
-  clock_gettime_retspec.tv_nsec = 0;
-  stream.num_missed_cb = 5;
-  stream.first_missed_cb_ts.tv_sec = 100;
-  stream.first_missed_cb_ts.tv_nsec = 0;
-
-  stream.direction = CRAS_STREAM_INPUT;
-  cras_server_metrics_missed_cb_frequency(&stream);
-
-  subtract_timespecs(&clock_gettime_retspec, &stream.start_ts, &diff_ts);
-  EXPECT_EQ(sent_msgs.size(), 2);
-  EXPECT_EQ(sent_msgs[0].header.type, CRAS_MAIN_METRICS);
-  EXPECT_EQ(sent_msgs[0].header.length,
-            sizeof(struct cras_server_metrics_message));
-  EXPECT_EQ(sent_msgs[0].metrics_type, MISSED_CB_FREQUENCY_INPUT);
-  EXPECT_EQ(sent_msgs[0].data.value,
-            stream.num_missed_cb * 86400 / diff_ts.tv_sec);
-
-  subtract_timespecs(&clock_gettime_retspec, &stream.first_missed_cb_ts,
-                     &diff_ts);
-  EXPECT_EQ(sent_msgs[1].header.type, CRAS_MAIN_METRICS);
-  EXPECT_EQ(sent_msgs[1].header.length,
-            sizeof(struct cras_server_metrics_message));
-  EXPECT_EQ(sent_msgs[1].metrics_type,
-            MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_INPUT);
-  EXPECT_EQ(sent_msgs[1].data.value,
-            (stream.num_missed_cb - 1) * 86400 / diff_ts.tv_sec);
-}
-
-TEST(ServerMetricsTestSuite, SetMetricsMissedCallbackFrequencyOutputStream) {
-  ResetStubData();
-  struct cras_rstream stream;
-  struct timespec diff_ts;
-
-  stream.flags = 0;
-  stream.start_ts.tv_sec = 0;
-  stream.start_ts.tv_nsec = 0;
-  clock_gettime_retspec.tv_sec = 1000;
-  clock_gettime_retspec.tv_nsec = 0;
-  stream.num_missed_cb = 5;
-  stream.first_missed_cb_ts.tv_sec = 100;
-  stream.first_missed_cb_ts.tv_nsec = 0;
-  stream.direction = CRAS_STREAM_OUTPUT;
-  cras_server_metrics_missed_cb_frequency(&stream);
-
-  subtract_timespecs(&clock_gettime_retspec, &stream.start_ts, &diff_ts);
-  EXPECT_EQ(sent_msgs.size(), 2);
-  EXPECT_EQ(sent_msgs[0].header.type, CRAS_MAIN_METRICS);
-  EXPECT_EQ(sent_msgs[0].header.length,
-            sizeof(struct cras_server_metrics_message));
-  EXPECT_EQ(sent_msgs[0].metrics_type, MISSED_CB_FREQUENCY_OUTPUT);
-  EXPECT_EQ(sent_msgs[0].data.value,
-            stream.num_missed_cb * 86400 / diff_ts.tv_sec);
-
-  subtract_timespecs(&clock_gettime_retspec, &stream.first_missed_cb_ts,
-                     &diff_ts);
-  EXPECT_EQ(sent_msgs[1].header.type, CRAS_MAIN_METRICS);
-  EXPECT_EQ(sent_msgs[1].header.length,
-            sizeof(struct cras_server_metrics_message));
-  EXPECT_EQ(sent_msgs[1].metrics_type,
-            MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_OUTPUT);
-  EXPECT_EQ(sent_msgs[1].data.value,
-            (stream.num_missed_cb - 1) * 86400 / diff_ts.tv_sec);
-}
-
 TEST(ServerMetricsTestSuite, SetMetricsMissedCallbackEventInputStream) {
   ResetStubData();
   struct cras_rstream stream;
@@ -315,21 +242,22 @@ TEST(ServerMetricsTestSuite, SetMetricsMissedCallbackEventOutputStream) {
   EXPECT_EQ(stream.num_missed_cb, 2);
 }
 
-TEST(ServerMetricsTestSuite, SetMetricsStreamConfig) {
+TEST(ServerMetricsTestSuite, SetMetricsStreamCreate) {
   ResetStubData();
-  struct cras_rstream_config config;
+  struct cras_rstream stream;
   struct cras_audio_format format;
 
-  config.direction = CRAS_STREAM_INPUT;
-  config.cb_threshold = 1024;
-  config.flags = BULK_AUDIO_OK;
+  stream.direction = CRAS_STREAM_INPUT;
+  stream.cb_threshold = 1024;
+  stream.flags = BULK_AUDIO_OK;
   format.format = SND_PCM_FORMAT_S16_LE;
   format.frame_rate = 48000;
-  config.client_type = CRAS_CLIENT_TYPE_TEST;
+  stream.client_type = CRAS_CLIENT_TYPE_TEST;
 
-  config.format = &format;
-  cras_server_metrics_stream_config(&config);
+  stream.format = format;
+  cras_server_metrics_stream_create(&stream);
 
+  // Log stream config.
   EXPECT_EQ(sent_msgs.size(), 1);
   EXPECT_EQ(sent_msgs[0].header.type, CRAS_MAIN_METRICS);
   EXPECT_EQ(sent_msgs[0].header.length,
@@ -343,6 +271,46 @@ TEST(ServerMetricsTestSuite, SetMetricsStreamConfig) {
   EXPECT_EQ(sent_msgs[0].data.stream_config.client_type, CRAS_CLIENT_TYPE_TEST);
 }
 
+TEST(ServerMetricsTestSuite, SetMetricsStreamDestroy) {
+  ResetStubData();
+  struct cras_rstream stream;
+  struct timespec diff_ts;
+
+  stream.flags = 0;
+  stream.start_ts.tv_sec = 0;
+  stream.start_ts.tv_nsec = 0;
+  clock_gettime_retspec.tv_sec = 1000;
+  clock_gettime_retspec.tv_nsec = 0;
+  stream.num_missed_cb = 5;
+  stream.first_missed_cb_ts.tv_sec = 100;
+  stream.first_missed_cb_ts.tv_nsec = 0;
+
+  stream.direction = CRAS_STREAM_INPUT;
+  cras_server_metrics_stream_destroy(&stream);
+
+  subtract_timespecs(&clock_gettime_retspec, &stream.start_ts, &diff_ts);
+  EXPECT_EQ(sent_msgs.size(), 2);
+
+  // Log missed cb frequency.
+  EXPECT_EQ(sent_msgs[0].header.type, CRAS_MAIN_METRICS);
+  EXPECT_EQ(sent_msgs[0].header.length,
+            sizeof(struct cras_server_metrics_message));
+  EXPECT_EQ(sent_msgs[0].metrics_type, MISSED_CB_FREQUENCY_INPUT);
+  EXPECT_EQ(sent_msgs[0].data.value,
+            stream.num_missed_cb * 86400 / diff_ts.tv_sec);
+
+  // Log missed cb frequency after rescheduling.
+  subtract_timespecs(&clock_gettime_retspec, &stream.first_missed_cb_ts,
+                     &diff_ts);
+  EXPECT_EQ(sent_msgs[1].header.type, CRAS_MAIN_METRICS);
+  EXPECT_EQ(sent_msgs[1].header.length,
+            sizeof(struct cras_server_metrics_message));
+  EXPECT_EQ(sent_msgs[1].metrics_type,
+            MISSED_CB_FREQUENCY_AFTER_RESCHEDULING_INPUT);
+  EXPECT_EQ(sent_msgs[1].data.value,
+            (stream.num_missed_cb - 1) * 86400 / diff_ts.tv_sec);
+}
+
 TEST(ServerMetricsTestSuite, SetMetricsBusyloop) {
   ResetStubData();
   struct timespec time = {40, 0};