Line data Source code
1 : /*
2 : * Copyright (c) 2015-19 David Lamparter, for NetDEF, Inc.
3 : *
4 : * Permission to use, copy, modify, and distribute this software for any
5 : * purpose with or without fee is hereby granted, provided that the above
6 : * copyright notice and this permission notice appear in all copies.
7 : *
8 : * THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
9 : * WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
10 : * MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
11 : * ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
12 : * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
13 : * ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
14 : * OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
15 : */
16 :
17 : #include "zebra.h"
18 :
19 : #include <sys/un.h>
20 : #include <syslog.h>
21 :
22 : #include "memory.h"
23 : #include "frrcu.h"
24 : #include "frr_pthread.h"
25 : #include "printfrr.h"
26 : #include "zlog.h"
27 : #include "zlog_targets.h"
28 :
29 : /* these allocations are intentionally left active even when doing full exit
30 : * cleanup, in order to keep the logging subsystem fully functional until the
31 : * absolute end.
32 : */
33 :
34 27 : DEFINE_MGROUP_ACTIVEATEXIT(LOG, "logging subsystem");
35 :
36 27 : DEFINE_MTYPE_STATIC(LOG, LOG_FD, "log file target");
37 27 : DEFINE_MTYPE_STATIC(LOG, LOG_FD_NAME, "log file name");
38 27 : DEFINE_MTYPE_STATIC(LOG, LOG_FD_ROTATE, "log file rotate helper");
39 27 : DEFINE_MTYPE_STATIC(LOG, LOG_SYSL, "syslog target");
40 :
41 : struct zlt_fd {
42 : struct zlog_target zt;
43 :
44 : atomic_uint_fast32_t fd;
45 :
46 : char ts_subsec;
47 : bool record_priority;
48 :
49 : struct rcu_head_close head_close;
50 : };
51 :
52 : static const char * const prionames[] = {
53 : [LOG_EMERG] = "emergencies: ",
54 : [LOG_ALERT] = "alerts: ",
55 : [LOG_CRIT] = "critical: ",
56 : [LOG_ERR] = "errors: ",
57 : [LOG_WARNING] = "warnings: ",
58 : [LOG_NOTICE] = "notifications: ",
59 : [LOG_INFO] = "informational: ",
60 : [LOG_DEBUG] = "debugging: ",
61 : };
62 :
63 258 : void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs)
64 258 : {
65 258 : struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt);
66 258 : int fd;
67 258 : size_t i, textlen, iovpos = 0;
68 258 : size_t niov = MIN(4 * nmsgs + 1, IOV_MAX);
69 258 : struct iovec iov[niov];
70 : /* "\nYYYY-MM-DD HH:MM:SS.NNNNNNNNN+ZZ:ZZ " = 37 chars */
71 : #define TS_LEN 40
72 258 : char ts_buf[TS_LEN * nmsgs], *ts_pos = ts_buf;
73 :
74 258 : fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
75 :
76 557 : for (i = 0; i < nmsgs; i++) {
77 299 : struct zlog_msg *msg = msgs[i];
78 299 : int prio = zlog_msg_prio(msg);
79 :
80 299 : if (prio <= zt->prio_min) {
81 290 : struct fbuf fbuf = {
82 : .buf = ts_buf,
83 : .pos = ts_pos,
84 : .len = sizeof(ts_buf),
85 : };
86 :
87 290 : iov[iovpos].iov_base = ts_pos;
88 290 : zlog_msg_ts(msg, &fbuf,
89 290 : ZLOG_TS_LEGACY | zte->ts_subsec);
90 290 : ts_pos = fbuf.pos;
91 :
92 290 : *ts_pos++ = ' ';
93 290 : iov[iovpos].iov_len =
94 290 : ts_pos - (char *)iov[iovpos].iov_base;
95 :
96 290 : iovpos++;
97 :
98 290 : if (zte->record_priority) {
99 220 : iov[iovpos].iov_base = (char *)prionames[prio];
100 220 : iov[iovpos].iov_len =
101 220 : strlen(iov[iovpos].iov_base);
102 :
103 220 : iovpos++;
104 : }
105 :
106 290 : iov[iovpos].iov_base = zlog_prefix;
107 290 : iov[iovpos].iov_len = zlog_prefixsz;
108 :
109 290 : iovpos++;
110 :
111 580 : iov[iovpos].iov_base =
112 290 : (char *)zlog_msg_text(msg, &textlen);
113 290 : iov[iovpos].iov_len = textlen + 1;
114 :
115 290 : iovpos++;
116 : }
117 :
118 : /* conditions that trigger writing:
119 : * - out of space for more timestamps/headers
120 : * - this being the last message in the batch
121 : * - not enough remaining iov entries
122 : */
123 299 : if (iovpos > 0 && (ts_buf + sizeof(ts_buf) - ts_pos < TS_LEN
124 44 : || i + 1 == nmsgs
125 41 : || array_size(iov) - iovpos < 5)) {
126 249 : writev(fd, iov, iovpos);
127 :
128 249 : iovpos = 0;
129 249 : ts_pos = ts_buf;
130 : }
131 : }
132 :
133 258 : assert(iovpos == 0);
134 258 : }
135 :
136 0 : static void zlog_fd_sigsafe(struct zlog_target *zt, const char *text,
137 : size_t len)
138 : {
139 0 : struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt);
140 0 : struct iovec iov[4];
141 0 : int fd;
142 :
143 0 : iov[0].iov_base = (char *)prionames[LOG_CRIT];
144 0 : iov[0].iov_len = zte->record_priority ? strlen(iov[0].iov_base) : 0;
145 :
146 0 : iov[1].iov_base = zlog_prefix;
147 0 : iov[1].iov_len = zlog_prefixsz;
148 :
149 0 : iov[2].iov_base = (char *)text;
150 0 : iov[2].iov_len = len;
151 :
152 0 : iov[3].iov_base = (char *)"\n";
153 0 : iov[3].iov_len = 1;
154 :
155 0 : fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
156 :
157 0 : writev(fd, iov, array_size(iov));
158 0 : }
159 :
160 : /*
161 : * (re-)configuration
162 : */
163 :
164 9 : void zlog_file_init(struct zlog_cfg_file *zcf)
165 : {
166 9 : memset(zcf, 0, sizeof(*zcf));
167 9 : zcf->prio_min = ZLOG_DISABLED;
168 9 : zcf->fd = -1;
169 9 : pthread_mutex_init(&zcf->cfg_mtx, NULL);
170 9 : }
171 :
172 99 : static void zlog_file_target_free(struct zlt_fd *zlt)
173 : {
174 99 : if (!zlt)
175 : return;
176 :
177 9 : rcu_close(&zlt->head_close, zlt->fd);
178 9 : rcu_free(MTYPE_LOG_FD, zlt, zt.rcu_head);
179 : }
180 :
181 0 : void zlog_file_fini(struct zlog_cfg_file *zcf)
182 : {
183 0 : if (zcf->active) {
184 0 : struct zlt_fd *ztf;
185 0 : struct zlog_target *zt;
186 :
187 0 : zt = zlog_target_replace(&zcf->active->zt, NULL);
188 0 : ztf = container_of(zt, struct zlt_fd, zt);
189 0 : zlog_file_target_free(ztf);
190 : }
191 0 : XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
192 0 : pthread_mutex_destroy(&zcf->cfg_mtx);
193 0 : }
194 :
195 99 : static bool zlog_file_cycle(struct zlog_cfg_file *zcf)
196 : {
197 99 : struct zlog_target *zt, *old;
198 99 : struct zlt_fd *zlt = NULL;
199 99 : int fd;
200 99 : bool rv = true;
201 :
202 117 : do {
203 99 : if (zcf->prio_min == ZLOG_DISABLED)
204 : break;
205 :
206 18 : if (zcf->fd != -1)
207 0 : fd = dup(zcf->fd);
208 18 : else if (zcf->filename)
209 18 : fd = open(zcf->filename,
210 : O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC
211 : | O_NOCTTY,
212 : LOGFILE_MASK);
213 : else
214 : fd = -1;
215 :
216 18 : if (fd < 0) {
217 : rv = false;
218 : break;
219 : }
220 :
221 18 : zt = zlog_target_clone(MTYPE_LOG_FD, &zcf->active->zt,
222 : sizeof(*zlt));
223 18 : zlt = container_of(zt, struct zlt_fd, zt);
224 :
225 18 : zlt->fd = fd;
226 18 : zlt->record_priority = zcf->record_priority;
227 18 : zlt->ts_subsec = zcf->ts_subsec;
228 :
229 18 : zlt->zt.prio_min = zcf->prio_min;
230 18 : zlt->zt.logfn = zcf->zlog_wrap ? zcf->zlog_wrap : zlog_fd;
231 18 : zlt->zt.logfn_sigsafe = zlog_fd_sigsafe;
232 : } while (0);
233 :
234 99 : old = zlog_target_replace(zcf->active ? &zcf->active->zt : NULL,
235 : zlt ? &zlt->zt : NULL);
236 99 : zcf->active = zlt;
237 :
238 99 : zlog_file_target_free(container_of_null(old, struct zlt_fd, zt));
239 :
240 99 : return rv;
241 : }
242 :
243 72 : void zlog_file_set_other(struct zlog_cfg_file *zcf)
244 : {
245 144 : frr_with_mutex (&zcf->cfg_mtx) {
246 72 : zlog_file_cycle(zcf);
247 : }
248 72 : }
249 :
250 18 : bool zlog_file_set_filename(struct zlog_cfg_file *zcf, const char *filename)
251 : {
252 18 : frr_with_mutex (&zcf->cfg_mtx) {
253 18 : XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
254 18 : zcf->filename = XSTRDUP(MTYPE_LOG_FD_NAME, filename);
255 18 : zcf->fd = -1;
256 :
257 18 : return zlog_file_cycle(zcf);
258 : }
259 : assert(0);
260 : return false;
261 : }
262 :
263 9 : bool zlog_file_set_fd(struct zlog_cfg_file *zcf, int fd)
264 : {
265 9 : frr_with_mutex (&zcf->cfg_mtx) {
266 9 : if (zcf->fd == fd)
267 : return true;
268 :
269 9 : XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
270 9 : zcf->fd = fd;
271 :
272 9 : return zlog_file_cycle(zcf);
273 : }
274 : assert(0);
275 : return false;
276 : }
277 :
278 : struct rcu_close_rotate {
279 : struct rcu_head_close head_close;
280 : struct rcu_head head_self;
281 : };
282 :
283 0 : bool zlog_file_rotate(struct zlog_cfg_file *zcf)
284 : {
285 0 : struct rcu_close_rotate *rcr;
286 0 : int fd;
287 :
288 0 : frr_with_mutex (&zcf->cfg_mtx) {
289 0 : if (!zcf->active || !zcf->filename)
290 : return true;
291 :
292 0 : fd = open(zcf->filename,
293 : O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC | O_NOCTTY,
294 : LOGFILE_MASK);
295 0 : if (fd < 0)
296 : return false;
297 :
298 0 : fd = atomic_exchange_explicit(&zcf->active->fd,
299 : (uint_fast32_t)fd,
300 : memory_order_relaxed);
301 : }
302 :
303 0 : rcr = XCALLOC(MTYPE_LOG_FD_ROTATE, sizeof(*rcr));
304 0 : rcu_close(&rcr->head_close, fd);
305 0 : rcu_free(MTYPE_LOG_FD_ROTATE, rcr, head_self);
306 :
307 0 : return true;
308 : }
309 :
310 : /* fixed crash logging */
311 :
312 : static struct zlt_fd zlog_crashlog;
313 :
314 0 : static void zlog_crashlog_sigsafe(struct zlog_target *zt, const char *text,
315 : size_t len)
316 : {
317 0 : static int crashlog_fd = -1;
318 :
319 0 : if (crashlog_fd == -1) {
320 : #ifdef HAVE_OPENAT
321 0 : crashlog_fd = openat(zlog_tmpdirfd, "crashlog",
322 : O_WRONLY | O_APPEND | O_CREAT,
323 : LOGFILE_MASK);
324 : #endif
325 0 : if (crashlog_fd < 0)
326 0 : crashlog_fd = -2;
327 : }
328 :
329 0 : if (crashlog_fd == -2)
330 : return;
331 :
332 0 : zlog_crashlog.fd = crashlog_fd;
333 0 : zlog_fd_sigsafe(&zlog_crashlog.zt, text, len);
334 : }
335 :
336 : /* this is used for assert failures (they don't need AS-Safe logging) */
337 153 : static void zlog_crashlog_plain(struct zlog_target *zt, struct zlog_msg *msgs[],
338 : size_t nmsgs)
339 : {
340 153 : size_t i, len;
341 153 : const char *text;
342 :
343 347 : for (i = 0; i < nmsgs; i++) {
344 194 : if (zlog_msg_prio(msgs[i]) > zt->prio_min)
345 194 : continue;
346 :
347 0 : text = zlog_msg_text(msgs[i], &len);
348 0 : zlog_crashlog_sigsafe(zt, text, len);
349 : }
350 153 : }
351 :
352 9 : static void zlog_crashlog_init(void)
353 : {
354 9 : zlog_crashlog.zt.prio_min = LOG_CRIT;
355 9 : zlog_crashlog.zt.logfn = zlog_crashlog_plain;
356 9 : zlog_crashlog.zt.logfn_sigsafe = zlog_crashlog_sigsafe;
357 9 : zlog_crashlog.fd = -1;
358 :
359 9 : zlog_target_replace(NULL, &zlog_crashlog.zt);
360 9 : }
361 :
362 : /* fixed logging for test/auxiliary programs */
363 :
364 : static struct zlt_fd zlog_aux_stdout;
365 : static bool zlog_is_aux;
366 :
367 0 : static int zlt_aux_init(const char *prefix, int prio_min)
368 : {
369 0 : zlog_is_aux = true;
370 :
371 0 : zlog_aux_stdout.zt.prio_min = prio_min;
372 0 : zlog_aux_stdout.zt.logfn = zlog_fd;
373 0 : zlog_aux_stdout.zt.logfn_sigsafe = zlog_fd_sigsafe;
374 0 : zlog_aux_stdout.fd = STDOUT_FILENO;
375 :
376 0 : zlog_target_replace(NULL, &zlog_aux_stdout.zt);
377 0 : zlog_startup_end();
378 0 : return 0;
379 : }
380 :
381 9 : static int zlt_init(const char *progname, const char *protoname,
382 : unsigned short instance, uid_t uid, gid_t gid)
383 : {
384 9 : openlog(progname, LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON);
385 9 : return 0;
386 : }
387 :
388 9 : static int zlt_fini(void)
389 : {
390 9 : closelog();
391 9 : return 0;
392 : }
393 :
394 : /* fixed startup logging to stderr */
395 :
396 : static struct zlt_fd zlog_startup_stderr;
397 :
398 9 : __attribute__((_CONSTRUCTOR(450))) static void zlog_startup_init(void)
399 : {
400 9 : zlog_startup_stderr.zt.prio_min = LOG_WARNING;
401 9 : zlog_startup_stderr.zt.logfn = zlog_fd;
402 9 : zlog_startup_stderr.zt.logfn_sigsafe = zlog_fd_sigsafe;
403 9 : zlog_startup_stderr.fd = STDERR_FILENO;
404 :
405 9 : zlog_target_replace(NULL, &zlog_startup_stderr.zt);
406 :
407 9 : hook_register(zlog_aux_init, zlt_aux_init);
408 9 : hook_register(zlog_init, zlt_init);
409 9 : hook_register(zlog_fini, zlt_fini);
410 9 : }
411 :
412 9 : void zlog_startup_end(void)
413 : {
414 9 : static bool startup_ended = false;
415 :
416 9 : if (startup_ended)
417 : return;
418 9 : startup_ended = true;
419 :
420 9 : zlog_target_replace(&zlog_startup_stderr.zt, NULL);
421 :
422 9 : if (zlog_is_aux)
423 : return;
424 :
425 : /* until here, crashlogs go to stderr */
426 9 : zlog_crashlog_init();
427 : }
428 :
429 : /* syslog */
430 :
431 : struct zlt_syslog {
432 : struct zlog_target zt;
433 :
434 : int syslog_facility;
435 : };
436 :
437 0 : static void zlog_syslog(struct zlog_target *zt, struct zlog_msg *msgs[],
438 : size_t nmsgs)
439 : {
440 0 : size_t i;
441 0 : struct zlt_syslog *zte = container_of(zt, struct zlt_syslog, zt);
442 0 : const char *text;
443 0 : size_t text_len;
444 :
445 0 : for (i = 0; i < nmsgs; i++) {
446 0 : if (zlog_msg_prio(msgs[i]) > zt->prio_min)
447 0 : continue;
448 :
449 0 : text = zlog_msg_text(msgs[i], &text_len);
450 0 : syslog(zlog_msg_prio(msgs[i]) | zte->syslog_facility, "%.*s",
451 : (int)text_len, text);
452 : }
453 0 : }
454 :
455 : #ifndef _PATH_LOG
456 : #define _PATH_LOG "/dev/log"
457 : #endif
458 :
459 0 : static void zlog_syslog_sigsafe(struct zlog_target *zt, const char *text,
460 : size_t len)
461 : {
462 0 : static int syslog_fd = -1;
463 :
464 0 : char hdr[192];
465 0 : size_t hdrlen;
466 0 : struct iovec iov[2];
467 :
468 0 : if (syslog_fd == -1) {
469 0 : syslog_fd = socket(AF_UNIX, SOCK_DGRAM, 0);
470 0 : if (syslog_fd >= 0) {
471 0 : struct sockaddr_un sa;
472 0 : socklen_t salen = sizeof(sa);
473 :
474 0 : sa.sun_family = AF_UNIX;
475 0 : strlcpy(sa.sun_path, _PATH_LOG, sizeof(sa.sun_path));
476 : #ifdef HAVE_STRUCT_SOCKADDR_UN_SUN_LEN
477 : salen = sa.sun_len = SUN_LEN(&sa);
478 : #endif
479 0 : if (connect(syslog_fd, (struct sockaddr *)&sa, salen)) {
480 0 : close(syslog_fd);
481 0 : syslog_fd = -1;
482 : }
483 : }
484 :
485 : /* /dev/log could be a fifo instead of a socket */
486 0 : if (syslog_fd == -1) {
487 0 : syslog_fd = open(_PATH_LOG, O_WRONLY | O_NOCTTY);
488 0 : if (syslog_fd < 0)
489 : /* give up ... */
490 0 : syslog_fd = -2;
491 : }
492 : }
493 :
494 0 : if (syslog_fd == -2)
495 0 : return;
496 :
497 : /* note zlog_prefix includes trailing ": ", need to cut off 2 chars */
498 0 : hdrlen = snprintfrr(hdr, sizeof(hdr), "<%d>%.*s[%ld]: ", LOG_CRIT,
499 0 : zlog_prefixsz > 2 ? (int)(zlog_prefixsz - 2) : 0,
500 0 : zlog_prefix, (long)getpid());
501 :
502 0 : iov[0].iov_base = hdr;
503 0 : iov[0].iov_len = hdrlen;
504 :
505 0 : iov[1].iov_base = (char *)text;
506 0 : iov[1].iov_len = len;
507 :
508 0 : writev(syslog_fd, iov, array_size(iov));
509 : }
510 :
511 :
512 : static pthread_mutex_t syslog_cfg_mutex = PTHREAD_MUTEX_INITIALIZER;
513 : static struct zlt_syslog *zlt_syslog;
514 : static int syslog_facility = LOG_DAEMON;
515 : static int syslog_prio_min = ZLOG_DISABLED;
516 :
517 0 : void zlog_syslog_set_facility(int facility)
518 : {
519 0 : struct zlog_target *newztc;
520 0 : struct zlt_syslog *newzt;
521 :
522 0 : frr_with_mutex (&syslog_cfg_mutex) {
523 0 : if (facility == syslog_facility)
524 : return;
525 0 : syslog_facility = facility;
526 :
527 0 : if (syslog_prio_min == ZLOG_DISABLED)
528 : return;
529 :
530 0 : newztc = zlog_target_clone(MTYPE_LOG_SYSL, &zlt_syslog->zt,
531 : sizeof(*newzt));
532 0 : newzt = container_of(newztc, struct zlt_syslog, zt);
533 0 : newzt->syslog_facility = syslog_facility;
534 :
535 0 : zlog_target_free(MTYPE_LOG_SYSL,
536 : zlog_target_replace(&zlt_syslog->zt,
537 : &newzt->zt));
538 :
539 0 : zlt_syslog = newzt;
540 : }
541 : }
542 :
543 0 : int zlog_syslog_get_facility(void)
544 : {
545 0 : frr_with_mutex (&syslog_cfg_mutex) {
546 0 : return syslog_facility;
547 : }
548 : assert(0);
549 : return 0;
550 : }
551 :
552 9 : void zlog_syslog_set_prio_min(int prio_min)
553 : {
554 9 : struct zlog_target *newztc;
555 9 : struct zlt_syslog *newzt = NULL;
556 :
557 18 : frr_with_mutex (&syslog_cfg_mutex) {
558 9 : if (prio_min == syslog_prio_min)
559 9 : return;
560 0 : syslog_prio_min = prio_min;
561 :
562 0 : if (syslog_prio_min != ZLOG_DISABLED) {
563 0 : newztc = zlog_target_clone(MTYPE_LOG_SYSL,
564 0 : &zlt_syslog->zt,
565 : sizeof(*newzt));
566 0 : newzt = container_of(newztc, struct zlt_syslog, zt);
567 0 : newzt->zt.prio_min = prio_min;
568 0 : newzt->zt.logfn = zlog_syslog;
569 0 : newzt->zt.logfn_sigsafe = zlog_syslog_sigsafe;
570 0 : newzt->syslog_facility = syslog_facility;
571 : }
572 :
573 0 : zlog_target_free(MTYPE_LOG_SYSL,
574 : zlog_target_replace(&zlt_syslog->zt,
575 : &newzt->zt));
576 :
577 0 : zlt_syslog = newzt;
578 : }
579 : }
580 :
581 0 : int zlog_syslog_get_prio_min(void)
582 : {
583 0 : frr_with_mutex (&syslog_cfg_mutex) {
584 0 : return syslog_prio_min;
585 : }
586 : assert(0);
587 : return 0;
588 : }
|