lib/zlog_targets.c

   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 DEFINE_MGROUP_ACTIVEATEXIT(LOG, "logging subsystem");
  35
  36 DEFINE_MTYPE_STATIC(LOG, LOG_FD,        "log file target");
  37 DEFINE_MTYPE_STATIC(LOG, LOG_FD_NAME,   "log file name");
  38 DEFINE_MTYPE_STATIC(LOG, LOG_FD_ROTATE, "log file rotate helper");
  39 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 void zlog_fd(struct zlog_target *zt, struct zlog_msg *msgs[], size_t nmsgs)
  64 {
  65         struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt);
  66         int fd;
  67         size_t i, textlen, iovpos = 0;
  68         size_t niov = MIN(4 * nmsgs + 1, IOV_MAX);
  69         struct iovec iov[niov];
  70         /* "\nYYYY-MM-DD HH:MM:SS.NNNNNNNNN+ZZ:ZZ " = 37 chars */
  71 #define TS_LEN 40
  72         char ts_buf[TS_LEN * nmsgs], *ts_pos = ts_buf;
  73
  74         fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
  75
  76         for (i = 0; i < nmsgs; i++) {
  77                 struct zlog_msg *msg = msgs[i];
  78                 int prio = zlog_msg_prio(msg);
  79
  80                 if (prio <= zt->prio_min) {
  81                         struct fbuf fbuf = {
  82                                 .buf = ts_buf,
  83                                 .pos = ts_pos,
  84                                 .len = sizeof(ts_buf),
  85                         };
  86
  87                         iov[iovpos].iov_base = ts_pos;
  88                         zlog_msg_ts(msg, &fbuf,
  89                                     ZLOG_TS_LEGACY | zte->ts_subsec);
  90                         ts_pos = fbuf.pos;
  91
  92                         *ts_pos++ = ' ';
  93                         iov[iovpos].iov_len =
  94                                 ts_pos - (char *)iov[iovpos].iov_base;
  95
  96                         iovpos++;
  97
  98                         if (zte->record_priority) {
  99                                 iov[iovpos].iov_base = (char *)prionames[prio];
 100                                 iov[iovpos].iov_len =
 101                                         strlen(iov[iovpos].iov_base);
 102
 103                                 iovpos++;
 104                         }
 105
 106                         iov[iovpos].iov_base = zlog_prefix;
 107                         iov[iovpos].iov_len = zlog_prefixsz;
 108
 109                         iovpos++;
 110
 111                         iov[iovpos].iov_base =
 112                                 (char *)zlog_msg_text(msg, &textlen);
 113                         iov[iovpos].iov_len = textlen + 1;
 114
 115                         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                 if (iovpos > 0 && (ts_buf + sizeof(ts_buf) - ts_pos < TS_LEN
 124                                    || i + 1 == nmsgs
 125                                    || array_size(iov) - iovpos < 5)) {
 126                         writev(fd, iov, iovpos);
 127
 128                         iovpos = 0;
 129                         ts_pos = ts_buf;
 130                 }
 131         }
 132
 133         assert(iovpos == 0);
 134 }
 135
 136 static void zlog_fd_sigsafe(struct zlog_target *zt, const char *text,
 137                             size_t len)
 138 {
 139         struct zlt_fd *zte = container_of(zt, struct zlt_fd, zt);
 140         struct iovec iov[4];
 141         int fd;
 142
 143         iov[0].iov_base = (char *)prionames[LOG_CRIT];
 144         iov[0].iov_len = zte->record_priority ? strlen(iov[0].iov_base) : 0;
 145
 146         iov[1].iov_base = zlog_prefix;
 147         iov[1].iov_len = zlog_prefixsz;
 148
 149         iov[2].iov_base = (char *)text;
 150         iov[2].iov_len = len;
 151
 152         iov[3].iov_base = (char *)"\n";
 153         iov[3].iov_len = 1;
 154
 155         fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
 156
 157         writev(fd, iov, array_size(iov));
 158 }
 159
 160 /*
 161  * (re-)configuration
 162  */
 163
 164 void zlog_file_init(struct zlog_cfg_file *zcf)
 165 {
 166         memset(zcf, 0, sizeof(*zcf));
 167         zcf->prio_min = ZLOG_DISABLED;
 168         zcf->fd = -1;
 169         pthread_mutex_init(&zcf->cfg_mtx, NULL);
 170 }
 171
 172 static void zlog_file_target_free(struct zlt_fd *zlt)
 173 {
 174         if (!zlt)
 175                 return;
 176
 177         rcu_close(&zlt->head_close, zlt->fd);
 178         rcu_free(MTYPE_LOG_FD, zlt, zt.rcu_head);
 179 }
 180
 181 void zlog_file_fini(struct zlog_cfg_file *zcf)
 182 {
 183         if (zcf->active) {
 184                 struct zlt_fd *ztf;
 185                 struct zlog_target *zt;
 186
 187                 zt = zlog_target_replace(&zcf->active->zt, NULL);
 188                 ztf = container_of(zt, struct zlt_fd, zt);
 189                 zlog_file_target_free(ztf);
 190         }
 191         XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
 192         pthread_mutex_destroy(&zcf->cfg_mtx);
 193 }
 194
 195 static bool zlog_file_cycle(struct zlog_cfg_file *zcf)
 196 {
 197         struct zlog_target *zt, *old;
 198         struct zlt_fd *zlt = NULL;
 199         int fd;
 200         bool rv = true;
 201
 202         do {
 203                 if (zcf->prio_min == ZLOG_DISABLED)
 204                         break;
 205
 206                 if (zcf->fd != -1)
 207                         fd = dup(zcf->fd);
 208                 else if (zcf->filename)
 209                         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                 if (fd < 0) {
 217                         rv = false;
 218                         break;
 219                 }
 220
 221                 zt = zlog_target_clone(MTYPE_LOG_FD, &zcf->active->zt,
 222                                        sizeof(*zlt));
 223                 zlt = container_of(zt, struct zlt_fd, zt);
 224
 225                 zlt->fd = fd;
 226                 zlt->record_priority = zcf->record_priority;
 227                 zlt->ts_subsec = zcf->ts_subsec;
 228
 229                 zlt->zt.prio_min = zcf->prio_min;
 230                 zlt->zt.logfn = zcf->zlog_wrap ? zcf->zlog_wrap : zlog_fd;
 231                 zlt->zt.logfn_sigsafe = zlog_fd_sigsafe;
 232         } while (0);
 233
 234         old = zlog_target_replace(zcf->active ? &zcf->active->zt : NULL,
 235                                   zlt ? &zlt->zt : NULL);
 236         zcf->active = zlt;
 237
 238         zlog_file_target_free(container_of_null(old, struct zlt_fd, zt));
 239
 240         return rv;
 241 }
 242
 243 void zlog_file_set_other(struct zlog_cfg_file *zcf)
 244 {
 245         frr_with_mutex (&zcf->cfg_mtx) {
 246                 zlog_file_cycle(zcf);
 247         }
 248 }
 249
 250 bool zlog_file_set_filename(struct zlog_cfg_file *zcf, const char *filename)
 251 {
 252         frr_with_mutex (&zcf->cfg_mtx) {
 253                 XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
 254                 zcf->filename = XSTRDUP(MTYPE_LOG_FD_NAME, filename);
 255                 zcf->fd = -1;
 256
 257                 return zlog_file_cycle(zcf);
 258         }
 259         assert(0);
 260         return false;
 261 }
 262
 263 bool zlog_file_set_fd(struct zlog_cfg_file *zcf, int fd)
 264 {
 265         frr_with_mutex (&zcf->cfg_mtx) {
 266                 if (zcf->fd == fd)
 267                         return true;
 268
 269                 XFREE(MTYPE_LOG_FD_NAME, zcf->filename);
 270                 zcf->fd = fd;
 271
 272                 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 bool zlog_file_rotate(struct zlog_cfg_file *zcf)
 284 {
 285         struct rcu_close_rotate *rcr;
 286         int fd;
 287
 288         frr_with_mutex (&zcf->cfg_mtx) {
 289                 if (!zcf->active || !zcf->filename)
 290                         return true;
 291
 292                 fd = open(zcf->filename,
 293                           O_WRONLY | O_APPEND | O_CREAT | O_CLOEXEC | O_NOCTTY,
 294                           LOGFILE_MASK);
 295                 if (fd < 0)
 296                         return false;
 297
 298                 fd = atomic_exchange_explicit(&zcf->active->fd,
 299                                               (uint_fast32_t)fd,
 300                                               memory_order_relaxed);
 301         }
 302
 303         rcr = XCALLOC(MTYPE_LOG_FD_ROTATE, sizeof(*rcr));
 304         rcu_close(&rcr->head_close, fd);
 305         rcu_free(MTYPE_LOG_FD_ROTATE, rcr, head_self);
 306
 307         return true;
 308 }
 309
 310 /* fixed crash logging */
 311
 312 static struct zlt_fd zlog_crashlog;
 313
 314 static void zlog_crashlog_sigsafe(struct zlog_target *zt, const char *text,
 315                                   size_t len)
 316 {
 317         static int crashlog_fd = -1;
 318
 319         if (crashlog_fd == -1) {
 320 #ifdef HAVE_OPENAT
 321                 crashlog_fd = openat(zlog_tmpdirfd, "crashlog",
 322                                      O_WRONLY | O_APPEND | O_CREAT,
 323                                      LOGFILE_MASK);
 324 #endif
 325                 if (crashlog_fd < 0)
 326                         crashlog_fd = -2;
 327         }
 328
 329         if (crashlog_fd == -2)
 330                 return;
 331
 332         zlog_crashlog.fd = crashlog_fd;
 333         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 static void zlog_crashlog_plain(struct zlog_target *zt, struct zlog_msg *msgs[],
 338                                 size_t nmsgs)
 339 {
 340         size_t i, len;
 341         const char *text;
 342
 343         for (i = 0; i < nmsgs; i++) {
 344                 if (zlog_msg_prio(msgs[i]) > zt->prio_min)
 345                         continue;
 346
 347                 text = zlog_msg_text(msgs[i], &len);
 348                 zlog_crashlog_sigsafe(zt, text, len);
 349         }
 350 }
 351
 352 static void zlog_crashlog_init(void)
 353 {
 354         zlog_crashlog.zt.prio_min = LOG_CRIT;
 355         zlog_crashlog.zt.logfn = zlog_crashlog_plain;
 356         zlog_crashlog.zt.logfn_sigsafe = zlog_crashlog_sigsafe;
 357         zlog_crashlog.fd = -1;
 358
 359         zlog_target_replace(NULL, &zlog_crashlog.zt);
 360 }
 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 static int zlt_aux_init(const char *prefix, int prio_min)
 368 {
 369         zlog_is_aux = true;
 370
 371         zlog_aux_stdout.zt.prio_min = prio_min;
 372         zlog_aux_stdout.zt.logfn = zlog_fd;
 373         zlog_aux_stdout.zt.logfn_sigsafe = zlog_fd_sigsafe;
 374         zlog_aux_stdout.fd = STDOUT_FILENO;
 375
 376         zlog_target_replace(NULL, &zlog_aux_stdout.zt);
 377         zlog_startup_end();
 378         return 0;
 379 }
 380
 381 static int zlt_init(const char *progname, const char *protoname,
 382                      unsigned short instance, uid_t uid, gid_t gid)
 383 {
 384         openlog(progname, LOG_CONS | LOG_NDELAY | LOG_PID, LOG_DAEMON);
 385         return 0;
 386 }
 387
 388 static int zlt_fini(void)
 389 {
 390         closelog();
 391         return 0;
 392 }
 393
 394 /* fixed startup logging to stderr */
 395
 396 static struct zlt_fd zlog_startup_stderr;
 397
 398 __attribute__((_CONSTRUCTOR(450))) static void zlog_startup_init(void)
 399 {
 400         zlog_startup_stderr.zt.prio_min = LOG_WARNING;
 401         zlog_startup_stderr.zt.logfn = zlog_fd;
 402         zlog_startup_stderr.zt.logfn_sigsafe = zlog_fd_sigsafe;
 403         zlog_startup_stderr.fd = STDERR_FILENO;
 404
 405         zlog_target_replace(NULL, &zlog_startup_stderr.zt);
 406
 407         hook_register(zlog_aux_init, zlt_aux_init);
 408         hook_register(zlog_init, zlt_init);
 409         hook_register(zlog_fini, zlt_fini);
 410 }
 411
 412 void zlog_startup_end(void)
 413 {
 414         static bool startup_ended = false;
 415
 416         if (startup_ended)
 417                 return;
 418         startup_ended = true;
 419
 420         zlog_target_replace(&zlog_startup_stderr.zt, NULL);
 421
 422         if (zlog_is_aux)
 423                 return;
 424
 425         /* until here, crashlogs go to stderr */
 426         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 static void zlog_syslog(struct zlog_target *zt, struct zlog_msg *msgs[],
 438                         size_t nmsgs)
 439 {
 440         size_t i;
 441         struct zlt_syslog *zte = container_of(zt, struct zlt_syslog, zt);
 442         const char *text;
 443         size_t text_len;
 444
 445         for (i = 0; i < nmsgs; i++) {
 446                 if (zlog_msg_prio(msgs[i]) > zt->prio_min)
 447                         continue;
 448
 449                 text = zlog_msg_text(msgs[i], &text_len);
 450                 syslog(zlog_msg_prio(msgs[i]) | zte->syslog_facility, "%.*s",
 451                        (int)text_len, text);
 452         }
 453 }
 454
 455 #ifndef _PATH_LOG
 456 #define _PATH_LOG "/dev/log"
 457 #endif
 458
 459 static void zlog_syslog_sigsafe(struct zlog_target *zt, const char *text,
 460                                 size_t len)
 461 {
 462         static int syslog_fd = -1;
 463
 464         char hdr[192];
 465         size_t hdrlen;
 466         struct iovec iov[2];
 467
 468         if (syslog_fd == -1) {
 469                 syslog_fd = socket(AF_UNIX, SOCK_DGRAM, 0);
 470                 if (syslog_fd >= 0) {
 471                         struct sockaddr_un sa;
 472                         socklen_t salen = sizeof(sa);
 473
 474                         sa.sun_family = AF_UNIX;
 475                         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                         if (connect(syslog_fd, (struct sockaddr *)&sa, salen)) {
 480                                 close(syslog_fd);
 481                                 syslog_fd = -1;
 482                         }
 483                 }
 484
 485                 /* /dev/log could be a fifo instead of a socket */
 486                 if (syslog_fd == -1) {
 487                         syslog_fd = open(_PATH_LOG, O_WRONLY | O_NOCTTY);
 488                         if (syslog_fd < 0)
 489                                 /* give up ... */
 490                                 syslog_fd = -2;
 491                 }
 492         }
 493
 494         if (syslog_fd == -2)
 495                 return;
 496
 497         /* note zlog_prefix includes trailing ": ", need to cut off 2 chars */
 498         hdrlen = snprintfrr(hdr, sizeof(hdr), "<%d>%.*s[%ld]: ", LOG_CRIT,
 499                             zlog_prefixsz > 2 ? (int)(zlog_prefixsz - 2) : 0,
 500                             zlog_prefix, (long)getpid());
 501
 502         iov[0].iov_base = hdr;
 503         iov[0].iov_len = hdrlen;
 504
 505         iov[1].iov_base = (char *)text;
 506         iov[1].iov_len = len;
 507
 508         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 void zlog_syslog_set_facility(int facility)
 518 {
 519         struct zlog_target *newztc;
 520         struct zlt_syslog *newzt;
 521
 522         frr_with_mutex (&syslog_cfg_mutex) {
 523                 if (facility == syslog_facility)
 524                         return;
 525                 syslog_facility = facility;
 526
 527                 if (syslog_prio_min == ZLOG_DISABLED)
 528                         return;
 529
 530                 newztc = zlog_target_clone(MTYPE_LOG_SYSL, &zlt_syslog->zt,
 531                                            sizeof(*newzt));
 532                 newzt = container_of(newztc, struct zlt_syslog, zt);
 533                 newzt->syslog_facility = syslog_facility;
 534
 535                 zlog_target_free(MTYPE_LOG_SYSL,
 536                                  zlog_target_replace(&zlt_syslog->zt,
 537                                                      &newzt->zt));
 538
 539                 zlt_syslog = newzt;
 540         }
 541 }
 542
 543 int zlog_syslog_get_facility(void)
 544 {
 545         frr_with_mutex (&syslog_cfg_mutex) {
 546                 return syslog_facility;
 547         }
 548         assert(0);
 549         return 0;
 550 }
 551
 552 void zlog_syslog_set_prio_min(int prio_min)
 553 {
 554         struct zlog_target *newztc;
 555         struct zlt_syslog *newzt = NULL;
 556
 557         frr_with_mutex (&syslog_cfg_mutex) {
 558                 if (prio_min == syslog_prio_min)
 559                         return;
 560                 syslog_prio_min = prio_min;
 561
 562                 if (syslog_prio_min != ZLOG_DISABLED) {
 563                         newztc = zlog_target_clone(MTYPE_LOG_SYSL,
 564                                                    &zlt_syslog->zt,
 565                                                    sizeof(*newzt));
 566                         newzt = container_of(newztc, struct zlt_syslog, zt);
 567                         newzt->zt.prio_min = prio_min;
 568                         newzt->zt.logfn = zlog_syslog;
 569                         newzt->zt.logfn_sigsafe = zlog_syslog_sigsafe;
 570                         newzt->syslog_facility = syslog_facility;
 571                 }
 572
 573                 zlog_target_free(MTYPE_LOG_SYSL,
 574                                  zlog_target_replace(&zlt_syslog->zt,
 575                                                      &newzt->zt));
 576
 577                 zlt_syslog = newzt;
 578         }
 579 }
 580
 581 int zlog_syslog_get_prio_min(void)
 582 {
 583         frr_with_mutex (&syslog_cfg_mutex) {
 584                 return syslog_prio_min;
 585         }
 586         assert(0);
 587         return 0;
 588 }