log: support logging levels

9 files changed, 116 insertions, 57 deletions

diff --git a/src/.clang-format b/src/.clang-format
index d46a7a3..301680e 100644
--- a/src/.clang-format
+++ b/src/.clang-format
@@ -9,4 +9,5 @@ AllowShortIfStatementsOnASingleLine: false
 IndentCaseLabels: false
 
 ColumnLimit: 100
+AlignConsecutiveMacros: Consecutive
 AllowShortFunctionsOnASingleLine: Empty
diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt
index 23d5fe4..a6af563 100644
--- a/src/CMakeLists.txt
+++ b/src/CMakeLists.txt
@@ -37,6 +37,7 @@ add_my_executable(server server_main.c server.c
     command.c
     event_loop.c
     file.c
+    log.c
     msg.c
     net.c
     run_queue.c
@@ -54,6 +55,7 @@ target_include_directories(server PRIVATE "${CMAKE_CURRENT_BINARY_DIR}")
 add_my_executable(client client_main.c client.c
     cmd_line.c
     file.c
+    log.c
     msg.c
     net.c)
 
@@ -64,6 +66,7 @@ add_my_executable(worker worker_main.c worker.c
     event_loop.c
     file.c
     git.c
+    log.c
     msg.c
     net.c
     process.c
diff --git a/src/client_main.c b/src/client_main.c
index 1969952..0a417d9 100644
--- a/src/client_main.c
+++ b/src/client_main.c
@@ -8,6 +8,7 @@
 #include "client.h"
 #include "cmd_line.h"
 #include "const.h"
+#include "log.h"
 
 #include <getopt.h>
 #include <unistd.h>
@@ -20,7 +21,7 @@ static struct settings default_settings(void)
 
 const char *get_usage_string(void)
 {
-	return "[-h|--help] [-V|--version] [-H|--host HOST] [-p|--port PORT]";
+	return "[-h|--help] [-V|--version] [-v|--verbose] [-H|--host HOST] [-p|--port PORT]";
 }
 
 static int parse_settings(struct settings *settings, int argc, char *argv[])
@@ -32,12 +33,13 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 	static struct option long_options[] = {
 	    {"help", no_argument, 0, 'h'},
 	    {"version", no_argument, 0, 'V'},
+	    {"verbose", no_argument, 0, 'v'},
 	    {"host", required_argument, 0, 'H'},
 	    {"port", required_argument, 0, 'p'},
 	    {0, 0, 0, 0},
 	};
 
-	while ((opt = getopt_long(argc, argv, "hVH:p:", long_options, &longind)) != -1) {
+	while ((opt = getopt_long(argc, argv, "hVvH:p:", long_options, &longind)) != -1) {
 		switch (opt) {
 		case 'h':
 			exit_with_usage(0);
@@ -45,6 +47,9 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 		case 'V':
 			exit_with_version();
 			break;
+		case 'v':
+			g_log_lvl = LOG_LVL_DEBUG;
+			break;
 		case 'H':
 			settings->host = optarg;
 			break;
diff --git a/src/compiler.h b/src/compiler.h
index 9c4cbc5..97c583c 100644
--- a/src/compiler.h
+++ b/src/compiler.h
@@ -14,4 +14,7 @@
 #define UNUSED
 #endif
 
+#define CONCAT_(a, b) a##b
+#define CONCAT(a, b)  CONCAT_(a, b)
+
 #endif
diff --git a/src/event_loop.c b/src/event_loop.c
index de7fbf1..2744677 100644
--- a/src/event_loop.c
+++ b/src/event_loop.c
@@ -94,7 +94,7 @@ void event_loop_destroy(struct event_loop *loop)
 
 static void event_loop_add_internal(struct event_loop *loop, struct event_fd *entry)
 {
-	log("Adding descriptor %d to event loop\n", entry->fd);
+	log_debug("Adding descriptor %d to event loop\n", entry->fd);
 
 	nfds_t nfds = loop->nfds + 1;
 	SIMPLEQ_INSERT_TAIL(&loop->entries, entry, entries);
@@ -123,7 +123,7 @@ int event_loop_add_once(struct event_loop *loop, int fd, short events, event_han
 
 static void event_loop_remove(struct event_loop *loop, struct event_fd *entry)
 {
-	log("Removing descriptor %d from event loop\n", entry->fd);
+	log_debug("Removing descriptor %d from event loop\n", entry->fd);
 
 	SIMPLEQ_REMOVE(&loop->entries, entry, event_fd, entries);
 	net_close(entry->fd);
@@ -179,10 +179,10 @@ static struct pollfd *make_pollfds(const struct event_loop *loop)
 		fds[i].events = entry->events;
 	}
 
-	log("Descriptors:\n");
+	log_debug("Descriptors:\n");
 	for (nfds_t i = 0; i < loop->nfds; ++i) {
 		char *events = events_to_string(fds[i].events);
-		log("    %d (%s)\n", fds[i].fd, events ? events : "");
+		log_debug("    %d (%s)\n", fds[i].fd, events ? events : "");
 		free(events);
 	}
 
@@ -210,7 +210,7 @@ int event_loop_run(struct event_loop *loop)
 			goto next;
 
 		char *events = events_to_string(fds[i].revents);
-		log("Descriptor %d is ready: %s\n", fds[i].fd, events ? events : "");
+		log_debug("Descriptor %d is ready: %s\n", fds[i].fd, events ? events : "");
 		free(events);
 
 		/* Execute all handlers but notice if any of them fail. */
diff --git a/src/log.c b/src/log.c
new file mode 100644
index 0000000..3886a1a
--- /dev/null
+++ b/src/log.c
@@ -0,0 +1,53 @@
+/*
+ * Copyright (c) 2023 Egor Tensin <Egor.Tensin@gmail.com>
+ * This file is part of the "cimple" project.
+ * For details, see https://github.com/egor-tensin/cimple.
+ * Distributed under the MIT License.
+ */
+
+#include "log.h"
+
+#include <stdio.h>
+#include <sys/time.h>
+#include <time.h>
+#include <unistd.h>
+
+int g_log_lvl = LOG_LVL_INFO;
+
+static inline void log_prefix_timestamp(FILE *dest)
+{
+	struct timeval tv;
+	struct tm tm;
+	char buf[64];
+	size_t used = 0;
+
+	if (gettimeofday(&tv, NULL) < 0)
+		return;
+	if (!gmtime_r(&tv.tv_sec, &tm))
+		return;
+
+	buf[0] = '\0';
+	used += strftime(buf + used, sizeof(buf) - used, "%F %T", &tm);
+	used += snprintf(buf + used, sizeof(buf) - used, ".%03ld | ", tv.tv_usec / 1000);
+	fprintf(dest, "%s", buf);
+}
+
+static inline void log_prefix_thread_id(FILE *dest)
+{
+	fprintf(dest, "%d | ", gettid());
+}
+
+int log_entry_start(int lvl, FILE *dest)
+{
+	if (lvl < g_log_lvl)
+		return 0;
+	flockfile(dest);
+	log_prefix_timestamp(dest);
+	log_prefix_thread_id(dest);
+	return 1;
+}
+
+void log_entry_end(FILE *dest)
+{
+	funlockfile(dest);
+}
diff --git a/src/log.h b/src/log.h
index 6ad16f3..201ef5a 100644
--- a/src/log.h
+++ b/src/log.h
@@ -8,74 +8,58 @@
 #ifndef __LOG_H__
 #define __LOG_H__
 
+#include "compiler.h"
+
 #include <errno.h>
 #include <libgen.h>
-#include <netdb.h>
 #include <stdio.h>
-#include <sys/time.h>
-#include <time.h>
-#include <unistd.h>
-
-static inline void log_print_timestamp(FILE *dest)
-{
-	struct timeval tv;
-	struct tm tm;
-	char buf[64];
-	size_t used = 0;
-
-	if (gettimeofday(&tv, NULL) < 0)
-		return;
-	if (!gmtime_r(&tv.tv_sec, &tm))
-		return;
 
-	buf[0] = '\0';
-	used += strftime(buf + used, sizeof(buf) - used, "%F %T", &tm);
-	used += snprintf(buf + used, sizeof(buf) - used, ".%03ld | ", tv.tv_usec / 1000);
-	fprintf(dest, "%s", buf);
-}
+#define LOG_LVL_DEBUG 0
+#define LOG_LVL_INFO  1
+#define LOG_LVL_ERR   2
 
-static inline void log_print_thread_id(FILE *dest)
-{
-	fprintf(dest, "%d | ", gettid());
-}
+extern int g_log_lvl;
 
-#define CONCAT_INNER(a, b) a##b
-#define CONCAT(a, b) CONCAT_INNER(a, b)
+int log_entry_start(int lvl, FILE *dest);
+void log_entry_end(FILE *dest);
 
-static inline void log_prefix(FILE *dest)
-{
-	log_print_timestamp(dest);
-	log_print_thread_id(dest);
-}
-
-#define log_err_prefix()                                                                           \
+#define log_debug(...)                                                                             \
 	do {                                                                                       \
-		log_prefix(stderr);                                                                \
-		fprintf(stderr, "%s(%d): ", basename(__FILE__), __LINE__);                         \
+		if (!log_entry_start(LOG_LVL_DEBUG, stdout))                                       \
+			break;                                                                     \
+		fprintf(stdout, __VA_ARGS__);                                                      \
+		log_entry_end(stdout);                                                             \
 	} while (0)
 
 #define log(...)                                                                                   \
 	do {                                                                                       \
-		flockfile(stdout);                                                                 \
-		log_prefix(stdout);                                                                \
-		printf(__VA_ARGS__);                                                               \
-		funlockfile(stdout);                                                               \
+		if (!log_entry_start(LOG_LVL_INFO, stdout))                                        \
+			break;                                                                     \
+		fprintf(stdout, __VA_ARGS__);                                                      \
+		log_entry_end(stdout);                                                             \
+	} while (0)
+
+#define log_err_file_loc()                                                                         \
+	do {                                                                                       \
+		fprintf(stderr, "%s(%d): ", basename(__FILE__), __LINE__);                         \
 	} while (0)
 
 #define log_err(...)                                                                               \
 	do {                                                                                       \
-		flockfile(stderr);                                                                 \
-		log_err_prefix();                                                                  \
+		if (!log_entry_start(LOG_LVL_ERR, stderr))                                         \
+			break;                                                                     \
+		log_err_file_loc();                                                                \
 		fprintf(stderr, __VA_ARGS__);                                                      \
-		funlockfile(stderr);                                                               \
+		log_entry_end(stderr);                                                             \
 	} while (0)
 
 #define log_errno(fn)                                                                              \
 	do {                                                                                       \
-		flockfile(stderr);                                                                 \
-		log_err_prefix();                                                                  \
+		if (!log_entry_start(LOG_LVL_ERR, stderr))                                         \
+			break;                                                                     \
+		log_err_file_loc();                                                                \
 		perror(fn);                                                                        \
-		funlockfile(stderr);                                                               \
+		log_entry_end(stderr);                                                             \
 	} while (0)
 
 #define log_errno_if(expr, fn)                                                                     \
diff --git a/src/server_main.c b/src/server_main.c
index 5a0531b..ac43bc5 100644
--- a/src/server_main.c
+++ b/src/server_main.c
@@ -7,6 +7,7 @@
 
 #include "cmd_line.h"
 #include "const.h"
+#include "log.h"
 #include "server.h"
 
 #include <getopt.h>
@@ -20,7 +21,7 @@ static struct settings default_settings(void)
 
 const char *get_usage_string(void)
 {
-	return "[-h|--help] [-V|--version] [-p|--port PORT] [-s|--sqlite PATH]";
+	return "[-h|--help] [-V|--version] [-v|--verbose] [-p|--port PORT] [-s|--sqlite PATH]";
 }
 
 static int parse_settings(struct settings *settings, int argc, char *argv[])
@@ -32,12 +33,13 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 	static struct option long_options[] = {
 	    {"help", no_argument, 0, 'h'},
 	    {"version", no_argument, 0, 'V'},
+	    {"verbose", no_argument, 0, 'v'},
 	    {"port", required_argument, 0, 'p'},
 	    {"sqlite", required_argument, 0, 's'},
 	    {0, 0, 0, 0},
 	};
 
-	while ((opt = getopt_long(argc, argv, "hVp:s:", long_options, &longind)) != -1) {
+	while ((opt = getopt_long(argc, argv, "hVvp:s:", long_options, &longind)) != -1) {
 		switch (opt) {
 		case 'h':
 			exit_with_usage(0);
@@ -45,6 +47,9 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 		case 'V':
 			exit_with_version();
 			break;
+		case 'v':
+			g_log_lvl = LOG_LVL_DEBUG;
+			break;
 		case 'p':
 			settings->port = optarg;
 			break;
diff --git a/src/worker_main.c b/src/worker_main.c
index 1bb3289..227f9a9 100644
--- a/src/worker_main.c
+++ b/src/worker_main.c
@@ -7,6 +7,7 @@
 
 #include "cmd_line.h"
 #include "const.h"
+#include "log.h"
 #include "worker.h"
 
 #include <getopt.h>
@@ -20,7 +21,7 @@ static struct settings default_settings(void)
 
 const char *get_usage_string(void)
 {
-	return "[-h|--help] [-V|--version] [-H|--host HOST] [-p|--port PORT]";
+	return "[-h|--help] [-V|--version] [-v|--verbose] [-H|--host HOST] [-p|--port PORT]";
 }
 
 static int parse_settings(struct settings *settings, int argc, char *argv[])
@@ -32,12 +33,13 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 	static struct option long_options[] = {
 	    {"help", no_argument, 0, 'h'},
 	    {"version", no_argument, 0, 'V'},
+	    {"verbose", no_argument, 0, 'v'},
 	    {"host", required_argument, 0, 'H'},
 	    {"port", required_argument, 0, 'p'},
 	    {0, 0, 0, 0},
 	};
 
-	while ((opt = getopt_long(argc, argv, "hVH:p:", long_options, &longind)) != -1) {
+	while ((opt = getopt_long(argc, argv, "hVvH:p:", long_options, &longind)) != -1) {
 		switch (opt) {
 		case 'h':
 			exit_with_usage(0);
@@ -45,6 +47,9 @@ static int parse_settings(struct settings *settings, int argc, char *argv[])
 		case 'V':
 			exit_with_version();
 			break;
+		case 'v':
+			g_log_lvl = LOG_LVL_DEBUG;
+			break;
 		case 'H':
 			settings->host = optarg;
 			break;