X-Git-Url: https://tinc-vpn.org/git/browse?a=blobdiff_plain;f=src%2Flogger.c;h=3e630f230c73485b1e30e809f147c63f897ba73c;hb=48dd371b2ec69f02870aa5e2a67fc8adb4617ff1;hp=026a120260e8de51a3d9bb6a100151617e2fca4d;hpb=a5c6c6ea1ab657d83a4d8b064ac9bfa9c16adf63;p=tinc

diff --git a/src/logger.c b/src/logger.c
index 026a1202..3e630f23 100644
--- a/src/logger.c
+++ b/src/logger.c
@@ -28,7 +28,7 @@
 #include "control_common.h"
 #include "process.h"
 #include "sptps.h"
-#include "compression.h"
+#include "console.h"
 
 debug_t debug_level = DEBUG_NOTHING;
 static logmode_t logmode = LOGMODE_STDERR;
@@ -38,15 +38,108 @@ static FILE *logfile = NULL;
 static HANDLE loghandle = NULL;
 #endif
 static const char *logident = NULL;
+static bool colorize_stderr = false;
 bool logcontrol = false; // controlled by REQ_LOG <level>
 int umbilical = 0;
+bool umbilical_colorize = false;
+
+#define SGR(s) ("\x1b[" s "m")
+
+typedef enum color_t {
+	RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, GRAY,
+	RESET, // not really a color
+} color_t;
+
+typedef struct priority_disp_t {
+	const char *name;
+	color_t color;
+} priority_disp_t;
+
+static const priority_disp_t priorities[] = {
+	[LOG_EMERG]   = {"EMERGENCY", MAGENTA},
+	[LOG_ALERT]   = {"ALERT",     MAGENTA},
+	[LOG_CRIT]    = {"CRITICAL",  MAGENTA},
+	[LOG_ERR]     = {"ERROR",     RED},
+	[LOG_WARNING] = {"WARNING",   YELLOW},
+	[LOG_NOTICE]  = {"NOTICE",    CYAN},
+	[LOG_INFO]    = {"INFO",      GREEN},
+	[LOG_DEBUG]   = {"DEBUG",     BLUE},
+};
+
+static const char *ansi_codes[] = {
+	[RED]     = SGR("31;1"),
+	[GREEN]   = SGR("32;1"),
+	[YELLOW]  = SGR("33;1"),
+	[BLUE]    = SGR("34;1"),
+	[MAGENTA] = SGR("35;1"),
+	[CYAN]    = SGR("36;1"),
+	[WHITE]   = SGR("37;1"),
+	[GRAY]    = SGR("90"),
+	[RESET]   = SGR("0"),
+};
+
+static priority_disp_t get_priority(int priority) {
+	static const priority_disp_t unknown = {"UNKNOWN", WHITE};
+
+	if(priority >= LOG_EMERG && priority <= LOG_DEBUG) {
+		return priorities[priority];
+	} else {
+		return unknown;
+	}
+}
+
+// Formats current time to the second.
+// Reuses result so repeated calls within the same second are more efficient.
+static const char *current_time_str(void) {
+	static char timestr[sizeof("2000-12-31 12:34:56")] = "";
+	static time_t last_time = 0;
+
+	if(!now.tv_sec) {
+		gettimeofday(&now, NULL);
+	}
+
+	time_t now_sec = now.tv_sec;
+
+	if(!*timestr || now_sec != last_time) {
+		last_time = now_sec;
+		strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S", localtime(&now_sec));
+	}
+
+	return timestr;
+}
+
+// Format log entry with time, log level, and (possibly) colors, remembering if it was colorized.
+// Returns true if buffer has been changed.
+static bool format_pretty(char *buf, size_t buflen, int prio, const char *message, bool colorize, bool *colorized) {
+	// If we already wrote to buffer, and its colorization matches, we're done here
+	if(*buf && colorize == *colorized) {
+		return false;
+	}
+
+	// Otherwise, remember current colorization for future comparisons
+	*colorized = colorize;
+
+	priority_disp_t priority = get_priority(prio);
+	const char *color = "", *reset = "", *timecol = "";
+
+	if(colorize) {
+		color = ansi_codes[priority.color];
+		reset = ansi_codes[RESET];
+		timecol = ansi_codes[GRAY];
+	}
+
+	const char *timestr = current_time_str();
+	snprintf(buf, buflen, "%s%s %s%-7s%s %s", timecol, timestr, color, priority.name, reset, message);
+	return true;
+}
 
 static bool should_log(debug_t level) {
 	return (level <= debug_level && logmode != LOGMODE_NULL) || logcontrol;
 }
 
 static void real_logger(debug_t level, int priority, const char *message) {
-	char timestr[32] = "";
+	char pretty[1024] = "";
+	bool pretty_colorized = false;
 	static bool suppress = false;
 
 	if(suppress) {
@@ -56,20 +149,17 @@ static void real_logger(debug_t level, int priority, const char *message) {
 	if(level <= debug_level) {
 		switch(logmode) {
 		case LOGMODE_STDERR:
-			fprintf(stderr, "%s\n", message);
+			format_pretty(pretty, sizeof(pretty), priority, message, colorize_stderr, &pretty_colorized);
+			fprintf(stderr, "%s\n", pretty);
 			fflush(stderr);
 			break;
 
-		case LOGMODE_FILE:
-			if(!now.tv_sec) {
-				gettimeofday(&now, NULL);
-			}
-
-			time_t now_sec = now.tv_sec;
-			strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S", localtime(&now_sec));
+		case LOGMODE_FILE: {
+			const char *timestr = current_time_str();
 			fprintf(logfile, "%s %s[%ld]: %s\n", timestr, logident, (long)logpid, message);
 			fflush(logfile);
 			break;
+		}
 
 		case LOGMODE_SYSLOG:
 #ifdef HAVE_WINDOWS
@@ -91,9 +181,9 @@ static void real_logger(debug_t level, int priority, const char *message) {
 		}
 
 		if(umbilical && do_detach) {
-			size_t len = strlen(message);
+			format_pretty(pretty, sizeof(pretty), priority, message, umbilical_colorize, &pretty_colorized);
 
-			if(write(umbilical, message, len) != (ssize_t)len || write(umbilical, "\n", 1) != 1) {
+			if(write(umbilical, pretty, strlen(pretty)) == -1 || write(umbilical, "\n", 1) == -1) {
 				// Other end broken, nothing we can do about it.
 			}
 		}
@@ -103,6 +193,8 @@ static void real_logger(debug_t level, int priority, const char *message) {
 		suppress = true;
 		logcontrol = false;
 
+		size_t msglen = strlen(pretty);
+
 		for list_each(connection_t, c, &connection_list) {
 			if(!c->status.log) {
 				continue;
@@ -114,10 +206,12 @@ static void real_logger(debug_t level, int priority, const char *message) {
 				continue;
 			}
 
-			size_t len = strlen(message);
+			if(format_pretty(pretty, sizeof(pretty), priority, message, c->status.log_color, &pretty_colorized)) {
+				msglen = strlen(pretty);
+			}
 
-			if(send_request(c, "%d %d %lu", CONTROL, REQ_LOG, (unsigned long)len)) {
-				send_meta(c, message, len);
+			if(send_request(c, "%d %d %lu", CONTROL, REQ_LOG, (unsigned long)msglen)) {
+				send_meta(c, pretty, msglen);
 			}
 		}
 
@@ -181,6 +275,7 @@ void openlogger(const char *ident, logmode_t mode) {
 	switch(mode) {
 	case LOGMODE_STDERR:
 		logpid = getpid();
+		colorize_stderr = use_ansi_escapes(stderr);
 		break;
 
 	case LOGMODE_FILE: