xref: /openbsd-src/usr.bin/dig/lib/isc/log.c (revision 1fb015a8af3a7e9b85db2510147a155826ef04d9)
1 /*
2  * Copyright (C) Internet Systems Consortium, Inc. ("ISC")
3  *
4  * Permission to use, copy, modify, and/or distribute this software for any
5  * purpose with or without fee is hereby granted, provided that the above
6  * copyright notice and this permission notice appear in all copies.
7  *
8  * THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
9  * REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
10  * AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
11  * INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
12  * LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
13  * OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
14  * PERFORMANCE OF THIS SOFTWARE.
15  */
16 
17 /* $Id: log.c,v 1.18 2020/09/14 08:40:44 florian Exp $ */
18 
19 /*! \file
20  * \author  Principal Authors: DCL */
21 
22 #include <sys/time.h>
23 #include <limits.h>
24 #include <stdlib.h>
25 #include <string.h>
26 #include <syslog.h>
27 #include <time.h>
28 
29 #include <isc/log.h>
30 #include <isc/util.h>
31 
32 /*
33  * XXXDCL make dynamic?
34  */
35 #define LOG_BUFFER_SIZE	(8 * 1024)
36 
37 /*!
38  * This is the structure that holds each named channel.  A simple linked
39  * list chains all of the channels together, so an individual channel is
40  * found by doing strcmp()s with the names down the list.  Their should
41  * be no performance penalty from this as it is expected that the number
42  * of named channels will be no more than a dozen or so, and name lookups
43  * from the head of the list are only done when isc_log_usechannel() is
44  * called, which should also be very infrequent.
45  */
46 typedef struct isc_logchannel isc_logchannel_t;
47 
48 struct isc_logchannel {
49 	char *				name;
50 	unsigned int			type;
51 	int 				level;
52 	unsigned int			flags;
53 	isc_logdestination_t 		destination;
54 	ISC_LINK(isc_logchannel_t)	link;
55 };
56 
57 /*!
58  * The logchannellist structure associates categories and modules with
59  * channels.  First the appropriate channellist is found based on the
60  * category, and then each structure in the linked list is checked for
61  * a matching module.  It is expected that the number of channels
62  * associated with any given category will be very short, no more than
63  * three or four in the more unusual cases.
64  */
65 typedef struct isc_logchannellist isc_logchannellist_t;
66 
67 struct isc_logchannellist {
68 	const isc_logmodule_t *		module;
69 	isc_logchannel_t *		channel;
70 	ISC_LINK(isc_logchannellist_t)	link;
71 };
72 
73 /*!
74  * This structure is used to remember messages for pruning via
75  * isc_log_[v]write1().
76  */
77 typedef struct isc_logmessage isc_logmessage_t;
78 
79 struct isc_logmessage {
80 	char *				text;
81 	struct timespec			time;
82 	ISC_LINK(isc_logmessage_t)	link;
83 };
84 
85 /*!
86  * The isc_logconfig structure is used to store the configurable information
87  * about where messages are actually supposed to be sent -- the information
88  * that could changed based on some configuration file, as opposed to the
89  * the category/module specification of isc_log_[v]write[1] that is compiled
90  * into a program, or the debug_level which is dynamic state information.
91  */
92 struct isc_logconfig {
93 	isc_log_t *			lctx;
94 	ISC_LIST(isc_logchannel_t)	channels;
95 	ISC_LIST(isc_logchannellist_t) *channellists;
96 	unsigned int			channellist_count;
97 	unsigned int			duplicate_interval;
98 	int				highest_level;
99 	char *				tag;
100 	int			dynamic;
101 };
102 
103 /*!
104  * This isc_log structure provides the context for the isc_log functions.
105  * The log context locks itself in isc_log_doit, the internal backend to
106  * isc_log_write.  The locking is necessary both to provide exclusive access
107  * to the buffer into which the message is formatted and to guard against
108  * competing threads trying to write to the same syslog resource.  (On
109  * some systems, such as BSD/OS, stdio is thread safe but syslog is not.)
110  * Unfortunately, the lock cannot guard against a _different_ logging
111  * context in the same program competing for syslog's attention.  Thus
112  * There Can Be Only One, but this is not enforced.
113  * XXXDCL enforce it?
114  *
115  * Note that the category and module information is not locked.
116  * This is because in the usual case, only one isc_log_t is ever created
117  * in a program, and the category/module registration happens only once.
118  * XXXDCL it might be wise to add more locking overall.
119  */
120 struct isc_log {
121 	/* Not locked. */
122 	isc_logcategory_t *		categories;
123 	unsigned int			category_count;
124 	isc_logmodule_t *		modules;
125 	unsigned int			module_count;
126 	int				debug_level;
127 	/* Locked by isc_log lock. */
128 	isc_logconfig_t * 		logconfig;
129 	char 				buffer[LOG_BUFFER_SIZE];
130 	ISC_LIST(isc_logmessage_t)	messages;
131 };
132 
133 /*!
134  * Used when ISC_LOG_PRINTLEVEL is enabled for a channel.
135  */
136 static const char *log_level_strings[] = {
137 	"debug",
138 	"info",
139 	"notice",
140 	"warning",
141 	"error",
142 	"critical"
143 };
144 
145 /*!
146  * Used to convert ISC_LOG_* priorities into syslog priorities.
147  * XXXDCL This will need modification for NT.
148  */
149 static const int syslog_map[] = {
150 	LOG_DEBUG,
151 	LOG_INFO,
152 	LOG_NOTICE,
153 	LOG_WARNING,
154 	LOG_ERR,
155 	LOG_CRIT
156 };
157 
158 /*!
159  * When adding new categories, a corresponding ISC_LOGCATEGORY_foo
160  * definition needs to be added to <isc/log.h>.
161  *
162  * The default category is provided so that the internal default can
163  * be overridden.  Since the default is always looked up as the first
164  * channellist in the log context, it must come first in isc_categories[].
165  */
166 isc_logcategory_t isc_categories[] = {
167 	{ "default", 0 },	/* "default" must come first. */
168 	{ "general", 0 },
169 	{ NULL, 0 }
170 };
171 
172 /*!
173  * See above comment for categories on LIBISC_EXTERNAL_DATA, and apply it to modules.
174  */
175 isc_logmodule_t isc_modules[] = {
176 	{ "socket", 0 },
177 	{ "time", 0 },
178 	{ "interface", 0 },
179 	{ "timer", 0 },
180 	{ "file", 0 },
181 	{ "other", 0 },
182 	{ NULL, 0 }
183 };
184 
185 /*!
186  * This essentially constant structure must be filled in at run time,
187  * because its channel member is pointed to a channel that is created
188  * dynamically with isc_log_createchannel.
189  */
190 static isc_logchannellist_t default_channel;
191 
192 /*!
193  * libisc logs to this context.
194  */
195 isc_log_t *isc_lctx = NULL;
196 
197 /*!
198  * Forward declarations.
199  */
200 static isc_result_t
201 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id,
202 	      const isc_logmodule_t *module, isc_logchannel_t *channel);
203 
204 static isc_result_t
205 sync_channellist(isc_logconfig_t *lcfg);
206 
207 static void
208 isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
209 	     isc_logmodule_t *module, int level, int write_once,
210 	     const char *format, va_list args)
211      __attribute__((__format__(__printf__, 6, 0)));
212 
213 /*@{*/
214 /*!
215  * Convenience macros.
216  */
217 
218 #define FACILITY(channel)	 (channel->destination.facility)
219 #define FILE_NAME(channel)	 (channel->destination.file.name)
220 #define FILE_STREAM(channel)	 (channel->destination.file.stream)
221 #define FILE_VERSIONS(channel)	 (channel->destination.file.versions)
222 #define FILE_MAXSIZE(channel)	 (channel->destination.file.maximum_size)
223 
224 /*@}*/
225 /****
226  **** Public interfaces.
227  ****/
228 
229 /*
230  * Establish a new logging context, with default channels.
231  */
232 isc_result_t
isc_log_create(isc_log_t ** lctxp,isc_logconfig_t ** lcfgp)233 isc_log_create(isc_log_t **lctxp, isc_logconfig_t **lcfgp) {
234 	isc_log_t *lctx;
235 	isc_logconfig_t *lcfg = NULL;
236 	isc_result_t result;
237 
238 	REQUIRE(lctxp != NULL && *lctxp == NULL);
239 	REQUIRE(lcfgp == NULL || *lcfgp == NULL);
240 
241 	lctx = malloc(sizeof(*lctx));
242 	if (lctx != NULL) {
243 		lctx->categories = NULL;
244 		lctx->category_count = 0;
245 		lctx->modules = NULL;
246 		lctx->module_count = 0;
247 		lctx->debug_level = 0;
248 
249 		ISC_LIST_INIT(lctx->messages);
250 
251 		isc_log_registercategories(lctx, isc_categories);
252 		isc_log_registermodules(lctx, isc_modules);
253 		result = isc_logconfig_create(lctx, &lcfg);
254 
255 	} else
256 		result = ISC_R_NOMEMORY;
257 
258 	if (result == ISC_R_SUCCESS)
259 		result = sync_channellist(lcfg);
260 
261 	if (result == ISC_R_SUCCESS) {
262 		lctx->logconfig = lcfg;
263 
264 		*lctxp = lctx;
265 		if (lcfgp != NULL)
266 			*lcfgp = lcfg;
267 
268 	} else {
269 		if (lcfg != NULL)
270 			isc_logconfig_destroy(&lcfg);
271 		if (lctx != NULL)
272 			isc_log_destroy(&lctx);
273 	}
274 
275 	return (result);
276 }
277 
278 isc_result_t
isc_logconfig_create(isc_log_t * lctx,isc_logconfig_t ** lcfgp)279 isc_logconfig_create(isc_log_t *lctx, isc_logconfig_t **lcfgp) {
280 	isc_logconfig_t *lcfg;
281 	isc_logdestination_t destination;
282 	isc_result_t result = ISC_R_SUCCESS;
283 	int level = ISC_LOG_INFO;
284 
285 	REQUIRE(lcfgp != NULL && *lcfgp == NULL);
286 
287 	lcfg = malloc(sizeof(*lcfg));
288 
289 	if (lcfg != NULL) {
290 		lcfg->lctx = lctx;
291 		lcfg->channellists = NULL;
292 		lcfg->channellist_count = 0;
293 		lcfg->duplicate_interval = 0;
294 		lcfg->highest_level = level;
295 		lcfg->tag = NULL;
296 		lcfg->dynamic = 0;
297 
298 		ISC_LIST_INIT(lcfg->channels);
299 
300 	} else
301 		result = ISC_R_NOMEMORY;
302 
303 	/*
304 	 * Create the default channels:
305 	 *   	default_syslog, default_stderr, default_debug and null.
306 	 */
307 	if (result == ISC_R_SUCCESS) {
308 		destination.facility = LOG_DAEMON;
309 		result = isc_log_createchannel(lcfg, "default_syslog",
310 					       ISC_LOG_TOSYSLOG, level,
311 					       &destination, 0);
312 	}
313 
314 	if (result == ISC_R_SUCCESS) {
315 		destination.file.stream = stderr;
316 		destination.file.name = NULL;
317 		destination.file.versions = ISC_LOG_ROLLNEVER;
318 		destination.file.maximum_size = 0;
319 		result = isc_log_createchannel(lcfg, "default_stderr",
320 					       ISC_LOG_TOFILEDESC,
321 					       level,
322 					       &destination,
323 					       ISC_LOG_PRINTTIME);
324 	}
325 
326 	if (result == ISC_R_SUCCESS) {
327 		/*
328 		 * Set the default category's channel to default_stderr,
329 		 * which is at the head of the channels list because it was
330 		 * just created.
331 		 */
332 		default_channel.channel = ISC_LIST_HEAD(lcfg->channels);
333 
334 		destination.file.stream = stderr;
335 		destination.file.name = NULL;
336 		destination.file.versions = ISC_LOG_ROLLNEVER;
337 		destination.file.maximum_size = 0;
338 		result = isc_log_createchannel(lcfg, "default_debug",
339 					       ISC_LOG_TOFILEDESC,
340 					       ISC_LOG_DYNAMIC,
341 					       &destination,
342 					       ISC_LOG_PRINTTIME);
343 	}
344 
345 	if (result == ISC_R_SUCCESS)
346 		result = isc_log_createchannel(lcfg, "null",
347 					       ISC_LOG_TONULL,
348 					       ISC_LOG_DYNAMIC,
349 					       NULL, 0);
350 
351 	if (result == ISC_R_SUCCESS)
352 		*lcfgp = lcfg;
353 
354 	else
355 		if (lcfg != NULL)
356 			isc_logconfig_destroy(&lcfg);
357 
358 	return (result);
359 }
360 
361 void
isc_log_destroy(isc_log_t ** lctxp)362 isc_log_destroy(isc_log_t **lctxp) {
363 	isc_log_t *lctx;
364 	isc_logconfig_t *lcfg;
365 	isc_logmessage_t *message;
366 
367 	REQUIRE(lctxp != NULL);
368 
369 	lctx = *lctxp;
370 	if (lctx->logconfig != NULL) {
371 		lcfg = lctx->logconfig;
372 		lctx->logconfig = NULL;
373 		isc_logconfig_destroy(&lcfg);
374 	}
375 
376 	while ((message = ISC_LIST_HEAD(lctx->messages)) != NULL) {
377 		ISC_LIST_UNLINK(lctx->messages, message, link);
378 
379 		free(message);
380 	}
381 
382 	lctx->buffer[0] = '\0';
383 	lctx->debug_level = 0;
384 	lctx->categories = NULL;
385 	lctx->category_count = 0;
386 	lctx->modules = NULL;
387 	lctx->module_count = 0;
388 	free(lctx);
389 	*lctxp = NULL;
390 }
391 
392 void
isc_logconfig_destroy(isc_logconfig_t ** lcfgp)393 isc_logconfig_destroy(isc_logconfig_t **lcfgp) {
394 	isc_logconfig_t *lcfg;
395 	isc_logchannel_t *channel;
396 	isc_logchannellist_t *item;
397 	unsigned int i;
398 
399 	REQUIRE(lcfgp != NULL);
400 
401 	lcfg = *lcfgp;
402 
403 	/*
404 	 * This function cannot be called with a logconfig that is in
405 	 * use by a log context.
406 	 */
407 	REQUIRE(lcfg->lctx != NULL && lcfg->lctx->logconfig != lcfg);
408 
409 	while ((channel = ISC_LIST_HEAD(lcfg->channels)) != NULL) {
410 		ISC_LIST_UNLINK(lcfg->channels, channel, link);
411 
412 		free(channel->name);
413 		free(channel);
414 	}
415 
416 	for (i = 0; i < lcfg->channellist_count; i++)
417 		while ((item = ISC_LIST_HEAD(lcfg->channellists[i])) != NULL) {
418 			ISC_LIST_UNLINK(lcfg->channellists[i], item, link);
419 			free(item);
420 		}
421 
422 	if (lcfg->channellist_count > 0)
423 		free(lcfg->channellists);
424 
425 	lcfg->dynamic = 0;
426 	if (lcfg->tag != NULL)
427 		free(lcfg->tag);
428 	lcfg->tag = NULL;
429 	lcfg->highest_level = 0;
430 	lcfg->duplicate_interval = 0;
431 	free(lcfg);
432 	*lcfgp = NULL;
433 }
434 
435 void
isc_log_registercategories(isc_log_t * lctx,isc_logcategory_t categories[])436 isc_log_registercategories(isc_log_t *lctx, isc_logcategory_t categories[]) {
437 	isc_logcategory_t *catp;
438 
439 	REQUIRE(categories != NULL && categories[0].name != NULL);
440 
441 	/*
442 	 * XXXDCL This somewhat sleazy situation of using the last pointer
443 	 * in one category array to point to the next array exists because
444 	 * this registration function returns void and I didn't want to have
445 	 * change everything that used it by making it return an isc_result_t.
446 	 * It would need to do that if it had to allocate memory to store
447 	 * pointers to each array passed in.
448 	 */
449 	if (lctx->categories == NULL)
450 		lctx->categories = categories;
451 
452 	else {
453 		/*
454 		 * Adjust the last (NULL) pointer of the already registered
455 		 * categories to point to the incoming array.
456 		 */
457 		for (catp = lctx->categories; catp->name != NULL; )
458 			if (catp->id == UINT_MAX)
459 				/*
460 				 * The name pointer points to the next array.
461 				 * Ick.
462 				 */
463 				DE_CONST(catp->name, catp);
464 			else
465 				catp++;
466 
467 		catp->name = (void *)categories;
468 		catp->id = UINT_MAX;
469 	}
470 
471 	/*
472 	 * Update the id number of the category with its new global id.
473 	 */
474 	for (catp = categories; catp->name != NULL; catp++)
475 		catp->id = lctx->category_count++;
476 }
477 
478 void
isc_log_registermodules(isc_log_t * lctx,isc_logmodule_t modules[])479 isc_log_registermodules(isc_log_t *lctx, isc_logmodule_t modules[]) {
480 	isc_logmodule_t *modp;
481 
482 	REQUIRE(modules != NULL && modules[0].name != NULL);
483 
484 	/*
485 	 * XXXDCL This somewhat sleazy situation of using the last pointer
486 	 * in one category array to point to the next array exists because
487 	 * this registration function returns void and I didn't want to have
488 	 * change everything that used it by making it return an isc_result_t.
489 	 * It would need to do that if it had to allocate memory to store
490 	 * pointers to each array passed in.
491 	 */
492 	if (lctx->modules == NULL)
493 		lctx->modules = modules;
494 
495 	else {
496 		/*
497 		 * Adjust the last (NULL) pointer of the already registered
498 		 * modules to point to the incoming array.
499 		 */
500 		for (modp = lctx->modules; modp->name != NULL; )
501 			if (modp->id == UINT_MAX)
502 				/*
503 				 * The name pointer points to the next array.
504 				 * Ick.
505 				 */
506 				DE_CONST(modp->name, modp);
507 			else
508 				modp++;
509 
510 		modp->name = (void *)modules;
511 		modp->id = UINT_MAX;
512 	}
513 
514 	/*
515 	 * Update the id number of the module with its new global id.
516 	 */
517 	for (modp = modules; modp->name != NULL; modp++)
518 		modp->id = lctx->module_count++;
519 }
520 
521 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)522 isc_log_createchannel(isc_logconfig_t *lcfg, const char *name,
523 		      unsigned int type, int level,
524 		      const isc_logdestination_t *destination,
525 		      unsigned int flags)
526 {
527 	isc_logchannel_t *channel;
528 
529 	REQUIRE(name != NULL);
530 	REQUIRE(type == ISC_LOG_TOSYSLOG   ||
531 		type == ISC_LOG_TOFILEDESC || type == ISC_LOG_TONULL);
532 	REQUIRE(destination != NULL || type == ISC_LOG_TONULL);
533 	REQUIRE(level >= ISC_LOG_CRITICAL);
534 	REQUIRE((flags &
535 		 (unsigned int)~(ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY)) == 0);
536 
537 	/* XXXDCL find duplicate names? */
538 
539 	channel = malloc(sizeof(*channel));
540 	if (channel == NULL)
541 		return (ISC_R_NOMEMORY);
542 
543 	channel->name = strdup(name);
544 	if (channel->name == NULL) {
545 		free(channel);
546 		return (ISC_R_NOMEMORY);
547 	}
548 
549 	channel->type = type;
550 	channel->level = level;
551 	channel->flags = flags;
552 	ISC_LINK_INIT(channel, link);
553 
554 	switch (type) {
555 	case ISC_LOG_TOSYSLOG:
556 		FACILITY(channel) = destination->facility;
557 		break;
558 
559 	case ISC_LOG_TOFILEDESC:
560 		FILE_NAME(channel) = NULL;
561 		FILE_STREAM(channel) = destination->file.stream;
562 		FILE_MAXSIZE(channel) = 0;
563 		FILE_VERSIONS(channel) = ISC_LOG_ROLLNEVER;
564 		break;
565 
566 	case ISC_LOG_TONULL:
567 		/* Nothing. */
568 		break;
569 
570 	default:
571 		free(channel->name);
572 		free(channel);
573 		return (ISC_R_UNEXPECTED);
574 	}
575 
576 	ISC_LIST_PREPEND(lcfg->channels, channel, link);
577 
578 	/*
579 	 * If default_stderr was redefined, make the default category
580 	 * point to the new default_stderr.
581 	 */
582 	if (strcmp(name, "default_stderr") == 0)
583 		default_channel.channel = channel;
584 
585 	return (ISC_R_SUCCESS);
586 }
587 
588 isc_result_t
isc_log_usechannel(isc_logconfig_t * lcfg,const char * name,const isc_logcategory_t * category,const isc_logmodule_t * module)589 isc_log_usechannel(isc_logconfig_t *lcfg, const char *name,
590 		   const isc_logcategory_t *category,
591 		   const isc_logmodule_t *module)
592 {
593 	isc_log_t *lctx;
594 	isc_logchannel_t *channel;
595 	isc_result_t result = ISC_R_SUCCESS;
596 	unsigned int i;
597 
598 	REQUIRE(name != NULL);
599 
600 	lctx = lcfg->lctx;
601 
602 	REQUIRE(category == NULL || category->id < lctx->category_count);
603 	REQUIRE(module == NULL || module->id < lctx->module_count);
604 
605 	for (channel = ISC_LIST_HEAD(lcfg->channels); channel != NULL;
606 	     channel = ISC_LIST_NEXT(channel, link))
607 		if (strcmp(name, channel->name) == 0)
608 			break;
609 
610 	if (channel == NULL)
611 		return (ISC_R_NOTFOUND);
612 
613 	if (category != NULL)
614 		result = assignchannel(lcfg, category->id, module, channel);
615 
616 	else
617 		/*
618 		 * Assign to all categories.  Note that this includes
619 		 * the default channel.
620 		 */
621 		for (i = 0; i < lctx->category_count; i++) {
622 			result = assignchannel(lcfg, i, module, channel);
623 			if (result != ISC_R_SUCCESS)
624 				break;
625 		}
626 
627 	return (result);
628 }
629 
630 void
isc_log_write(isc_log_t * lctx,isc_logcategory_t * category,isc_logmodule_t * module,int level,const char * format,...)631 isc_log_write(isc_log_t *lctx, isc_logcategory_t *category,
632 	      isc_logmodule_t *module, int level, const char *format, ...)
633 {
634 	va_list args;
635 
636 	/*
637 	 * Contract checking is done in isc_log_doit().
638 	 */
639 
640 	va_start(args, format);
641 	isc_log_doit(lctx, category, module, level, 0, format, args);
642 	va_end(args);
643 }
644 
645 void
isc_log_setcontext(isc_log_t * lctx)646 isc_log_setcontext(isc_log_t *lctx) {
647 	isc_lctx = lctx;
648 }
649 
650 void
isc_log_setdebuglevel(isc_log_t * lctx,unsigned int level)651 isc_log_setdebuglevel(isc_log_t *lctx, unsigned int level) {
652 
653 	lctx->debug_level = level;
654 }
655 
656 /****
657  **** Internal functions
658  ****/
659 
660 static isc_result_t
assignchannel(isc_logconfig_t * lcfg,unsigned int category_id,const isc_logmodule_t * module,isc_logchannel_t * channel)661 assignchannel(isc_logconfig_t *lcfg, unsigned int category_id,
662 	      const isc_logmodule_t *module, isc_logchannel_t *channel)
663 {
664 	isc_logchannellist_t *new_item;
665 	isc_log_t *lctx;
666 	isc_result_t result;
667 
668 	lctx = lcfg->lctx;
669 
670 	REQUIRE(category_id < lctx->category_count);
671 	REQUIRE(module == NULL || module->id < lctx->module_count);
672 	REQUIRE(channel != NULL);
673 
674 	/*
675 	 * Ensure lcfg->channellist_count == lctx->category_count.
676 	 */
677 	result = sync_channellist(lcfg);
678 	if (result != ISC_R_SUCCESS)
679 		return (result);
680 
681 	new_item = malloc(sizeof(*new_item));
682 	if (new_item == NULL)
683 		return (ISC_R_NOMEMORY);
684 
685 	new_item->channel = channel;
686 	new_item->module = module;
687 	ISC_LIST_INITANDPREPEND(lcfg->channellists[category_id],
688 			       new_item, link);
689 
690 	/*
691 	 * Remember the highest logging level set by any channel in the
692 	 * logging config, so isc_log_doit() can quickly return if the
693 	 * message is too high to be logged by any channel.
694 	 */
695 	if (channel->type != ISC_LOG_TONULL) {
696 		if (lcfg->highest_level < channel->level)
697 			lcfg->highest_level = channel->level;
698 		if (channel->level == ISC_LOG_DYNAMIC)
699 			lcfg->dynamic = 1;
700 	}
701 
702 	return (ISC_R_SUCCESS);
703 }
704 
705 /*
706  * This would ideally be part of isc_log_registercategories(), except then
707  * that function would have to return isc_result_t instead of void.
708  */
709 static isc_result_t
sync_channellist(isc_logconfig_t * lcfg)710 sync_channellist(isc_logconfig_t *lcfg) {
711 	unsigned int bytes;
712 	isc_log_t *lctx;
713 	void *lists;
714 
715 	lctx = lcfg->lctx;
716 
717 	REQUIRE(lctx->category_count != 0);
718 
719 	if (lctx->category_count == lcfg->channellist_count)
720 		return (ISC_R_SUCCESS);
721 
722 	bytes = lctx->category_count * sizeof(ISC_LIST(isc_logchannellist_t));
723 
724 	lists = malloc(bytes);
725 
726 	if (lists == NULL)
727 		return (ISC_R_NOMEMORY);
728 
729 	memset(lists, 0, bytes);
730 
731 	if (lcfg->channellist_count != 0) {
732 		bytes = lcfg->channellist_count *
733 			sizeof(ISC_LIST(isc_logchannellist_t));
734 		memmove(lists, lcfg->channellists, bytes);
735 		free(lcfg->channellists);
736 	}
737 
738 	lcfg->channellists = lists;
739 	lcfg->channellist_count = lctx->category_count;
740 
741 	return (ISC_R_SUCCESS);
742 }
743 
744 int
isc_log_wouldlog(isc_log_t * lctx,int level)745 isc_log_wouldlog(isc_log_t *lctx, int level) {
746 	/*
747 	 * If the level is (mathematically) less than or equal to the
748 	 * highest_level, or if there is a dynamic channel and the level is
749 	 * less than or equal to the debug level, the main loop must be
750 	 * entered to see if the message should really be output.
751 	 *
752 	 * NOTE: this is UNLOCKED access to the logconfig.  However,
753 	 * the worst thing that can happen is that a bad decision is made
754 	 * about returning without logging, and that's not a big concern,
755 	 * because that's a risk anyway if the logconfig is being
756 	 * dynamically changed.
757 	 */
758 
759 	if (lctx == NULL || lctx->logconfig == NULL)
760 		return (0);
761 
762 	return (level <= lctx->logconfig->highest_level ||
763 		       (lctx->logconfig->dynamic &&
764 			level <= lctx->debug_level));
765 }
766 
767 static void
isc_log_doit(isc_log_t * lctx,isc_logcategory_t * category,isc_logmodule_t * module,int level,int write_once,const char * format,va_list args)768 isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
769 	     isc_logmodule_t *module, int level, int write_once,
770 	     const char *format, va_list args)
771 {
772 	int syslog_level;
773 	char time_string[64];
774 	char level_string[24];
775 	const char *iformat;
776 	int matched = 0;
777 	int printtime, printtag, printcolon;
778 	int printcategory, printmodule, printlevel;
779 	isc_logconfig_t *lcfg;
780 	isc_logchannel_t *channel;
781 	isc_logchannellist_t *category_channels;
782 
783 	REQUIRE(category != NULL);
784 	REQUIRE(module != NULL);
785 	REQUIRE(level != ISC_LOG_DYNAMIC);
786 	REQUIRE(format != NULL);
787 
788 	/*
789 	 * Programs can use libraries that use this logging code without
790 	 * wanting to do any logging, thus the log context is allowed to
791 	 * be non-existent.
792 	 */
793 	if (lctx == NULL)
794 		return;
795 
796 	REQUIRE(category->id < lctx->category_count);
797 	REQUIRE(module->id < lctx->module_count);
798 
799 	if (! isc_log_wouldlog(lctx, level))
800 		return;
801 
802 	iformat = format;
803 
804 	time_string[0]  = '\0';
805 	level_string[0] = '\0';
806 
807 	lctx->buffer[0] = '\0';
808 
809 	lcfg = lctx->logconfig;
810 
811 	category_channels = ISC_LIST_HEAD(lcfg->channellists[category->id]);
812 
813 	/*
814 	 * XXXDCL add duplicate filtering? (To not write multiple times to
815 	 * the same source via various channels).
816 	 */
817 	do {
818 		/*
819 		 * If the channel list end was reached and a match was made,
820 		 * everything is finished.
821 		 */
822 		if (category_channels == NULL && matched)
823 			break;
824 
825 		if (category_channels == NULL && ! matched &&
826 		    category_channels != ISC_LIST_HEAD(lcfg->channellists[0]))
827 			/*
828 			 * No category/module pair was explicitly configured.
829 			 * Try the category named "default".
830 			 */
831 			category_channels =
832 				ISC_LIST_HEAD(lcfg->channellists[0]);
833 
834 		if (category_channels == NULL && ! matched)
835 			/*
836 			 * No matching module was explicitly configured
837 			 * for the category named "default".  Use the internal
838 			 * default channel.
839 			 */
840 			category_channels = &default_channel;
841 
842 		if (category_channels->module != NULL &&
843 		    category_channels->module != module) {
844 			category_channels = ISC_LIST_NEXT(category_channels,
845 							  link);
846 			continue;
847 		}
848 
849 		matched = 1;
850 
851 		channel = category_channels->channel;
852 		category_channels = ISC_LIST_NEXT(category_channels, link);
853 
854 		if (((channel->flags & ISC_LOG_DEBUGONLY) != 0) &&
855 		    lctx->debug_level == 0)
856 			continue;
857 
858 		if (channel->level == ISC_LOG_DYNAMIC) {
859 			if (lctx->debug_level < level)
860 				continue;
861 		} else if (channel->level < level)
862 			continue;
863 
864 		if ((channel->flags & ISC_LOG_PRINTTIME) != 0 &&
865 		    time_string[0] == '\0') {
866 			time_t now;
867 			now = time(NULL);
868 			strftime(time_string, sizeof(time_string),
869 			    "%d-%b-%Y %X", localtime(&now));
870 		}
871 
872 		if ((channel->flags & ISC_LOG_PRINTLEVEL) != 0 &&
873 		    level_string[0] == '\0') {
874 			if (level < ISC_LOG_CRITICAL)
875 				snprintf(level_string, sizeof(level_string),
876 					 "level %d: ", level);
877 			else if (level > ISC_LOG_DYNAMIC)
878 				snprintf(level_string, sizeof(level_string),
879 					 "%s %d: ", log_level_strings[0],
880 					 level);
881 			else
882 				snprintf(level_string, sizeof(level_string),
883 					 "%s: ", log_level_strings[-level]);
884 		}
885 
886 		/*
887 		 * Only format the message once.
888 		 */
889 		if (lctx->buffer[0] == '\0') {
890 			(void)vsnprintf(lctx->buffer, sizeof(lctx->buffer),
891 					iformat, args);
892 
893 			/*
894 			 * Check for duplicates.
895 			 */
896 			if (write_once) {
897 				isc_logmessage_t *message, *next;
898 				struct timespec oldest;
899 				struct timespec interval;
900 				size_t size;
901 				interval.tv_sec = lcfg->duplicate_interval;
902 				interval.tv_nsec = 0;
903 
904 				/*
905 				 * 'oldest' is the age of the oldest messages
906 				 * which fall within the duplicate_interval
907 				 * range.
908 				 */
909 				clock_gettime(CLOCK_MONOTONIC, &oldest);
910 				timespecsub(&oldest, &interval, &oldest);
911 				message = ISC_LIST_HEAD(lctx->messages);
912 
913 				while (message != NULL) {
914 					if (timespeccmp(&message->time,
915 					    &oldest, <)) {
916 						/*
917 						 * This message is older
918 						 * than the duplicate_interval,
919 						 * so it should be dropped from
920 						 * the history.
921 						 *
922 						 * Setting the interval to be
923 						 * to be longer will obviously
924 						 * not cause the expired
925 						 * message to spring back into
926 						 * existence.
927 						 */
928 						next = ISC_LIST_NEXT(message,
929 								     link);
930 
931 						ISC_LIST_UNLINK(lctx->messages,
932 								message, link);
933 
934 						free(message);
935 
936 						message = next;
937 						continue;
938 					}
939 
940 					/*
941 					 * This message is in the duplicate
942 					 * filtering interval ...
943 					 */
944 					if (strcmp(lctx->buffer, message->text)
945 					    == 0) {
946 						/*
947 						 * ... and it is a duplicate.
948 						 */
949 						return;
950 					}
951 
952 					message = ISC_LIST_NEXT(message, link);
953 				}
954 
955 				/*
956 				 * It wasn't in the duplicate interval,
957 				 * so add it to the message list.
958 				 */
959 				size = sizeof(isc_logmessage_t) +
960 				       strlen(lctx->buffer) + 1;
961 				message = malloc(size);
962 				if (message != NULL) {
963 					/*
964 					 * Put the text immediately after
965 					 * the struct.  The strcpy is safe.
966 					 */
967 					message->text = (char *)(message + 1);
968 					size -= sizeof(isc_logmessage_t);
969 					strlcpy(message->text, lctx->buffer,
970 						size);
971 
972 					clock_gettime(CLOCK_MONOTONIC,
973 					    &message->time);
974 
975 					ISC_LINK_INIT(message, link);
976 					ISC_LIST_APPEND(lctx->messages,
977 							message, link);
978 				}
979 			}
980 		}
981 
982 		printtime     = (channel->flags & ISC_LOG_PRINTTIME) != 0;
983 		printtag      = (channel->flags &
984 					(ISC_LOG_PRINTTAG|ISC_LOG_PRINTPREFIX))
985 				       != 0 && lcfg->tag != NULL;
986 		printcolon    = (channel->flags & ISC_LOG_PRINTTAG)
987 				       != 0 && lcfg->tag != NULL;
988 		printcategory = (channel->flags & ISC_LOG_PRINTCATEGORY) != 0;
989 		printmodule   = (channel->flags & ISC_LOG_PRINTMODULE) != 0;
990 		printlevel    = (channel->flags & ISC_LOG_PRINTLEVEL) != 0;
991 
992 		switch (channel->type) {
993 		case ISC_LOG_TOFILEDESC:
994 			fprintf(FILE_STREAM(channel),
995 				"%s%s%s%s%s%s%s%s%s%s\n",
996 				printtime     ? time_string	: "",
997 				printtime     ? " "		: "",
998 				printtag      ? lcfg->tag	: "",
999 				printcolon    ? ": "		: "",
1000 				printcategory ? category->name	: "",
1001 				printcategory ? ": "		: "",
1002 				printmodule   ? (module != NULL ? module->name
1003 								: "no_module")
1004 								: "",
1005 				printmodule   ? ": "		: "",
1006 				printlevel    ? level_string	: "",
1007 				lctx->buffer);
1008 
1009 			fflush(FILE_STREAM(channel));
1010 			break;
1011 
1012 		case ISC_LOG_TOSYSLOG:
1013 			if (level > 0)
1014 				syslog_level = LOG_DEBUG;
1015 			else if (level < ISC_LOG_CRITICAL)
1016 				syslog_level = LOG_CRIT;
1017 			else
1018 				syslog_level = syslog_map[-level];
1019 
1020 			(void)syslog(FACILITY(channel) | syslog_level,
1021 			       "%s%s%s%s%s%s%s%s%s%s",
1022 			       printtime     ? time_string	: "",
1023 			       printtime     ? " "		: "",
1024 			       printtag      ? lcfg->tag	: "",
1025 			       printcolon    ? ": "		: "",
1026 			       printcategory ? category->name	: "",
1027 			       printcategory ? ": "		: "",
1028 			       printmodule   ? (module != NULL
1029 						 ? module->name
1030 						 : "no_module")
1031 								: "",
1032 			       printmodule   ? ": "		: "",
1033 			       printlevel    ? level_string	: "",
1034 			       lctx->buffer);
1035 			break;
1036 
1037 		case ISC_LOG_TONULL:
1038 			break;
1039 
1040 		}
1041 
1042 	} while (1);
1043 }
1044