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