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 */
62 typedef struct isc_logchannel isc_logchannel_t;
63
64 struct 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 */
81 typedef struct isc_logchannellist isc_logchannellist_t;
82
83 struct 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 */
93 typedef struct isc_logmessage isc_logmessage_t;
94
95 struct 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 */
108 struct 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 */
137 struct 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 */
156 static 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 */
169 static 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 */
186 LIBISC_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 */
195 LIBISC_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 */
210 static isc_logchannellist_t default_channel;
211
212 /*!
213 * libisc logs to this context.
214 */
215 LIBISC_EXTERNAL_DATA isc_log_t *isc_lctx = NULL;
216
217 /*!
218 * Forward declarations.
219 */
220 static isc_result_t
221 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id,
222 const isc_logmodule_t *module, isc_logchannel_t *channel);
223
224 static isc_result_t
225 sync_channellist(isc_logconfig_t *lcfg);
226
227 static isc_result_t
228 greatest_version(isc_logfile_t *file, int versions, int *greatest);
229
230 static void
231 isc_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 */
258 isc_result_t
259 isc_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
322 isc_result_t
323 isc_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
416 isc_logconfig_t *
417 isc_logconfig_get(isc_log_t *lctx) {
418 REQUIRE(VALID_CONTEXT(lctx));
419
420 ENSURE(lctx->logconfig != NULL);
421
422 return (lctx->logconfig);
423 }
424
425 isc_result_t
426 isc_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
455 void
456 isc_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
496 void
497 isc_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
562 void
563 isc_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
606 isc_logcategory_t *
607 isc_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
629 void
630 isc_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
673 isc_logmodule_t *
674 isc_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
696 isc_result_t
697 isc_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
785 isc_result_t
786 isc_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
828 void
829 isc_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
844 void
845 isc_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
856 void
857 isc_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
872 void
873 isc_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
884 void
885 isc_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
902 void
903 isc_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
915 void
916 isc_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
933 void
934 isc_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
946 void
947 isc_log_setcontext(isc_log_t *lctx) {
948 isc_lctx = lctx;
949 }
950
951 void
952 isc_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
976 unsigned int
977 isc_log_getdebuglevel(isc_log_t *lctx) {
978 REQUIRE(VALID_CONTEXT(lctx));
979
980 return (lctx->debug_level);
981 }
982
983 void
984 isc_log_setduplicateinterval(isc_logconfig_t *lcfg, unsigned int interval) {
985 REQUIRE(VALID_CONFIG(lcfg));
986
987 lcfg->duplicate_interval = interval;
988 }
989
990 unsigned int
991 isc_log_getduplicateinterval(isc_logconfig_t *lcfg) {
992 REQUIRE(VALID_CONTEXT(lcfg));
993
994 return (lcfg->duplicate_interval);
995 }
996
997 isc_result_t
998 isc_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
1017 char *
1018 isc_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. */
1025 void
1026 isc_log_opensyslog(const char *tag, int options, int facility) {
1027 (void)openlog(tag, options, facility);
1028 }
1029
1030 void
1031 isc_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
1053 static isc_result_t
1054 assignchannel(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 */
1104 static isc_result_t
1105 sync_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
1141 static isc_result_t
1142 greatest_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
1220 static isc_result_t
1221 remove_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
1339 static isc_result_t
1340 roll_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
1423 static isc_result_t
1424 roll_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
1465 isc_result_t
1466 isc_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
1497 static isc_result_t
1498 isc_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
1556 isc_boolean_t
1557 isc_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
1583 static void
1584 isc_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