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