log.c revision 1.7
1 /* $NetBSD: log.c,v 1.7 2022/09/23 12:15:33 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 (void)fclose(FILE_STREAM(channel)); 924 FILE_STREAM(channel) = NULL; 925 } 926 } 927 UNLOCK(&lctx->lock); 928 } 929 RDUNLOCK(&lctx->lcfg_rwl); 930 } 931 932 /**** 933 **** Internal functions 934 ****/ 935 936 static void 937 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id, 938 const isc_logmodule_t *module, isc_logchannel_t *channel) { 939 isc_logchannellist_t *new_item; 940 isc_log_t *lctx; 941 942 REQUIRE(VALID_CONFIG(lcfg)); 943 944 lctx = lcfg->lctx; 945 946 REQUIRE(category_id < lctx->category_count); 947 REQUIRE(module == NULL || module->id < lctx->module_count); 948 REQUIRE(channel != NULL); 949 950 /* 951 * Ensure lcfg->channellist_count == lctx->category_count. 952 */ 953 sync_channellist(lcfg); 954 955 new_item = isc_mem_get(lctx->mctx, sizeof(*new_item)); 956 957 new_item->channel = channel; 958 new_item->module = module; 959 ISC_LIST_INITANDPREPEND(lcfg->channellists[category_id], new_item, 960 link); 961 962 /* 963 * Remember the highest logging level set by any channel in the 964 * logging config, so isc_log_doit() can quickly return if the 965 * message is too high to be logged by any channel. 966 */ 967 if (channel->type != ISC_LOG_TONULL) { 968 if (lcfg->highest_level < channel->level) { 969 lcfg->highest_level = channel->level; 970 } 971 if (channel->level == ISC_LOG_DYNAMIC) { 972 lcfg->dynamic = true; 973 } 974 } 975 } 976 977 /* 978 * This would ideally be part of isc_log_registercategories(), except then 979 * that function would have to return isc_result_t instead of void. 980 */ 981 static void 982 sync_channellist(isc_logconfig_t *lcfg) { 983 unsigned int bytes; 984 isc_log_t *lctx; 985 void *lists; 986 987 REQUIRE(VALID_CONFIG(lcfg)); 988 989 lctx = lcfg->lctx; 990 991 REQUIRE(lctx->category_count != 0); 992 993 if (lctx->category_count == lcfg->channellist_count) { 994 return; 995 } 996 997 bytes = lctx->category_count * sizeof(ISC_LIST(isc_logchannellist_t)); 998 999 lists = isc_mem_get(lctx->mctx, bytes); 1000 1001 memset(lists, 0, bytes); 1002 1003 if (lcfg->channellist_count != 0) { 1004 bytes = lcfg->channellist_count * 1005 sizeof(ISC_LIST(isc_logchannellist_t)); 1006 memmove(lists, lcfg->channellists, bytes); 1007 isc_mem_put(lctx->mctx, lcfg->channellists, bytes); 1008 } 1009 1010 lcfg->channellists = lists; 1011 lcfg->channellist_count = lctx->category_count; 1012 } 1013 1014 static void 1015 sync_highest_level(isc_log_t *lctx, isc_logconfig_t *lcfg) { 1016 atomic_store(&lctx->highest_level, lcfg->highest_level); 1017 atomic_store(&lctx->dynamic, lcfg->dynamic); 1018 } 1019 1020 static isc_result_t 1021 greatest_version(isc_logfile_t *file, int versions, int *greatestp) { 1022 char *bname, *digit_end; 1023 const char *dirname; 1024 int version, greatest = -1; 1025 size_t bnamelen; 1026 isc_dir_t dir; 1027 isc_result_t result; 1028 char sep = '/'; 1029 #ifdef _WIN32 1030 char *bname2; 1031 #endif /* ifdef _WIN32 */ 1032 1033 /* 1034 * It is safe to DE_CONST the file.name because it was copied 1035 * with isc_mem_strdup(). 1036 */ 1037 bname = strrchr(file->name, sep); 1038 #ifdef _WIN32 1039 bname2 = strrchr(file->name, '\\'); 1040 if ((bname != NULL && bname2 != NULL && bname2 > bname) || 1041 (bname == NULL && bname2 != NULL)) 1042 { 1043 bname = bname2; 1044 sep = '\\'; 1045 } 1046 #endif /* ifdef _WIN32 */ 1047 if (bname != NULL) { 1048 *bname++ = '\0'; 1049 dirname = file->name; 1050 } else { 1051 DE_CONST(file->name, bname); 1052 dirname = "."; 1053 } 1054 bnamelen = strlen(bname); 1055 1056 isc_dir_init(&dir); 1057 result = isc_dir_open(&dir, dirname); 1058 1059 /* 1060 * Replace the file separator if it was taken out. 1061 */ 1062 if (bname != file->name) { 1063 *(bname - 1) = sep; 1064 } 1065 1066 /* 1067 * Return if the directory open failed. 1068 */ 1069 if (result != ISC_R_SUCCESS) { 1070 return (result); 1071 } 1072 1073 while (isc_dir_read(&dir) == ISC_R_SUCCESS) { 1074 if (dir.entry.length > bnamelen && 1075 strncmp(dir.entry.name, bname, bnamelen) == 0 && 1076 dir.entry.name[bnamelen] == '.') 1077 { 1078 version = strtol(&dir.entry.name[bnamelen + 1], 1079 &digit_end, 10); 1080 /* 1081 * Remove any backup files that exceed versions. 1082 */ 1083 if (*digit_end == '\0' && version >= versions) { 1084 result = isc_file_remove(dir.entry.name); 1085 if (result != ISC_R_SUCCESS && 1086 result != ISC_R_FILENOTFOUND) { 1087 syslog(LOG_ERR, 1088 "unable to remove " 1089 "log file '%s': %s", 1090 dir.entry.name, 1091 isc_result_totext(result)); 1092 } 1093 } else if (*digit_end == '\0' && version > greatest) { 1094 greatest = version; 1095 } 1096 } 1097 } 1098 isc_dir_close(&dir); 1099 1100 *greatestp = greatest; 1101 1102 return (ISC_R_SUCCESS); 1103 } 1104 1105 static void 1106 insert_sort(int64_t to_keep[], int64_t versions, int version) { 1107 int i = 0; 1108 while (i < versions && version < to_keep[i]) { 1109 i++; 1110 } 1111 if (i == versions) { 1112 return; 1113 } 1114 if (i < versions - 1) { 1115 memmove(&to_keep[i + 1], &to_keep[i], 1116 sizeof(to_keep[0]) * (versions - i - 1)); 1117 } 1118 to_keep[i] = version; 1119 } 1120 1121 static int64_t 1122 last_to_keep(int64_t versions, isc_dir_t *dirp, char *bname, size_t bnamelen) { 1123 if (versions <= 0) { 1124 return INT64_MAX; 1125 } 1126 1127 int64_t to_keep[ISC_LOG_MAX_VERSIONS] = { 0 }; 1128 int64_t version = 0; 1129 if (versions > ISC_LOG_MAX_VERSIONS) { 1130 versions = ISC_LOG_MAX_VERSIONS; 1131 } 1132 /* 1133 * First we fill 'to_keep' structure using insertion sort 1134 */ 1135 memset(to_keep, 0, sizeof(to_keep)); 1136 while (isc_dir_read(dirp) == ISC_R_SUCCESS) { 1137 if (dirp->entry.length <= bnamelen || 1138 strncmp(dirp->entry.name, bname, bnamelen) != 0 || 1139 dirp->entry.name[bnamelen] != '.') 1140 { 1141 continue; 1142 } 1143 1144 char *digit_end; 1145 char *ename = &dirp->entry.name[bnamelen + 1]; 1146 version = strtoull(ename, &digit_end, 10); 1147 if (*digit_end == '\0') { 1148 insert_sort(to_keep, versions, version); 1149 } 1150 } 1151 1152 isc_dir_reset(dirp); 1153 1154 /* 1155 * to_keep[versions - 1] is the last one we want to keep 1156 */ 1157 return (to_keep[versions - 1]); 1158 } 1159 1160 static isc_result_t 1161 remove_old_tsversions(isc_logfile_t *file, int versions) { 1162 isc_result_t result; 1163 char *bname, *digit_end; 1164 const char *dirname; 1165 int64_t version, last = INT64_MAX; 1166 size_t bnamelen; 1167 isc_dir_t dir; 1168 char sep = '/'; 1169 #ifdef _WIN32 1170 char *bname2; 1171 #endif /* ifdef _WIN32 */ 1172 /* 1173 * It is safe to DE_CONST the file.name because it was copied 1174 * with isc_mem_strdup(). 1175 */ 1176 bname = strrchr(file->name, sep); 1177 #ifdef _WIN32 1178 bname2 = strrchr(file->name, '\\'); 1179 if ((bname != NULL && bname2 != NULL && bname2 > bname) || 1180 (bname == NULL && bname2 != NULL)) 1181 { 1182 bname = bname2; 1183 sep = '\\'; 1184 } 1185 #endif /* ifdef _WIN32 */ 1186 if (bname != NULL) { 1187 *bname++ = '\0'; 1188 dirname = file->name; 1189 } else { 1190 DE_CONST(file->name, bname); 1191 dirname = "."; 1192 } 1193 bnamelen = strlen(bname); 1194 1195 isc_dir_init(&dir); 1196 result = isc_dir_open(&dir, dirname); 1197 1198 /* 1199 * Replace the file separator if it was taken out. 1200 */ 1201 if (bname != file->name) { 1202 *(bname - 1) = sep; 1203 } 1204 1205 /* 1206 * Return if the directory open failed. 1207 */ 1208 if (result != ISC_R_SUCCESS) { 1209 return (result); 1210 } 1211 1212 last = last_to_keep(versions, &dir, bname, bnamelen); 1213 1214 /* 1215 * Then we remove all files that we don't want to_keep 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 char *ename = &dir.entry.name[bnamelen + 1]; 1223 version = strtoull(ename, &digit_end, 10); 1224 /* 1225 * Remove any backup files that exceed versions. 1226 */ 1227 if (*digit_end == '\0' && version < last) { 1228 result = isc_file_remove(dir.entry.name); 1229 if (result != ISC_R_SUCCESS && 1230 result != ISC_R_FILENOTFOUND) { 1231 syslog(LOG_ERR, 1232 "unable to remove " 1233 "log file '%s': %s", 1234 dir.entry.name, 1235 isc_result_totext(result)); 1236 } 1237 } 1238 } 1239 } 1240 1241 isc_dir_close(&dir); 1242 1243 return (ISC_R_SUCCESS); 1244 } 1245 1246 static isc_result_t 1247 roll_increment(isc_logfile_t *file) { 1248 int i, n, greatest; 1249 char current[PATH_MAX + 1]; 1250 char newpath[PATH_MAX + 1]; 1251 const char *path; 1252 isc_result_t result = ISC_R_SUCCESS; 1253 1254 REQUIRE(file != NULL); 1255 REQUIRE(file->versions != 0); 1256 1257 path = file->name; 1258 1259 if (file->versions == ISC_LOG_ROLLINFINITE) { 1260 /* 1261 * Find the first missing entry in the log file sequence. 1262 */ 1263 for (greatest = 0; greatest < INT_MAX; greatest++) { 1264 n = snprintf(current, sizeof(current), "%s.%u", path, 1265 (unsigned)greatest); 1266 if (n >= (int)sizeof(current) || n < 0 || 1267 !isc_file_exists(current)) { 1268 break; 1269 } 1270 } 1271 } else { 1272 /* 1273 * Get the largest existing version and remove any 1274 * version greater than the permitted version. 1275 */ 1276 result = greatest_version(file, file->versions, &greatest); 1277 if (result != ISC_R_SUCCESS) { 1278 return (result); 1279 } 1280 1281 /* 1282 * Increment if greatest is not the actual maximum value. 1283 */ 1284 if (greatest < file->versions - 1) { 1285 greatest++; 1286 } 1287 } 1288 1289 for (i = greatest; i > 0; i--) { 1290 result = ISC_R_SUCCESS; 1291 n = snprintf(current, sizeof(current), "%s.%u", path, 1292 (unsigned)(i - 1)); 1293 if (n >= (int)sizeof(current) || n < 0) { 1294 result = ISC_R_NOSPACE; 1295 } 1296 if (result == ISC_R_SUCCESS) { 1297 n = snprintf(newpath, sizeof(newpath), "%s.%u", path, 1298 (unsigned)i); 1299 if (n >= (int)sizeof(newpath) || n < 0) { 1300 result = ISC_R_NOSPACE; 1301 } 1302 } 1303 if (result == ISC_R_SUCCESS) { 1304 result = isc_file_rename(current, newpath); 1305 } 1306 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1307 syslog(LOG_ERR, 1308 "unable to rename log file '%s.%u' to " 1309 "'%s.%u': %s", 1310 path, i - 1, path, i, isc_result_totext(result)); 1311 } 1312 } 1313 1314 n = snprintf(newpath, sizeof(newpath), "%s.0", path); 1315 if (n >= (int)sizeof(newpath) || n < 0) { 1316 result = ISC_R_NOSPACE; 1317 } else { 1318 result = isc_file_rename(path, newpath); 1319 } 1320 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1321 syslog(LOG_ERR, "unable to rename log file '%s' to '%s.0': %s", 1322 path, path, isc_result_totext(result)); 1323 } 1324 1325 return (ISC_R_SUCCESS); 1326 } 1327 1328 static isc_result_t 1329 roll_timestamp(isc_logfile_t *file) { 1330 int n; 1331 char newts[PATH_MAX + 1]; 1332 char newpath[PATH_MAX + 1]; 1333 const char *path; 1334 isc_time_t now; 1335 isc_result_t result = ISC_R_SUCCESS; 1336 1337 REQUIRE(file != NULL); 1338 REQUIRE(file->versions != 0); 1339 1340 path = file->name; 1341 1342 /* 1343 * First find all the logfiles and remove the oldest ones 1344 * Save one fewer than file->versions because we'll be renaming 1345 * the existing file to a timestamped version after this. 1346 */ 1347 if (file->versions != ISC_LOG_ROLLINFINITE) { 1348 remove_old_tsversions(file, file->versions - 1); 1349 } 1350 1351 /* Then just rename the current logfile */ 1352 isc_time_now(&now); 1353 isc_time_formatshorttimestamp(&now, newts, PATH_MAX + 1); 1354 n = snprintf(newpath, sizeof(newpath), "%s.%s", path, newts); 1355 if (n >= (int)sizeof(newpath) || n < 0) { 1356 result = ISC_R_NOSPACE; 1357 } else { 1358 result = isc_file_rename(path, newpath); 1359 } 1360 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1361 syslog(LOG_ERR, "unable to rename log file '%s' to '%s.0': %s", 1362 path, path, isc_result_totext(result)); 1363 } 1364 1365 return (ISC_R_SUCCESS); 1366 } 1367 1368 isc_result_t 1369 isc_logfile_roll(isc_logfile_t *file) { 1370 isc_result_t result; 1371 1372 REQUIRE(file != NULL); 1373 1374 /* 1375 * Do nothing (not even excess version trimming) if ISC_LOG_ROLLNEVER 1376 * is specified. Apparently complete external control over the log 1377 * files is desired. 1378 */ 1379 if (file->versions == ISC_LOG_ROLLNEVER) { 1380 return (ISC_R_SUCCESS); 1381 } else if (file->versions == 0) { 1382 result = isc_file_remove(file->name); 1383 if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { 1384 syslog(LOG_ERR, "unable to remove log file '%s': %s", 1385 file->name, isc_result_totext(result)); 1386 } 1387 return (ISC_R_SUCCESS); 1388 } 1389 1390 switch (file->suffix) { 1391 case isc_log_rollsuffix_increment: 1392 return (roll_increment(file)); 1393 case isc_log_rollsuffix_timestamp: 1394 return (roll_timestamp(file)); 1395 default: 1396 return (ISC_R_UNEXPECTED); 1397 } 1398 } 1399 1400 static isc_result_t 1401 isc_log_open(isc_logchannel_t *channel) { 1402 struct stat statbuf; 1403 bool regular_file; 1404 bool roll = false; 1405 isc_result_t result = ISC_R_SUCCESS; 1406 const char *path; 1407 1408 REQUIRE(channel->type == ISC_LOG_TOFILE); 1409 REQUIRE(FILE_STREAM(channel) == NULL); 1410 1411 path = FILE_NAME(channel); 1412 1413 REQUIRE(path != NULL && *path != '\0'); 1414 1415 /* 1416 * Determine type of file; only regular files will be 1417 * version renamed, and only if the base file exists 1418 * and either has no size limit or has reached its size limit. 1419 */ 1420 if (stat(path, &statbuf) == 0) { 1421 regular_file = S_ISREG(statbuf.st_mode) ? true : false; 1422 /* XXXDCL if not regular_file complain? */ 1423 if ((FILE_MAXSIZE(channel) == 0 && 1424 FILE_VERSIONS(channel) != ISC_LOG_ROLLNEVER) || 1425 (FILE_MAXSIZE(channel) > 0 && 1426 statbuf.st_size >= FILE_MAXSIZE(channel))) 1427 { 1428 roll = regular_file; 1429 } 1430 } else if (errno == ENOENT) { 1431 regular_file = true; 1432 POST(regular_file); 1433 } else { 1434 result = ISC_R_INVALIDFILE; 1435 } 1436 1437 /* 1438 * Version control. 1439 */ 1440 if (result == ISC_R_SUCCESS && roll) { 1441 if (FILE_VERSIONS(channel) == ISC_LOG_ROLLNEVER) { 1442 return (ISC_R_MAXSIZE); 1443 } 1444 result = isc_logfile_roll(&channel->destination.file); 1445 if (result != ISC_R_SUCCESS) { 1446 if ((channel->flags & ISC_LOG_OPENERR) == 0) { 1447 syslog(LOG_ERR, 1448 "isc_log_open: isc_logfile_roll '%s' " 1449 "failed: %s", 1450 FILE_NAME(channel), 1451 isc_result_totext(result)); 1452 channel->flags |= ISC_LOG_OPENERR; 1453 } 1454 return (result); 1455 } 1456 } 1457 1458 result = isc_stdio_open(path, "a", &FILE_STREAM(channel)); 1459 1460 return (result); 1461 } 1462 1463 ISC_NO_SANITIZE_THREAD bool 1464 isc_log_wouldlog(isc_log_t *lctx, int level) { 1465 /* 1466 * Try to avoid locking the mutex for messages which can't 1467 * possibly be logged to any channels -- primarily debugging 1468 * messages that the debug level is not high enough to print. 1469 * 1470 * If the level is (mathematically) less than or equal to the 1471 * highest_level, or if there is a dynamic channel and the level is 1472 * less than or equal to the debug level, the main loop must be 1473 * entered to see if the message should really be output. 1474 */ 1475 if (lctx == NULL) { 1476 return (false); 1477 } 1478 1479 int highest_level = atomic_load_acquire(&lctx->highest_level); 1480 if (level <= highest_level) { 1481 return (true); 1482 } 1483 if (atomic_load_acquire(&lctx->dynamic)) { 1484 int debug_level = atomic_load_acquire(&lctx->debug_level); 1485 if (level <= debug_level) { 1486 return (true); 1487 } 1488 } 1489 1490 return (false); 1491 } 1492 1493 static void 1494 isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category, 1495 isc_logmodule_t *module, int level, bool write_once, 1496 const char *format, va_list args) { 1497 int syslog_level; 1498 const char *time_string; 1499 char local_time[64]; 1500 char iso8601z_string[64]; 1501 char iso8601l_string[64]; 1502 char level_string[24] = { 0 }; 1503 struct stat statbuf; 1504 bool matched = false; 1505 bool printtime, iso8601, utc, printtag, printcolon; 1506 bool printcategory, printmodule, printlevel, buffered; 1507 isc_logchannel_t *channel; 1508 isc_logchannellist_t *category_channels; 1509 isc_result_t result; 1510 1511 REQUIRE(lctx == NULL || VALID_CONTEXT(lctx)); 1512 REQUIRE(category != NULL); 1513 REQUIRE(module != NULL); 1514 REQUIRE(level != ISC_LOG_DYNAMIC); 1515 REQUIRE(format != NULL); 1516 1517 /* 1518 * Programs can use libraries that use this logging code without 1519 * wanting to do any logging, thus the log context is allowed to 1520 * be non-existent. 1521 */ 1522 if (lctx == NULL) { 1523 return; 1524 } 1525 1526 REQUIRE(category->id < lctx->category_count); 1527 REQUIRE(module->id < lctx->module_count); 1528 1529 if (!isc_log_wouldlog(lctx, level)) { 1530 return; 1531 } 1532 1533 local_time[0] = '\0'; 1534 iso8601l_string[0] = '\0'; 1535 iso8601z_string[0] = '\0'; 1536 1537 RDLOCK(&lctx->lcfg_rwl); 1538 LOCK(&lctx->lock); 1539 1540 lctx->buffer[0] = '\0'; 1541 1542 isc_logconfig_t *lcfg = lctx->logconfig; 1543 1544 category_channels = ISC_LIST_HEAD(lcfg->channellists[category->id]); 1545 1546 /* 1547 * XXXDCL add duplicate filtering? (To not write multiple times 1548 * to the same source via various channels). 1549 */ 1550 do { 1551 /* 1552 * If the channel list end was reached and a match was 1553 * made, everything is finished. 1554 */ 1555 if (category_channels == NULL && matched) { 1556 break; 1557 } 1558 1559 if (category_channels == NULL && !matched && 1560 category_channels != ISC_LIST_HEAD(lcfg->channellists[0])) 1561 { 1562 /* 1563 * No category/module pair was explicitly 1564 * configured. Try the category named "default". 1565 */ 1566 category_channels = 1567 ISC_LIST_HEAD(lcfg->channellists[0]); 1568 } 1569 1570 if (category_channels == NULL && !matched) { 1571 /* 1572 * No matching module was explicitly configured 1573 * for the category named "default". Use the 1574 * internal default channel. 1575 */ 1576 category_channels = &default_channel; 1577 } 1578 1579 if (category_channels->module != NULL && 1580 category_channels->module != module) { 1581 category_channels = ISC_LIST_NEXT(category_channels, 1582 link); 1583 continue; 1584 } 1585 1586 matched = true; 1587 1588 channel = category_channels->channel; 1589 category_channels = ISC_LIST_NEXT(category_channels, link); 1590 1591 int_fast32_t dlevel = atomic_load_acquire(&lctx->debug_level); 1592 if (((channel->flags & ISC_LOG_DEBUGONLY) != 0) && dlevel == 0) 1593 { 1594 continue; 1595 } 1596 1597 if (channel->level == ISC_LOG_DYNAMIC) { 1598 if (dlevel < level) { 1599 continue; 1600 } 1601 } else if (channel->level < level) { 1602 continue; 1603 } 1604 1605 if ((channel->flags & ISC_LOG_PRINTTIME) != 0 && 1606 local_time[0] == '\0') { 1607 isc_time_t isctime; 1608 1609 TIME_NOW(&isctime); 1610 1611 isc_time_formattimestamp(&isctime, local_time, 1612 sizeof(local_time)); 1613 isc_time_formatISO8601ms(&isctime, iso8601z_string, 1614 sizeof(iso8601z_string)); 1615 isc_time_formatISO8601Lms(&isctime, iso8601l_string, 1616 sizeof(iso8601l_string)); 1617 } 1618 1619 if ((channel->flags & ISC_LOG_PRINTLEVEL) != 0 && 1620 level_string[0] == '\0') { 1621 if (level < ISC_LOG_CRITICAL) { 1622 snprintf(level_string, sizeof(level_string), 1623 "level %d: ", level); 1624 } else if (level > ISC_LOG_DYNAMIC) { 1625 snprintf(level_string, sizeof(level_string), 1626 "%s %d: ", log_level_strings[0], 1627 level); 1628 } else { 1629 snprintf(level_string, sizeof(level_string), 1630 "%s: ", log_level_strings[-level]); 1631 } 1632 } 1633 1634 /* 1635 * Only format the message once. 1636 */ 1637 if (lctx->buffer[0] == '\0') { 1638 (void)vsnprintf(lctx->buffer, sizeof(lctx->buffer), 1639 format, args); 1640 1641 /* 1642 * Check for duplicates. 1643 */ 1644 if (write_once) { 1645 isc_logmessage_t *message, *next; 1646 isc_time_t oldest; 1647 isc_interval_t interval; 1648 size_t size; 1649 1650 isc_interval_set(&interval, 1651 lcfg->duplicate_interval, 0); 1652 1653 /* 1654 * 'oldest' is the age of the oldest 1655 * messages which fall within the 1656 * duplicate_interval range. 1657 */ 1658 TIME_NOW(&oldest); 1659 if (isc_time_subtract(&oldest, &interval, 1660 &oldest) != ISC_R_SUCCESS) 1661 { 1662 /* 1663 * Can't effectively do the 1664 * checking without having a 1665 * valid time. 1666 */ 1667 message = NULL; 1668 } else { 1669 message = ISC_LIST_HEAD(lctx->messages); 1670 } 1671 1672 while (message != NULL) { 1673 if (isc_time_compare(&message->time, 1674 &oldest) < 0) { 1675 /* 1676 * This message is older 1677 * than the 1678 * duplicate_interval, 1679 * so it should be 1680 * dropped from the 1681 * history. 1682 * 1683 * Setting the interval 1684 * to be to be longer 1685 * will obviously not 1686 * cause the expired 1687 * message to spring 1688 * back into existence. 1689 */ 1690 next = ISC_LIST_NEXT(message, 1691 link); 1692 1693 ISC_LIST_UNLINK(lctx->messages, 1694 message, link); 1695 1696 isc_mem_put( 1697 lctx->mctx, message, 1698 sizeof(*message) + 1 + 1699 strlen(message->text)); 1700 1701 message = next; 1702 continue; 1703 } 1704 1705 /* 1706 * This message is in the 1707 * duplicate filtering interval 1708 * ... 1709 */ 1710 if (strcmp(lctx->buffer, 1711 message->text) == 0) { 1712 /* 1713 * ... and it is a 1714 * duplicate. Unlock the 1715 * mutex and get the 1716 * hell out of Dodge. 1717 */ 1718 goto unlock; 1719 } 1720 1721 message = ISC_LIST_NEXT(message, link); 1722 } 1723 1724 /* 1725 * It wasn't in the duplicate interval, 1726 * so add it to the message list. 1727 */ 1728 size = sizeof(isc_logmessage_t) + 1729 strlen(lctx->buffer) + 1; 1730 message = isc_mem_get(lctx->mctx, size); 1731 message->text = (char *)(message + 1); 1732 size -= sizeof(isc_logmessage_t); 1733 strlcpy(message->text, lctx->buffer, size); 1734 TIME_NOW(&message->time); 1735 ISC_LINK_INIT(message, link); 1736 ISC_LIST_APPEND(lctx->messages, message, link); 1737 } 1738 } 1739 1740 utc = ((channel->flags & ISC_LOG_UTC) != 0); 1741 iso8601 = ((channel->flags & ISC_LOG_ISO8601) != 0); 1742 printtime = ((channel->flags & ISC_LOG_PRINTTIME) != 0); 1743 printtag = ((channel->flags & 1744 (ISC_LOG_PRINTTAG | ISC_LOG_PRINTPREFIX)) != 0 && 1745 lcfg->tag != NULL); 1746 printcolon = ((channel->flags & ISC_LOG_PRINTTAG) != 0 && 1747 lcfg->tag != NULL); 1748 printcategory = ((channel->flags & ISC_LOG_PRINTCATEGORY) != 0); 1749 printmodule = ((channel->flags & ISC_LOG_PRINTMODULE) != 0); 1750 printlevel = ((channel->flags & ISC_LOG_PRINTLEVEL) != 0); 1751 buffered = ((channel->flags & ISC_LOG_BUFFERED) != 0); 1752 1753 if (printtime) { 1754 if (iso8601) { 1755 if (utc) { 1756 time_string = iso8601z_string; 1757 } else { 1758 time_string = iso8601l_string; 1759 } 1760 } else { 1761 time_string = local_time; 1762 } 1763 } else { 1764 time_string = ""; 1765 } 1766 1767 switch (channel->type) { 1768 case ISC_LOG_TOFILE: 1769 if (FILE_MAXREACHED(channel)) { 1770 /* 1771 * If the file can be rolled, OR 1772 * If the file no longer exists, OR 1773 * If the file is less than the maximum 1774 * size, (such as if it had been renamed 1775 * and a new one touched, or it was 1776 * truncated in place) 1777 * ... then close it to trigger 1778 * reopening. 1779 */ 1780 if (FILE_VERSIONS(channel) != 1781 ISC_LOG_ROLLNEVER || 1782 (stat(FILE_NAME(channel), &statbuf) != 0 && 1783 errno == ENOENT) || 1784 statbuf.st_size < FILE_MAXSIZE(channel)) 1785 { 1786 (void)fclose(FILE_STREAM(channel)); 1787 FILE_STREAM(channel) = NULL; 1788 FILE_MAXREACHED(channel) = false; 1789 } else { 1790 /* 1791 * Eh, skip it. 1792 */ 1793 break; 1794 } 1795 } 1796 1797 if (FILE_STREAM(channel) == NULL) { 1798 result = isc_log_open(channel); 1799 if (result != ISC_R_SUCCESS && 1800 result != ISC_R_MAXSIZE && 1801 (channel->flags & ISC_LOG_OPENERR) == 0) 1802 { 1803 syslog(LOG_ERR, 1804 "isc_log_open '%s' " 1805 "failed: %s", 1806 FILE_NAME(channel), 1807 isc_result_totext(result)); 1808 channel->flags |= ISC_LOG_OPENERR; 1809 } 1810 if (result != ISC_R_SUCCESS) { 1811 break; 1812 } 1813 channel->flags &= ~ISC_LOG_OPENERR; 1814 } 1815 FALLTHROUGH; 1816 1817 case ISC_LOG_TOFILEDESC: 1818 fprintf(FILE_STREAM(channel), "%s%s%s%s%s%s%s%s%s%s\n", 1819 printtime ? time_string : "", 1820 printtime ? " " : "", printtag ? lcfg->tag : "", 1821 printcolon ? ": " : "", 1822 printcategory ? category->name : "", 1823 printcategory ? ": " : "", 1824 printmodule ? (module != NULL ? module->name 1825 : "no_module") 1826 : "", 1827 printmodule ? ": " : "", 1828 printlevel ? level_string : "", lctx->buffer); 1829 1830 if (!buffered) { 1831 fflush(FILE_STREAM(channel)); 1832 } 1833 1834 /* 1835 * If the file now exceeds its maximum size 1836 * threshold, note it so that it will not be 1837 * logged to any more. 1838 */ 1839 if (FILE_MAXSIZE(channel) > 0) { 1840 INSIST(channel->type == ISC_LOG_TOFILE); 1841 1842 /* XXXDCL NT fstat/fileno */ 1843 /* XXXDCL complain if fstat fails? */ 1844 if (fstat(fileno(FILE_STREAM(channel)), 1845 &statbuf) >= 0 && 1846 statbuf.st_size > FILE_MAXSIZE(channel)) 1847 { 1848 FILE_MAXREACHED(channel) = true; 1849 } 1850 } 1851 1852 break; 1853 1854 case ISC_LOG_TOSYSLOG: 1855 if (level > 0) { 1856 syslog_level = LOG_DEBUG; 1857 } else if (level < ISC_LOG_CRITICAL) { 1858 syslog_level = LOG_CRIT; 1859 } else { 1860 syslog_level = syslog_map[-level]; 1861 } 1862 1863 (void)syslog( 1864 FACILITY(channel) | syslog_level, 1865 "%s%s%s%s%s%s%s%s%s%s", 1866 printtime ? time_string : "", 1867 printtime ? " " : "", printtag ? lcfg->tag : "", 1868 printcolon ? ": " : "", 1869 printcategory ? category->name : "", 1870 printcategory ? ": " : "", 1871 printmodule ? (module != NULL ? module->name 1872 : "no_module") 1873 : "", 1874 printmodule ? ": " : "", 1875 printlevel ? level_string : "", lctx->buffer); 1876 break; 1877 1878 case ISC_LOG_TONULL: 1879 break; 1880 } 1881 } while (1); 1882 1883 unlock: 1884 UNLOCK(&lctx->lock); 1885 RDUNLOCK(&lctx->lcfg_rwl); 1886 } 1887
Indexes created Thu Apr 16 00:22:31 UTC 2026