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