]>
Commit | Line | Data |
---|---|---|
1 | /* | |
2 | * BIRD Library -- Logging Functions | |
3 | * | |
4 | * (c) 1998--2000 Martin Mares <mj@ucw.cz> | |
5 | * | |
6 | * Can be freely distributed and used under the terms of the GNU GPL. | |
7 | */ | |
8 | ||
9 | /** | |
10 | * DOC: Logging | |
11 | * | |
12 | * The Logging module offers a simple set of functions for writing | |
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. | |
16 | */ | |
17 | ||
18 | #include <stdio.h> | |
19 | #include <stdlib.h> | |
20 | #include <stdarg.h> | |
21 | #include <time.h> | |
22 | #include <sys/types.h> | |
23 | #include <sys/stat.h> | |
24 | #include <unistd.h> | |
25 | #include <errno.h> | |
26 | ||
27 | #include "nest/bird.h" | |
28 | #include "nest/cli.h" | |
29 | #include "conf/conf.h" | |
30 | #include "lib/string.h" | |
31 | #include "lib/lists.h" | |
32 | #include "lib/socket.h" | |
33 | #include "sysdep/unix/unix.h" | |
34 | ||
35 | static int dbg_fd = -1; | |
36 | static FILE *dbgf; | |
37 | static list *current_log_list; | |
38 | static char *current_syslog_name; /* NULL -> syslog closed */ | |
39 | ||
40 | ||
41 | #ifdef USE_PTHREADS | |
42 | ||
43 | #include <pthread.h> | |
44 | ||
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 | ||
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 | ||
53 | #else | |
54 | ||
55 | static inline void log_lock(void) { } | |
56 | static inline void log_unlock(void) { } | |
57 | void main_thread_init(void) { } | |
58 | static int main_thread_self(void) { return 1; } | |
59 | ||
60 | #endif | |
61 | ||
62 | ||
63 | #ifdef HAVE_SYSLOG_H | |
64 | #include <sys/syslog.h> | |
65 | ||
66 | static int syslog_priorities[L_MAX] = { | |
67 | LOG_DEBUG, | |
68 | LOG_DEBUG, | |
69 | LOG_DEBUG, | |
70 | LOG_INFO, | |
71 | LOG_ERR, | |
72 | LOG_WARNING, | |
73 | LOG_ERR, | |
74 | LOG_ERR, | |
75 | LOG_CRIT, | |
76 | LOG_CRIT | |
77 | }; | |
78 | #endif | |
79 | ||
80 | static char *class_names[L_MAX] = { | |
81 | "???", | |
82 | "DBG", | |
83 | "TRACE", | |
84 | "INFO", | |
85 | "RMT", | |
86 | "WARN", | |
87 | "ERR", | |
88 | "AUTH", | |
89 | "FATAL", | |
90 | "BUG" | |
91 | }; | |
92 | ||
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 | } | |
141 | ||
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 | ||
191 | /** | |
192 | * log_commit - commit a log message | |
193 | * @class: message class information (%L_DEBUG to %L_BUG, see |lib/birdlib.h|) | |
194 | * @buf: message to write | |
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 | |
205 | log_commit(int class, buffer *buf) | |
206 | { | |
207 | struct log_config *l; | |
208 | ||
209 | if (buf->pos == buf->end) | |
210 | strcpy(buf->end - 100, " ... <too long>"); | |
211 | ||
212 | log_lock(); | |
213 | WALK_LIST(l, *current_log_list) | |
214 | { | |
215 | if (!(l->mask & (1 << class))) | |
216 | continue; | |
217 | if (l->fh) | |
218 | { | |
219 | if (l->terminal_flag) | |
220 | fputs("bird: ", l->fh); | |
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 | } | |
233 | else | |
234 | { | |
235 | byte tbuf[TM_DATETIME_BUFFER_SIZE]; | |
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())) | |
238 | strcpy(tbuf, "<error>"); | |
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 | ||
255 | fprintf(l->fh, "%s <%s> ", tbuf, class_names[class]); | |
256 | } | |
257 | fputs(buf->start, l->fh); | |
258 | fputc('\n', l->fh); | |
259 | fflush(l->fh); | |
260 | } | |
261 | #ifdef HAVE_SYSLOG_H | |
262 | else | |
263 | syslog(syslog_priorities[class], "%s", buf->start); | |
264 | #endif | |
265 | } | |
266 | log_unlock(); | |
267 | ||
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); | |
271 | ||
272 | buf->pos = buf->start; | |
273 | } | |
274 | ||
275 | int buffer_vprint(buffer *buf, const char *fmt, va_list args); | |
276 | ||
277 | void | |
278 | vlog(int class, const char *msg, va_list args) | |
279 | { | |
280 | buffer buf; | |
281 | LOG_BUFFER_INIT(buf); | |
282 | buffer_vprint(&buf, msg, args); | |
283 | log_commit(class, &buf); | |
284 | } | |
285 | ||
286 | ||
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 | |
293 | * and writes it to the corresponding log file (as specified in the | |
294 | * configuration). Please note that the message is automatically | |
295 | * formatted as a full line, no need to include |\n| inside. | |
296 | * It is essentially a sequence of log_reset(), logn() and log_commit(). | |
297 | */ | |
298 | void | |
299 | log_msg(const char *msg, ...) | |
300 | { | |
301 | int class = 1; | |
302 | va_list args; | |
303 | ||
304 | va_start(args, msg); | |
305 | if (*msg >= 1 && *msg < L_MAX) | |
306 | class = *msg++; | |
307 | vlog(class, msg, args); | |
308 | va_end(args); | |
309 | } | |
310 | ||
311 | void | |
312 | log_rl(struct tbf *f, const char *msg, ...) | |
313 | { | |
314 | int class = 1; | |
315 | va_list args; | |
316 | ||
317 | /* Rate limiting is a bit tricky here as it also logs '...' during the first hit */ | |
318 | if (tbf_limit(f) && (f->drop > 1)) | |
319 | return; | |
320 | ||
321 | if (*msg >= 1 && *msg < L_MAX) | |
322 | class = *msg++; | |
323 | ||
324 | va_start(args, msg); | |
325 | vlog(class, (f->drop ? "..." : msg), args); | |
326 | va_end(args); | |
327 | } | |
328 | ||
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 | */ | |
336 | void | |
337 | bug(const char *msg, ...) | |
338 | { | |
339 | va_list args; | |
340 | ||
341 | va_start(args, msg); | |
342 | vlog(L_BUG[0], msg, args); | |
343 | va_end(args); | |
344 | abort(); | |
345 | } | |
346 | ||
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 | */ | |
354 | void | |
355 | die(const char *msg, ...) | |
356 | { | |
357 | va_list args; | |
358 | ||
359 | va_start(args, msg); | |
360 | vlog(L_FATAL[0], msg, args); | |
361 | va_end(args); | |
362 | exit(1); | |
363 | } | |
364 | ||
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 | */ | |
372 | void | |
373 | debug(const char *msg, ...) | |
374 | { | |
375 | #define MAX_DEBUG_BUFSIZE 16384 | |
376 | va_list args; | |
377 | char buf[MAX_DEBUG_BUFSIZE]; | |
378 | ||
379 | va_start(args, msg); | |
380 | if (dbgf) | |
381 | { | |
382 | if (bvsnprintf(buf, MAX_DEBUG_BUFSIZE, msg, args) < 0) | |
383 | bug("Extremely long debug output, split it."); | |
384 | ||
385 | fputs(buf, dbgf); | |
386 | } | |
387 | va_end(args); | |
388 | } | |
389 | ||
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 | ||
405 | static list * | |
406 | default_log_list(int initial, const char **syslog_name) | |
407 | { | |
408 | static list log_list; | |
409 | init_list(&log_list); | |
410 | *syslog_name = NULL; | |
411 | ||
412 | #ifdef HAVE_SYSLOG_H | |
413 | if (!dbgf) | |
414 | { | |
415 | static struct log_config lc_syslog; | |
416 | lc_syslog = (struct log_config){ | |
417 | .mask = ~0 | |
418 | }; | |
419 | ||
420 | add_tail(&log_list, &lc_syslog.n); | |
421 | *syslog_name = bird_name; | |
422 | } | |
423 | #endif | |
424 | ||
425 | if (dbgf && (dbgf != stderr)) | |
426 | { | |
427 | static struct log_config lc_debug; | |
428 | lc_debug = (struct log_config){ | |
429 | .mask = ~0, | |
430 | .fh = dbgf | |
431 | }; | |
432 | ||
433 | add_tail(&log_list, &lc_debug.n); | |
434 | } | |
435 | ||
436 | if (initial || (dbgf == stderr)) | |
437 | { | |
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 | ||
445 | add_tail(&log_list, &lc_stderr.n); | |
446 | } | |
447 | ||
448 | return &log_list; | |
449 | } | |
450 | ||
451 | void | |
452 | log_switch(int initial, list *logs, const char *new_syslog_name) | |
453 | { | |
454 | struct log_config *l; | |
455 | ||
456 | /* We should not manipulate with log list when other threads may use it */ | |
457 | log_lock(); | |
458 | ||
459 | if (!logs || EMPTY_LIST(*logs)) | |
460 | logs = default_log_list(initial, &new_syslog_name); | |
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) | |
465 | if (l->filename && l->rf) | |
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); | |
473 | ||
474 | current_log_list = logs; | |
475 | ||
476 | #ifdef HAVE_SYSLOG_H | |
477 | if (!bstrcmp(current_syslog_name, new_syslog_name)) | |
478 | goto done; | |
479 | ||
480 | if (current_syslog_name) | |
481 | { | |
482 | closelog(); | |
483 | xfree(current_syslog_name); | |
484 | current_syslog_name = NULL; | |
485 | } | |
486 | ||
487 | if (new_syslog_name) | |
488 | { | |
489 | current_syslog_name = xstrdup(new_syslog_name); | |
490 | openlog(current_syslog_name, LOG_CONS | LOG_NDELAY, LOG_DAEMON); | |
491 | } | |
492 | ||
493 | #endif | |
494 | ||
495 | done: | |
496 | /* Logs exchange done, let the threads log as before */ | |
497 | log_unlock(); | |
498 | } | |
499 | ||
500 | void | |
501 | log_init_debug(char *f) | |
502 | { | |
503 | dbg_fd = -1; | |
504 | if (dbgf && dbgf != stderr) | |
505 | fclose(dbgf); | |
506 | ||
507 | if (!f) | |
508 | dbgf = NULL; | |
509 | else if (!*f) | |
510 | dbgf = stderr; | |
511 | else if (!(dbgf = fopen(f, "a"))) | |
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 | } | |
517 | ||
518 | if (dbgf) | |
519 | { | |
520 | setvbuf(dbgf, NULL, _IONBF, 0); | |
521 | dbg_fd = fileno(dbgf); | |
522 | } | |
523 | } |