Add colors to tincd logger
[tinc] / src / logger.c
index 026a120..3e630f2 100644 (file)
@@ -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: