1 /* $NetBSD: log.c,v 1.10 2024/02/21 22:52:28 christos Exp $ */ 2 3 /* 4 * Copyright (C) Internet Systems Consortium, Inc. ("ISC") 5 * 6 * SPDX-License-Identifier: MPL-2.0 7 * 8 * This Source Code Form is subject to the terms of the Mozilla Public 9 * License, v. 2.0. If a copy of the MPL was not distributed with this 10 * file, you can obtain one at https://mozilla.org/MPL/2.0/. 11 * 12 * See the COPYRIGHT file distributed with this work for additional 13 * information regarding copyright ownership. 14 */ 15 16 /*! \file */ 17 18 #include <errno.h> 19 #include <inttypes.h> 20 #include <limits.h> 21 #include <stdbool.h> 22 #include <stdlib.h> 23 #include <sys/types.h> /* dev_t FreeBSD 2.1 */ 24 #include <time.h> 25 #include <unistd.h> 26 27 #include <isc/atomic.h> 28 #include <isc/dir.h> 29 #include <isc/errno.h> 30 #include <isc/file.h> 31 #include <isc/log.h> 32 #include <isc/magic.h> 33 #include <isc/mem.h> 34 #include <isc/print.h> 35 #include <isc/rwlock.h> 36 #include <isc/stat.h> 37 #include <isc/stdio.h> 38 #include <isc/string.h> 39 #include <isc/thread.h> 40 #include <isc/time.h> 41 #include <isc/util.h> 42 43 #define LCTX_MAGIC ISC_MAGIC('L', 'c', 't', 'x') 44 #define VALID_CONTEXT(lctx) ISC_MAGIC_VALID(lctx, LCTX_MAGIC) 45 46 #define LCFG_MAGIC ISC_MAGIC('L', 'c', 'f', 'g') 47 #define VALID_CONFIG(lcfg) ISC_MAGIC_VALID(lcfg, LCFG_MAGIC) 48 49 #define RDLOCK(lp) RWLOCK(lp, isc_rwlocktype_read); 50 #define WRLOCK(lp) RWLOCK(lp, isc_rwlocktype_write); 51 #define RDUNLOCK(lp) RWUNLOCK(lp, isc_rwlocktype_read); 52 #define WRUNLOCK(lp) RWUNLOCK(lp, isc_rwlocktype_write); 53 54 static thread_local bool forcelog = false; 55 56 /* 57 * XXXDCL make dynamic? 58 */ 59 #define LOG_BUFFER_SIZE (8 * 1024) 60 61 /*! 62 * This is the structure that holds each named channel. A simple linked 63 * list chains all of the channels together, so an individual channel is 64 * found by doing strcmp()s with the names down the list. Their should 65 * be no performance penalty from this as it is expected that the number 66 * of named channels will be no more than a dozen or so, and name lookups 67 * from the head of the list are only done when isc_log_usechannel() is 68 * called, which should also be very infrequent. 69 */ 70 typedef struct isc_logchannel isc_logchannel_t; 71 72 struct isc_logchannel { 73 char *name; 74 unsigned int type; 75 int level; 76 unsigned int flags; 77 isc_logdestination_t destination; 78 ISC_LINK(isc_logchannel_t) link; 79 }; 80 81 /*! 82 * The logchannellist structure associates categories and modules with 83 * channels. First the appropriate channellist is found based on the 84 * category, and then each structure in the linked list is checked for 85 * a matching module. It is expected that the number of channels 86 * associated with any given category will be very short, no more than 87 * three or four in the more unusual cases. 88 */ 89 typedef struct isc_logchannellist isc_logchannellist_t; 90 91 struct isc_logchannellist { 92 const isc_logmodule_t *module; 93 isc_logchannel_t *channel; 94 ISC_LINK(isc_logchannellist_t) link; 95 }; 96 97 /*! 98 * This structure is used to remember messages for pruning via 99 * isc_log_[v]write1(). 100 */ 101 typedef struct isc_logmessage isc_logmessage_t; 102 103 struct isc_logmessage { 104 char *text; 105 isc_time_t time; 106 ISC_LINK(isc_logmessage_t) link; 107 }; 108 109 /*! 110 * The isc_logconfig structure is used to store the configurable information 111 * about where messages are actually supposed to be sent -- the information 112 * that could changed based on some configuration file, as opposed to the 113 * the category/module specification of isc_log_[v]write[1] that is compiled 114 * into a program, or the debug_level which is dynamic state information. 115 */ 116 struct isc_logconfig { 117 unsigned int magic; 118 isc_log_t *lctx; 119 ISC_LIST(isc_logchannel_t) channels; 120 ISC_LIST(isc_logchannellist_t) * channellists; 121 unsigned int channellist_count; 122 unsigned int duplicate_interval; 123 int_fast32_t highest_level; 124 char *tag; 125 bool dynamic; 126 }; 127 128 /*! 129 * This isc_log structure provides the context for the isc_log functions. 130 * The log context locks itself in isc_log_doit, the internal backend to 131 * isc_log_write. The locking is necessary both to provide exclusive access 132 * to the buffer into which the message is formatted and to guard against 133 * competing threads trying to write to the same syslog resource. (On 134 * some systems, such as BSD/OS, stdio is thread safe but syslog is not.) 135 * Unfortunately, the lock cannot guard against a _different_ logging 136 * context in the same program competing for syslog's attention. Thus 137 * There Can Be Only One, but this is not enforced. 138 * XXXDCL enforce it? 139 * 140 * Note that the category and module information is not locked. 141 * This is because in the usual case, only one isc_log_t is ever created 142 * in a program, and the category/module registration happens only once. 143 * XXXDCL it might be wise to add more locking overall. 144 */ 145 struct isc_log { 146 /* Not locked. */ 147 unsigned int magic; 148 isc_mem_t *mctx; 149 isc_logcategory_t *categories; 150 unsigned int category_count; 151 isc_logmodule_t *modules; 152 unsigned int module_count; 153 atomic_int_fast32_t debug_level; 154 isc_rwlock_t lcfg_rwl; 155 /* Locked by isc_log lcfg_rwl */ 156 isc_logconfig_t *logconfig; 157 isc_mutex_t lock; 158 /* Locked by isc_log lock. */ 159 char buffer[LOG_BUFFER_SIZE]; 160 ISC_LIST(isc_logmessage_t) messages; 161 atomic_bool dynamic; 162 atomic_int_fast32_t highest_level; 163 }; 164 165 /*! 166 * Used when ISC_LOG_PRINTLEVEL is enabled for a channel. 167 */ 168 static const char *log_level_strings[] = { "debug", "info", "notice", 169 "warning", "error", "critical" }; 170 171 /*! 172 * Used to convert ISC_LOG_* priorities into syslog priorities. 173 * XXXDCL This will need modification for NT. 174 */ 175 static const int syslog_map[] = { LOG_DEBUG, LOG_INFO, LOG_NOTICE, 176 LOG_WARNING, LOG_ERR, LOG_CRIT }; 177 178 /*! 179 * When adding new categories, a corresponding ISC_LOGCATEGORY_foo 180 * definition needs to be added to <isc/log.h>. 181 * 182 * The default category is provided so that the internal default can 183 * be overridden. Since the default is always looked up as the first 184 * channellist in the log context, it must come first in isc_categories[]. 185 */ 186 isc_logcategory_t isc_categories[] = { { "default", 0 }, /* "default 187 must come 188 first. */ 189 { "general", 0 }, 190 { "sslkeylog", 0 }, 191 { NULL, 0 } }; 192 193 /*! 194 * See above comment for categories, and apply it to modules. 195 */ 196 isc_logmodule_t isc_modules[] = { { "socket", 0 }, { "time", 0 }, 197 { "interface", 0 }, { "timer", 0 }, 198 { "file", 0 }, { "netmgr", 0 }, 199 { "other", 0 }, { NULL, 0 } }; 200 201 /*! 202 * This essentially constant structure must be filled in at run time, 203 * because its channel member is pointed to a channel that is created 204 * dynamically with isc_log_createchannel. 205 */ 206 static isc_logchannellist_t default_channel; 207 208 /*! 209 * libisc logs to this context. 210 */ 211 isc_log_t *isc_lctx = NULL; 212 213 /*! 214 * Forward declarations. 215 */ 216 static void 217 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id, 218 const isc_logmodule_t *module, isc_logchannel_t *channel); 219 220 static void 221 sync_channellist(isc_logconfig_t *lcfg); 222 223 static void 224 sync_highest_level(isc_log_t *lctx, isc_logconfig_t *lcfg); 225 226 static isc_result_t 227 greatest_version(isc_logfile_t *file, int versions, int *greatest); 228 229 static void 230 isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category, 231 isc_logmodule_t *module, int level, bool write_once, 232 const char *format, va_list args) ISC_FORMAT_PRINTF(6, 0); 233 234 /*@{*/ 235 /*! 236 * Convenience macros. 237 */ 238 239 #define FACILITY(channel) (channel->destination.facility) 240 #define FILE_NAME(channel) (channel->destination.file.name) 241 #define FILE_STREAM(channel) (channel->destination.file.stream) 242 #define FILE_VERSIONS(channel) (channel->destination.file.versions) 243 #define FILE_SUFFIX(channel) (channel->destination.file.suffix) 244 #define FILE_MAXSIZE(channel) (channel->destination.file.maximum_size) 245 #define FILE_MAXREACHED(channel) (channel->destination.file.maximum_reached) 246 247 /*@}*/ 248 /**** 249 **** Public interfaces. 250 ****/ 251 252 /* 253 * Establish a new logging context, with default channels. 254 */ 255 void 256 isc_log_create(isc_mem_t *mctx, isc_log_t **lctxp, isc_logconfig_t **lcfgp) { 257 isc_log_t *lctx; 258 isc_logconfig_t *lcfg = NULL; 259 260 REQUIRE(mctx != NULL); 261 REQUIRE(lctxp != NULL && *lctxp == NULL); 262 REQUIRE(lcfgp == NULL || *lcfgp == NULL); 263 264 lctx = isc_mem_get(mctx, sizeof(*lctx)); 265 lctx->mctx = NULL; 266 isc_mem_attach(mctx, &lctx->mctx); 267 lctx->categories = NULL; 268 lctx->category_count = 0; 269 lctx->modules = NULL; 270 lctx->module_count = 0; 271 atomic_init(&lctx->debug_level, 0); 272 273 ISC_LIST_INIT(lctx->messages); 274 275 isc_mutex_init(&lctx->lock); 276 isc_rwlock_init(&lctx->lcfg_rwl, 0, 0); 277 278 /* 279 * Normally setting the magic number is the last step done 280 * in a creation function, but a valid log context is needed 281 * by isc_log_registercategories and isc_logconfig_create. 282 * If either fails, the lctx is destroyed and not returned 283 * to the caller. 284 */ 285 lctx->magic = LCTX_MAGIC; 286 287 isc_log_registercategories(lctx, isc_categories); 288 isc_log_registermodules(lctx, isc_modules); 289 isc_logconfig_create(lctx, &lcfg); 290 291 sync_channellist(lcfg); 292 293 lctx->logconfig = lcfg; 294 295 atomic_init(&lctx->highest_level, lcfg->highest_level); 296 atomic_init(&lctx->dynamic, lcfg->dynamic); 297 298 *lctxp = lctx; 299 if (lcfgp != NULL) { 300 *lcfgp = lcfg; 301 } 302 } 303 304 void 305 isc_logconfig_create(isc_log_t *lctx, isc_logconfig_t **lcfgp) { 306 isc_logconfig_t *lcfg; 307 isc_logdestination_t destination; 308 int level = ISC_LOG_INFO; 309 310 REQUIRE(lcfgp != NULL && *lcfgp == NULL); 311 REQUIRE(VALID_CONTEXT(lctx)); 312 313 lcfg = isc_mem_get(lctx->mctx, sizeof(*lcfg)); 314 315 lcfg->lctx = lctx; 316 lcfg->channellists = NULL; 317 lcfg->channellist_count = 0; 318 lcfg->duplicate_interval = 0; 319 lcfg->highest_level = level; 320 lcfg->tag = NULL; 321 lcfg->dynamic = false; 322 ISC_LIST_INIT(lcfg->channels); 323 lcfg->magic = LCFG_MAGIC; 324 325 /* 326 * Create the default channels: 327 * default_syslog, default_stderr, default_debug and null. 328 */ 329 destination.facility = LOG_DAEMON; 330 isc_log_createchannel(lcfg, "default_syslog", ISC_LOG_TOSYSLOG, level, 331 &destination, 0); 332 333 destination.file.stream = stderr; 334 destination.file.name = NULL; 335 destination.file.versions = ISC_LOG_ROLLNEVER; 336 destination.file.suffix = isc_log_rollsuffix_increment; 337 destination.file.maximum_size = 0; 338 isc_log_createchannel(lcfg, "default_stderr", ISC_LOG_TOFILEDESC, level, 339 &destination, ISC_LOG_PRINTTIME); 340 341 /* 342 * Set the default category's channel to default_stderr, 343 * which is at the head of the channels list because it was 344 * just created. 345 */ 346 default_channel.channel = ISC_LIST_HEAD(lcfg->channels); 347 348 destination.file.stream = stderr; 349 destination.file.name = NULL; 350 destination.file.versions = ISC_LOG_ROLLNEVER; 351 destination.file.suffix = isc_log_rollsuffix_increment; 352 destination.file.maximum_size = 0; 353 isc_log_createchannel(lcfg, "default_debug", ISC_LOG_TOFILEDESC, 354 ISC_LOG_DYNAMIC, &destination, ISC_LOG_PRINTTIME); 355 356 isc_log_createchannel(lcfg, "null", ISC_LOG_TONULL, ISC_LOG_DYNAMIC, 357 NULL, 0); 358 359 *lcfgp = lcfg; 360 } 361 362 void 363 isc_logconfig_use(isc_log_t *lctx, isc_logconfig_t *lcfg) { 364 isc_logconfig_t *old_cfg; 365 366 REQUIRE(VALID_CONTEXT(lctx)); 367 REQUIRE(VALID_CONFIG(lcfg)); 368 REQUIRE(lcfg->lctx == lctx); 369 370 /* 371 * Ensure that lcfg->channellist_count == lctx->category_count. 372 * They won't be equal if isc_log_usechannel has not been called 373 * since any call to isc_log_registercategories. 374 */ 375 sync_channellist(lcfg); 376 377 WRLOCK(&lctx->lcfg_rwl); 378 old_cfg = lctx->logconfig; 379 lctx->logconfig = lcfg; 380 sync_highest_level(lctx, lcfg); 381 WRUNLOCK(&lctx->lcfg_rwl); 382 383 isc_logconfig_destroy(&old_cfg); 384 } 385 386 void 387 isc_log_destroy(isc_log_t **lctxp) { 388 isc_log_t *lctx; 389 isc_logconfig_t *lcfg; 390 isc_mem_t *mctx; 391 isc_logmessage_t *message; 392 393 REQUIRE(lctxp != NULL && VALID_CONTEXT(*lctxp)); 394 395 lctx = *lctxp; 396 *lctxp = NULL; 397 mctx = lctx->mctx; 398 399 /* Stop the logging as a first thing */ 400 atomic_store_release(&lctx->debug_level, 0); 401 atomic_store_release(&lctx->highest_level, 0); 402 atomic_store_release(&lctx->dynamic, false); 403 404 WRLOCK(&lctx->lcfg_rwl); 405 lcfg = lctx->logconfig; 406 lctx->logconfig = NULL; 407 WRUNLOCK(&lctx->lcfg_rwl); 408 409 if (lcfg != NULL) { 410 isc_logconfig_destroy(&lcfg); 411 } 412 413 isc_rwlock_destroy(&lctx->lcfg_rwl); 414 isc_mutex_destroy(&lctx->lock); 415 416 while ((message = ISC_LIST_HEAD(lctx->messages)) != NULL) { 417 ISC_LIST_UNLINK(lctx->messages, message, link); 418 419 isc_mem_put(mctx, message, 420 sizeof(*message) + strlen(message->text) + 1); 421 } 422 423 lctx->buffer[0] = '\0'; 424 lctx->categories = NULL; 425 lctx->category_count = 0; 426 lctx->modules = NULL; 427 lctx->module_count = 0; 428 lctx->mctx = NULL; 429 lctx->magic = 0; 430 431 isc_mem_putanddetach(&mctx, lctx, sizeof(*lctx)); 432 } 433 434 void 435 isc_logconfig_destroy(isc_logconfig_t **lcfgp) { 436 isc_logconfig_t *lcfg; 437 isc_mem_t *mctx; 438 isc_logchannel_t *channel; 439 char *filename; 440 unsigned int i; 441 442 REQUIRE(lcfgp != NULL && VALID_CONFIG(*lcfgp)); 443 444 lcfg = *lcfgp; 445 *lcfgp = NULL; 446 447 /* 448 * This function cannot be called with a logconfig that is in 449 * use by a log context. 450 */ 451 REQUIRE(lcfg->lctx != NULL); 452 453 RDLOCK(&lcfg->lctx->lcfg_rwl); 454 REQUIRE(lcfg->lctx->logconfig != lcfg); 455 RDUNLOCK(&lcfg->lctx->lcfg_rwl); 456 457 mctx = lcfg->lctx->mctx; 458 459 while ((channel = ISC_LIST_HEAD(lcfg->channels)) != NULL) { 460 ISC_LIST_UNLINK(lcfg->channels, channel, link); 461 462 if (channel->type == ISC_LOG_TOFILE) { 463 /* 464 * The filename for the channel may have ultimately 465 * started its life in user-land as a const string, 466 * but in isc_log_createchannel it gets copied 467 * into writable memory and is not longer truly const. 468 */ 469 DE_CONST(FILE_NAME(channel), filename); 470 isc_mem_free(mctx, filename); 471 472 if (FILE_STREAM(channel) != NULL) { 473 (void)fclose(FILE_STREAM(channel)); 474 } 475 } 476 477 isc_mem_free(mctx, channel->name); 478 isc_mem_put(mctx, channel, sizeof(*channel)); 479 } 480 481 for (i = 0; i < lcfg->channellist_count; i++) { 482 isc_logchannellist_t *item; 483 while ((item = ISC_LIST_HEAD(lcfg->channellists[i])) != NULL) { 484 ISC_LIST_UNLINK(lcfg->channellists[i], item, link); 485 isc_mem_put(mctx, item, sizeof(*item)); 486 } 487 } 488 489 if (lcfg->channellist_count > 0) { 490 isc_mem_put(mctx, lcfg->channellists, 491 lcfg->channellist_count * 492 sizeof(ISC_LIST(isc_logchannellist_t))); 493 } 494 495 lcfg->dynamic = false; 496 if (lcfg->tag != NULL) { 497 isc_mem_free(lcfg->lctx->mctx, lcfg->tag); 498 } 499 lcfg->tag = NULL; 500 lcfg->highest_level = 0; 501 lcfg->duplicate_interval = 0; 502 lcfg->magic = 0; 503 504 isc_mem_put(mctx, lcfg, sizeof(*lcfg)); 505 } 506 507 void 508 isc_log_registercategories(isc_log_t *lctx, isc_logcategory_t categories[]) { 509 isc_logcategory_t *catp; 510 511 REQUIRE(VALID_CONTEXT(lctx)); 512 REQUIRE(categories != NULL && categories[0].name != NULL); 513 514 /* 515 * XXXDCL This somewhat sleazy situation of using the last pointer 516 * in one category array to point to the next array exists because 517 * this registration function returns void and I didn't want to have 518 * change everything that used it by making it return an isc_result_t. 519 * It would need to do that if it had to allocate memory to store 520 * pointers to each array passed in. 521 */ 522 if (lctx->categories == NULL) { 523 lctx->categories = categories; 524 } else { 525 /* 526 * Adjust the last (NULL) pointer of the already registered 527 * categories to point to the incoming array. 528 */ 529 for (catp = lctx->categories; catp->name != NULL;) { 530 if (catp->id == UINT_MAX) { 531 /* 532 * The name pointer points to the next array. 533 * Ick. 534 */ 535 DE_CONST(catp->name, catp); 536 } else { 537 catp++; 538 } 539 } 540 541 catp->name = (void *)categories; 542 catp->id = UINT_MAX; 543 } 544 545 /* 546 * Update the id number of the category with its new global id. 547 */ 548 for (catp = categories; catp->name != NULL; catp++) { 549 catp->id = lctx->category_count++; 550 } 551 } 552 553 isc_logcategory_t * 554 isc_log_categorybyname(isc_log_t *lctx, const char *name) { 555 isc_logcategory_t *catp; 556 557 REQUIRE(VALID_CONTEXT(lctx)); 558 REQUIRE(name != NULL); 559 560 for (catp = lctx->categories; catp->name != NULL;) { 561 if (catp->id == UINT_MAX) { 562 /* 563 * catp is neither modified nor returned to the 564 * caller, so removing its const qualifier is ok. 565 */ 566 DE_CONST(catp->name, catp); 567 } else { 568 if (strcmp(catp->name, name) == 0) { 569 return (catp); 570 } 571 catp++; 572 } 573 } 574 575 return (NULL); 576 } 577 578 void 579 isc_log_registermodules(isc_log_t *lctx, isc_logmodule_t modules[]) { 580 isc_logmodule_t *modp; 581 582 REQUIRE(VALID_CONTEXT(lctx)); 583 REQUIRE(modules != NULL && modules[0].name != NULL); 584 585 /* 586 * XXXDCL This somewhat sleazy situation of using the last pointer 587 * in one category array to point to the next array exists because 588 * this registration function returns void and I didn't want to have 589 * change everything that used it by making it return an isc_result_t. 590 * It would need to do that if it had to allocate memory to store 591 * pointers to each array passed in. 592 */ 593 if (lctx->modules == NULL) { 594 lctx->modules = modules; 595 } else { 596 /* 597 * Adjust the last (NULL) pointer of the already registered 598 * modules to point to the incoming array. 599 */ 600 for (modp = lctx->modules; modp->name != NULL;) { 601 if (modp->id == UINT_MAX) { 602 /* 603 * The name pointer points to the next array. 604 * Ick. 605 */ 606 DE_CONST(modp->name, modp); 607 } else { 608 modp++; 609 } 610 } 611 612 modp->name = (void *)modules; 613 modp->id = UINT_MAX; 614 } 615 616 /* 617 * Update the id number of the module with its new global id. 618 */ 619 for (modp = modules; modp->name != NULL; modp++) { 620 modp->id = lctx->module_count++; 621 } 622 } 623 624 isc_logmodule_t * 625 isc_log_modulebyname(isc_log_t *lctx, const char *name) { 626 isc_logmodule_t *modp; 627 628 REQUIRE(VALID_CONTEXT(lctx)); 629 REQUIRE(name != NULL); 630 631 for (modp = lctx->modules; modp->name != NULL;) { 632 if (modp->id == UINT_MAX) { 633 /* 634 * modp is neither modified nor returned to the 635 * caller, so removing its const qualifier is ok. 636 */ 637 DE_CONST(modp->name, modp); 638 } else { 639 if (strcmp(modp->name, name) == 0) { 640 return (modp); 641 } 642 modp++; 643 } 644 } 645 646 return (NULL); 647 } 648 649 void 650 isc_log_createchannel(isc_logconfig_t *lcfg, const char *name, 651 unsigned int type, int level, 652 const isc_logdestination_t *destination, 653 unsigned int flags) { 654 isc_logchannel_t *channel; 655 isc_mem_t *mctx; 656 unsigned int permitted = ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY | 657 ISC_LOG_BUFFERED | ISC_LOG_ISO8601 | 658 ISC_LOG_UTC; 659 660 REQUIRE(VALID_CONFIG(lcfg)); 661 REQUIRE(name != NULL); 662 REQUIRE(type == ISC_LOG_TOSYSLOG || type == ISC_LOG_TOFILE || 663 type == ISC_LOG_TOFILEDESC || type == ISC_LOG_TONULL); 664 REQUIRE(destination != NULL || type == ISC_LOG_TONULL); 665 REQUIRE(level >= ISC_LOG_CRITICAL); 666 REQUIRE((flags & ~permitted) == 0); 667 668 /* XXXDCL find duplicate names? */ 669 670 mctx = lcfg->lctx->mctx; 671 672 channel = isc_mem_get(mctx, sizeof(*channel)); 673 674 channel->name = isc_mem_strdup(mctx, name); 675 676 channel->type = type; 677 channel->level = level; 678 channel->flags = flags; 679 ISC_LINK_INIT(channel, link); 680 681 switch (type) { 682 case ISC_LOG_TOSYSLOG: 683 FACILITY(channel) = destination->facility; 684 break; 685 686 case ISC_LOG_TOFILE: 687 /* 688 * The file name is copied because greatest_version wants 689 * to scribble on it, so it needs to be definitely in 690 * writable memory. 691 */ 692 FILE_NAME(channel) = isc_mem_strdup(mctx, 693 destination->file.name); 694 FILE_STREAM(channel) = NULL; 695 FILE_VERSIONS(channel) = destination->file.versions; 696 FILE_SUFFIX(channel) = destination->file.suffix; 697 FILE_MAXSIZE(channel) = destination->file.maximum_size; 698 FILE_MAXREACHED(channel) = false; 699 break; 700 701 case ISC_LOG_TOFILEDESC: 702 FILE_NAME(channel) = NULL; 703 FILE_STREAM(channel) = destination->file.stream; 704 FILE_MAXSIZE(channel) = 0; 705 FILE_VERSIONS(channel) = ISC_LOG_ROLLNEVER; 706 FILE_SUFFIX(channel) = isc_log_rollsuffix_increment; 707 break; 708 709 case ISC_LOG_TONULL: 710 /* Nothing. */ 711 break; 712 713 default: 714 UNREACHABLE(); 715 } 716 717 ISC_LIST_PREPEND(lcfg->channels, channel, link); 718 719 /* 720 * If default_stderr was redefined, make the default category 721 * point to the new default_stderr. 722 */ 723 if (strcmp(name, "default_stderr") == 0) { 724 default_channel.channel = channel; 725 } 726 } 727 728 isc_result_t 729 isc_log_usechannel(isc_logconfig_t *lcfg, const char *name, 730 const isc_logcategory_t *category, 731 const isc_logmodule_t *module) { 732 isc_log_t *lctx; 733 isc_logchannel_t *channel; 734 735 REQUIRE(VALID_CONFIG(lcfg)); 736 REQUIRE(name != NULL); 737 738 lctx = lcfg->lctx; 739 740 REQUIRE(category == NULL || category->id < lctx->category_count); 741 REQUIRE(module == NULL || module->id < lctx->module_count); 742 743 for (channel = ISC_LIST_HEAD(lcfg->channels); channel != NULL; 744 channel = ISC_LIST_NEXT(channel, link)) 745 { 746 if (strcmp(name, channel->name) == 0) { 747 break; 748 } 749 } 750 751 if (channel == NULL) { 752 return (ISC_R_NOTFOUND); 753 } 754 755 if (category != NULL) { 756 assignchannel(lcfg, category->id, module, channel); 757 } else { 758 /* 759 * Assign to all categories. Note that this includes 760 * the default channel. 761 */ 762 for (size_t i = 0; i < lctx->category_count; i++) { 763 assignchannel(lcfg, i, module, channel); 764 } 765 } 766 767 /* 768 * Update the highest logging level, if the current lcfg is in use. 769 */ 770 if (lcfg->lctx->logconfig == lcfg) { 771 sync_highest_level(lctx, lcfg); 772 } 773 774 return (ISC_R_SUCCESS); 775 } 776 777 void 778 isc_log_write(isc_log_t *lctx, isc_logcategory_t *category, 779 isc_logmodule_t *module, int level, const char *format, ...) { 780 va_list args; 781 782 /* 783 * Contract checking is done in isc_log_doit(). 784 */ 785 786 va_start(args, format); 787 isc_log_doit(lctx, category, module, level, false, format, args); 788 va_end(args); 789 } 790 791 void 792 isc_log_vwrite(isc_log_t *lctx, isc_logcategory_t *category, 793 isc_logmodule_t *module, int level, const char *format, 794 va_list args) { 795 /* 796 * Contract checking is done in isc_log_doit(). 797 */ 798 isc_log_doit(lctx, category, module, level, false, format, args); 799 } 800 801 void 802 isc_log_write1(isc_log_t *lctx, isc_logcategory_t *category, 803 isc_logmodule_t *module, int level, const char *format, ...) { 804 va_list args; 805 806 /* 807 * Contract checking is done in isc_log_doit(). 808 */ 809 810 va_start(args, format); 811 isc_log_doit(lctx, category, module, level, true, format, args); 812 va_end(args); 813 } 814 815 void 816 isc_log_vwrite1(isc_log_t *lctx, isc_logcategory_t *category, 817 isc_logmodule_t *module, int level, const char *format, 818 va_list args) { 819 /* 820 * Contract checking is done in isc_log_doit(). 821 */ 822 isc_log_doit(lctx, category, module, level, true, format, args); 823 } 824 825 void 826 isc_log_setcontext(isc_log_t *lctx) { 827 isc_lctx = lctx; 828 } 829 830 void 831 isc_log_setdebuglevel(isc_log_t *lctx, unsigned int level) { 832 REQUIRE(VALID_CONTEXT(lctx)); 833 834 atomic_store_release(&lctx->debug_level, level); 835 /* 836 * Close ISC_LOG_DEBUGONLY channels if level is zero. 837 */ 838 if (level == 0) { 839 RDLOCK(&lctx->lcfg_rwl); 840 isc_logconfig_t *lcfg = lctx->logconfig; 841 if (lcfg != NULL) { 842 LOCK(&lctx->lock); 843 for (isc_logchannel_t *channel = 844 ISC_LIST_HEAD(lcfg->channels); 845 channel != NULL; 846 channel = ISC_LIST_NEXT(channel, link)) 847 { 848 if (channel->type == ISC_LOG_TOFILE && 849 (channel->flags & ISC_LOG_DEBUGONLY) != 0 && 850 FILE_STREAM(channel) != NULL) 851 { 852 (void)fclose(FILE_STREAM(channel)); 853 FILE_STREAM(channel) = NULL; 854 } 855 } 856 UNLOCK(&lctx->lock); 857 } 858 RDUNLOCK(&lctx->lcfg_rwl); 859 } 860 } 861 862 unsigned int 863 isc_log_getdebuglevel(isc_log_t *lctx) { 864 REQUIRE(VALID_CONTEXT(lctx)); 865 866 return (atomic_load_acquire(&lctx->debug_level)); 867 } 868 869 void 870 isc_log_setduplicateinterval(isc_logconfig_t *lcfg, unsigned int interval) { 871 REQUIRE(VALID_CONFIG(lcfg)); 872 873 lcfg->duplicate_interval = interval; 874 } 875 876 unsigned int 877 isc_log_getduplicateinterval(isc_logconfig_t *lcfg) { 878 REQUIRE(VALID_CONTEXT(lcfg)); 879 880 return (lcfg->duplicate_interval); 881 } 882 883 void 884 isc_log_settag(isc_logconfig_t *lcfg, const char *tag) { 885 REQUIRE(VALID_CONFIG(lcfg)); 886 887 if (tag != NULL && *tag != '\0') { 888 if (lcfg->tag != NULL) { 889 isc_mem_free(lcfg->lctx->mctx, lcfg->tag); 890 } 891 lcfg->tag = isc_mem_strdup(lcfg->lctx->mctx, tag); 892 } else { 893 if (lcfg->tag != NULL) { 894 isc_mem_free(lcfg->lctx->mctx, lcfg->tag); 895 } 896 lcfg->tag = NULL; 897 } 898 } 899 900 char * 901 isc_log_gettag(isc_logconfig_t *lcfg) { 902 REQUIRE(VALID_CONFIG(lcfg)); 903 904 return (lcfg->tag); 905 } 906 907 /* XXXDCL NT -- This interface will assuredly be changing. */ 908 void 909 isc_log_opensyslog(const char *tag, int options, int facility) { 910 (void)openlog(tag, options, facility); 911 } 912 913 void 914 isc_log_closefilelogs(isc_log_t *lctx) { 915 REQUIRE(VALID_CONTEXT(lctx)); 916 917 RDLOCK(&lctx->lcfg_rwl); 918 isc_logconfig_t *lcfg = lctx->logconfig; 919 if (lcfg != NULL) { 920 LOCK(&lctx->lock); 921 for (isc_logchannel_t *channel = ISC_LIST_HEAD(lcfg->channels); 922 channel != NULL; channel = ISC_LIST_NEXT(channel, link)) 923 { 924 if (channel->type == ISC_LOG_TOFILE && 925 FILE_STREAM(channel) != NULL) 926 { 927 (void)fclose(FILE_STREAM(channel)); 928 FILE_STREAM(channel) = NULL; 929 } 930 } 931 UNLOCK(&lctx->lock); 932 } 933 RDUNLOCK(&lctx->lcfg_rwl); 934 } 935 936 /**** 937 **** Internal functions 938 ****/ 939 940 static void 941 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id, 942 const isc_logmodule_t *module, isc_logchannel_t *channel) { 943 isc_logchannellist_t *new_item; 944 isc_log_t *lctx; 945 946 REQUIRE(VALID_CONFIG(lcfg)); 947 948 lctx = lcfg->lctx; 949 950 REQUIRE(category_id < lctx->category_count); 951 REQUIRE(module == NULL || module->id < lctx->module_count); 952 REQUIRE(channel != NULL); 953 954 /* 955 * Ensure lcfg->channellist_count == lctx->category_count. 956 */ 957 sync_channellist(lcfg); 958 959 new_item = isc_mem_get(lctx->mctx, sizeof(*new_item)); 960 961 new_item->channel = channel; 962 new_item->module = module; 963 ISC_LIST_INITANDPREPEND(lcfg->channellists[category_id], new_item, 964 link); 965 966 /* 967 * Remember the highest logging level set by any channel in the 968 * logging config, so isc_log_doit() can quickly return if the 969 * message is too high to be logged by any channel. 970 */ 971 if (channel->type != ISC_LOG_TONULL) { 972 if (lcfg->highest_level < channel->level) { 973 lcfg->highest_level = channel->level; 974 } 975 if (channel->level == ISC_LOG_DYNAMIC) { 976 lcfg->dynamic = true; 977 } 978 } 979 } 980 981 /* 982 * This would ideally be part of isc_log_registercategories(), except then 983 * that function would have to return isc_result_t instead of void. 984 */ 985 static void 986 sync_channellist(isc_logconfig_t *lcfg) { 987 unsigned int bytes; 988 isc_log_t *lctx; 989 void *lists; 990 991 REQUIRE(VALID_CONFIG(lcfg)); 992 993 lctx = lcfg->lctx; 994 995 REQUIRE(lctx->category_count != 0); 996 997 if (lctx->category_count == lcfg->channellist_count) { 998 return; 999 } 1000 1001 bytes = lctx->category_count * sizeof(ISC_LIST(isc_logchannellist_t)); 1002 1003 lists = isc_mem_get(lctx->mctx, bytes); 1004 1005 memset(lists, 0, bytes); 1006 1007 if (lcfg->channellist_count != 0) { 1008 bytes = lcfg->channellist_count * 1009 sizeof(ISC_LIST(isc_logchannellist_t)); 1010 memmove(lists, lcfg->channellists, bytes); 1011 isc_mem_put(lctx->mctx, lcfg->channellists, bytes); 1012 } 1013 1014 lcfg->channellists = lists; 1015 lcfg->channellist_count = lctx->category_count; 1016 } 1017 1018 static void 1019 sync_highest_level(isc_log_t *lctx, isc_logconfig_t *lcfg) { 1020 atomic_store(&lctx->highest_level, lcfg->highest_level); 1021 atomic_store(&lctx->dynamic, lcfg->dynamic); 1022 } 1023 1024 static isc_result_t 1025 greatest_version(isc_logfile_t *file, int versions, int *greatestp) { 1026 char *digit_end; 1027 char dirbuf[PATH_MAX + 1]; 1028 const char *bname; 1029 const char *dirname = "."; 1030 int version, greatest = -1; 1031 isc_dir_t dir; 1032 isc_result_t result; 1033 size_t bnamelen; 1034 1035 bname = strrchr(file->name, '/'); 1036 if (bname != NULL) { 1037 /* 1038 * Copy the complete file name to dirbuf. 1039 */ 1040 size_t len = strlcpy(dirbuf, file->name, sizeof(dirbuf)); 1041 if (len >= sizeof(dirbuf)) { 1042 result = ISC_R_NOSPACE; 1043 syslog(LOG_ERR, "unable to remove log files: %s", 1044 isc_result_totext(result)); 1045 return (result); 1046 } 1047 1048 /* 1049 * Truncate after trailing '/' so the code works for 1050 * files in the root directory. 1051 */ 1052 bname++; 1053 dirbuf[bname - file->name] = '\0'; 1054 dirname = dirbuf; 1055 } else { 1056 bname = file->name; 1057 } 1058 bnamelen = strlen(bname); 1059 1060 isc_dir_init(&dir); 1061 result = isc_dir_open(&dir, dirname); 1062 1063 /* 1064 * Return if the directory open failed. 1065 */ 1066 if (result != ISC_R_SUCCESS) { 1067 return (result); 1068 } 1069 1070 while (isc_dir_read(&dir) == ISC_R_SUCCESS) { 1071 if (dir.entry.length > bnamelen && 1072 strncmp(dir.entry.name, bname, bnamelen) == 0 && 1073 dir.entry.name[bnamelen] == '.') 1074 { 1075 version = strtol(&dir.entry.name[bnamelen + 1], 1076 &digit_end, 10); 1077 /* 1078 * Remove any backup files that exceed versions. 1079 */ 1080 if (*digit_end == '\0' && version >= versions) { 1081 int n = unlinkat(dirfd(dir.handle), 1082 dir.entry.name, 0); 1083 if (n < 0) { 1084 result = isc_errno_toresult(errno); 1085 if (result != ISC_R_SUCCESS && 1086 result != ISC_R_FILENOTFOUND) 1087 { 1088 syslog(LOG_ERR, 1089 "unable to remove log " 1090 "file '%s%s': %s", 1091 bname == file->name 1092 ? "" 1093 : dirname, 1094 dir.entry.name, 1095 isc_result_totext( 1096 result)); 1097 } 1098 } 1099 } else if (*digit_end == '\0' && version > greatest) { 1100 greatest = version; 1101 } 1102 } 1103 } 1104 isc_dir_close(&dir); 1105 1106 *greatestp = greatest; 1107 return (ISC_R_SUCCESS); 1108 } 1109 1110 static void 1111 insert_sort(int64_t to_keep[], int64_t versions, int64_t version) { 1112 int i = 0; 1113 while (i < versions && version < to_keep[i]) { 1114 i++; 1115 } 1116 if (i == versions) { 1117 return; 1118 } 1119 if (i < versions - 1) { 1120 memmove(&to_keep[i + 1], &to_keep[i], 1121 sizeof(to_keep[0]) * (versions - i - 1)); 1122 } 1123 to_keep[i] = version; 1124 } 1125 1126 static int64_t 1127 last_to_keep(int64_t versions, isc_dir_t *dirp, const char *bname, 1128 size_t bnamelen) { 1129 int64_t to_keep[ISC_LOG_MAX_VERSIONS] = { 0 }; 1130 int64_t version = 0; 1131 1132 if (versions <= 0) { 1133 return (INT64_MAX); 1134 } 1135 1136 if (versions > ISC_LOG_MAX_VERSIONS) { 1137 versions = ISC_LOG_MAX_VERSIONS; 1138 } 1139 /* 1140 * First we fill 'to_keep' structure using insertion sort 1141 */ 1142 memset(to_keep, 0, sizeof(to_keep)); 1143 while (isc_dir_read(dirp) == ISC_R_SUCCESS) { 1144 char *digit_end = NULL; 1145 char *ename = NULL; 1146 1147 if (dirp->entry.length <= bnamelen || 1148 strncmp(dirp->entry.name, bname, bnamelen) != 0 || 1149 dirp->entry.name[bnamelen] != '.') 1150 { 1151 continue; 1152 } 1153 1154 ename = &dirp->entry.name[bnamelen + 1]; 1155 version = strtoull(ename, &digit_end, 10); 1156 if (*digit_end == '\0') { 1157 insert_sort(to_keep, versions, version); 1158 } 1159 } 1160 1161 isc_dir_reset(dirp); 1162 1163 /* 1164 * to_keep[versions - 1] is the last one we want to keep 1165 */ 1166 return (to_keep[versions - 1]); 1167 } 1168 1169 static isc_result_t 1170 remove_old_tsversions(isc_logfile_t *file, int versions) { 1171 char *digit_end; 1172 char dirbuf[PATH_MAX + 1]; 1173 const char *bname; 1174 const char *dirname = "."; 1175 int64_t version, last = INT64_MAX; 1176 isc_dir_t dir; 1177 isc_result_t result; 1178 size_t bnamelen; 1179 1180 bname = strrchr(file->name, '/'); 1181 if (bname != NULL) { 1182 /* 1183 * Copy the complete file name to dirbuf. 1184 */ 1185 size_t len = strlcpy(dirbuf, file->name, sizeof(dirbuf)); 1186 if (len >= sizeof(dirbuf)) { 1187 result = ISC_R_NOSPACE; 1188 syslog(LOG_ERR, "unable to remove log files: %s", 1189 isc_result_totext(result)); 1190 return (result); 1191 } 1192 1193 /* 1194 * Truncate after trailing '/' so the code works for 1195 * files in the root directory. 1196 */ 1197 bname++; 1198 dirbuf[bname - file->name] = '\0'; 1199 dirname = dirbuf; 1200 } else { 1201 bname = file->name; 1202 } 1203 bnamelen = strlen(bname); 1204 1205 isc_dir_init(&dir); 1206 result = isc_dir_open(&dir, dirname); 1207 1208 /* 1209 * Return if the directory open failed. 1210 */ 1211 if (result != ISC_R_SUCCESS) { 1212 return (result); 1213 } 1214 1215 last = last_to_keep(versions, &dir, bname, bnamelen); 1216 1217 while (isc_dir_read(&dir) == ISC_R_SUCCESS) { 1218 if (dir.entry.length > bnamelen && 1219 strncmp(dir.entry.name, bname, bnamelen) == 0 && 1220 dir.entry.name[bnamelen] == '.') 1221 { 1222 version = strtoull(&dir.entry.name[bnamelen + 1], 1223 &digit_end, 10); 1224 /* 1225 * Remove any backup files that exceed versions. 1226 */ 1227 if (*digit_end == '\0' && version < last) { 1228 int n = unlinkat(dirfd(dir.handle), 1229 dir.entry.name, 0); 1230 if (n < 0) { 1231 result = isc_errno_toresult(errno); 1232 if (result != ISC_R_SUCCESS && 1233 result != ISC_R_FILENOTFOUND) 1234 { 1235 syslog(LOG_ERR, 1236 "unable to remove log " 1237 "file '%s%s': %s", 1238 bname == file->name 1239 ? "" 1240 : dirname, 1241 dir.entry.name, 1242 isc_result_totext( 1243 result)); 1244 } 1245 } 1246 } 1247 } 1248 } 1249 isc_dir_close(&dir); 1250 return (ISC_R_SUCCESS); 1251 } 1252 1253 static isc_result_t 1254 roll_increment(isc_logfile_t *file) { 1255 int i, n, greatest; 1256 char current[PATH_MAX + 1]; 1257 char newpath[PATH_MAX + 1]; 1258 const char *path; 1259 isc_result_t result = ISC_R_SUCCESS; 1260 1261 REQUIRE(file != NULL); 1262 REQUIRE(file->versions != 0); 1263 1264 path = file->name; 1265 1266 if (file->versions == ISC_LOG_ROLLINFINITE) { 1267 /* 1268 * Find the first missing entry in the log file sequence. 1269 */ 1270 for (greatest = 0; greatest < INT_MAX; greatest++) { 1271 n = snprintf(current, sizeof(current), "%s.%u", path, 1272 (unsigned)greatest); 1273 if (n >= (int)sizeof(current) || n < 0 || 1274 !isc_file_exists(current)) 1275 { 1276 break; 1277 } 1278 } 1279 } else { 1280 /* 1281 * Get the largest existing version and remove any 1282 * version greater than the permitted version. 1283 */ 1284 result = greatest_version(file, file->versions, &greatest); 1285 if (result != ISC_R_SUCCESS) { 1286 return (result); 1287 } 1288 1289 /* 1290 * Increment if greatest is not the actual maximum value. 1291 */ 1292 if (greatest < file->versions - 1) { 1293 greatest++; 1294 } 1295 } 1296 1297 for (i = greatest; i > 0; i--) { 1298 result = ISC_R_SUCCESS; 1299 n = snprintf(current, sizeof(current), "%s.%u", path, 1300 (unsigned)(i - 1)); 1301 if (n >= (int)sizeof(current) || n < 0) { 1302 result = ISC_R_NOSPACE; 1303 } 1304 if (result == ISC_R_SUCCESS) { 1305 n = snprintf(newpath, sizeof(newpath), "%s.%u", path, 1306 (unsigned)i); 1307 if (n >= (int)sizeof(newpath) || n < 0) { 1308 result = ISC_R_NOSPACE; 1309 } 1310 } 1311 if (result == ISC_R_SUCCESS) { 1312 result = isc_file_rename(current, newpath); 1313 } 1314 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1315 syslog(LOG_ERR, 1316 "unable to rename log file '%s.%u' to " 1317 "'%s.%u': %s", 1318 path, i - 1, path, i, isc_result_totext(result)); 1319 } 1320 } 1321 1322 n = snprintf(newpath, sizeof(newpath), "%s.0", path); 1323 if (n >= (int)sizeof(newpath) || n < 0) { 1324 result = ISC_R_NOSPACE; 1325 } else { 1326 result = isc_file_rename(path, newpath); 1327 } 1328 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1329 syslog(LOG_ERR, "unable to rename log file '%s' to '%s.0': %s", 1330 path, path, isc_result_totext(result)); 1331 } 1332 1333 return (ISC_R_SUCCESS); 1334 } 1335 1336 static isc_result_t 1337 roll_timestamp(isc_logfile_t *file) { 1338 int n; 1339 char newts[PATH_MAX + 1]; 1340 char newpath[PATH_MAX + 1]; 1341 const char *path; 1342 isc_time_t now; 1343 isc_result_t result = ISC_R_SUCCESS; 1344 1345 REQUIRE(file != NULL); 1346 REQUIRE(file->versions != 0); 1347 1348 path = file->name; 1349 1350 /* 1351 * First find all the logfiles and remove the oldest ones 1352 * Save one fewer than file->versions because we'll be renaming 1353 * the existing file to a timestamped version after this. 1354 */ 1355 if (file->versions != ISC_LOG_ROLLINFINITE) { 1356 remove_old_tsversions(file, file->versions - 1); 1357 } 1358 1359 /* Then just rename the current logfile */ 1360 isc_time_now(&now); 1361 isc_time_formatshorttimestamp(&now, newts, PATH_MAX + 1); 1362 n = snprintf(newpath, sizeof(newpath), "%s.%s", path, newts); 1363 if (n >= (int)sizeof(newpath) || n < 0) { 1364 result = ISC_R_NOSPACE; 1365 } else { 1366 result = isc_file_rename(path, newpath); 1367 } 1368 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1369 syslog(LOG_ERR, "unable to rename log file '%s' to '%s.0': %s", 1370 path, path, isc_result_totext(result)); 1371 } 1372 1373 return (ISC_R_SUCCESS); 1374 } 1375 1376 isc_result_t 1377 isc_logfile_roll(isc_logfile_t *file) { 1378 isc_result_t result; 1379 1380 REQUIRE(file != NULL); 1381 1382 /* 1383 * Do nothing (not even excess version trimming) if ISC_LOG_ROLLNEVER 1384 * is specified. Apparently complete external control over the log 1385 * files is desired. 1386 */ 1387 if (file->versions == ISC_LOG_ROLLNEVER) { 1388 return (ISC_R_SUCCESS); 1389 } else if (file->versions == 0) { 1390 result = isc_file_remove(file->name); 1391 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1392 syslog(LOG_ERR, "unable to remove log file '%s': %s", 1393 file->name, isc_result_totext(result)); 1394 } 1395 return (ISC_R_SUCCESS); 1396 } 1397 1398 switch (file->suffix) { 1399 case isc_log_rollsuffix_increment: 1400 return (roll_increment(file)); 1401 case isc_log_rollsuffix_timestamp: 1402 return (roll_timestamp(file)); 1403 default: 1404 return (ISC_R_UNEXPECTED); 1405 } 1406 } 1407 1408 static isc_result_t 1409 isc_log_open(isc_logchannel_t *channel) { 1410 struct stat statbuf; 1411 bool regular_file; 1412 bool roll = false; 1413 isc_result_t result = ISC_R_SUCCESS; 1414 const char *path; 1415 1416 REQUIRE(channel->type == ISC_LOG_TOFILE); 1417 REQUIRE(FILE_STREAM(channel) == NULL); 1418 1419 path = FILE_NAME(channel); 1420 1421 REQUIRE(path != NULL && *path != '\0'); 1422 1423 /* 1424 * Determine type of file; only regular files will be 1425 * version renamed, and only if the base file exists 1426 * and either has no size limit or has reached its size limit. 1427 */ 1428 if (stat(path, &statbuf) == 0) { 1429 regular_file = S_ISREG(statbuf.st_mode) ? true : false; 1430 /* XXXDCL if not regular_file complain? */ 1431 if ((FILE_MAXSIZE(channel) == 0 && 1432 FILE_VERSIONS(channel) != ISC_LOG_ROLLNEVER) || 1433 (FILE_MAXSIZE(channel) > 0 && 1434 statbuf.st_size >= FILE_MAXSIZE(channel))) 1435 { 1436 roll = regular_file; 1437 } 1438 } else if (errno == ENOENT) { 1439 regular_file = true; 1440 POST(regular_file); 1441 } else { 1442 result = ISC_R_INVALIDFILE; 1443 } 1444 1445 /* 1446 * Version control. 1447 */ 1448 if (result == ISC_R_SUCCESS && roll) { 1449 if (FILE_VERSIONS(channel) == ISC_LOG_ROLLNEVER) { 1450 return (ISC_R_MAXSIZE); 1451 } 1452 result = isc_logfile_roll(&channel->destination.file); 1453 if (result != ISC_R_SUCCESS) { 1454 if ((channel->flags & ISC_LOG_OPENERR) == 0) { 1455 syslog(LOG_ERR, 1456 "isc_log_open: isc_logfile_roll '%s' " 1457 "failed: %s", 1458 FILE_NAME(channel), 1459 isc_result_totext(result)); 1460 channel->flags |= ISC_LOG_OPENERR; 1461 } 1462 return (result); 1463 } 1464 } 1465 1466 result = isc_stdio_open(path, "a", &FILE_STREAM(channel)); 1467 1468 return (result); 1469 } 1470 1471 ISC_NO_SANITIZE_THREAD bool 1472 isc_log_wouldlog(isc_log_t *lctx, int level) { 1473 /* 1474 * Try to avoid locking the mutex for messages which can't 1475 * possibly be logged to any channels -- primarily debugging 1476 * messages that the debug level is not high enough to print. 1477 * 1478 * If the level is (mathematically) less than or equal to the 1479 * highest_level, or if there is a dynamic channel and the level is 1480 * less than or equal to the debug level, the main loop must be 1481 * entered to see if the message should really be output. 1482 */ 1483 if (lctx == NULL) { 1484 return (false); 1485 } 1486 if (forcelog) { 1487 return (true); 1488 } 1489 1490 int highest_level = atomic_load_acquire(&lctx->highest_level); 1491 if (level <= highest_level) { 1492 return (true); 1493 } 1494 if (atomic_load_acquire(&lctx->dynamic)) { 1495 int debug_level = atomic_load_acquire(&lctx->debug_level); 1496 if (level <= debug_level) { 1497 return (true); 1498 } 1499 } 1500 1501 return (false); 1502 } 1503 1504 static void 1505 isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category, 1506 isc_logmodule_t *module, int level, bool write_once, 1507 const char *format, va_list args) { 1508 int syslog_level; 1509 const char *time_string; 1510 char local_time[64]; 1511 char iso8601z_string[64]; 1512 char iso8601l_string[64]; 1513 char level_string[24] = { 0 }; 1514 struct stat statbuf; 1515 bool matched = false; 1516 bool printtime, iso8601, utc, printtag, printcolon; 1517 bool printcategory, printmodule, printlevel, buffered; 1518 isc_logchannel_t *channel; 1519 isc_logchannellist_t *category_channels; 1520 int_fast32_t dlevel; 1521 isc_result_t result; 1522 1523 REQUIRE(lctx == NULL || VALID_CONTEXT(lctx)); 1524 REQUIRE(category != NULL); 1525 REQUIRE(module != NULL); 1526 REQUIRE(level != ISC_LOG_DYNAMIC); 1527 REQUIRE(format != NULL); 1528 1529 /* 1530 * Programs can use libraries that use this logging code without 1531 * wanting to do any logging, thus the log context is allowed to 1532 * be non-existent. 1533 */ 1534 if (lctx == NULL) { 1535 return; 1536 } 1537 1538 REQUIRE(category->id < lctx->category_count); 1539 REQUIRE(module->id < lctx->module_count); 1540 1541 if (!isc_log_wouldlog(lctx, level)) { 1542 return; 1543 } 1544 1545 local_time[0] = '\0'; 1546 iso8601l_string[0] = '\0'; 1547 iso8601z_string[0] = '\0'; 1548 1549 RDLOCK(&lctx->lcfg_rwl); 1550 LOCK(&lctx->lock); 1551 1552 lctx->buffer[0] = '\0'; 1553 1554 isc_logconfig_t *lcfg = lctx->logconfig; 1555 1556 category_channels = ISC_LIST_HEAD(lcfg->channellists[category->id]); 1557 1558 /* 1559 * XXXDCL add duplicate filtering? (To not write multiple times 1560 * to the same source via various channels). 1561 */ 1562 do { 1563 /* 1564 * If the channel list end was reached and a match was 1565 * made, everything is finished. 1566 */ 1567 if (category_channels == NULL && matched) { 1568 break; 1569 } 1570 1571 if (category_channels == NULL && !matched && 1572 category_channels != ISC_LIST_HEAD(lcfg->channellists[0])) 1573 { 1574 /* 1575 * No category/module pair was explicitly 1576 * configured. Try the category named "default". 1577 */ 1578 category_channels = 1579 ISC_LIST_HEAD(lcfg->channellists[0]); 1580 } 1581 1582 if (category_channels == NULL && !matched) { 1583 /* 1584 * No matching module was explicitly configured 1585 * for the category named "default". Use the 1586 * internal default channel. 1587 */ 1588 category_channels = &default_channel; 1589 } 1590 1591 if (category_channels->module != NULL && 1592 category_channels->module != module) 1593 { 1594 category_channels = ISC_LIST_NEXT(category_channels, 1595 link); 1596 continue; 1597 } 1598 1599 matched = true; 1600 1601 channel = category_channels->channel; 1602 category_channels = ISC_LIST_NEXT(category_channels, link); 1603 1604 if (!forcelog) { 1605 dlevel = atomic_load_acquire(&lctx->debug_level); 1606 if (((channel->flags & ISC_LOG_DEBUGONLY) != 0) && 1607 dlevel == 0) 1608 { 1609 continue; 1610 } 1611 1612 if (channel->level == ISC_LOG_DYNAMIC) { 1613 if (dlevel < level) { 1614 continue; 1615 } 1616 } else if (channel->level < level) { 1617 continue; 1618 } 1619 } 1620 1621 if ((channel->flags & ISC_LOG_PRINTTIME) != 0 && 1622 local_time[0] == '\0') 1623 { 1624 isc_time_t isctime; 1625 1626 TIME_NOW(&isctime); 1627 1628 isc_time_formattimestamp(&isctime, local_time, 1629 sizeof(local_time)); 1630 isc_time_formatISO8601ms(&isctime, iso8601z_string, 1631 sizeof(iso8601z_string)); 1632 isc_time_formatISO8601Lms(&isctime, iso8601l_string, 1633 sizeof(iso8601l_string)); 1634 } 1635 1636 if ((channel->flags & ISC_LOG_PRINTLEVEL) != 0 && 1637 level_string[0] == '\0') 1638 { 1639 if (level < ISC_LOG_CRITICAL) { 1640 snprintf(level_string, sizeof(level_string), 1641 "level %d: ", level); 1642 } else if (level > ISC_LOG_DYNAMIC) { 1643 snprintf(level_string, sizeof(level_string), 1644 "%s %d: ", log_level_strings[0], 1645 level); 1646 } else { 1647 snprintf(level_string, sizeof(level_string), 1648 "%s: ", log_level_strings[-level]); 1649 } 1650 } 1651 1652 /* 1653 * Only format the message once. 1654 */ 1655 if (lctx->buffer[0] == '\0') { 1656 (void)vsnprintf(lctx->buffer, sizeof(lctx->buffer), 1657 format, args); 1658 1659 /* 1660 * Check for duplicates. 1661 */ 1662 if (write_once) { 1663 isc_logmessage_t *message, *next; 1664 isc_time_t oldest; 1665 isc_interval_t interval; 1666 size_t size; 1667 1668 isc_interval_set(&interval, 1669 lcfg->duplicate_interval, 0); 1670 1671 /* 1672 * 'oldest' is the age of the oldest 1673 * messages which fall within the 1674 * duplicate_interval range. 1675 */ 1676 TIME_NOW(&oldest); 1677 if (isc_time_subtract(&oldest, &interval, 1678 &oldest) != ISC_R_SUCCESS) 1679 { 1680 /* 1681 * Can't effectively do the 1682 * checking without having a 1683 * valid time. 1684 */ 1685 message = NULL; 1686 } else { 1687 message = ISC_LIST_HEAD(lctx->messages); 1688 } 1689 1690 while (message != NULL) { 1691 if (isc_time_compare(&message->time, 1692 &oldest) < 0) 1693 { 1694 /* 1695 * This message is older 1696 * than the 1697 * duplicate_interval, 1698 * so it should be 1699 * dropped from the 1700 * history. 1701 * 1702 * Setting the interval 1703 * to be to be longer 1704 * will obviously not 1705 * cause the expired 1706 * message to spring 1707 * back into existence. 1708 */ 1709 next = ISC_LIST_NEXT(message, 1710 link); 1711 1712 ISC_LIST_UNLINK(lctx->messages, 1713 message, link); 1714 1715 isc_mem_put( 1716 lctx->mctx, message, 1717 sizeof(*message) + 1 + 1718 strlen(message->text)); 1719 1720 message = next; 1721 continue; 1722 } 1723 1724 /* 1725 * This message is in the 1726 * duplicate filtering interval 1727 * ... 1728 */ 1729 if (strcmp(lctx->buffer, 1730 message->text) == 0) 1731 { 1732 /* 1733 * ... and it is a 1734 * duplicate. Unlock the 1735 * mutex and get the 1736 * hell out of Dodge. 1737 */ 1738 goto unlock; 1739 } 1740 1741 message = ISC_LIST_NEXT(message, link); 1742 } 1743 1744 /* 1745 * It wasn't in the duplicate interval, 1746 * so add it to the message list. 1747 */ 1748 size = sizeof(isc_logmessage_t) + 1749 strlen(lctx->buffer) + 1; 1750 message = isc_mem_get(lctx->mctx, size); 1751 message->text = (char *)(message + 1); 1752 size -= sizeof(isc_logmessage_t); 1753 strlcpy(message->text, lctx->buffer, size); 1754 TIME_NOW(&message->time); 1755 ISC_LINK_INIT(message, link); 1756 ISC_LIST_APPEND(lctx->messages, message, link); 1757 } 1758 } 1759 1760 utc = ((channel->flags & ISC_LOG_UTC) != 0); 1761 iso8601 = ((channel->flags & ISC_LOG_ISO8601) != 0); 1762 printtime = ((channel->flags & ISC_LOG_PRINTTIME) != 0); 1763 printtag = ((channel->flags & 1764 (ISC_LOG_PRINTTAG | ISC_LOG_PRINTPREFIX)) != 0 && 1765 lcfg->tag != NULL); 1766 printcolon = ((channel->flags & ISC_LOG_PRINTTAG) != 0 && 1767 lcfg->tag != NULL); 1768 printcategory = ((channel->flags & ISC_LOG_PRINTCATEGORY) != 0); 1769 printmodule = ((channel->flags & ISC_LOG_PRINTMODULE) != 0); 1770 printlevel = ((channel->flags & ISC_LOG_PRINTLEVEL) != 0); 1771 buffered = ((channel->flags & ISC_LOG_BUFFERED) != 0); 1772 1773 if (printtime) { 1774 if (iso8601) { 1775 if (utc) { 1776 time_string = iso8601z_string; 1777 } else { 1778 time_string = iso8601l_string; 1779 } 1780 } else { 1781 time_string = local_time; 1782 } 1783 } else { 1784 time_string = ""; 1785 } 1786 1787 switch (channel->type) { 1788 case ISC_LOG_TOFILE: 1789 if (FILE_MAXREACHED(channel)) { 1790 /* 1791 * If the file can be rolled, OR 1792 * If the file no longer exists, OR 1793 * If the file is less than the maximum 1794 * size, (such as if it had been renamed 1795 * and a new one touched, or it was 1796 * truncated in place) 1797 * ... then close it to trigger 1798 * reopening. 1799 */ 1800 if (FILE_VERSIONS(channel) != 1801 ISC_LOG_ROLLNEVER || 1802 (stat(FILE_NAME(channel), &statbuf) != 0 && 1803 errno == ENOENT) || 1804 statbuf.st_size < FILE_MAXSIZE(channel)) 1805 { 1806 (void)fclose(FILE_STREAM(channel)); 1807 FILE_STREAM(channel) = NULL; 1808 FILE_MAXREACHED(channel) = false; 1809 } else { 1810 /* 1811 * Eh, skip it. 1812 */ 1813 break; 1814 } 1815 } 1816 1817 if (FILE_STREAM(channel) == NULL) { 1818 result = isc_log_open(channel); 1819 if (result != ISC_R_SUCCESS && 1820 result != ISC_R_MAXSIZE && 1821 (channel->flags & ISC_LOG_OPENERR) == 0) 1822 { 1823 syslog(LOG_ERR, 1824 "isc_log_open '%s' " 1825 "failed: %s", 1826 FILE_NAME(channel), 1827 isc_result_totext(result)); 1828 channel->flags |= ISC_LOG_OPENERR; 1829 } 1830 if (result != ISC_R_SUCCESS) { 1831 break; 1832 } 1833 channel->flags &= ~ISC_LOG_OPENERR; 1834 } 1835 FALLTHROUGH; 1836 1837 case ISC_LOG_TOFILEDESC: 1838 fprintf(FILE_STREAM(channel), "%s%s%s%s%s%s%s%s%s%s\n", 1839 printtime ? time_string : "", 1840 printtime ? " " : "", printtag ? lcfg->tag : "", 1841 printcolon ? ": " : "", 1842 printcategory ? category->name : "", 1843 printcategory ? ": " : "", 1844 printmodule ? (module != NULL ? module->name 1845 : "no_module") 1846 : "", 1847 printmodule ? ": " : "", 1848 printlevel ? level_string : "", lctx->buffer); 1849 1850 if (!buffered) { 1851 fflush(FILE_STREAM(channel)); 1852 } 1853 1854 /* 1855 * If the file now exceeds its maximum size 1856 * threshold, note it so that it will not be 1857 * logged to any more. 1858 */ 1859 if (FILE_MAXSIZE(channel) > 0) { 1860 INSIST(channel->type == ISC_LOG_TOFILE); 1861 1862 /* XXXDCL NT fstat/fileno */ 1863 /* XXXDCL complain if fstat fails? */ 1864 if (fstat(fileno(FILE_STREAM(channel)), 1865 &statbuf) >= 0 && 1866 statbuf.st_size > FILE_MAXSIZE(channel)) 1867 { 1868 FILE_MAXREACHED(channel) = true; 1869 } 1870 } 1871 1872 break; 1873 1874 case ISC_LOG_TOSYSLOG: 1875 if (level > 0) { 1876 syslog_level = LOG_DEBUG; 1877 } else if (level < ISC_LOG_CRITICAL) { 1878 syslog_level = LOG_CRIT; 1879 } else { 1880 syslog_level = syslog_map[-level]; 1881 } 1882 1883 (void)syslog( 1884 FACILITY(channel) | syslog_level, 1885 "%s%s%s%s%s%s%s%s%s%s", 1886 printtime ? time_string : "", 1887 printtime ? " " : "", printtag ? lcfg->tag : "", 1888 printcolon ? ": " : "", 1889 printcategory ? category->name : "", 1890 printcategory ? ": " : "", 1891 printmodule ? (module != NULL ? module->name 1892 : "no_module") 1893 : "", 1894 printmodule ? ": " : "", 1895 printlevel ? level_string : "", lctx->buffer); 1896 break; 1897 1898 case ISC_LOG_TONULL: 1899 break; 1900 } 1901 } while (1); 1902 1903 unlock: 1904 UNLOCK(&lctx->lock); 1905 RDUNLOCK(&lctx->lcfg_rwl); 1906 } 1907 1908 void 1909 isc_log_setforcelog(bool v) { 1910 forcelog = v; 1911 } 1912