log: dynamically load the logger API

pipewire/client/context.c

@@ -37,6 +37,8 @@
 struct context {
 	struct pw_context this;
 
+	struct spa_support support[3];
+
 	bool no_proxy;
 
 	int fd;
@@ -437,10 +439,20 @@ struct pw_context *pw_context_new(struct pw_loop *loop,
 	pw_fill_context_properties(properties);
 	this->properties = properties;
 
+	this->loop = loop;
+
 	pw_type_init(&this->type);
+
 	spa_debug_set_type_map(this->type.map);
 
-	this->loop = loop;
+	impl->support[0].type = SPA_TYPE__TypeMap;
+	impl->support[0].data = this->type.map;
+	impl->support[1].type = SPA_TYPE_LOOP__MainLoop;
+	impl->support[1].data = this->loop->loop;
+	impl->support[2].type = SPA_TYPE__Log;
+	impl->support[2].data = pw_log_get(impl->support, 2);
+	this->support = impl->support;
+	this->n_support = 3;
 
 	impl->flush_event = pw_loop_add_event(loop, do_flush_event, impl);
 

pipewire/client/context.h

@@ -144,6 +144,9 @@ struct pw_context {
 
 	struct pw_loop *loop;			/**< the loop */
 
+	struct spa_support *support;		/**< support for spa plugins */
+	uint32_t n_support;			/**< number of support items */
+
 	struct pw_proxy *core_proxy;		/**< proxy for the core object */
 	struct pw_proxy *registry_proxy;	/**< proxy for the registry object. Can
 						 *   be NULL when \ref PW_CONTEXT_FLAG_NO_PROXY

pipewire/client/log.c

@@ -20,147 +20,100 @@
 #include <stdio.h>
 #include <unistd.h>
 #include <errno.h>
-#include <sys/eventfd.h>
+#include <dlfcn.h>
 
-#include <spa/ringbuffer.h>
+#include <spa/log.h>
 
 #include <pipewire/client/log.h>
+#include <pipewire/client/type.h>
 
 #define DEFAULT_LOG_LEVEL SPA_LOG_LEVEL_ERROR
 
 enum spa_log_level pw_log_level = DEFAULT_LOG_LEVEL;
 
-/** \cond */
-#define TRACE_BUFFER (16*1024)
+static struct spa_log *global_log = NULL;
 
-struct debug_log {
-	struct spa_log log;
-	struct spa_ringbuffer trace_rb;
-	uint8_t trace_data[TRACE_BUFFER];
-	bool have_source;
-	struct spa_source source;
-};
-/** \endcond */
-
-static void
-do_logv(struct spa_log *log,
-	enum spa_log_level level,
-	const char *file,
-	int line,
-	const char *func,
-	const char *fmt,
-	va_list args)
+struct spa_log *pw_spa_log_load(const char *lib,
+				const char *factory_name,
+				struct spa_support *support,
+				uint32_t n_support)
 {
-	struct debug_log *l = SPA_CONTAINER_OF(log, struct debug_log, log);
-	char text[1024], location[1024];
-	static const char *levels[] = { "-", "E", "W", "I", "D", "T", "*T*" };
-	int size;
-	bool do_trace;
+        int res;
+        struct spa_handle *handle;
+        void *hnd;
+        uint32_t index, type_log;
+        spa_handle_factory_enum_func_t enum_func;
+        const struct spa_handle_factory *factory;
+        void *iface;
+	struct spa_type_map *map = NULL;
 
-	vsnprintf(text, sizeof(text), fmt, args);
-
-	if ((do_trace = (level == SPA_LOG_LEVEL_TRACE && l->have_source)))
-		level++;
-
-	size = snprintf(location, sizeof(location), "[%s][%s:%i %s()] %s\n",
-			levels[level], strrchr(file, '/') + 1, line, func, text);
-
-	if (SPA_UNLIKELY(do_trace)) {
-		uint32_t index;
-		uint64_t count = 1;
-
-		spa_ringbuffer_get_write_index(&l->trace_rb, &index);
-		spa_ringbuffer_write_data(&l->trace_rb, l->trace_data,
-					  index & l->trace_rb.mask, location, size);
-		spa_ringbuffer_write_update(&l->trace_rb, index + size);
-
-		write(l->source.fd, &count, sizeof(uint64_t));
-	} else
-		fputs(location, stdout);
-}
-
-static void
-do_log(struct spa_log *log,
-       enum spa_log_level level,
-       const char *file,
-       int line,
-       const char *func,
-       const char *fmt, ...)
-{
-	va_list args;
-	va_start(args, fmt);
-	do_logv(log, level, file, line, func, fmt, args);
-	va_end(args);
-}
-
-static void on_trace_event(struct spa_source *source)
-{
-	struct debug_log *l = source->data;
-	int32_t avail;
-	uint32_t index;
-	uint64_t count;
-
-	if (read(source->fd, &count, sizeof(uint64_t)) != sizeof(uint64_t))
-		fprintf(stderr, "failed to read event fd: %s", strerror(errno));
-
-	while ((avail = spa_ringbuffer_get_read_index(&l->trace_rb, &index)) > 0) {
-		uint32_t offset, first;
-
-		if (avail > l->trace_rb.size) {
-			fprintf(stderr, "\n** trace overflow ** %d\n", avail);
-			index += avail - l->trace_rb.size;
-			avail = l->trace_rb.size;
-		}
-		offset = index & l->trace_rb.mask;
-		first = SPA_MIN(avail, l->trace_rb.size - offset);
-
-		fwrite(l->trace_data + offset, first, 1, stderr);
-		if (SPA_UNLIKELY(avail > first)) {
-			fwrite(l->trace_data, avail - first, 1, stderr);
-		}
-		spa_ringbuffer_read_update(&l->trace_rb, index + avail);
+	for (index = 0; index < n_support; index++) {
+		if (strcmp(support[index].type, SPA_TYPE__TypeMap) == 0)
+                        map = support[index].data;
 	}
-}
-
-static void
-do_set_loop(struct spa_log *log, struct spa_loop *loop)
-{
-	struct debug_log *l = SPA_CONTAINER_OF(log, struct debug_log, log);
-
-	if (l->have_source) {
-		spa_loop_remove_source(l->source.loop, &l->source);
-		close(l->source.fd);
-		l->have_source = false;
+	if (map == NULL) {
+                fprintf(stderr, "no type map");
+		return NULL;
 	}
-	if (loop) {
-		l->source.func = on_trace_event;
-		l->source.data = l;
-		l->source.fd = eventfd(0, EFD_CLOEXEC | EFD_NONBLOCK);
-		l->source.mask = SPA_IO_IN;
-		l->source.rmask = 0;
-		spa_loop_add_source(loop, &l->source);
-		l->have_source = true;
-	}
-}
 
-static struct debug_log log = {
-	{sizeof(struct spa_log),
-	 NULL,
-	 DEFAULT_LOG_LEVEL,
-	 do_log,
-	 do_logv,
-	 do_set_loop,
-	 },
-	{0, 0, TRACE_BUFFER, TRACE_BUFFER - 1},
-};
+	type_log = spa_type_map_get_id(map, SPA_TYPE__Log);
+
+        if ((hnd = dlopen(lib, RTLD_NOW)) == NULL) {
+                fprintf(stderr, "can't load %s: %s", lib, dlerror());
+                return NULL;
+        }
+        if ((enum_func = dlsym(hnd, SPA_HANDLE_FACTORY_ENUM_FUNC_NAME)) == NULL) {
+                fprintf(stderr, "can't find enum function");
+                goto no_symbol;
+        }
+
+        for (index = 0;; index++) {
+                if ((res = enum_func(&factory, index)) < 0) {
+                        if (res != SPA_RESULT_ENUM_END)
+                                fprintf(stderr, "can't enumerate factories: %d", res);
+                        goto enum_failed;
+                }
+                if (strcmp(factory->name, factory_name) == 0)
+                        break;
+        }
+
+        handle = calloc(1, factory->size);
+        if ((res = spa_handle_factory_init(factory,
+                                           handle, NULL, support, n_support)) < 0) {
+                fprintf(stderr, "can't make factory instance: %d", res);
+                goto init_failed;
+        }
+        if ((res = spa_handle_get_interface(handle, type_log, &iface)) < 0) {
+                fprintf(stderr, "can't get log interface %d", res);
+                goto interface_failed;
+        }
+        return iface;
+
+      interface_failed:
+        spa_handle_clear(handle);
+      init_failed:
+        free(handle);
+      enum_failed:
+      no_symbol:
+        dlclose(hnd);
+        return NULL;
+}
 
 /** Get the global log interface
  * \return the global log
  * \memberof pw_log
  */
-struct spa_log *pw_log_get(void)
+struct spa_log *pw_log_get(struct spa_support *support,
+			   uint32_t n_support)
 {
-	return &log.log;
+	if (global_log == NULL) {
+		global_log = pw_spa_log_load("build/spa/plugins/logger/libspa-logger.so",
+					     "logger",
+					     support,
+					     n_support);
+		global_log->level = pw_log_level;
+	}
+	return global_log;
 }
 
 /** Set the global log level
@@ -170,19 +123,8 @@ struct spa_log *pw_log_get(void)
 void pw_log_set_level(enum spa_log_level level)
 {
 	pw_log_level = level;
-	log.log.level = level;
-}
-
-/** Set the trace loop
- * \param loop the trace loop
- *
- * Trace logging will be done in this loop.
- *
- * \memberof pw_log
- */
-void pw_log_set_loop(struct spa_loop *loop)
-{
-	do_set_loop(&log.log, loop);
+	if (global_log)
+		global_log->level = level;
 }
 
 /** Log a message
@@ -202,10 +144,10 @@ pw_log_log(enum spa_log_level level,
 	   const char *func,
 	   const char *fmt, ...)
 {
-	if (SPA_UNLIKELY(pw_log_level_enabled(level))) {
+	if (SPA_UNLIKELY(pw_log_level_enabled(level) && global_log)) {
 		va_list args;
 		va_start(args, fmt);
-		do_logv(&log.log, level, file, line, func, fmt, args);
+		global_log->logv(global_log, level, file, line, func, fmt, args);
 		va_end(args);
 	}
 }
@@ -228,8 +170,8 @@ pw_log_logv(enum spa_log_level level,
 	    const char *fmt,
 	    va_list args)
 {
-	if (SPA_UNLIKELY(pw_log_level_enabled(level))) {
-		do_logv(&log.log, level, file, line, func, fmt, args);
+	if (SPA_UNLIKELY(pw_log_level_enabled(level) && global_log)) {
+		global_log->logv(global_log, level, file, line, func, fmt, args);
 	}
 }
 

pipewire/client/log.h

@@ -39,14 +39,11 @@ extern "C" {
 /** The global log level */
 extern enum spa_log_level pw_log_level;
 
-struct spa_log *pw_log_get(void);
+struct spa_log *pw_log_get(struct spa_support *support, uint32_t n_support);
 
 void
 pw_log_set_level(enum spa_log_level level);
 
-void
-pw_log_set_loop(struct spa_loop *loop);
-
 
 void
 pw_log_log(enum spa_log_level level,

pipewire/client/meson.build

@@ -58,7 +58,7 @@ libpipewire = shared_library('pipewire', pipewire_sources,
   include_directories : [configinc, spa_inc],
   link_with : spalib,
   install : true,
-  dependencies : [dbus_dep, mathlib, pthread_lib],
+  dependencies : [dbus_dep, dl_lib, mathlib, pthread_lib],
 )
 
 pipewire_dep = declare_dependency(link_with : libpipewire,

pipewire/client/proxy.c

@@ -67,7 +67,7 @@ struct pw_proxy *pw_proxy_new(struct pw_context *context, uint32_t id, uint32_t
 
 	spa_list_insert(&this->context->proxy_list, &this->link);
 
-	pw_log_trace("proxy %p: new %u", this, this->id);
+	pw_log_debug("proxy %p: new %u", this, this->id);
 
 	return this;
 
@@ -89,7 +89,7 @@ void pw_proxy_destroy(struct pw_proxy *proxy)
 {
 	struct proxy *impl = SPA_CONTAINER_OF(proxy, struct proxy, this);
 
-	pw_log_trace("proxy %p: destroy %u", proxy, proxy->id);
+	pw_log_debug("proxy %p: destroy %u", proxy, proxy->id);
 	pw_signal_emit(&proxy->destroy_signal, proxy);
 
 	pw_map_remove(&proxy->context->objects, proxy->id);

pipewire/client/type.c

@@ -48,6 +48,7 @@ void pw_type_init(struct pw_type *type)
 	type->client_node = spa_type_map_get_id(type->map, PIPEWIRE_TYPE__ClientNode);
 	type->module = spa_type_map_get_id(type->map, PIPEWIRE_TYPE__Module);
 
+	type->spa_log = spa_type_map_get_id(type->map, SPA_TYPE__Log);
 	type->spa_node = spa_type_map_get_id(type->map, SPA_TYPE__Node);
 	type->spa_clock = spa_type_map_get_id(type->map, SPA_TYPE__Clock);
 	type->spa_monitor = spa_type_map_get_id(type->map, SPA_TYPE__Monitor);

pipewire/client/type.h

@@ -67,6 +67,7 @@ struct pw_type {
 	uint32_t client_node;
 	uint32_t module;
 
+	uint32_t spa_log;
 	uint32_t spa_node;
 	uint32_t spa_clock;
 	uint32_t spa_monitor;

pipewire/daemon/main.c

@@ -41,7 +41,6 @@ int main(int argc, char *argv[])
 	}
 
 	loop = pw_main_loop_new();
-	pw_log_set_loop(loop->loop->loop);
 
 	core = pw_core_new(loop, NULL);
 

pipewire/server/client-node.c

@@ -993,7 +993,9 @@ static const struct spa_node proxy_node = {
 
 static int
 proxy_init(struct proxy *this,
-	   struct spa_dict *info, const struct spa_support *support, uint32_t n_support)
+	   struct spa_dict *info,
+	   const struct spa_support *support,
+	   uint32_t n_support)
 {
 	uint32_t i;
 
@@ -1005,7 +1007,7 @@ proxy_init(struct proxy *this,
 		else if (strcmp(support[i].type, SPA_TYPE_LOOP__DataLoop) == 0)
 			this->data_loop = support[i].data;
 	}
-	if (this->data_loop == NULL) {
+	if (this->main_loop == NULL) {
 		spa_log_error(this->log, "a main-loop is needed");
 	}
 	if (this->data_loop == NULL) {

pipewire/server/core.c

@@ -365,12 +365,12 @@ struct pw_core *pw_core_new(struct pw_main_loop *main_loop, struct pw_properties
 
 	impl->support[0].type = SPA_TYPE__TypeMap;
 	impl->support[0].data = this->type.map;
-	impl->support[1].type = SPA_TYPE__Log;
-	impl->support[1].data = pw_log_get();
-	impl->support[2].type = SPA_TYPE_LOOP__DataLoop;
-	impl->support[2].data = this->data_loop->loop->loop;
-	impl->support[3].type = SPA_TYPE_LOOP__MainLoop;
-	impl->support[3].data = this->main_loop->loop->loop;
+	impl->support[1].type = SPA_TYPE_LOOP__DataLoop;
+	impl->support[1].data = this->data_loop->loop->loop;
+	impl->support[2].type = SPA_TYPE_LOOP__MainLoop;
+	impl->support[2].data = this->main_loop->loop->loop;
+	impl->support[3].type = SPA_TYPE__Log;
+	impl->support[3].data = pw_log_get(impl->support, 3);
 	this->support = impl->support;
 	this->n_support = 4;
 

spa/include/spa/log-impl.h

@@ -55,10 +55,6 @@ static inline void spa_log_impl_log(struct spa_log *log,
 	va_end(args);
 }
 
-static inline void spa_log_impl_set_loop(struct spa_log *log, struct spa_loop *loop)
-{
-}
-
 #define SPA_LOG_IMPL_DEFINE(name)		\
 struct {					\
 	struct spa_log log;			\
@@ -69,8 +65,7 @@ struct {					\
             NULL,				\
 	    SPA_LOG_LEVEL_INFO,			\
 	    spa_log_impl_log,			\
-	    spa_log_impl_logv,			\
-	    spa_log_impl_set_loop,} }
+	    spa_log_impl_logv,} }
 
 #define SPA_LOG_IMPL(name)			\
         SPA_LOG_IMPL_DEFINE(name) = SPA_LOG_IMPL_INIT

spa/include/spa/log.h

@@ -103,21 +103,8 @@ struct spa_log {
 		      const char *func,
 		      const char *fmt,
 		      va_list args) SPA_PRINTF_FUNC(6, 0);
-	/**
-	 * Set the loop for trace logging
-	 * \param log the logger
-	 * \param loop the loop for trace logging
-	 *
-	 * Trace logging will be done to a ringbuffer and written to
-	 * the console/device from \a loop to ensure no blocking operations
-	 * are done from the realtime thread.
-	 */
-	void (*set_loop) (struct spa_log *log,
-			  struct spa_loop *loop);
 };
 
-#define spa_log_set_loop(l,...)	     (l)->set_loop((l),__VA_ARGS__)
-
 #define spa_log_level_enabled(l,lev) ((l) && (l)->level >= (lev))
 
 #if __STDC_VERSION__ >= 199901L

spa/plugins/logger/logger.c

@@ -38,7 +38,7 @@
 
 #define DEFAULT_LOG_LEVEL SPA_LOG_LEVEL_INFO
 
-#define TRACE_BUFFER 4096
+#define TRACE_BUFFER (16*1024)
 
 struct type {
 	uint32_t log;
@@ -142,33 +142,12 @@ static void on_trace_event(struct spa_source *source)
         }
 }
 
-static void
-impl_log_set_loop(struct spa_log *log, struct spa_loop *loop)
-{
-	struct impl *impl = SPA_CONTAINER_OF(log, struct impl, log);
-	if (impl->have_source) {
-		spa_loop_remove_source(impl->source.loop, &impl->source);
-		close(impl->source.fd);
-		impl->have_source = false;
-	}
-	if (loop) {
-		impl->source.func = on_trace_event;
-		impl->source.data = impl;
-		impl->source.fd = eventfd(0, EFD_CLOEXEC | EFD_NONBLOCK);
-		impl->source.mask = SPA_IO_IN;
-		impl->source.rmask = 0;
-		spa_loop_add_source(loop, &impl->source);
-		impl->have_source = true;
-	}
-}
-
 static const struct spa_log impl_log = {
 	sizeof(struct spa_log),
 	NULL,
 	DEFAULT_LOG_LEVEL,
-        impl_log_log,
-        impl_log_logv,
-        impl_log_set_loop,
+	impl_log_log,
+	impl_log_logv,
 };
 
 static int impl_get_interface(struct spa_handle *handle, uint32_t interface_id, void **interface)
@@ -196,8 +175,11 @@ static int impl_clear(struct spa_handle *handle)
 
 	this = (struct impl *) handle;
 
-	impl_log_set_loop(&this->log, NULL);
-
+	if (this->have_source) {
+		spa_loop_remove_source(this->source.loop, &this->source);
+		close(this->source.fd);
+		this->have_source = false;
+	}
 	return SPA_RESULT_OK;
 }
 
@@ -210,6 +192,7 @@ impl_init(const struct spa_handle_factory *factory,
 {
 	struct impl *this;
 	uint32_t i;
+	struct spa_loop *loop = NULL;
 
 	spa_return_val_if_fail(factory != NULL, SPA_RESULT_INVALID_ARGUMENTS);
 	spa_return_val_if_fail(handle != NULL, SPA_RESULT_INVALID_ARGUMENTS);
@@ -224,6 +207,8 @@ impl_init(const struct spa_handle_factory *factory,
 	for (i = 0; i < n_support; i++) {
 		if (strcmp(support[i].type, SPA_TYPE__TypeMap) == 0)
 			this->map = support[i].data;
+		if (strcmp(support[i].type, SPA_TYPE_LOOP__MainLoop) == 0)
+			loop = support[i].data;
 	}
 	if (this->map == NULL) {
 		spa_log_error(&this->log, "a type-map is needed");
@@ -231,6 +216,16 @@ impl_init(const struct spa_handle_factory *factory,
 	}
 	init_type(&this->type, this->map);
 
+	if (loop) {
+		this->source.func = on_trace_event;
+		this->source.data = this;
+		this->source.fd = eventfd(0, EFD_CLOEXEC | EFD_NONBLOCK);
+		this->source.mask = SPA_IO_IN;
+		this->source.rmask = 0;
+		spa_loop_add_source(loop, &this->source);
+		this->have_source = true;
+	}
+
 	spa_ringbuffer_init(&this->trace_rb, TRACE_BUFFER);
 
 	spa_log_info(&this->log, NAME " %p: initialized", this);