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