]>
Commit | Line | Data |
---|---|---|
6032aa6a MM |
1 | /* |
2 | * BIRD Library -- Logging Functions | |
3 | * | |
73275d85 | 4 | * (c) 1998--2000 Martin Mares <mj@ucw.cz> |
6032aa6a MM |
5 | * |
6 | * Can be freely distributed and used under the terms of the GNU GPL. | |
7 | */ | |
8 | ||
73275d85 MM |
9 | /** |
10 | * DOC: Logging | |
11 | * | |
12 | * The Logging module offers a simple set of functions for writing | |
725270cb MM |
13 | * messages to system logs and to the debug output. Message classes |
14 | * used by this module are described in |birdlib.h| and also in the | |
15 | * user's manual. | |
73275d85 MM |
16 | */ |
17 | ||
6032aa6a MM |
18 | #include <stdio.h> |
19 | #include <stdlib.h> | |
20 | #include <stdarg.h> | |
01b776e1 | 21 | #include <time.h> |
6712e772 OZ |
22 | #include <sys/types.h> |
23 | #include <sys/stat.h> | |
e81b440f | 24 | #include <unistd.h> |
f0b822a8 | 25 | #include <errno.h> |
6032aa6a MM |
26 | |
27 | #include "nest/bird.h" | |
34350a52 | 28 | #include "nest/cli.h" |
863ecfc7 | 29 | #include "conf/conf.h" |
9556f225 | 30 | #include "lib/string.h" |
a0c37b45 | 31 | #include "lib/lists.h" |
2c7555cf | 32 | #include "lib/socket.h" |
7152e5ef | 33 | #include "sysdep/unix/unix.h" |
6032aa6a | 34 | |
64a2b7aa | 35 | static int dbg_fd = -1; |
44d4ab7a | 36 | static FILE *dbgf; |
a0c37b45 | 37 | static list *current_log_list; |
44d4ab7a | 38 | static char *current_syslog_name; /* NULL -> syslog closed */ |
6032aa6a | 39 | |
0e175f9f | 40 | |
1ec52253 | 41 | #ifdef USE_PTHREADS |
0e175f9f OZ |
42 | |
43 | #include <pthread.h> | |
4e398e34 | 44 | |
0e175f9f OZ |
45 | static pthread_mutex_t log_mutex; |
46 | static inline void log_lock(void) { pthread_mutex_lock(&log_mutex); } | |
47 | static inline void log_unlock(void) { pthread_mutex_unlock(&log_mutex); } | |
48 | ||
4e398e34 OZ |
49 | static pthread_t main_thread; |
50 | void main_thread_init(void) { main_thread = pthread_self(); } | |
51 | static int main_thread_self(void) { return pthread_equal(pthread_self(), main_thread); } | |
52 | ||
1ec52253 OZ |
53 | #else |
54 | ||
55 | static inline void log_lock(void) { } | |
56 | static inline void log_unlock(void) { } | |
4e398e34 OZ |
57 | void main_thread_init(void) { } |
58 | static int main_thread_self(void) { return 1; } | |
1ec52253 OZ |
59 | |
60 | #endif | |
61 | ||
cb530392 | 62 | |
5d6dc930 | 63 | #ifdef HAVE_SYSLOG_H |
6032aa6a MM |
64 | #include <sys/syslog.h> |
65 | ||
71ca7d75 | 66 | static int syslog_priorities[L_MAX] = { |
a0c37b45 MM |
67 | LOG_DEBUG, |
68 | LOG_DEBUG, | |
6032aa6a MM |
69 | LOG_DEBUG, |
70 | LOG_INFO, | |
a0c37b45 | 71 | LOG_ERR, |
6032aa6a MM |
72 | LOG_WARNING, |
73 | LOG_ERR, | |
a0c37b45 MM |
74 | LOG_ERR, |
75 | LOG_CRIT, | |
6032aa6a MM |
76 | LOG_CRIT |
77 | }; | |
78 | #endif | |
79 | ||
71ca7d75 | 80 | static char *class_names[L_MAX] = { |
6032aa6a MM |
81 | "???", |
82 | "DBG", | |
a0c37b45 | 83 | "TRACE", |
6032aa6a | 84 | "INFO", |
a0c37b45 | 85 | "RMT", |
6032aa6a MM |
86 | "WARN", |
87 | "ERR", | |
88 | "AUTH", | |
a0c37b45 MM |
89 | "FATAL", |
90 | "BUG" | |
6032aa6a MM |
91 | }; |
92 | ||
6712e772 OZ |
93 | static inline off_t |
94 | log_size(struct log_config *l) | |
95 | { | |
96 | struct stat st; | |
97 | return (!fstat(rf_fileno(l->rf), &st) && S_ISREG(st.st_mode)) ? st.st_size : 0; | |
98 | } | |
99 | ||
100 | static void | |
101 | log_close(struct log_config *l) | |
102 | { | |
103 | rfree(l->rf); | |
104 | l->rf = NULL; | |
105 | l->fh = NULL; | |
106 | } | |
107 | ||
108 | static int | |
109 | log_open(struct log_config *l) | |
110 | { | |
111 | l->rf = rf_open(config->pool, l->filename, "a"); | |
112 | if (!l->rf) | |
113 | { | |
114 | /* Well, we cannot do much in case of error as log is closed */ | |
115 | l->mask = 0; | |
116 | return -1; | |
117 | } | |
118 | ||
119 | l->fh = rf_file(l->rf); | |
120 | l->pos = log_size(l); | |
121 | ||
122 | return 0; | |
123 | } | |
124 | ||
125 | static int | |
126 | log_rotate(struct log_config *l) | |
127 | { | |
128 | log_close(l); | |
129 | ||
130 | /* If we cannot rename the logfile, we at least try to delete it | |
131 | in order to continue logging and not exceeding logfile size */ | |
132 | if ((rename(l->filename, l->backup) < 0) && | |
133 | (unlink(l->filename) < 0)) | |
134 | { | |
135 | l->mask = 0; | |
136 | return -1; | |
137 | } | |
138 | ||
139 | return log_open(l); | |
140 | } | |
9556f225 | 141 | |
2c7555cf OZ |
142 | /* Expected to be called during config parsing */ |
143 | int | |
144 | log_open_udp(struct log_config *l, pool *p) | |
145 | { | |
146 | ASSERT(l->host || ipa_nonzero(l->ip)); | |
147 | ||
148 | if (l->host && ipa_zero(l->ip)) | |
149 | { | |
150 | const char *err_msg; | |
151 | l->ip = resolve_hostname(l->host, SK_UDP, &err_msg); | |
152 | ||
153 | if (ipa_zero(l->ip)) | |
154 | { | |
155 | cf_warn("Cannot resolve hostname '%s': %s", l->host, err_msg); | |
156 | goto err0; | |
157 | } | |
158 | } | |
159 | ||
160 | sock *sk = sk_new(p); | |
161 | sk->type = SK_UDP; | |
162 | sk->daddr = l->ip; | |
163 | sk->dport = l->port; | |
164 | sk->flags = SKF_CONNECT | SKF_THREAD; | |
165 | ||
166 | if (sk_open(sk) < 0) | |
167 | { | |
168 | cf_warn("Cannot open UDP log socket: %s%#m", sk->err); | |
169 | goto err1; | |
170 | } | |
171 | ||
172 | /* Move fd from sk resource to rf resource */ | |
173 | l->rf = rf_fdopen(p, sk->fd, "a"); | |
174 | if (!l->rf) | |
175 | goto err1; | |
176 | ||
177 | l->fh = rf_file(l->rf); | |
178 | ||
179 | sk->fd = -1; | |
180 | rfree(sk); | |
181 | ||
182 | return 0; | |
183 | ||
184 | err1: | |
185 | rfree(sk); | |
186 | err0: | |
187 | l->mask = 0; | |
188 | return -1; | |
189 | } | |
190 | ||
0d1b3c4c OZ |
191 | /** |
192 | * log_commit - commit a log message | |
193 | * @class: message class information (%L_DEBUG to %L_BUG, see |lib/birdlib.h|) | |
8e433d6a | 194 | * @buf: message to write |
0d1b3c4c OZ |
195 | * |
196 | * This function writes a message prepared in the log buffer to the | |
197 | * log file (as specified in the configuration). The log buffer is | |
198 | * reset after that. The log message is a full line, log_commit() | |
199 | * terminates it. | |
200 | * | |
201 | * The message class is an integer, not a first char of a string like | |
202 | * in log(), so it should be written like *L_INFO. | |
203 | */ | |
204 | void | |
0e175f9f | 205 | log_commit(int class, buffer *buf) |
0d1b3c4c OZ |
206 | { |
207 | struct log_config *l; | |
9556f225 | 208 | |
0e175f9f OZ |
209 | if (buf->pos == buf->end) |
210 | strcpy(buf->end - 100, " ... <too long>"); | |
211 | ||
212 | log_lock(); | |
a0c37b45 | 213 | WALK_LIST(l, *current_log_list) |
6032aa6a | 214 | { |
a0c37b45 MM |
215 | if (!(l->mask & (1 << class))) |
216 | continue; | |
217 | if (l->fh) | |
218 | { | |
a0c37b45 MM |
219 | if (l->terminal_flag) |
220 | fputs("bird: ", l->fh); | |
2c7555cf OZ |
221 | else if (l->udp_flag) |
222 | { | |
223 | int pri = LOG_DAEMON | syslog_priorities[class]; | |
224 | char tbuf[TM_DATETIME_BUFFER_SIZE]; | |
225 | const char *hostname = (config && config->hostname) ? config->hostname : "<none>"; | |
226 | const char *fmt = "%b %d %T.%6f"; | |
227 | if (!tm_format_real_time(tbuf, sizeof(tbuf), fmt, current_real_time())) | |
228 | strcpy(tbuf, "<error>"); | |
229 | ||
230 | /* Legacy RFC 3164 format, but with us precision */ | |
231 | fprintf(l->fh, "<%d>%s %s %s: ", pri, tbuf, hostname, bird_name); | |
232 | } | |
a0c37b45 MM |
233 | else |
234 | { | |
c37e7851 | 235 | byte tbuf[TM_DATETIME_BUFFER_SIZE]; |
3fda08e4 OZ |
236 | const char *fmt = config ? config->tf_log.fmt1 : "%F %T.%3f"; |
237 | if (!tm_format_real_time(tbuf, sizeof(tbuf), fmt, current_real_time())) | |
863ecfc7 | 238 | strcpy(tbuf, "<error>"); |
6712e772 OZ |
239 | |
240 | if (l->limit) | |
241 | { | |
242 | off_t msg_len = strlen(tbuf) + strlen(class_names[class]) + | |
243 | (buf->pos - buf->start) + 5; | |
244 | ||
245 | if (l->pos < 0) | |
246 | l->pos = log_size(l); | |
247 | ||
248 | if (l->pos + msg_len > l->limit) | |
249 | if (log_rotate(l) < 0) | |
250 | continue; | |
251 | ||
252 | l->pos += msg_len; | |
253 | } | |
254 | ||
c37e7851 | 255 | fprintf(l->fh, "%s <%s> ", tbuf, class_names[class]); |
a0c37b45 | 256 | } |
0e175f9f | 257 | fputs(buf->start, l->fh); |
a0c37b45 MM |
258 | fputc('\n', l->fh); |
259 | fflush(l->fh); | |
260 | } | |
5d6dc930 | 261 | #ifdef HAVE_SYSLOG_H |
a0c37b45 | 262 | else |
0e175f9f | 263 | syslog(syslog_priorities[class], "%s", buf->start); |
6032aa6a | 264 | #endif |
6032aa6a | 265 | } |
0e175f9f | 266 | log_unlock(); |
0d1b3c4c | 267 | |
4e398e34 OZ |
268 | /* cli_echo is not thread-safe, so call it just from the main thread */ |
269 | if (main_thread_self()) | |
270 | cli_echo(class, buf->start); | |
56027b5c OZ |
271 | |
272 | buf->pos = buf->start; | |
0d1b3c4c OZ |
273 | } |
274 | ||
0e175f9f | 275 | int buffer_vprint(buffer *buf, const char *fmt, va_list args); |
0d1b3c4c | 276 | |
4dd5b3d9 | 277 | void |
0d1b3c4c OZ |
278 | vlog(int class, const char *msg, va_list args) |
279 | { | |
0e175f9f OZ |
280 | buffer buf; |
281 | LOG_BUFFER_INIT(buf); | |
282 | buffer_vprint(&buf, msg, args); | |
283 | log_commit(class, &buf); | |
0d1b3c4c OZ |
284 | } |
285 | ||
286 | ||
73275d85 MM |
287 | /** |
288 | * log - log a message | |
289 | * @msg: printf-like formatting string with message class information | |
290 | * prepended (%L_DEBUG to %L_BUG, see |lib/birdlib.h|) | |
291 | * | |
292 | * This function formats a message according to the format string @msg | |
2e9b2421 | 293 | * and writes it to the corresponding log file (as specified in the |
73275d85 MM |
294 | * configuration). Please note that the message is automatically |
295 | * formatted as a full line, no need to include |\n| inside. | |
0d1b3c4c | 296 | * It is essentially a sequence of log_reset(), logn() and log_commit(). |
73275d85 | 297 | */ |
6032aa6a | 298 | void |
e598853e | 299 | log_msg(const char *msg, ...) |
6032aa6a MM |
300 | { |
301 | int class = 1; | |
302 | va_list args; | |
303 | ||
304 | va_start(args, msg); | |
71ca7d75 | 305 | if (*msg >= 1 && *msg < L_MAX) |
6032aa6a MM |
306 | class = *msg++; |
307 | vlog(class, msg, args); | |
308 | va_end(args); | |
309 | } | |
310 | ||
cb530392 | 311 | void |
e598853e | 312 | log_rl(struct tbf *f, const char *msg, ...) |
cb530392 OZ |
313 | { |
314 | int class = 1; | |
315 | va_list args; | |
316 | ||
1123e707 | 317 | /* Rate limiting is a bit tricky here as it also logs '...' during the first hit */ |
574b2324 | 318 | if (tbf_limit(f) && (f->drop > 1)) |
cb530392 OZ |
319 | return; |
320 | ||
71ca7d75 | 321 | if (*msg >= 1 && *msg < L_MAX) |
cb530392 | 322 | class = *msg++; |
1123e707 OZ |
323 | |
324 | va_start(args, msg); | |
574b2324 | 325 | vlog(class, (f->drop ? "..." : msg), args); |
cb530392 OZ |
326 | va_end(args); |
327 | } | |
328 | ||
73275d85 MM |
329 | /** |
330 | * bug - report an internal error | |
331 | * @msg: a printf-like error message | |
332 | * | |
333 | * This function logs an internal error and aborts execution | |
334 | * of the program. | |
335 | */ | |
98e87c86 | 336 | void |
e598853e | 337 | bug(const char *msg, ...) |
98e87c86 MM |
338 | { |
339 | va_list args; | |
340 | ||
341 | va_start(args, msg); | |
342 | vlog(L_BUG[0], msg, args); | |
8f01879c | 343 | va_end(args); |
818ff1e2 | 344 | abort(); |
98e87c86 MM |
345 | } |
346 | ||
73275d85 MM |
347 | /** |
348 | * bug - report a fatal error | |
349 | * @msg: a printf-like error message | |
350 | * | |
351 | * This function logs a fatal error and aborts execution | |
352 | * of the program. | |
353 | */ | |
6032aa6a | 354 | void |
e598853e | 355 | die(const char *msg, ...) |
6032aa6a MM |
356 | { |
357 | va_list args; | |
358 | ||
359 | va_start(args, msg); | |
98e87c86 | 360 | vlog(L_FATAL[0], msg, args); |
8f01879c | 361 | va_end(args); |
6032aa6a MM |
362 | exit(1); |
363 | } | |
364 | ||
73275d85 MM |
365 | /** |
366 | * debug - write to debug output | |
367 | * @msg: a printf-like message | |
368 | * | |
369 | * This function formats the message @msg and prints it out | |
370 | * to the debugging output. No newline character is appended. | |
371 | */ | |
6032aa6a | 372 | void |
e598853e | 373 | debug(const char *msg, ...) |
6032aa6a | 374 | { |
227e2d55 | 375 | #define MAX_DEBUG_BUFSIZE 16384 |
6032aa6a | 376 | va_list args; |
227e2d55 | 377 | char buf[MAX_DEBUG_BUFSIZE]; |
6032aa6a MM |
378 | |
379 | va_start(args, msg); | |
380 | if (dbgf) | |
a0c37b45 | 381 | { |
227e2d55 MM |
382 | if (bvsnprintf(buf, MAX_DEBUG_BUFSIZE, msg, args) < 0) |
383 | bug("Extremely long debug output, split it."); | |
422a9334 | 384 | |
a0c37b45 MM |
385 | fputs(buf, dbgf); |
386 | } | |
6032aa6a MM |
387 | va_end(args); |
388 | } | |
389 | ||
64a2b7aa MC |
390 | /** |
391 | * debug_safe - async-safe write to debug output | |
392 | * @msg: a string message | |
393 | * | |
394 | * This function prints the message @msg to the debugging output in a | |
395 | * way that is async safe and can be used in signal handlers. No newline | |
396 | * character is appended. | |
397 | */ | |
398 | void | |
399 | debug_safe(const char *msg) | |
400 | { | |
401 | if (dbg_fd >= 0) | |
402 | write(dbg_fd, msg, strlen(msg)); | |
403 | } | |
404 | ||
44d4ab7a | 405 | static list * |
fd9f0c06 | 406 | default_log_list(int initial, const char **syslog_name) |
6032aa6a | 407 | { |
3fda08e4 OZ |
408 | static list log_list; |
409 | init_list(&log_list); | |
44d4ab7a | 410 | *syslog_name = NULL; |
6032aa6a | 411 | |
5d6dc930 | 412 | #ifdef HAVE_SYSLOG_H |
3fda08e4 | 413 | if (!dbgf) |
6032aa6a | 414 | { |
0ef082c5 OZ |
415 | static struct log_config lc_syslog; |
416 | lc_syslog = (struct log_config){ | |
417 | .mask = ~0 | |
418 | }; | |
419 | ||
3fda08e4 | 420 | add_tail(&log_list, &lc_syslog.n); |
44d4ab7a | 421 | *syslog_name = bird_name; |
6032aa6a | 422 | } |
a0c37b45 MM |
423 | #endif |
424 | ||
3fda08e4 OZ |
425 | if (dbgf && (dbgf != stderr)) |
426 | { | |
0ef082c5 OZ |
427 | static struct log_config lc_debug; |
428 | lc_debug = (struct log_config){ | |
429 | .mask = ~0, | |
430 | .fh = dbgf | |
431 | }; | |
432 | ||
3fda08e4 OZ |
433 | add_tail(&log_list, &lc_debug.n); |
434 | } | |
435 | ||
436 | if (initial || (dbgf == stderr)) | |
437 | { | |
0ef082c5 OZ |
438 | static struct log_config lc_stderr; |
439 | lc_stderr = (struct log_config){ | |
440 | .mask = ~0, | |
441 | .terminal_flag = 1, | |
442 | .fh = stderr | |
443 | }; | |
444 | ||
3fda08e4 OZ |
445 | add_tail(&log_list, &lc_stderr.n); |
446 | } | |
447 | ||
448 | return &log_list; | |
a0c37b45 MM |
449 | } |
450 | ||
451 | void | |
fd9f0c06 | 452 | log_switch(int initial, list *logs, const char *new_syslog_name) |
a0c37b45 | 453 | { |
6712e772 OZ |
454 | struct log_config *l; |
455 | ||
62d57b9b OZ |
456 | /* We should not manipulate with log list when other threads may use it */ |
457 | log_lock(); | |
458 | ||
6712e772 | 459 | if (!logs || EMPTY_LIST(*logs)) |
3fda08e4 | 460 | logs = default_log_list(initial, &new_syslog_name); |
6712e772 OZ |
461 | |
462 | /* Close the logs to avoid pinning them on disk when deleted */ | |
463 | if (current_log_list) | |
464 | WALK_LIST(l, *current_log_list) | |
2c7555cf | 465 | if (l->filename && l->rf) |
6712e772 OZ |
466 | log_close(l); |
467 | ||
468 | /* Reopen the logs, needed for 'configure undo' */ | |
469 | if (logs) | |
470 | WALK_LIST(l, *logs) | |
471 | if (l->filename && !l->rf) | |
472 | log_open(l); | |
44d4ab7a | 473 | |
6712e772 | 474 | current_log_list = logs; |
44d4ab7a | 475 | |
5d6dc930 | 476 | #ifdef HAVE_SYSLOG_H |
15b0a922 | 477 | if (!bstrcmp(current_syslog_name, new_syslog_name)) |
48addc88 | 478 | goto done; |
44d4ab7a | 479 | |
17fe57d8 OZ |
480 | if (current_syslog_name) |
481 | { | |
44d4ab7a | 482 | closelog(); |
17fe57d8 OZ |
483 | xfree(current_syslog_name); |
484 | current_syslog_name = NULL; | |
485 | } | |
44d4ab7a OZ |
486 | |
487 | if (new_syslog_name) | |
17fe57d8 OZ |
488 | { |
489 | current_syslog_name = xstrdup(new_syslog_name); | |
490 | openlog(current_syslog_name, LOG_CONS | LOG_NDELAY, LOG_DAEMON); | |
491 | } | |
48addc88 | 492 | |
44d4ab7a | 493 | #endif |
48addc88 MM |
494 | |
495 | done: | |
496 | /* Logs exchange done, let the threads log as before */ | |
497 | log_unlock(); | |
6032aa6a MM |
498 | } |
499 | ||
500 | void | |
501 | log_init_debug(char *f) | |
502 | { | |
64a2b7aa | 503 | dbg_fd = -1; |
6032aa6a MM |
504 | if (dbgf && dbgf != stderr) |
505 | fclose(dbgf); | |
64a2b7aa | 506 | |
6032aa6a | 507 | if (!f) |
6032aa6a | 508 | dbgf = NULL; |
a0c37b45 MM |
509 | else if (!*f) |
510 | dbgf = stderr; | |
6032aa6a | 511 | else if (!(dbgf = fopen(f, "a"))) |
f0b822a8 OZ |
512 | { |
513 | /* Cannot use die() nor log() here, logging is not yet initialized */ | |
514 | fprintf(stderr, "bird: Unable to open debug file %s: %s\n", f, strerror(errno)); | |
515 | exit(1); | |
516 | } | |
64a2b7aa | 517 | |
f098e072 | 518 | if (dbgf) |
64a2b7aa | 519 | { |
f098e072 | 520 | setvbuf(dbgf, NULL, _IONBF, 0); |
64a2b7aa MC |
521 | dbg_fd = fileno(dbgf); |
522 | } | |
6032aa6a | 523 | } |