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