Use hardening option to add only hardening flags
[tinc] / src / logger.c
1 /*
2     logger.c -- logging code
3     Copyright (C) 2004-2022 Guus Sliepen <guus@tinc-vpn.org>
4                   2004-2005 Ivo Timmermans
5
6     This program is free software; you can redistribute it and/or modify
7     it under the terms of the GNU General Public License as published by
8     the Free Software Foundation; either version 2 of the License, or
9     (at your option) any later version.
10
11     This program is distributed in the hope that it will be useful,
12     but WITHOUT ANY WARRANTY; without even the implied warranty of
13     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
14     GNU General Public License for more details.
15
16     You should have received a copy of the GNU General Public License along
17     with this program; if not, write to the Free Software Foundation, Inc.,
18     51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
19 */
20
21 #include "system.h"
22
23 #include "conf.h"
24 #include "meta.h"
25 #include "names.h"
26 #include "logger.h"
27 #include "connection.h"
28 #include "control_common.h"
29 #include "process.h"
30 #include "sptps.h"
31 #include "console.h"
32
33 debug_t debug_level = DEBUG_NOTHING;
34 static logmode_t logmode = LOGMODE_STDERR;
35 static pid_t logpid;
36 static FILE *logfile = NULL;
37 #ifdef HAVE_WINDOWS
38 static HANDLE loghandle = NULL;
39 #endif
40 static const char *logident = NULL;
41 static bool colorize_stderr = false;
42 bool logcontrol = false; // controlled by REQ_LOG <level>
43 int umbilical = 0;
44 bool umbilical_colorize = false;
45
46 #define SGR(s) ("\x1b[" s "m")
47
48 typedef enum color_t {
49         RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, GRAY,
50         RESET, // not really a color
51 } color_t;
52
53 typedef struct priority_disp_t {
54         const char *name;
55         color_t color;
56 } priority_disp_t;
57
58 static const priority_disp_t priorities[] = {
59         [LOG_EMERG]   = {"EMERGENCY", MAGENTA},
60         [LOG_ALERT]   = {"ALERT",     MAGENTA},
61         [LOG_CRIT]    = {"CRITICAL",  MAGENTA},
62         [LOG_ERR]     = {"ERROR",     RED},
63         [LOG_WARNING] = {"WARNING",   YELLOW},
64         [LOG_NOTICE]  = {"NOTICE",    CYAN},
65         [LOG_INFO]    = {"INFO",      GREEN},
66         [LOG_DEBUG]   = {"DEBUG",     BLUE},
67 };
68
69 static const char *ansi_codes[] = {
70         [RED]     = SGR("31;1"),
71         [GREEN]   = SGR("32;1"),
72         [YELLOW]  = SGR("33;1"),
73         [BLUE]    = SGR("34;1"),
74         [MAGENTA] = SGR("35;1"),
75         [CYAN]    = SGR("36;1"),
76         [WHITE]   = SGR("37;1"),
77         [GRAY]    = SGR("90"),
78         [RESET]   = SGR("0"),
79 };
80
81 static priority_disp_t get_priority(int priority) {
82         static const priority_disp_t unknown = {"UNKNOWN", WHITE};
83
84         if(priority >= LOG_EMERG && priority <= LOG_DEBUG) {
85                 return priorities[priority];
86         } else {
87                 return unknown;
88         }
89 }
90
91 // Formats current time to the second.
92 // Reuses result so repeated calls within the same second are more efficient.
93 static const char *current_time_str(void) {
94         static char timestr[sizeof("2000-12-31 12:34:56")] = "";
95         static time_t last_time = 0;
96
97         if(!now.tv_sec) {
98                 gettimeofday(&now, NULL);
99         }
100
101         time_t now_sec = now.tv_sec;
102
103         if(!*timestr || now_sec != last_time) {
104                 last_time = now_sec;
105                 strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S", localtime(&now_sec));
106         }
107
108         return timestr;
109 }
110
111 // Format log entry with time, log level, and (possibly) colors, remembering if it was colorized.
112 // Returns true if buffer has been changed.
113 static bool format_pretty(char *buf, size_t buflen, int prio, const char *message, bool colorize, bool *colorized) {
114         // If we already wrote to buffer, and its colorization matches, we're done here
115         if(*buf && colorize == *colorized) {
116                 return false;
117         }
118
119         // Otherwise, remember current colorization for future comparisons
120         *colorized = colorize;
121
122         priority_disp_t priority = get_priority(prio);
123         const char *color = "", *reset = "", *timecol = "";
124
125         if(colorize) {
126                 color = ansi_codes[priority.color];
127                 reset = ansi_codes[RESET];
128                 timecol = ansi_codes[GRAY];
129         }
130
131         const char *timestr = current_time_str();
132         snprintf(buf, buflen, "%s%s %s%-7s%s %s", timecol, timestr, color, priority.name, reset, message);
133         return true;
134 }
135
136 static bool should_log(debug_t level) {
137         return (level <= debug_level && logmode != LOGMODE_NULL) || logcontrol;
138 }
139
140 static void real_logger(debug_t level, int priority, const char *message) {
141         char pretty[1024] = "";
142         bool pretty_colorized = false;
143         static bool suppress = false;
144
145         if(suppress) {
146                 return;
147         }
148
149         if(level <= debug_level) {
150                 switch(logmode) {
151                 case LOGMODE_STDERR:
152                         format_pretty(pretty, sizeof(pretty), priority, message, colorize_stderr, &pretty_colorized);
153                         fprintf(stderr, "%s\n", pretty);
154                         fflush(stderr);
155                         break;
156
157                 case LOGMODE_FILE: {
158                         const char *timestr = current_time_str();
159                         fprintf(logfile, "%s %s[%ld]: %s\n", timestr, logident, (long)logpid, message);
160                         fflush(logfile);
161                         break;
162                 }
163
164                 case LOGMODE_SYSLOG:
165 #ifdef HAVE_WINDOWS
166                         {
167                                 const char *messages[] = {message};
168                                 ReportEvent(loghandle, priority, 0, 0, NULL, 1, 0, messages, NULL);
169                         }
170
171 #else
172 #ifdef HAVE_SYSLOG_H
173                         syslog(priority, "%s", message);
174 #endif
175 #endif
176                         break;
177
178                 case LOGMODE_NULL:
179                 default:
180                         break;
181                 }
182
183                 if(umbilical && do_detach) {
184                         format_pretty(pretty, sizeof(pretty), priority, message, umbilical_colorize, &pretty_colorized);
185
186                         if(write(umbilical, pretty, strlen(pretty)) == -1 || write(umbilical, "\n", 1) == -1) {
187                                 // Other end broken, nothing we can do about it.
188                         }
189                 }
190         }
191
192         if(logcontrol) {
193                 suppress = true;
194                 logcontrol = false;
195
196                 size_t msglen = strlen(pretty);
197
198                 for list_each(connection_t, c, &connection_list) {
199                         if(!c->status.log) {
200                                 continue;
201                         }
202
203                         logcontrol = true;
204
205                         if(level > (c->log_level != DEBUG_UNSET ? c->log_level : debug_level)) {
206                                 continue;
207                         }
208
209                         if(format_pretty(pretty, sizeof(pretty), priority, message, c->status.log_color, &pretty_colorized)) {
210                                 msglen = strlen(pretty);
211                         }
212
213                         if(send_request(c, "%d %d %lu", CONTROL, REQ_LOG, (unsigned long)msglen)) {
214                                 send_meta(c, pretty, msglen);
215                         }
216                 }
217
218                 suppress = false;
219         }
220 }
221
222 void logger(debug_t level, int priority, const char *format, ...) {
223         va_list ap;
224         char message[1024] = "";
225
226         if(!should_log(level)) {
227                 return;
228         }
229
230         va_start(ap, format);
231         int len = vsnprintf(message, sizeof(message), format, ap);
232         message[sizeof(message) - 1] = 0;
233         va_end(ap);
234
235         if(len > 0 && (size_t)len < sizeof(message) - 1 && message[len - 1] == '\n') {
236                 message[len - 1] = 0;
237         }
238
239         real_logger(level, priority, message);
240 }
241
242 static void sptps_logger(sptps_t *s, int s_errno, const char *format, va_list ap) ATTR_FORMAT(printf, 3, 0);
243 static void sptps_logger(sptps_t *s, int s_errno, const char *format, va_list ap) {
244         (void)s_errno;
245         char message[1024];
246         size_t msglen = sizeof(message);
247
248         if(!should_log(DEBUG_TRAFFIC)) {
249                 return;
250         }
251
252         int len = vsnprintf(message, msglen, format, ap);
253         message[sizeof(message) - 1] = 0;
254
255         if(len > 0 && (size_t)len < sizeof(message) - 1) {
256                 if(message[len - 1] == '\n') {
257                         message[--len] = 0;
258                 }
259
260                 // WARNING: s->handle can point to a connection_t or a node_t,
261                 // but both types have the name and hostname fields at the same offsets.
262                 connection_t *c = s->handle;
263
264                 if(c) {
265                         snprintf(message + len, sizeof(message) - len, " from %s (%s)", c->name, c->hostname);
266                 }
267         }
268
269         real_logger(DEBUG_TRAFFIC, LOG_ERR, message);
270 }
271
272 void openlogger(const char *ident, logmode_t mode) {
273         logident = ident;
274         logmode = mode;
275
276         switch(mode) {
277         case LOGMODE_STDERR:
278                 logpid = getpid();
279                 colorize_stderr = use_ansi_escapes(stderr);
280                 break;
281
282         case LOGMODE_FILE:
283                 logpid = getpid();
284                 logfile = fopen(logfilename, "a");
285
286                 if(!logfile) {
287                         fprintf(stderr, "Could not open log file %s: %s\n", logfilename, strerror(errno));
288                         logmode = LOGMODE_NULL;
289                 }
290
291                 break;
292
293         case LOGMODE_SYSLOG:
294 #ifdef HAVE_WINDOWS
295                 loghandle = RegisterEventSource(NULL, logident);
296
297                 if(!loghandle) {
298                         fprintf(stderr, "Could not open log handle!\n");
299                         logmode = LOGMODE_NULL;
300                 }
301
302                 break;
303 #else
304 #ifdef HAVE_SYSLOG_H
305                 openlog(logident, LOG_CONS | LOG_PID, LOG_DAEMON);
306                 break;
307 #endif
308 #endif
309
310         case LOGMODE_NULL:
311         default:
312                 break;
313         }
314
315         if(logmode != LOGMODE_NULL) {
316                 sptps_log = sptps_logger;
317         } else {
318                 sptps_log = sptps_log_quiet;
319         }
320 }
321
322 void reopenlogger(void) {
323         if(logmode != LOGMODE_FILE) {
324                 return;
325         }
326
327         fflush(logfile);
328         FILE *newfile = fopen(logfilename, "a");
329
330         if(!newfile) {
331                 logger(DEBUG_ALWAYS, LOG_ERR, "Unable to reopen log file %s: %s", logfilename, strerror(errno));
332                 return;
333         }
334
335         fclose(logfile);
336         logfile = newfile;
337 }
338
339
340 void closelogger(void) {
341         switch(logmode) {
342         case LOGMODE_FILE:
343                 fclose(logfile);
344                 break;
345
346         case LOGMODE_SYSLOG:
347 #ifdef HAVE_WINDOWS
348                 DeregisterEventSource(loghandle);
349                 break;
350 #else
351 #ifdef HAVE_SYSLOG_H
352                 closelog();
353                 break;
354 #endif
355 #endif
356
357         case LOGMODE_NULL:
358         case LOGMODE_STDERR:
359         default:
360                 break;
361         }
362 }