color logging

src/encoders/omx/formatters.h

@@ -22,23 +22,15 @@
 
 #pragma once
 
-#include <stdio.h>
-
-#include <sys/syscall.h>
-
 #include <IL/OMX_IVCommon.h>
 #include <IL/OMX_Core.h>
 #include <IL/OMX_Image.h>
 
 #include "../../logging.h"
-#include "../../tools.h"
 
 
 #define LOG_OMX_ERROR(_error, _msg, ...) { \
-		LOGGING_LOCK; \
-		printf("-- ERROR [%.03Lf tid=%ld] -- " _msg ": %s\n", get_now_monotonic(), \
-			syscall(SYS_gettid), ##__VA_ARGS__, omx_error_to_string(_error)); \
-		LOGGING_UNLOCK; \
+		LOG_ERROR(_msg ": %s", ##__VA_ARGS__, omx_error_to_string(_error)); \
 	}
 
 

src/http/server.c

@@ -895,7 +895,7 @@ static bool _expose_new_picture_unsafe(struct http_server_t *server) {
 	EXPOSED(expose_cmp_time) = EXPOSED(expose_begin_time);
 	EXPOSED(expose_end_time) = get_now_monotonic();
 
-	LOG_VERBOSE("HTTP: exposed new frame; full exposition time =  %.06Lf",
+	LOG_VERBOSE("HTTP: exposed new frame; full exposition time = %.06Lf",
 		 EXPOSED(expose_end_time) - EXPOSED(expose_begin_time));
 
 #	undef EXPOSED

src/logging.h

@@ -23,8 +23,10 @@
 #pragma once
 
 #include <stdio.h>
+#include <stdbool.h>
 #include <stdlib.h>
 #include <string.h>
+#include <unistd.h>
 #include <errno.h>
 #include <time.h>
 #include <assert.h>
@@ -41,11 +43,14 @@ enum {
 	LOG_LEVEL_DEBUG,
 } log_level;
 
+bool log_colored;
+
 pthread_mutex_t log_mutex;
 
 
 #define LOGGING_INIT { \
 		log_level = LOG_LEVEL_INFO; \
+		log_colored = isatty(1); \
 		assert(!pthread_mutex_init(&log_mutex, NULL)); \
 	}
 
@@ -55,6 +60,15 @@ pthread_mutex_t log_mutex;
 #define LOGGING_UNLOCK	assert(!pthread_mutex_unlock(&log_mutex))
 
 
+#define COLOR_GRAY		"\x1b[30;1m"
+#define COLOR_RED		"\x1b[31;1m"
+#define COLOR_GREEN		"\x1b[32;1m"
+#define COLOR_YELLOW	"\x1b[33;1m"
+#define COLOR_BLUE		"\x1b[34;1m"
+#define COLOR_CYAN		"\x1b[36;1m"
+#define COLOR_RESET		"\x1b[0m"
+
+
 #define SEP_INFO(_ch) { \
 		LOGGING_LOCK; \
 		for (int _i = 0; _i < 80; ++_i) { \
@@ -71,57 +85,64 @@ pthread_mutex_t log_mutex;
 		} \
 	}
 
-#define LOG_PRINTF_NOLOCK(_label, _msg, ...) { \
-		printf("-- " _label " [%.03Lf tid=%d] -- " _msg "\n", get_now_monotonic(), get_thread_id(), ##__VA_ARGS__); \
+
+#define LOG_PRINTF_NOLOCK(_label_color, _label, _msg_color, _msg, ...) { \
+		if (log_colored) { \
+			printf(COLOR_GRAY "-- " _label_color _label COLOR_GRAY " [%.03Lf tid=%d]" " -- " COLOR_RESET _msg_color _msg COLOR_RESET, \
+				get_now_monotonic(), get_thread_id(), ##__VA_ARGS__); \
+		} else { \
+			printf("-- " _label " [%.03Lf tid=%d] -- " _msg, \
+				get_now_monotonic(), get_thread_id(), ##__VA_ARGS__); \
+		} \
+		putchar('\n'); \
 		fflush(stdout); \
 	}
 
-#define LOG_ERROR(_msg, ...) { \
+#define LOG_PRINTF(_label_color, _label, _msg_color, _msg, ...) { \
 		LOGGING_LOCK; \
-		LOG_PRINTF_NOLOCK("ERROR", _msg, ##__VA_ARGS__); \
+		LOG_PRINTF_NOLOCK(_label_color, _label, _msg_color, _msg, ##__VA_ARGS__); \
 		LOGGING_UNLOCK; \
 	}
 
+#define LOG_ERROR(_msg, ...) { \
+		LOG_PRINTF(COLOR_RED, "ERROR", COLOR_RED, _msg, ##__VA_ARGS__); \
+	}
+
 #define LOG_PERROR(_msg, ...) { \
 		char _buf[1024] = ""; \
 		char *_ptr = errno_to_string(_buf, 1024); \
-		LOGGING_LOCK; \
-		printf("-- ERROR [%.03Lf tid=%d] -- " _msg ": %s\n", get_now_monotonic(), get_thread_id(), ##__VA_ARGS__, _ptr); \
-		fflush(stdout); \
-		LOGGING_UNLOCK; \
+		LOG_ERROR(_msg ": %s", ##__VA_ARGS__, _ptr); \
 	}
 
 #define LOG_INFO(_msg, ...) { \
-		LOGGING_LOCK; \
-		LOG_PRINTF_NOLOCK("INFO ", _msg, ##__VA_ARGS__); \
-		LOGGING_UNLOCK; \
+		LOG_PRINTF(COLOR_GREEN, "INFO ", "", _msg, ##__VA_ARGS__); \
 	}
 
 #define LOG_INFO_NOLOCK(_msg, ...) { \
-		LOG_PRINTF_NOLOCK("INFO ", _msg, ##__VA_ARGS__); \
+		LOG_PRINTF_NOLOCK(COLOR_GREEN, "INFO ", "", _msg, ##__VA_ARGS__); \
 	}
 
 #define LOG_PERF(_msg, ...) { \
 		if (log_level >= LOG_LEVEL_PERF) { \
-			LOGGING_LOCK; \
-			LOG_PRINTF_NOLOCK("PERF ", _msg, ##__VA_ARGS__); \
-			LOGGING_UNLOCK; \
+			LOG_PRINTF(COLOR_CYAN, "PERF ", COLOR_CYAN, _msg, ##__VA_ARGS__); \
+		} \
+	}
+
+#define LOG_PERF_FPS(_msg, ...) { \
+		if (log_level >= LOG_LEVEL_PERF) { \
+			LOG_PRINTF(COLOR_YELLOW, "PERF ", COLOR_YELLOW, _msg, ##__VA_ARGS__); \
 		} \
 	}
 
 #define LOG_VERBOSE(_msg, ...) { \
 		if (log_level >= LOG_LEVEL_VERBOSE) { \
-			LOGGING_LOCK; \
-			LOG_PRINTF_NOLOCK("VERB ", _msg, ##__VA_ARGS__); \
-			LOGGING_UNLOCK; \
+			LOG_PRINTF(COLOR_BLUE, "VERB ", COLOR_BLUE, _msg, ##__VA_ARGS__); \
 		} \
 	}
 
 #define LOG_DEBUG(_msg, ...) { \
 		if (log_level >= LOG_LEVEL_DEBUG) { \
-			LOGGING_LOCK; \
-			LOG_PRINTF_NOLOCK("DEBUG", _msg, ##__VA_ARGS__); \
-			LOGGING_UNLOCK; \
+			LOG_PRINTF(COLOR_GRAY, "DEBUG", COLOR_GRAY, _msg, ##__VA_ARGS__); \
 		} \
 	}
 

src/options.c

@@ -109,10 +109,12 @@ enum _OPT_VALUES {
 	_O_GPIO_WORKERS_BUSY_AT,
 #endif
 
+	_O_LOG_LEVEL,
 	_O_PERF,
 	_O_VERBOSE,
 	_O_DEBUG,
-	_O_LOG_LEVEL
+	_O_FORCE_COLORS,
+	_O_NO_COLORS,
 };
 
 static const struct option _LONG_OPTS[] = {
@@ -174,12 +176,16 @@ static const struct option _LONG_OPTS[] = {
 	{"gpio-workers-busy-at",	required_argument,	NULL,	_O_GPIO_WORKERS_BUSY_AT},
 #endif
 
+	{"log-level",				required_argument,	NULL,	_O_LOG_LEVEL},
 	{"perf",					no_argument,		NULL,	_O_PERF},
 	{"verbose",					no_argument,		NULL,	_O_VERBOSE},
 	{"debug",					no_argument,		NULL,	_O_DEBUG},
-	{"log-level",				required_argument,	NULL,	_O_LOG_LEVEL},
+	{"force-colors",			no_argument,		NULL,	_O_FORCE_COLORS},
+	{"no-colors",				no_argument,		NULL,	_O_NO_COLORS},
+
 	{"help",					no_argument,		NULL,	_O_HELP},
 	{"version",					no_argument,		NULL,	_O_VERSION},
+
 	{NULL, 0, NULL, 0},
 };
 
@@ -340,15 +346,18 @@ int parse_options(int argc, char *argv[], struct device_t *dev, struct encoder_t
 			case _O_GPIO_WORKERS_BUSY_AT:	OPT_NUMBER("--gpio-workers-busy-at", gpio_pin_workers_busy_at, 0, 256, 0);
 #			endif
 
-			case _O_PERF:		OPT_SET(log_level, LOG_LEVEL_PERF);
-			case _O_VERBOSE:	OPT_SET(log_level, LOG_LEVEL_VERBOSE);
-			case _O_DEBUG:		OPT_SET(log_level, LOG_LEVEL_DEBUG);
-			case _O_LOG_LEVEL:	OPT_NUMBER("--log-level", log_level, LOG_LEVEL_INFO, LOG_LEVEL_DEBUG, 0);
+			case _O_LOG_LEVEL:		OPT_NUMBER("--log-level", log_level, LOG_LEVEL_INFO, LOG_LEVEL_DEBUG, 0);
+			case _O_PERF:			OPT_SET(log_level, LOG_LEVEL_PERF);
+			case _O_VERBOSE:		OPT_SET(log_level, LOG_LEVEL_VERBOSE);
+			case _O_DEBUG:			OPT_SET(log_level, LOG_LEVEL_DEBUG);
+			case _O_FORCE_COLORS:	OPT_SET(log_colored, true);
+			case _O_NO_COLORS:		OPT_SET(log_colored, false);
 
 			case _O_HELP:		_help(dev, encoder, server); return 1;
 			case _O_VERSION:	_version(true); return 1;
-			case 0:				break;
-			default:			_help(dev, encoder, server); return -1;
+
+			case 0:		break;
+			default:	_help(dev, encoder, server); return -1;
 		}
 	}
 
@@ -539,6 +548,8 @@ static void _help(struct device_t *dev, struct encoder_t *encoder, struct http_s
 	printf("    --perf  ────────── Enable performance messages (same as --log-level=1). Default: disabled.\n\n");
 	printf("    --verbose  ─────── Enable verbose messages and lower (same as --log-level=2). Default: disabled.\n\n");
 	printf("    --debug  ───────── Enable debug messages and lower (same as --log-level=3). Default: disabled.\n\n");
+	printf("    --force-colors  ── Force color logging. Default: colored if stdout is a TTY.\n\n");
+	printf("    --no-colors  ───── Disable color logging. Default: ditto.\n\n");
 	printf("Help options:\n");
 	printf("═════════════\n");
 	printf("    -h|--help  ─────── Print this text and exit.\n\n");

src/stream.c

@@ -240,7 +240,7 @@ void stream_loop(struct stream_t *stream) {
 							captured_fps = captured_fps_accum;
 							captured_fps_accum = 0;
 							captured_fps_second = now_second;
-							LOG_PERF("A new second has come; captured_fps=%u", captured_fps);
+							LOG_PERF_FPS("A new second has come; captured_fps=%u", captured_fps);
 						}
 						captured_fps_accum += 1;