log.c revision 0c27b3fe77ac1d5094ba3521e8142d9e7973133f
/*
* Copyright (C) 1999-2007, 2009, 2011-2014, 2016 Internet Systems Consortium, Inc. ("ISC")
*
* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/.
*/
/* $Id$ */
/*! \file
* \author Principal Authors: DCL */
#include <config.h>
#include <errno.h>
#include <stdlib.h>
#include <limits.h>
#include <time.h>
/*
* XXXDCL make dynamic?
*/
#ifndef PATH_MAX
#endif
/*!
* This is the structure that holds each named channel. A simple linked
* list chains all of the channels together, so an individual channel is
* found by doing strcmp()s with the names down the list. Their should
* be no performance penalty from this as it is expected that the number
* of named channels will be no more than a dozen or so, and name lookups
* from the head of the list are only done when isc_log_usechannel() is
* called, which should also be very infrequent.
*/
typedef struct isc_logchannel isc_logchannel_t;
struct isc_logchannel {
char * name;
unsigned int type;
int level;
unsigned int flags;
};
/*!
* The logchannellist structure associates categories and modules with
* channels. First the appropriate channellist is found based on the
* category, and then each structure in the linked list is checked for
* a matching module. It is expected that the number of channels
* associated with any given category will be very short, no more than
* three or four in the more unusual cases.
*/
typedef struct isc_logchannellist isc_logchannellist_t;
struct isc_logchannellist {
const isc_logmodule_t * module;
};
/*!
* This structure is used to remember messages for pruning via
* isc_log_[v]write1().
*/
typedef struct isc_logmessage isc_logmessage_t;
struct isc_logmessage {
char * text;
};
/*!
* The isc_logconfig structure is used to store the configurable information
* about where messages are actually supposed to be sent -- the information
* that could changed based on some configuration file, as opposed to the
* into a program, or the debug_level which is dynamic state information.
*/
struct isc_logconfig {
unsigned int magic;
unsigned int channellist_count;
unsigned int duplicate_interval;
int highest_level;
char * tag;
};
/*!
* This isc_log structure provides the context for the isc_log functions.
* The log context locks itself in isc_log_doit, the internal backend to
* isc_log_write. The locking is necessary both to provide exclusive access
* to the buffer into which the message is formatted and to guard against
* competing threads trying to write to the same syslog resource. (On
* Unfortunately, the lock cannot guard against a _different_ logging
* context in the same program competing for syslog's attention. Thus
* There Can Be Only One, but this is not enforced.
* XXXDCL enforce it?
*
* Note that the category and module information is not locked.
* This is because in the usual case, only one isc_log_t is ever created
* XXXDCL it might be wise to add more locking overall.
*/
struct isc_log {
/* Not locked. */
unsigned int magic;
unsigned int category_count;
unsigned int module_count;
int debug_level;
/* Locked by isc_log lock. */
char buffer[LOG_BUFFER_SIZE];
};
/*!
* Used when ISC_LOG_PRINTLEVEL is enabled for a channel.
*/
static const char *log_level_strings[] = {
"debug",
"info",
"notice",
"warning",
"error",
"critical"
};
/*!
* Used to convert ISC_LOG_* priorities into syslog priorities.
* XXXDCL This will need modification for NT.
*/
static const int syslog_map[] = {
};
/*!
* When adding new categories, a corresponding ISC_LOGCATEGORY_foo
*
* The default category is provided so that the internal default can
* be overridden. Since the default is always looked up as the first
* channellist in the log context, it must come first in isc_categories[].
*/
{ "default", 0 }, /* "default" must come first. */
{ "general", 0 },
{ NULL, 0 }
};
/*!
* See above comment for categories on LIBISC_EXTERNAL_DATA, and apply it to modules.
*/
{ "socket", 0 },
{ "time", 0 },
{ "interface", 0 },
{ "timer", 0 },
{ "file", 0 },
{ "other", 0 },
{ NULL, 0 }
};
/*!
* This essentially constant structure must be filled in at run time,
* because its channel member is pointed to a channel that is created
* dynamically with isc_log_createchannel.
*/
static isc_logchannellist_t default_channel;
/*!
* libisc logs to this context.
*/
/*!
* Forward declarations.
*/
static isc_result_t
static isc_result_t
static isc_result_t
static isc_result_t
static void
ISC_FORMAT_PRINTF(9, 0);
/*@{*/
/*!
* Convenience macros.
*/
/*@}*/
/****
**** Public interfaces.
****/
/*
* Establish a new logging context, with default channels.
*/
lctx->category_count = 0;
lctx->module_count = 0;
lctx->debug_level = 0;
if (result != ISC_R_SUCCESS) {
return (result);
}
/*
* Normally setting the magic number is the last step done
* in a creation function, but a valid log context is needed
* by isc_log_registercategories and isc_logconfig_create.
* If either fails, the lctx is destroyed and not returned
* to the caller.
*/
} else
if (result == ISC_R_SUCCESS)
if (result == ISC_R_SUCCESS) {
} else {
}
return (result);
}
int level = ISC_LOG_INFO;
lcfg->channellist_count = 0;
lcfg->duplicate_interval = 0;
/*
* Normally the magic number is the last thing set in the
* structure, but isc_log_createchannel() needs a valid
* config. If the channel creation fails, the lcfg is not
* returned to the caller.
*/
} else
/*
* Create the default channels:
* default_syslog, default_stderr, default_debug and null.
*/
if (result == ISC_R_SUCCESS) {
&destination, 0);
}
if (result == ISC_R_SUCCESS) {
}
if (result == ISC_R_SUCCESS) {
/*
* Set the default category's channel to default_stderr,
* which is at the head of the channels list because it was
* just created.
*/
}
if (result == ISC_R_SUCCESS)
NULL, 0);
if (result == ISC_R_SUCCESS)
else
return (result);
}
}
/*
* Ensure that lcfg->channellist_count == lctx->category_count.
* They won't be equal if isc_log_usechannel has not been called
* since any call to isc_log_registercategories.
*/
if (result != ISC_R_SUCCESS)
return (result);
return (ISC_R_SUCCESS);
}
void
}
}
lctx->debug_level = 0;
lctx->category_count = 0;
lctx->module_count = 0;
}
void
char *filename;
unsigned int i;
/*
* This function cannot be called with a logconfig that is in
* use by a log context.
*/
/*
* The filename for the channel may have ultimately
* started its life in user-land as a const string,
* but in isc_log_createchannel it gets copied
* into writable memory and is not longer truly const.
*/
}
}
for (i = 0; i < lcfg->channellist_count; i++)
}
if (lcfg->channellist_count > 0)
sizeof(ISC_LIST(isc_logchannellist_t)));
lcfg->highest_level = 0;
lcfg->duplicate_interval = 0;
}
void
/*
* XXXDCL This somewhat sleazy situation of using the last pointer
* in one category array to point to the next array exists because
* this registration function returns void and I didn't want to have
* change everything that used it by making it return an isc_result_t.
* It would need to do that if it had to allocate memory to store
* pointers to each array passed in.
*/
else {
/*
* Adjust the last (NULL) pointer of the already registered
* categories to point to the incoming array.
*/
/*
* The name pointer points to the next array.
* Ick.
*/
else
catp++;
}
/*
* Update the id number of the category with its new global id.
*/
}
/*
* catp is neither modified nor returned to the
* caller, so removing its const qualifier is ok.
*/
else {
return (catp);
catp++;
}
return (NULL);
}
void
/*
* XXXDCL This somewhat sleazy situation of using the last pointer
* in one category array to point to the next array exists because
* this registration function returns void and I didn't want to have
* change everything that used it by making it return an isc_result_t.
* It would need to do that if it had to allocate memory to store
* pointers to each array passed in.
*/
else {
/*
* Adjust the last (NULL) pointer of the already registered
* modules to point to the incoming array.
*/
/*
* The name pointer points to the next array.
* Ick.
*/
else
modp++;
}
/*
* Update the id number of the module with its new global id.
*/
}
/*
* modp is neither modified nor returned to the
* caller, so removing its const qualifier is ok.
*/
else {
return (modp);
modp++;
}
return (NULL);
}
const isc_logdestination_t *destination,
unsigned int flags)
{
/* XXXDCL find duplicate names? */
return (ISC_R_NOMEMORY);
return (ISC_R_NOMEMORY);
}
switch (type) {
case ISC_LOG_TOSYSLOG:
break;
case ISC_LOG_TOFILE:
/*
* The file name is copied because greatest_version wants
* to scribble on it, so it needs to be definitely in
* writable memory.
*/
break;
case ISC_LOG_TOFILEDESC:
FILE_MAXSIZE(channel) = 0;
break;
case ISC_LOG_TONULL:
/* Nothing. */
break;
default:
return (ISC_R_UNEXPECTED);
}
/*
* If default_stderr was redefined, make the default category
* point to the new default_stderr.
*/
return (ISC_R_SUCCESS);
}
const isc_logcategory_t *category,
const isc_logmodule_t *module)
{
unsigned int i;
break;
return (ISC_R_NOTFOUND);
else
/*
* Assign to all categories. Note that this includes
* the default channel.
*/
for (i = 0; i < lctx->category_count; i++) {
if (result != ISC_R_SUCCESS)
break;
}
return (result);
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
const char *format, ...)
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
const char *format, ...)
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
{
/*
* Contract checking is done in isc_log_doit().
*/
}
void
}
void
/*
* Close ISC_LOG_DEBUGONLY channels if level is zero.
*/
if (lctx->debug_level == 0)
}
}
unsigned int
return (lctx->debug_level);
}
void
}
unsigned int
return (lcfg->duplicate_interval);
}
return (ISC_R_NOMEMORY);
} else {
}
return (ISC_R_SUCCESS);
}
char *
}
/* XXXDCL NT -- This interface will assuredly be changing. */
void
}
void
}
}
/****
**** Internal functions
****/
static isc_result_t
{
/*
* Ensure lcfg->channellist_count == lctx->category_count.
*/
if (result != ISC_R_SUCCESS)
return (result);
return (ISC_R_NOMEMORY);
/*
* Remember the highest logging level set by any channel in the
* logging config, so isc_log_doit() can quickly return if the
* message is too high to be logged by any channel.
*/
}
return (ISC_R_SUCCESS);
}
/*
* This would ideally be part of isc_log_registercategories(), except then
* that function would have to return isc_result_t instead of void.
*/
static isc_result_t
unsigned int bytes;
void *lists;
return (ISC_R_SUCCESS);
return (ISC_R_NOMEMORY);
if (lcfg->channellist_count != 0) {
sizeof(ISC_LIST(isc_logchannellist_t));
}
return (ISC_R_SUCCESS);
}
static isc_result_t
/* XXXDCL HIGHLY NT */
const char *dirname;
char sep = '/';
#ifdef _WIN32
char *basename2;
#endif
/*
* It is safe to DE_CONST the file.name because it was copied
* with isc_mem_strdup in isc_log_createchannel.
*/
#ifdef _WIN32
sep = '\\';
}
#endif
*basename++ = '\0';
} else {
dirname = ".";
}
isc_dir_init(&dir);
/*
* Replace the file separator if it was taken out.
*/
/*
* Return if the directory open failed.
*/
if (result != ISC_R_SUCCESS)
return (result);
&digit_end, 10);
}
}
isc_dir_close(&dir);
return (ISC_R_SUCCESS);
}
static isc_result_t
int i, n, greatest;
const char *path;
/*
* Do nothing (not even excess version trimming) if ISC_LOG_ROLLNEVER
* is specified. Apparently complete external control over the log
* files is desired.
*/
return (ISC_R_SUCCESS);
/*
* Set greatest_version to the greatest existing version
* (not the maximum requested version). This is 1 based even
* though the file names are 0 based, so an oldest log of log.1
* is a greatest_version of 2.
*/
if (result != ISC_R_SUCCESS)
return (result);
/*
* Now greatest should be set to the highest version number desired.
* Since the highest number is one less than FILE_VERSIONS(channel)
* when not doing infinite log rolling, greatest will need to be
* decremented when it is equal to -- or greater than --
* FILE_VERSIONS(channel). When greatest is less than
* FILE_VERSIONS(channel), it is already suitable for use as
* the maximum version number.
*/
; /* Do nothing. */
else
/*
* When greatest is >= FILE_VERSIONS(channel), it needs to
* be reduced until it is FILE_VERSIONS(channel) - 1.
* Remove any excess logs on the way to that value.
*/
if (n >= (int)sizeof(current) || n < 0)
else
if (result != ISC_R_SUCCESS &&
"unable to remove log file '%s.%d': %s",
}
for (i = greatest; i > 0; i--) {
if (n >= (int)sizeof(current) || n < 0)
if (result == ISC_R_SUCCESS) {
if (n >= (int)sizeof(new) || n < 0)
}
if (result == ISC_R_SUCCESS)
if (result != ISC_R_SUCCESS &&
"unable to rename log file '%s.%d' to "
}
if (FILE_VERSIONS(channel) != 0) {
if (n >= (int)sizeof(new) || n < 0)
else
if (result != ISC_R_SUCCESS &&
"unable to rename log file '%s' to '%s.0': %s",
} else {
if (result != ISC_R_SUCCESS &&
}
return (ISC_R_SUCCESS);
}
static isc_result_t
const char *path;
/*
* Determine type of file; only regular files will be
* version renamed, and only if the base file exists
* and either has no size limit or has reached its size limit.
*/
/* XXXDCL if not regular_file complain? */
if ((FILE_MAXSIZE(channel) == 0 &&
(FILE_MAXSIZE(channel) > 0 &&
roll = regular_file;
} else
/*
* Version control.
*/
return (ISC_R_MAXSIZE);
if (result != ISC_R_SUCCESS) {
"isc_log_open: roll_log '%s' "
"failed: %s",
}
return (result);
}
}
return (result);
}
/*
* Try to avoid locking the mutex for messages which can't
* possibly be logged to any channels -- primarily debugging
* messages that the debug level is not high enough to print.
*
* If the level is (mathematically) less than or equal to the
* highest_level, or if there is a dynamic channel and the level is
* less than or equal to the debug level, the main loop must be
* entered to see if the message should really be output.
*
* NOTE: this is UNLOCKED access to the logconfig. However,
* the worst thing that can happen is that a bad decision is made
* about returning without logging, and that's not a big concern,
* because that's a risk anyway if the logconfig is being
* dynamically changed.
*/
return (ISC_FALSE);
}
static void
{
int syslog_level;
char time_string[64];
char level_string[24];
const char *iformat;
/*
* Programs can use libraries that use this logging code without
* wanting to do any logging, thus the log context is allowed to
* be non-existent.
*/
return;
return;
else
time_string[0] = '\0';
level_string[0] = '\0';
/*
* XXXDCL add duplicate filtering? (To not write multiple times to
* the same source via various channels).
*/
do {
/*
* If the channel list end was reached and a match was made,
* everything is finished.
*/
break;
/*
* Try the category named "default".
*/
/*
* No matching module was explicitly configured
* for the category named "default". Use the internal
* default channel.
*/
link);
continue;
}
lctx->debug_level == 0)
continue;
continue;
continue;
time_string[0] == '\0') {
sizeof(time_string));
}
level_string[0] == '\0') {
if (level < ISC_LOG_CRITICAL)
"level %d: "),
level);
else if (level > ISC_LOG_DYNAMIC)
"%s %d: ", log_level_strings[0],
level);
else
}
/*
* Only format the message once.
*/
/*
* Check for duplicates.
*/
if (write_once) {
lcfg->duplicate_interval, 0);
/*
* 'oldest' is the age of the oldest messages
* which fall within the duplicate_interval
* range.
*/
!= ISC_R_SUCCESS)
/*
* Can't effectively do the checking
* without having a valid time.
*/
else
&oldest) < 0) {
/*
* This message is older
* than the duplicate_interval,
* so it should be dropped from
* the history.
*
* Setting the interval to be
* to be longer will obviously
* not cause the expired
* message to spring back into
* existence.
*/
link);
sizeof(*message) + 1 +
continue;
}
/*
* This message is in the duplicate
* filtering interval ...
*/
== 0) {
/*
* ... and it is a duplicate.
* Unlock the mutex and
* get the hell out of Dodge.
*/
return;
}
}
/*
* It wasn't in the duplicate interval,
* so add it to the message list.
*/
sizeof(isc_logmessage_t) +
/*
* Put the text immediately after
* the struct. The strcpy is safe.
*/
}
}
}
!= 0);
!= 0);
!= 0);
!= 0);
!= 0);
case ISC_LOG_TOFILE:
if (FILE_MAXREACHED(channel)) {
/*
* If the file can be rolled, OR
* If the file no longer exists, OR
* If the file is less than the maximum size,
* (such as if it had been renamed and
* a new one touched, or it was truncated
* in place)
* ... then close it to trigger reopening.
*/
if (FILE_VERSIONS(channel) !=
} else
/*
* Eh, skip it.
*/
break;
}
if (result != ISC_R_SUCCESS &&
result != ISC_R_MAXSIZE &&
"isc_log_open '%s' failed: %s",
}
if (result != ISC_R_SUCCESS)
break;
}
/* FALLTHROUGH */
case ISC_LOG_TOFILEDESC:
"%s%s%s%s%s%s%s%s%s%s\n",
: "no_module")
: "",
if (!buffered)
/*
* If the file now exceeds its maximum size
* threshold, note it so that it will not be logged
* to any more.
*/
if (FILE_MAXSIZE(channel) > 0) {
/* XXXDCL complain if fstat fails? */
&statbuf) >= 0 &&
}
break;
case ISC_LOG_TOSYSLOG:
if (level > 0)
else if (level < ISC_LOG_CRITICAL)
else
"%s%s%s%s%s%s%s%s%s%s",
: "no_module")
: "",
break;
case ISC_LOG_TONULL:
break;
}
} while (1);
}