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