libeis: replace the logger utility with a custom logger handling

The logger utilities are useful for quick prototyping, but we've reached the
point where we need the "proper" implementation of a log handler.

Signed-off-by: Peter Hutterer <peter.hutterer@who-t.net>

meson.build

@@ -74,6 +74,7 @@ src_libeis = [
     'src/libeis-client.c',
     'src/libeis-device.c',
     'src/libeis-event.c',
+    'src/libeis-log.c',
     'src/libeis-socket.c',
     'src/libeis-fd.c',
     'src/libeis-proto.h',

src/libeis-client.c

@@ -30,7 +30,6 @@
 
 #include "util-bits.h"
 #include "util-io.h"
-#include "util-logger.h"
 #include "util-macros.h"
 #include "util-mem.h"
 #include "util-sources.h"

src/libeis-event.c

@@ -27,7 +27,6 @@
 
 #include "util-object.h"
 #include "util-macros.h"
-#include "util-logger.h"
 
 #include "libeis-private.h"
 

src/libeis-fd.c

@@ -27,7 +27,6 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 
-#include "util-logger.h"
 #include "util-mem.h"
 #include "util-macros.h"
 #include "util-sources.h"

src/libeis-log.c

@@ -0,0 +1,217 @@
+/*
+ * Copyright © 2020 Red Hat, Inc.
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a
+ * copy of this software and associated documentation files (the "Software"),
+ * to deal in the Software without restriction, including without limitation
+ * the rights to use, copy, modify, merge, publish, distribute, sublicense,
+ * and/or sell copies of the Software, and to permit persons to whom the
+ * Software is furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice (including the next
+ * paragraph) shall be included in all copies or substantial portions of the
+ * Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.  IN NO EVENT SHALL
+ * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
+ * FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER
+ * DEALINGS IN THE SOFTWARE.
+ */
+
+#include "config.h"
+
+#include <stdio.h>
+#include <time.h>
+
+#include "util-macros.h"
+#include "util-color.h"
+#include "util-strings.h"
+#include "libeis-private.h"
+
+static void
+eis_default_log_handler(struct eis *eis,
+		       enum eis_log_priority priority,
+		       const char *message,
+		       bool is_continuation)
+{
+	static struct lut {
+		const char *color;
+		const char *prefix;
+	} lut[] = {
+		{ .color = ansi_colorcode[RED],		.prefix = "<undefined>", }, /* debug starts at 10 */
+		{ .color = ansi_colorcode[HIGHLIGHT],	.prefix = "DEBUG", },
+		{ .color = ansi_colorcode[GREEN],	.prefix = "INFO", },
+		{ .color = ansi_colorcode[BLUE],	.prefix = "WARN", },
+		{ .color = ansi_colorcode[RED],		.prefix = "ERROR", },
+	};
+	static time_t last_time = 0;
+	static const char *reset_code = ansi_colorcode[RESET];
+
+	run_only_once {
+		if (!isatty(STDERR_FILENO)) {
+			struct lut *l;
+			ARRAY_FOR_EACH(lut, l)
+				l->color = "";
+			reset_code = "";
+		}
+	}
+
+	time_t now = time(NULL);
+
+	if (is_continuation) {
+		fprintf(stderr, "%s", message);
+	} else {
+		char timestamp[64];
+
+		if (last_time != now) {
+			struct tm *tm = localtime(&now);
+			strftime(timestamp, sizeof(timestamp), "%T", tm);
+		} else {
+			xsnprintf(timestamp, sizeof(timestamp), "...");
+		}
+
+		size_t idx = priority/10;
+		assert(idx < ARRAY_LENGTH(lut));
+		fprintf(stderr, " EIS: %8s | %s%4s%s | %s", timestamp,
+			lut[idx].color, lut[idx].prefix, reset_code, message);
+	}
+
+	last_time = now;
+}
+
+_public_ void
+eis_log_set_handler(struct eis *eis, eis_log_handler log_handler)
+{
+	eis->log.handler = log_handler ? log_handler : eis_default_log_handler;
+}
+
+_public_ void
+eis_log_set_priority(struct eis *eis, enum eis_log_priority priority)
+{
+	switch (priority) {
+	case EIS_LOG_PRIORITY_DEBUG:
+	case EIS_LOG_PRIORITY_INFO:
+	case EIS_LOG_PRIORITY_WARNING:
+	case EIS_LOG_PRIORITY_ERROR:
+		break;
+	default:
+		abort();
+	}
+	eis->log.priority = priority;
+}
+
+_public_ enum eis_log_priority
+eis_log_get_priority(const struct eis *eis)
+{
+	return eis->log.priority;
+}
+
+void
+eis_log_msg(struct eis *eis,
+	   enum eis_log_priority priority,
+	   const char *format, ...)
+{
+	va_list args;
+
+	va_start(args, format);
+	eis_log_msg_va(eis, priority, format, args);
+	va_end(args);
+}
+
+void
+eis_log_msg_va(struct eis *eis,
+	      enum eis_log_priority priority,
+	      const char *format,
+	      va_list ap)
+{
+	if (eis->log.priority > priority)
+		return;
+
+	char line[1024];
+
+	if (xvsnprintf(line, sizeof(line), format, ap))
+		eis->log.handler(eis, priority, line, false);
+	else
+		eis->log.handler(eis, priority, "BUG: <message truncated>", false);
+
+}
+
+#ifdef _enable_tests_
+#include "util-munit.h"
+
+struct log_handler_check {
+	enum eis_log_priority min_priority;
+	const char *expected_message;
+	bool is_continuation;
+};
+
+static void
+test_loghandler(struct eis *eis,
+		 enum eis_log_priority priority,
+		 const char *message,
+		 bool is_continuation)
+{
+	struct log_handler_check *check = eis_get_user_data(eis);
+
+	munit_assert_int(priority, >=, check->min_priority);
+	munit_assert_string_equal(message, check->expected_message);
+	munit_assert(is_continuation == check->is_continuation);
+}
+
+MUNIT_TEST(test_log_handler)
+{
+	struct log_handler_check check = {0};
+	struct eis *eis = eis_new(&check);
+
+	munit_assert_ptr_equal(eis->log.handler, eis_default_log_handler);
+	munit_assert_int(eis->log.priority, ==, EIS_LOG_PRIORITY_INFO);
+
+	eis_log_set_handler(eis, test_loghandler);
+
+	check.min_priority = EIS_LOG_PRIORITY_INFO; /* default */
+	check.expected_message = "info message";
+	check.is_continuation = false,
+
+	log_debug(eis, "default is below this level");
+	log_info(eis, "info message");
+
+	check.expected_message = "error message";
+	log_error(eis, "error message");
+
+	check.min_priority = EIS_LOG_PRIORITY_ERROR;
+	eis_log_set_priority(eis, EIS_LOG_PRIORITY_ERROR);
+	munit_assert_int(eis->log.priority, ==, EIS_LOG_PRIORITY_ERROR);
+	log_error(eis, "error message");
+	log_warn(eis, "warn message");
+	log_info(eis, "info message");
+	log_debug(eis, "debug message");
+
+	eis_log_set_priority(eis, EIS_LOG_PRIORITY_DEBUG);
+
+	/* Make sure they come through at the right priority */
+	check.min_priority = EIS_LOG_PRIORITY_ERROR;
+	check.expected_message = "error message";
+	log_error(eis, "error message");
+	check.min_priority = EIS_LOG_PRIORITY_WARNING;
+	check.expected_message = "warn message";
+	log_warn(eis, "warn message");
+	check.min_priority = EIS_LOG_PRIORITY_INFO;
+	check.expected_message = "info message";
+	log_info(eis, "info message");
+	check.min_priority = EIS_LOG_PRIORITY_DEBUG;
+	check.expected_message = "debug message";
+	log_debug(eis, "debug message");
+
+	/* Can't capture this easily, so this is mostly just a crash test */
+	eis_log_set_handler(eis, NULL);
+	munit_assert_ptr_equal(eis->log.handler, eis_default_log_handler);
+	log_debug(eis, "ignore this, testing NULL log handler");
+
+	eis_unref(eis);
+
+	return MUNIT_OK;
+}
+#endif

src/libeis-private.h

@@ -23,6 +23,8 @@
 
 #pragma once
 
+#include <stdarg.h>
+
 #include "util-object.h"
 
 #include "libeis.h"
@@ -37,13 +39,17 @@ struct eis_backend_interface {
 struct eis {
 	struct object object;
 	void *user_data;
-	struct logger *logger;
 	struct sink *sink;
 	struct list clients;
 
 	struct eis_backend_interface backend_interface;
 	void *backend;
 	struct list event_queue;
+
+	struct {
+		eis_log_handler handler;
+		enum eis_log_priority priority;
+	} log;
 };
 
 enum eis_client_state {
@@ -201,3 +207,25 @@ eis_queue_pointer_button_event(struct eis_device *device, uint32_t button,
 void
 eis_queue_keyboard_key_event(struct eis_device *device, uint32_t key,
 			     bool is_press);
+
+void
+eis_log_msg(struct eis *eis,
+	    enum eis_log_priority priority,
+	    const char *format, ...);
+
+void
+eis_log_msg_va(struct eis *eis,
+	       enum eis_log_priority priority,
+	       const char *format,
+	       va_list args);
+
+#define log_debug(T_, ...) \
+	eis_log_msg((T_), EIS_LOG_PRIORITY_DEBUG, __VA_ARGS__)
+#define log_info(T_, ...) \
+	eis_log_msg((T_), EIS_LOG_PRIORITY_INFO, __VA_ARGS__)
+#define log_warn(T_, ...) \
+	eis_log_msg((T_), EIS_LOG_PRIORITY_WARNING, __VA_ARGS__)
+#define log_error(T_, ...) \
+	eis_log_msg((T_), EIS_LOG_PRIORITY_ERROR, __VA_ARGS__)
+#define log_bug(T_, ...) \
+	eis_log_msg((T_), EIS_LOG_PRIORITY_ERROR, "bug: " __VA_ARGS__)

src/libeis-proto.c

@@ -27,7 +27,6 @@
 
 #include "util-object.h"
 #include "util-io.h"
-#include "util-logger.h"
 #include "util-strings.h"
 
 #include "proto/ei.pb-c.h"

src/libeis-socket.c

@@ -27,7 +27,6 @@
 #include <sys/socket.h>
 #include <sys/un.h>
 
-#include "util-logger.h"
 #include "util-mem.h"
 #include "util-macros.h"
 #include "util-sources.h"

src/libeis.c

@@ -28,7 +28,6 @@
 #include <stdio.h>
 #include <unistd.h>
 
-#include "util-logger.h"
 #include "util-macros.h"
 #include "util-object.h"
 #include "util-sources.h"
@@ -50,7 +49,6 @@ eis_destroy(struct eis *eis)
 	while ((e = eis_get_event(eis)) != NULL)
 		eis_event_unref(e);
 
-	eis->logger = logger_unref(eis->logger);
 	if (eis->backend_interface.destroy)
 		eis->backend_interface.destroy(eis, eis->backend);
 	sink_unref(eis->sink);
@@ -74,8 +72,8 @@ eis_new(void *user_data)
 	list_init(&eis->clients);
 	list_init(&eis->event_queue);
 
-	eis->logger = logger_new("eis", eis);
-	logger_set_priority(eis->logger, LOGGER_DEBUG);
+	eis_log_set_handler(eis, NULL);
+	eis_log_set_priority(eis, EIS_LOG_PRIORITY_INFO);
 	eis->sink = sink_new();
 	if (!eis->sink)
 		return NULL;

src/libeis.h

@@ -102,6 +102,42 @@ enum eis_event_type {
 struct eis *
 eis_new(void *user_data);
 
+enum eis_log_priority {
+	EIS_LOG_PRIORITY_DEBUG = 10,
+	EIS_LOG_PRIORITY_INFO = 20,
+	EIS_LOG_PRIORITY_WARNING = 30,
+	EIS_LOG_PRIORITY_ERROR = 40,
+};
+
+/**
+ * The log handler for library logging. This handler is only called for
+ * messages with a log level equal or greater than than the one set in
+ * eis_log_set_priority().
+ *
+ * @param message The log message as a null-terminated string
+ * @param is_continuation The message is a continuation of the previous
+ * message. The caller should skip any per-line-based prefixes.
+ */
+typedef void (*eis_log_handler)(struct eis *eis,
+				enum eis_log_priority priority,
+				const char *message,
+				bool is_continuation);
+/**
+ * Change the log handler for this context. If the log handler is NULL, the
+ * built-in default log function is used.
+ *
+ * @param log_handler The log handler or NULL to use the default log
+ * handler.
+ */
+void
+eis_log_set_handler(struct eis *eis, eis_log_handler log_handler);
+
+void
+eis_log_set_priority(struct eis *eis, enum eis_log_priority priority);
+
+enum eis_log_priority
+eis_log_get_priority(const struct eis *eis);
+
 struct eis *
 eis_ref(struct eis *eis);
 

tools/eis-socket-server.c

@@ -56,6 +56,8 @@ int main(int argc, char **argv)
 	_cleanup_(eis_unrefp) struct eis *eis = eis_new(NULL);
 	assert(eis);
 
+	eis_log_set_priority(eis, EIS_LOG_PRIORITY_DEBUG);
+
 	_cleanup_unlink_free_ char *socketpath = NULL;
 	if (argc < 2) {
 		const char SOCKETNAME[] = "eis-0";