Make the log callback and level atomic

It's useful to be able to enable logging dynamically while the program
is running, and this can now be done on any thread.

Various threads are logging (directly or asynchronously via the ring
buffer), it's better to have those atomic.

Both values are always checked before logging, and both must be non-null
to log.

4 files changed, 57 insertions, 34 deletions

diff --git a/src/cubeb.c b/src/cubeb.c
index 7f14bfa..ea21046 100644
--- a/src/cubeb.c
+++ b/src/cubeb.c
@@ -639,7 +639,7 @@ cubeb_enumerate_devices(cubeb * context, cubeb_device_type devtype,
 
   rv = context->ops->enumerate_devices(context, devtype, collection);
 
-  if (g_cubeb_log_callback) {
+  if (cubeb_log_get_callback()) {
     for (size_t i = 0; i < collection->count; i++) {
       log_device(&collection->device[i]);
     }
@@ -701,21 +701,11 @@ cubeb_set_log_callback(cubeb_log_level log_level,
     return CUBEB_ERROR_INVALID_PARAMETER;
   }
 
-  if (g_cubeb_log_callback && log_callback) {
+  if (cubeb_log_get_callback() && log_callback) {
     return CUBEB_ERROR_NOT_SUPPORTED;
   }
 
-  g_cubeb_log_callback = log_callback;
-  g_cubeb_log_level = log_level;
-
-  // Logging a message here allows to initialize the asynchronous logger from a
-  // thread that is not the audio rendering thread, and especially to not
-  // initialize it the first time we find a verbose log, which is often in the
-  // audio rendering callback, that runs from the audio rendering thread, and
-  // that is high priority, and that we don't want to block.
-  if (log_level >= CUBEB_LOG_VERBOSE) {
-    ALOGV("Starting cubeb log");
-  }
+  cubeb_log_set(log_level, log_callback);
 
   return CUBEB_OK;
 }
diff --git a/src/cubeb_log.cpp b/src/cubeb_log.cpp
index 9bd4c9b..0d86518 100644
--- a/src/cubeb_log.cpp
+++ b/src/cubeb_log.cpp
@@ -16,8 +16,8 @@
 #include <time.h>
 #endif
 
-cubeb_log_level g_cubeb_log_level;
-cubeb_log_callback g_cubeb_log_callback;
+std::atomic<cubeb_log_level> g_cubeb_log_level;
+std::atomic<cubeb_log_callback> g_cubeb_log_callback;
 
 /** The maximum size of a log message, after having been formatted. */
 const size_t CUBEB_LOG_MESSAGE_MAX_SIZE = 256;
@@ -74,7 +74,7 @@ public:
       while (true) {
         cubeb_log_message msg;
         while (msg_queue.dequeue(&msg, 1)) {
-          LOG_INTERNAL_NO_FORMAT(CUBEB_LOG_NORMAL, "%s", msg.get());
+          cubeb_log_internal_no_format(msg.get());
         }
 #ifdef _WIN32
         Sleep(CUBEB_LOG_BATCH_PRINT_INTERVAL_MS);
@@ -109,11 +109,25 @@ private:
 };
 
 void
+cubeb_log_internal(char const * file, uint32_t line, char const * fmt, ...)
+{
+  va_list args;
+  va_start(args, fmt);
+  char msg[CUBEB_LOG_MESSAGE_MAX_SIZE];
+  vsnprintf(msg, CUBEB_LOG_MESSAGE_MAX_SIZE, fmt, args);
+  g_cubeb_log_callback.load()("%s:%d:%s", file, line, msg);
+  va_end(args);
+}
+
+void
+cubeb_log_internal_no_format(const char * msg)
+{
+  g_cubeb_log_callback.load()(msg);
+}
+
+void
 cubeb_async_log(char const * fmt, ...)
 {
-  if (!g_cubeb_log_callback) {
-    return;
-  }
   // This is going to copy a 256 bytes array around, which is fine.
   // We don't want to allocate memory here, because this is made to
   // be called from a real-time callback.
@@ -133,3 +147,22 @@ cubeb_async_log_reset_threads(void)
   }
   cubeb_async_logger::get().reset_producer_thread();
 }
+
+void
+cubeb_log_set(cubeb_log_level log_level, cubeb_log_callback log_callback)
+{
+  g_cubeb_log_level = log_level;
+  g_cubeb_log_callback = log_callback;
+}
+
+cubeb_log_level
+cubeb_log_get_level()
+{
+  return g_cubeb_log_level;
+}
+
+cubeb_log_callback
+cubeb_log_get_callback()
+{
+  return g_cubeb_log_callback;
+}
diff --git a/src/cubeb_log.h b/src/cubeb_log.h
index fcc9c89..906ea03 100644
--- a/src/cubeb_log.h
+++ b/src/cubeb_log.h
@@ -30,8 +30,16 @@ extern "C" {
   (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__)
 #endif
 
-extern cubeb_log_level g_cubeb_log_level;
-extern cubeb_log_callback g_cubeb_log_callback PRINTF_FORMAT(1, 2);
+void
+cubeb_log_set(cubeb_log_level log_level, cubeb_log_callback log_callback);
+cubeb_log_level
+cubeb_log_get_level();
+cubeb_log_callback
+cubeb_log_get_callback();
+void
+cubeb_log_internal_no_format(const char * msg);
+void
+cubeb_log_internal(const char * filename, uint32_t line, const char * fmt, ...);
 void
 cubeb_async_log(const char * fmt, ...);
 void
@@ -44,24 +52,16 @@ cubeb_async_log_reset_threads(void);
 #define LOGV(msg, ...) LOG_INTERNAL(CUBEB_LOG_VERBOSE, msg, ##__VA_ARGS__)
 #define LOG(msg, ...) LOG_INTERNAL(CUBEB_LOG_NORMAL, msg, ##__VA_ARGS__)
 
-#define LOG_INTERNAL_NO_FORMAT(level, fmt, ...)                                \
-  do {                                                                         \
-    if (g_cubeb_log_callback && level <= g_cubeb_log_level) {                  \
-      g_cubeb_log_callback(fmt, __VA_ARGS__);                                  \
-    }                                                                          \
-  } while (0)
-
 #define LOG_INTERNAL(level, fmt, ...)                                          \
   do {                                                                         \
-    if (g_cubeb_log_callback && level <= g_cubeb_log_level) {                  \
-      g_cubeb_log_callback("%s:%d: " fmt "\n", __FILENAME__, __LINE__,         \
-                           ##__VA_ARGS__);                                     \
+    if (cubeb_log_get_level() <= level && cubeb_log_get_callback()) {          \
+      cubeb_log_internal(__FILENAME__, __LINE__, fmt, ##__VA_ARGS__);          \
     }                                                                          \
   } while (0)
 
 #define ALOG_INTERNAL(level, fmt, ...)                                         \
   do {                                                                         \
-    if (level <= g_cubeb_log_level) {                                          \
+    if (cubeb_log_get_level() <= level && cubeb_log_get_callback()) {          \
       cubeb_async_log(fmt, ##__VA_ARGS__);                                     \
     }                                                                          \
   } while (0)
diff --git a/src/cubeb_pulse.c b/src/cubeb_pulse.c
index fc8fbf4..6866405 100644
--- a/src/cubeb_pulse.c
+++ b/src/cubeb_pulse.c
@@ -1025,7 +1025,7 @@ pulse_stream_init(cubeb * context, cubeb_stream ** stream,
     return CUBEB_ERROR;
   }
 
-  if (g_cubeb_log_level) {
+  if (cubeb_log_get_level()) {
     if (output_stream_params) {
       const pa_buffer_attr * output_att;
       output_att = WRAP(pa_stream_get_buffer_attr)(stm->output_stream);
@@ -1578,7 +1578,7 @@ pulse_subscribe_callback(pa_context * ctx, pa_subscription_event_type_t t,
   case PA_SUBSCRIPTION_EVENT_SOURCE:
   case PA_SUBSCRIPTION_EVENT_SINK:
 
-    if (g_cubeb_log_level) {
+    if (cubeb_log_get_level()) {
       if ((t & PA_SUBSCRIPTION_EVENT_FACILITY_MASK) ==
               PA_SUBSCRIPTION_EVENT_SOURCE &&
           (t & PA_SUBSCRIPTION_EVENT_TYPE_MASK) ==