Allow dynamic enabling and disabling of the log, add tests for the logging system.

Also clear out the memory used by the async logger when it's shut down.

This relies on the fact that enabling and disabling logging is performed
on the same thread, but I think this is a reasonnable thing to do. We
could assert it though.

1 files changed, 161 insertions, 0 deletions

diff --git a/test/test_logging.cpp b/test/test_logging.cpp
new file mode 100644
index 0000000..fdbf8d4
--- /dev/null
+++ b/test/test_logging.cpp
@@ -0,0 +1,161 @@
+/*
+ * Copyright © 2016 Mozilla Foundation
+ *
+ * This program is made available under an ISC-style license.  See the
+ * accompanying file LICENSE for details.
+ */
+
+/* cubeb_logging test  */
+#include "gtest/gtest.h"
+#if !defined(_XOPEN_SOURCE)
+#define _XOPEN_SOURCE 600
+#endif
+#include "cubeb/cubeb.h"
+#include <atomic>
+#include <math.h>
+#include <memory>
+#include <stdio.h>
+#include <stdlib.h>
+
+#include "common.h"
+
+#define PRINT_LOGS_TO_STDERR 0
+
+#define SAMPLE_FREQUENCY 48000
+#define STREAM_FORMAT CUBEB_SAMPLE_FLOAT32LE
+#define OUTPUT_CHANNELS 2
+#define OUTPUT_LAYOUT CUBEB_LAYOUT_STEREO
+
+std::atomic<uint32_t> log_statements_received = {0};
+std::atomic<uint32_t> data_callback_call_count = {0};
+
+void
+test_logging_callback(char const * fmt, ...)
+{
+  log_statements_received++;
+#if PRINT_LOGS_TO_STDERR == 1
+  char buf[1024];
+  va_list argslist;
+  va_start(argslist, fmt);
+  vsnprintf(buf, 1024, fmt, argslist);
+  fprintf(stderr, "%s\n", buf);
+  va_end(argslist);
+#endif // PRINT_LOGS_TO_STDERR
+}
+
+long
+data_cb_load(cubeb_stream * stream, void * user, const void * inputbuffer,
+             void * outputbuffer, long nframes)
+{
+  data_callback_call_count++;
+  return nframes;
+}
+
+void
+state_cb(cubeb_stream * stream, void * /*user*/, cubeb_state state)
+{
+  if (stream == NULL)
+    return;
+
+  switch (state) {
+  case CUBEB_STATE_STARTED:
+    fprintf(stderr, "stream started\n");
+    break;
+  case CUBEB_STATE_STOPPED:
+    fprintf(stderr, "stream stopped\n");
+    break;
+  case CUBEB_STATE_DRAINED:
+    fprintf(stderr, "stream drained\n");
+    break;
+  default:
+    fprintf(stderr, "unknown stream state %d\n", state);
+  }
+
+  return;
+}
+
+// Waits for at least one audio callback to have occured.
+void wait_for_audio_callback() {
+  uint32_t audio_callback_index =
+    data_callback_call_count.load(std::memory_order_acquire);
+  while (audio_callback_index ==
+         data_callback_call_count.load(std::memory_order_acquire)) {
+    delay(10);
+  }
+}
+
+TEST(cubeb, logging)
+{
+  cubeb * ctx;
+  cubeb_stream * stream;
+  cubeb_stream_params output_params;
+  int r;
+  uint32_t latency_frames = 0;
+
+  cubeb_set_log_callback(CUBEB_LOG_NORMAL, test_logging_callback);
+
+  r = common_init(&ctx, "Cubeb logging test");
+  ASSERT_EQ(r, CUBEB_OK) << "Error initializing cubeb library";
+
+  std::unique_ptr<cubeb, decltype(&cubeb_destroy)> cleanup_cubeb_at_exit(
+      ctx, cubeb_destroy);
+
+  output_params.format = STREAM_FORMAT;
+  output_params.rate = SAMPLE_FREQUENCY;
+  output_params.channels = OUTPUT_CHANNELS;
+  output_params.layout = OUTPUT_LAYOUT;
+  output_params.prefs = CUBEB_STREAM_PREF_NONE;
+
+  r = cubeb_get_min_latency(ctx, &output_params, &latency_frames);
+  ASSERT_EQ(r, CUBEB_OK) << "Could not get minimal latency";
+
+  r = cubeb_stream_init(ctx, &stream, "Cubeb logging", NULL, NULL, NULL,
+                        &output_params, latency_frames, data_cb_load, state_cb,
+                        NULL);
+  ASSERT_EQ(r, CUBEB_OK) << "Error initializing cubeb stream";
+
+  std::unique_ptr<cubeb_stream, decltype(&cubeb_stream_destroy)>
+      cleanup_stream_at_exit(stream, cubeb_stream_destroy);
+
+  ASSERT_NE(log_statements_received.load(std::memory_order_acquire), 0u);
+
+  cubeb_set_log_callback(CUBEB_LOG_DISABLED, nullptr);
+  log_statements_received.store(0, std::memory_order_release);
+
+  // This is synchronous and we'll receive log messages on all backends that we
+  // test
+  cubeb_stream_start(stream);
+
+  ASSERT_EQ(log_statements_received.load(std::memory_order_acquire), 0u);
+
+  cubeb_set_log_callback(CUBEB_LOG_VERBOSE, test_logging_callback);
+
+  wait_for_audio_callback();
+
+  ASSERT_NE(log_statements_received.load(std::memory_order_acquire), 0u);
+
+  bool log_callback_set = true;
+  uint32_t iterations = 100;
+  while (iterations--) {
+    wait_for_audio_callback();
+
+    if (!log_callback_set) {
+      ASSERT_EQ(log_statements_received.load(std::memory_order_acquire), 0u);
+      // Set a logging callback, start logging
+      cubeb_set_log_callback(CUBEB_LOG_VERBOSE, test_logging_callback);
+      log_callback_set = true;
+    } else {
+      // Disable the logging callback, stop logging.
+      ASSERT_NE(log_statements_received.load(std::memory_order_acquire), 0u);
+      cubeb_set_log_callback(CUBEB_LOG_DISABLED, nullptr);
+      log_statements_received.store(0, std::memory_order_release);
+      // Disabling logging should flush any log message -- wait a bit and check
+      // that this is true.
+      // delay(100);
+      ASSERT_EQ(log_statements_received.load(std::memory_order_acquire), 0u);
+      log_callback_set = false;
+    }
+  }
+
+  cubeb_stream_stop(stream);
+}