lib/zlog_targets.c

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