lib/isc/log.c

	log.c revision 5542df09597c479be604da0ece8271cbc6fd9c4a
/*
 * Copyright (C) 1999, 2000  Internet Software Consortium.
 *
 * Permission to use, copy, modify, and distribute this software for any
 * purpose with or without fee is hereby granted, provided that the above
 * copyright notice and this permission notice appear in all copies.
 *
 * THE SOFTWARE IS PROVIDED "AS IS" AND INTERNET SOFTWARE CONSORTIUM DISCLAIMS
 * ALL WARRANTIES WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES
 * OF MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL INTERNET SOFTWARE
 * CONSORTIUM BE LIABLE FOR ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL
 * DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR
 * PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS
 * ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS
 * SOFTWARE.
 */

/* $Id: log.c,v 1.20 2000/03/04 16:39:54 tale Exp $ */

/* Principal Authors: DCL */

#include <errno.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#include <limits.h>
#include <sys/stat.h>

#include <isc/assertions.h>
#include <isc/boolean.h>
#include <isc/dir.h>
#include <isc/error.h>
#include <isc/list.h>
#include <isc/log.h>
#include <isc/mem.h>
#include <isc/mutex.h>
#include <isc/print.h>
#include <isc/time.h>
#include <isc/util.h>

#define LCTX_MAGIC      0x4C637478U /* Lctx. */
#define VALID_CONTEXT(lctx) ((lctx) != NULL && (lctx)->magic == LCTX_MAGIC)
#define LCFG_MAGIC      0x4C636667U /* Lcfg. */
#define VALID_CONFIG(lcfg)  ((lcfg) != NULL && (lcfg)->magic == LCFG_MAGIC)

/*
 * XXXDCL make dynamic?
 */
#define LOG_BUFFER_SIZE (8 * 1024)

/*
 * 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 peformance 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;
    isc_logdestination_t        destination;
    ISC_LINK(isc_logchannel_t)  link;
};

/*
 * The logchannelist 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 {
    isc_logmodule_t *       module;
    isc_logchannel_t *      channel;
    ISC_LINK(isc_logchannellist_t)  link;
};

/*
 * 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;
    isc_time_t          time;
    ISC_LINK(isc_logmessage_t)  link;
};

/*
 * 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
 * the category/module specification of isc_log_[v]write[1] that is compiled
 * into a program, or the debug_level which is dynamic state information.
 */
struct isc_logconfig {
    unsigned int            magic;
    isc_log_t *         lctx;
    ISC_LIST(isc_logchannel_t)  channels;
    ISC_LIST(isc_logchannellist_t) *channellists;
    unsigned int            channellist_count;
    unsigned int            duplicate_interval;
};

/*
 * 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 the buffer into which the message is formatted and to guard against
 * competing threads trying to write to the same syslog resource.  (On
 * some systems, such as BSD/OS, stdio is thread safe but syslog is not.)
 * 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
 * in a program, and the category/module registration happens only once.
 * XXXDCL it might be wise to add more locking overall.
 */
struct isc_log {
    /* Not locked. */
    unsigned int            magic;
    isc_mem_t *         mctx;
    isc_logcategory_t *     categories;
    unsigned int            category_count;
    isc_logmodule_t *       modules;
    unsigned int            module_count;
    int             debug_level;
    isc_mutex_t         lock;
    /* Locked by isc_log lock. */
    isc_logconfig_t *       logconfig;
    char                buffer[LOG_BUFFER_SIZE];
    ISC_LIST(isc_logmessage_t)  messages;
};

/*
 * 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[] = {
    LOG_DEBUG, LOG_INFO, LOG_NOTICE, LOG_WARNING, LOG_ERR, LOG_CRIT
};

/*
 * When adding new categories, a corresponding ISC_LOGCATEGORY_foo
 * definition needs to be added to <isc/log.h>.
 *
 * 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[].
 */
isc_logcategory_t isc_categories[] = {
    { "default", 0 },   /* "default" must come first. */
    { NULL, 0 }
};

/*
 * This essentially static 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.
 */
isc_logchannellist_t default_channel;

/*
 * Forward declarations.
 */
static isc_result_t
assignchannel(isc_logconfig_t *lcfg, unsigned int category_id,
          isc_logmodule_t *module, isc_logchannel_t *channel);

static isc_result_t
sync_channellist(isc_logconfig_t *lcfg);

static unsigned int
greatest_version(isc_logchannel_t *channel);

static isc_result_t
roll_log(isc_logchannel_t *channel);

static void
isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
         isc_logmodule_t *module, int level, isc_boolean_t write_once,
         const char *format, va_list args);

/*
 * Convenience macros.
 */

#define FACILITY(channel)   (channel->destination.facility)
#define FILE_NAME(channel)  (channel->destination.file.name)
#define FILE_STREAM(channel)    (channel->destination.file.stream)
#define FILE_VERSIONS(channel)  (channel->destination.file.versions)
#define FILE_MAXSIZE(channel)   (channel->destination.file.maximum_size)

/****
 **** Public interfaces.
 ****/

/*
 * Establish a new logging context, with default channels.
 */
isc_result_t
isc_log_create(isc_mem_t *mctx, isc_log_t **lctxp, isc_logconfig_t **lcfgp) {
    isc_log_t *lctx;
    isc_logconfig_t *lcfg = NULL;
    isc_result_t result;

    REQUIRE(mctx != NULL);
    REQUIRE(lctxp != NULL && *lctxp == NULL);

    lctx = isc_mem_get(mctx, sizeof(*lctx));
    if (lctx != NULL) {
        lctx->mctx = mctx;
        lctx->categories = NULL;
        lctx->category_count = 0;
        lctx->modules = NULL;
        lctx->module_count = 0;
        lctx->debug_level = 0;

        ISC_LIST_INIT(lctx->messages);

        RUNTIME_CHECK(isc_mutex_init(&lctx->lock) == ISC_R_SUCCESS);

        /*
         * 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.
         */
        lctx->magic = LCTX_MAGIC;

        isc_log_registercategories(lctx, isc_categories);
        result = isc_logconfig_create(lctx, &lcfg);

    } else
        result = ISC_R_NOMEMORY;

    if (result == ISC_R_SUCCESS) {
        lctx->logconfig = lcfg;

        *lctxp = lctx;
        if (lcfgp != NULL)
            *lcfgp = lcfg;

    } else
        if (lctx != NULL)
            isc_log_destroy(&lctx);

    return (result);
}

isc_result_t
isc_logconfig_create(isc_log_t *lctx, isc_logconfig_t **lcfgp) {
    isc_logconfig_t *lcfg;
    isc_logdestination_t destination;
    isc_result_t result = ISC_R_SUCCESS;

    REQUIRE(lcfgp != NULL && *lcfgp == NULL);
    REQUIRE(VALID_CONTEXT(lctx));

    lcfg = isc_mem_get(lctx->mctx, sizeof(*lcfg));

    if (lcfg != NULL) {
        lcfg->lctx = lctx;
        lcfg->channellists = NULL;
        lcfg->channellist_count = 0;
        lcfg->duplicate_interval = 0;

        ISC_LIST_INIT(lcfg->channels);

        /*
         * 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.
         */
        lcfg->magic = LCFG_MAGIC;

    } else
        result = ISC_R_NOMEMORY;

    /*
     * Create the default channels:
     *      default_syslog, default_stderr, default_debug and null.
     */
    if (result == ISC_R_SUCCESS) {
        destination.facility = LOG_INFO;
        result = isc_log_createchannel(lcfg, "default_syslog",
                           ISC_LOG_TOSYSLOG, ISC_LOG_INFO,
                           &destination, 0);
    }

    if (result == ISC_R_SUCCESS) {
        destination.file.stream = stderr;
        destination.file.name = NULL;
        destination.file.versions = ISC_LOG_ROLLNEVER;
        destination.file.maximum_size = 0;
        result = isc_log_createchannel(lcfg, "default_stderr",
                           ISC_LOG_TOFILEDESC,
                           ISC_LOG_INFO,
                           &destination,
                           ISC_LOG_PRINTTIME);
    }

    /*
     * Set the default category's channel to default_stderr, which
     * is at the head of the channels list because it was just created.
     */
    default_channel.channel = ISC_LIST_HEAD(lcfg->channels);

    if (result == ISC_R_SUCCESS) {
        destination.file.stream = stderr;
        destination.file.name = NULL;
        destination.file.versions = ISC_LOG_ROLLNEVER;
        destination.file.maximum_size = 0;
        result = isc_log_createchannel(lcfg, "default_debug",
                           ISC_LOG_TOFILEDESC,
                           ISC_LOG_DYNAMIC,
                           &destination,
                           ISC_LOG_PRINTTIME);
    }

    if (result == ISC_R_SUCCESS)
        result = isc_log_createchannel(lcfg, "null",
                           ISC_LOG_TONULL,
                           ISC_LOG_DYNAMIC,
                           NULL, 0);

    if (result == ISC_R_SUCCESS)
        *lcfgp = lcfg;

    else
        if (lcfg != NULL)
            isc_logconfig_destroy(&lcfg);

    return (result);
}

isc_logconfig_t *
isc_logconfig_get(isc_log_t *lctx) {
    REQUIRE(VALID_CONTEXT(lctx));

    ENSURE(lctx->logconfig != NULL);

    return (lctx->logconfig);
}

isc_result_t
isc_logconfig_use(isc_log_t *lctx, isc_logconfig_t *lcfg) {
    isc_logconfig_t *old_cfg;
    isc_result_t result;

    REQUIRE(VALID_CONTEXT(lctx));
    REQUIRE(VALID_CONFIG(lcfg));
    REQUIRE(lcfg->lctx == lctx);

    /*
     * 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.
     */
    result = sync_channellist(lcfg);
    if (result != ISC_R_SUCCESS)
        return (result);

    LOCK(&lctx->lock);

    old_cfg = lctx->logconfig;
    lctx->logconfig = lcfg;

    UNLOCK(&lctx->lock);

    isc_logconfig_destroy(&old_cfg);

    return (ISC_R_SUCCESS);
}

void
isc_log_destroy(isc_log_t **lctxp) {
    isc_log_t *lctx;
    isc_logconfig_t *lcfg;
    isc_mem_t *mctx;
    isc_logmessage_t *message;

    REQUIRE(lctxp != NULL && VALID_CONTEXT(*lctxp));

    lctx = *lctxp;
    mctx = lctx->mctx;

    if (lctx->logconfig != NULL) {
        lcfg = lctx->logconfig;
        lctx->logconfig = NULL;
        isc_logconfig_destroy(&lcfg);
    }

    RUNTIME_CHECK(isc_mutex_destroy(&lctx->lock) == ISC_R_SUCCESS);

    while ((message = ISC_LIST_HEAD(lctx->messages)) != NULL) {
        ISC_LIST_UNLINK(lctx->messages, message, link);

        isc_mem_put(mctx, message,
                sizeof(*message) + strlen(message->text) + 1);
    }

    lctx->buffer[0] = '\0';
    lctx->debug_level = 0;
    lctx->categories = NULL;
    lctx->category_count = 0;
    lctx->modules = NULL;
    lctx->module_count = 0;
    lctx->mctx = NULL;
    lctx->magic = 0;

    isc_mem_put(mctx, lctx, sizeof(*lctx));

    *lctxp = NULL;
}

void
isc_logconfig_destroy(isc_logconfig_t **lcfgp) {
    isc_logconfig_t *lcfg;
    isc_mem_t *mctx;
    isc_logchannel_t *channel;
    isc_logchannellist_t *item;
    unsigned int i;

    REQUIRE(lcfgp != NULL && VALID_CONFIG(*lcfgp));

    lcfg = *lcfgp;

    /*
     * This function cannot be called with a logconfig that is in
     * use by a log context.
     */
    REQUIRE(lcfg->lctx != NULL && lcfg->lctx->logconfig != lcfg);

    mctx = lcfg->lctx->mctx;

    while ((channel = ISC_LIST_HEAD(lcfg->channels)) != NULL) {
        ISC_LIST_UNLINK(lcfg->channels, channel, link);

        if (channel->type == ISC_LOG_TOFILE) {
            isc_mem_free(mctx, FILE_NAME(channel));

            if (FILE_STREAM(channel) != NULL)
            (void)fclose(FILE_STREAM(channel));
        }

        isc_mem_free(mctx, channel->name);
        isc_mem_put(mctx, channel, sizeof(*channel));
    }

    for (i = 0; i < lcfg->channellist_count; i++)
        while ((item = ISC_LIST_HEAD(lcfg->channellists[i])) != NULL) {
            ISC_LIST_UNLINK(lcfg->channellists[i], item, link);
            isc_mem_put(mctx, item, sizeof(*item));
        }

    isc_mem_put(mctx, lcfg->channellists,
            lcfg->channellist_count *
            sizeof(ISC_LIST(isc_logchannellist_t)));

    lcfg->duplicate_interval = 0;
    lcfg->magic = 0;

    isc_mem_put(mctx, lcfg, sizeof(*lcfg));

    *lcfgp = NULL;
}

void
isc_log_registercategories(isc_log_t *lctx, isc_logcategory_t categories[]) {
    isc_logcategory_t *catp;

    REQUIRE(VALID_CONTEXT(lctx));
    REQUIRE(categories != NULL && categories[0].name != NULL);

    /*
     * 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.
     */
    if (lctx->categories == NULL)
        lctx->categories = categories;

    else {
        /*
         * Adjust the last (NULL) pointer of the already registered
         * categories to point to the incoming array.
         */
        for (catp = lctx->categories; catp->name != NULL; catp++)
            if (catp->id == UINT_MAX)
                catp = (isc_logcategory_t *)catp->name;

        catp->name = (void *)categories;
        catp->id = UINT_MAX;
    }

    /*
     * Update the id number of the category with its new global id.
     */
    for (catp = categories; catp->name != NULL; catp++)
        catp->id = lctx->category_count++;
}

isc_logcategory_t *
isc_log_categorybyname(isc_log_t *lctx, const char *name) {
    isc_logcategory_t *catp;

    REQUIRE(VALID_CONTEXT(lctx));
    REQUIRE(name != NULL);

    for (catp = lctx->categories; catp->name != NULL; catp++)
        if (catp->id == UINT_MAX)
            catp = (isc_logcategory_t *)catp->name;
        else
            if (strcmp(catp->name, name) == 0)
                return catp;

    return (NULL);
}

void
isc_log_registermodules(isc_log_t *lctx, isc_logmodule_t modules[]) {
    isc_logmodule_t *modp;

    REQUIRE(VALID_CONTEXT(lctx));
    REQUIRE(modules != NULL && modules[0].name != NULL);

    /*
     * 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.
     */
    if (lctx->modules == NULL)
        lctx->modules = modules;

    else {
        /*
         * Adjust the last (NULL) pointer of the already registered
         * modules to point to the incoming array.
         */
        for (modp = lctx->modules; modp->name != NULL; modp++)
            if (modp->id == UINT_MAX)
                modp = (isc_logmodule_t *)modp->name;

        modp->name = (void *)modules;
        modp->id = UINT_MAX;
    }

    /*
     * Update the id number of the module with its new global id.
     */
    for (modp = modules; modp->name != NULL; modp++)
        modp->id = lctx->module_count++;
}

isc_logmodule_t *
isc_log_modulebyname(isc_log_t *lctx, const char *name) {
    isc_logmodule_t *modp;

    REQUIRE(VALID_CONTEXT(lctx));
    REQUIRE(name != NULL);

    for (modp = lctx->modules; modp->name != NULL; modp++)
        if (modp->id == UINT_MAX)
            modp = (isc_logmodule_t *)modp->name;
        else
            if (strcmp(modp->name, name) == 0)
                return modp;

    return (NULL);
}

isc_result_t
isc_log_createchannel(isc_logconfig_t *lcfg, const char *name,
              unsigned int type, int level,
              isc_logdestination_t *destination, unsigned int flags)
{
    isc_logchannel_t *channel;
    isc_mem_t *mctx;

    REQUIRE(VALID_CONFIG(lcfg));
    REQUIRE(name != NULL);
    REQUIRE(type == ISC_LOG_TOSYSLOG   || type == ISC_LOG_TOFILE ||
        type == ISC_LOG_TOFILEDESC || type == ISC_LOG_TONULL);
    REQUIRE(destination != NULL || type == ISC_LOG_TONULL);
    REQUIRE(level >= ISC_LOG_CRITICAL);
    REQUIRE((flags & ~(ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY)) == 0);

    /* XXXDCL find duplicate names? */

    mctx = lcfg->lctx->mctx;

    channel = isc_mem_get(mctx, sizeof(*channel));
    if (channel == NULL)
        return (ISC_R_NOMEMORY);

    channel->name = isc_mem_strdup(mctx, name);
    if (channel->name == NULL) {
        isc_mem_put(mctx, channel, sizeof(*channel));
        return (ISC_R_NOMEMORY);
    }

    channel->type = type;
    channel->level = level;
    channel->flags = flags;

    switch (type) {
    case ISC_LOG_TOSYSLOG:
        FACILITY(channel) = destination->facility;
        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.
         */
        FILE_NAME(channel) =
            isc_mem_strdup(mctx, destination->file.name);
        FILE_STREAM(channel) = NULL;
        FILE_MAXSIZE(channel) = destination->file.maximum_size;
        FILE_VERSIONS(channel) = destination->file.versions;
        break;

    case ISC_LOG_TOFILEDESC:
        FILE_NAME(channel) = NULL;
        FILE_STREAM(channel) = destination->file.stream;
        FILE_MAXSIZE(channel) = 0;
        FILE_VERSIONS(channel) = ISC_LOG_ROLLNEVER;
        break;

    case ISC_LOG_TONULL:
        /* Nothing. */
        break;

    default:
        isc_mem_put(mctx, channel->name, strlen(channel->name) + 1);
        isc_mem_put(mctx, channel, sizeof(*channel));
        return (ISC_R_UNEXPECTED);
    }

    ISC_LIST_PREPEND(lcfg->channels, channel, link);

    /*
     * If default_stderr was redefined, make the default category
     * point to the new default_stderr.
     */
    if (strcmp(name, "default_stderr") == 0)
        default_channel.channel = channel;

    return (ISC_R_SUCCESS);
}

isc_result_t
isc_log_usechannel(isc_logconfig_t *lcfg, const char *name,
           isc_logcategory_t *category, isc_logmodule_t *module)
{
    isc_log_t *lctx;
    isc_logchannel_t *channel;
    isc_result_t result = ISC_R_SUCCESS;
    unsigned int i;

    REQUIRE(VALID_CONFIG(lcfg));
    REQUIRE(name != NULL);

    lctx = lcfg->lctx;

    REQUIRE(category == NULL || category->id < lctx->category_count);
    REQUIRE(module == NULL || module->id < lctx->module_count);

    for (channel = ISC_LIST_HEAD(lcfg->channels); channel != NULL;
         channel = ISC_LIST_NEXT(channel, link))
        if (strcmp(name, channel->name) == 0)
            break;

    if (channel == NULL)
        return (ISC_R_NOTFOUND);

    if (category != NULL)
        result = assignchannel(lcfg, category->id, module, channel);

    else
        /*
         * Assign to all categories.  Note that this includes
         * the default channel.
         */
        for (i = 0; i < lctx->category_count; i++) {
            result = assignchannel(lcfg, i, module, channel);
            if (result != ISC_R_SUCCESS)
                break;
        }

    return (result);
}

void
isc_log_write(isc_log_t *lctx, isc_logcategory_t *category,
          isc_logmodule_t *module, int level, const char *format, ...)

{
    va_list args;

    /*
     * Contract checking is done in isc_log_doit().
     */

    va_start(args, format);
    isc_log_doit(lctx, category, module, level, ISC_FALSE, format, args);
    va_end(args);
}

void
isc_log_vwrite(isc_log_t *lctx, isc_logcategory_t *category,
           isc_logmodule_t *module, int level,
           const char *format, va_list args)

{
    /*
     * Contract checking is done in isc_log_doit().
     */
    isc_log_doit(lctx, category, module, level, ISC_FALSE, format, args);
}

void
isc_log_write1(isc_log_t *lctx, isc_logcategory_t *category,
           isc_logmodule_t *module, int level, const char *format, ...)

{
    va_list args;

    /*
     * Contract checking is done in isc_log_doit().
     */

    va_start(args, format);
    isc_log_doit(lctx, category, module, level, ISC_TRUE, format, args);
    va_end(args);
}

void
isc_log_vwrite1(isc_log_t *lctx, isc_logcategory_t *category,
        isc_logmodule_t *module, int level,
        const char *format, va_list args)

{
    /*
     * Contract checking is done in isc_log_doit().
     */
    isc_log_doit(lctx, category, module, level, ISC_TRUE, format, args);
}

void
isc_log_setdebuglevel(isc_log_t *lctx, unsigned int level) {
    REQUIRE(VALID_CONTEXT(lctx));

    lctx->debug_level = level;
}

unsigned int
isc_log_getdebuglevel(isc_log_t *lctx) {
    REQUIRE(VALID_CONTEXT(lctx));

    return (lctx->debug_level);
}

void
isc_log_setduplicateinterval(isc_logconfig_t *lcfg, unsigned int interval) {
    REQUIRE(VALID_CONFIG(lcfg));

    lcfg->duplicate_interval = interval;
}

unsigned int
isc_log_getduplicateinterval(isc_logconfig_t *lcfg) {
    REQUIRE(VALID_CONTEXT(lcfg));

    return (lcfg->duplicate_interval);
}

/* XXXDCL NT  -- This interface will assuredly be changing. */
void
isc_log_opensyslog(const char *tag, int options, int facility) {
    openlog(tag, options, facility);
}

void
isc_log_closefilelogs(isc_log_t *lctx) {
    isc_logchannel_t *channel;

    REQUIRE(VALID_CONTEXT(lctx));

    for (channel = ISC_LIST_HEAD(lctx->logconfig->channels);
         channel != NULL;
         channel = ISC_LIST_NEXT(channel, link))

        if (channel->type == ISC_LOG_TOFILE &&
            FILE_STREAM(channel) != NULL) {
            (void)fclose(FILE_STREAM(channel));
            FILE_STREAM(channel) = NULL;
        }
}

/****
 **** Internal functions
 ****/

static isc_result_t
assignchannel(isc_logconfig_t *lcfg, unsigned int category_id,
          isc_logmodule_t *module, isc_logchannel_t *channel)
{
    isc_logchannellist_t *new_item;
    isc_log_t *lctx;
    isc_result_t result;

    REQUIRE(VALID_CONFIG(lcfg));

    lctx = lcfg->lctx;

    REQUIRE(category_id < lctx->category_count);
    REQUIRE(module == NULL || module->id < lctx->module_count);
    REQUIRE(channel != NULL);

    /*
     * Ensure lcfg->channellist_count == lctx->category_count.
     */
    result = sync_channellist(lcfg);
    if (result != ISC_R_SUCCESS)
        return (result);

    new_item = isc_mem_get(lctx->mctx, sizeof(*new_item));
    if (new_item == NULL)
        return (ISC_R_NOMEMORY);

    new_item->channel = channel;
    new_item->module = module;
    ISC_LIST_PREPEND(lcfg->channellists[category_id], new_item, link);

    return (ISC_R_SUCCESS);
}

static isc_result_t
sync_channellist(isc_logconfig_t *lcfg) {
    int bytes;
    isc_log_t *lctx;
    void *lists;

    REQUIRE(VALID_CONFIG(lcfg));

    lctx = lcfg->lctx;

    REQUIRE(lctx->category_count != 0);

    if (lctx->category_count == lcfg->channellist_count)
        return (ISC_R_SUCCESS);

    bytes = lctx->category_count * sizeof(ISC_LIST(isc_logchannellist_t));

    lists = isc_mem_get(lctx->mctx, bytes);

    if (lists == NULL)
        return (ISC_R_NOMEMORY);

    memset(lists, 0, bytes);

    if (lcfg->channellist_count != 0) {
        bytes = lcfg->channellist_count *
            sizeof(ISC_LIST(isc_logchannellist_t));
        memcpy(lists, lcfg->channellists, bytes);
        isc_mem_put(lctx->mctx, lcfg->channellists, bytes);
    }

    lcfg->channellists = lists;
    lcfg->channellist_count = lctx->category_count;

    return (ISC_R_SUCCESS);
}

static unsigned int
greatest_version(isc_logchannel_t *channel) {
    /* XXXDCL HIGHLY NT */
    char *dirname, *basename, *digit_end;
    int version, greatest = -1;
    unsigned int basenamelen;
    isc_dir_t dir;
    isc_result_t result;

    REQUIRE(channel->type == ISC_LOG_TOFILE);

    basename = strrchr(FILE_NAME(channel), '/');
    if (basename != NULL) {
        *basename++ = '\0';
        dirname = FILE_NAME(channel);
    } else {
        basename = FILE_NAME(channel);
        dirname = ".";
    }
    basenamelen = strlen(basename);


    isc_dir_init(&dir);
    result = isc_dir_open(&dir, dirname);
    if (result != ISC_R_SUCCESS)
        return (0); /* ... and roll_log will likely report an error. */

    while (isc_dir_read(&dir) == ISC_R_SUCCESS) {
        if (dir.entry.length > basenamelen &&
            strncmp(dir.entry.name, basename, basenamelen) == 0 &&
            dir.entry.name[basenamelen] == '.') {

            version = strtol(&dir.entry.name[basenamelen + 1],
                      &digit_end, 10);
            if (*digit_end == '\0' && version > greatest)
                greatest = version;
        }
    }

    if (basename != FILE_NAME(channel))
        *--basename = '/';

    return (++greatest);
}

static isc_result_t
roll_log(isc_logchannel_t *channel) {
    int i, greatest, digits = 0;
    char current[FILENAME_MAX + 1];
    char new[FILENAME_MAX + 1];
    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.
     */
    if (FILE_VERSIONS(channel) == ISC_LOG_ROLLNEVER)
        return (ISC_R_SUCCESS);

    path = FILE_NAME(channel);

    /*
     * 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.
     */
    greatest = greatest_version(channel);

    /*
     * 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.
     */

    if (FILE_VERSIONS(channel) == ISC_LOG_ROLLINFINITE ||
        FILE_VERSIONS(channel) > greatest)
        ;       /* 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.
         */
        while (--greatest >= FILE_VERSIONS(channel)) {
            sprintf(current, "%s.%d", path, greatest);
            (void)remove(current);
        }

    for (i = greatest; i > 0; i /= 10)
        digits++;

    /*
     * Ensure the name fits in the filesystem.  Note that in this will not
     * trigger failure until there is going to be a log rolled into a name
     * that is too long, not when the maximum possible version name would
     * be too long.  Imagine a case where the name for logs 0-9 is exactly
     * as long as the maximum filename, but FILE_VERSIONS is configured as
     * 11.  log.10's name will be too long, but no error will be triggered
     * until log.9 exists and needs to be rolled.
     */
    if (strlen(path) + 1 + digits > FILENAME_MAX)
        return (ISC_R_INVALIDFILE);

    for (i = greatest; i > 0; i--) {
        sprintf(current, "%s.%d", path, i - 1);
        sprintf(new, "%s.%d", path, i);
        (void)rename(current, new);
    }

    if (FILE_VERSIONS(channel) != 0) {
        sprintf(new, "%s.0", path);
        (void)rename(path, new);

    } else if (FILE_VERSIONS(channel) == 0)
        (void)remove(path);

    return (ISC_R_SUCCESS);
}

static isc_result_t
isc_log_open(isc_logchannel_t *channel) {
    FILE *stream;
    struct stat statbuf;
    isc_boolean_t regular_file;
    char *path;

    REQUIRE(channel->type == ISC_LOG_TOFILE);
    REQUIRE(FILE_STREAM(channel) == NULL);

    path = FILE_NAME(channel);

    REQUIRE(path != NULL && *path != '\0');

    /*
     * Determine type of file; only regular files will be
     * version renamed.
     */
    if (stat(path, &statbuf) == 0)
        regular_file = (statbuf.st_mode & S_IFREG) ?
                            ISC_TRUE : ISC_FALSE;
    else if (errno == ENOENT)
        regular_file = ISC_TRUE;
    else
        return (ISC_R_INVALIDFILE);

    /*
     * Version control.
     */
    if (regular_file)
        if (roll_log(channel) != ISC_R_SUCCESS)
            return (ISC_R_INVALIDFILE);
    /* XXXDCL if not regular_file complain? */

    stream = fopen(path, "a");
    if (stream == NULL)
        return (ISC_R_INVALIDFILE);

    FILE_STREAM(channel) = stream;

    return (ISC_R_SUCCESS);
}

static void
isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
         isc_logmodule_t *module, int level, isc_boolean_t write_once,
         const char *format, va_list args)
{
    int syslog_level;
    char time_string[64];
    char level_string[24];
    struct stat statbuf;
    struct tm *timeptr;
    time_t now;
    isc_boolean_t matched = ISC_FALSE;
    isc_logconfig_t *lcfg;
    isc_logchannel_t *channel;
    isc_logchannellist_t *category_channels;
    isc_result_t result;

    REQUIRE(lctx == NULL || VALID_CONTEXT(lctx));

    /*
     * 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.
     */
    if (lctx == NULL)
        return;

    REQUIRE(category != NULL && category->id < lctx->category_count);
    REQUIRE(module != NULL && module->id < lctx->module_count);
    REQUIRE(level != ISC_LOG_DYNAMIC);
    REQUIRE(format != NULL);

    time_string[0] = '\0';
    level_string[0] = '\0';
    lctx->buffer[0] = '\0';

    LOCK(&lctx->lock);

    lcfg = lctx->logconfig;

    category_channels = ISC_LIST_HEAD(lcfg->channellists[category->id]);

    /*
     * 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.
         */
        if (category_channels == NULL && matched)
            break;

        if (category_channels == NULL && ! matched &&
            category_channels != ISC_LIST_HEAD(lcfg->channellists[0]))
            /*
             * No category/module pair was explicitly configured.
             * Try the category named "default".
             */
            category_channels =
                ISC_LIST_HEAD(lcfg->channellists[0]);

        if (category_channels == NULL && ! matched)
            /*
             * No matching module was explicitly configured
             * for the category named "default".  Use the internal
             * default channel.
             */
            category_channels = &default_channel;

        if (category_channels->module != NULL &&
            category_channels->module != module) {
            category_channels = ISC_LIST_NEXT(category_channels,
                              link);
            continue;
        }

        matched = ISC_TRUE;

        channel = category_channels->channel;
        category_channels = ISC_LIST_NEXT(category_channels, link);

        if (((channel->flags & ISC_LOG_DEBUGONLY) > 0) &&
            lctx->debug_level == 0)
            continue;

        if (channel->level == ISC_LOG_DYNAMIC) {
            if (lctx->debug_level < level)
                continue;
        } else if (channel->level < level)
            continue;

        if ((channel->flags & ISC_LOG_PRINTTIME) &&
            time_string[0] == '\0') {
            time(&now);

            timeptr = localtime(&now);

            /*
             * Emulate syslog's time format.
             * XXXDCL it would be nice if format were configurable.
             */
            strftime(time_string, sizeof(time_string),
                 "%b %d %X ", timeptr);
        }

        if ((channel->flags & ISC_LOG_PRINTLEVEL) &&
            level_string[0] == '\0') {
            if (level < ISC_LOG_CRITICAL)
                sprintf(level_string, "level %d: ", level);
            else if (level > ISC_LOG_DYNAMIC)
                sprintf(level_string, "%s %d: ",
                    log_level_strings[0], level);
            else
                sprintf(level_string, "%s: ",
                    log_level_strings[-level]);
        }

        /*
         * Only format the message once.
         */
        if (lctx->buffer[0] == '\0') {
            (void)vsnprintf(lctx->buffer, sizeof(lctx->buffer),
                    format, args);

            /*
             * Check for duplicates.
             */
            if (write_once) {
                isc_logmessage_t *message, *new;
                isc_time_t oldest;
                isc_interval_t interval;

                isc_interval_set(&interval,
                         lcfg->duplicate_interval, 0);

                /*
                 * 'oldest' is the age of the oldest messages
                 * which fall within the duplicate_interval
                 * range.
                 */
                if (isc_time_now(&oldest) != ISC_R_SUCCESS)
                    message = NULL;
                else
                    isc_time_subtract(&oldest, &interval,
                              &oldest);

                message = ISC_LIST_HEAD(lctx->messages);
                while (message != NULL) {
                    if (isc_time_compare(&message->time,
                                 &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.
                         */
                        new = ISC_LIST_NEXT(message,
                                    link);

                        ISC_LIST_UNLINK(lctx->messages,
                                message, link);

                        isc_mem_put(lctx->mctx,
                            message,
                            sizeof(*message) + 1 +
                            strlen(message->text));

                        message = new;
                        continue;
                    }

                    /*
                     * This message is in the duplicate
                     * filtering interval ...
                     */
                    if (strcmp(lctx->buffer, message->text)
                        == 0) {
                        /*
                         * ... and it is a duplicate.
                         * Unlock the mutex and
                         * get the hell out of Dodge.
                         */
                        UNLOCK(&lctx->lock);
                        return;
                    }

                    message = ISC_LIST_NEXT(message, link);
                }

                /*
                 * It wasn't in the duplicate interval,
                 * so add it to the message list.
                 */
                new = isc_mem_get(lctx->mctx,
                          sizeof(isc_logmessage_t) +
                          strlen(lctx->buffer) + 1);
                if (new != NULL) {
                    /*
                     * Put the text immediately after
                     * the struct.  The strcpy is safe.
                     */
                    new->text = (char *)(new + 1);
                    strcpy(new->text, lctx->buffer);

                    if (isc_time_now(&new->time) !=
                        ISC_R_SUCCESS)
                        /*
                         * This will cause the message
                         * to immediately expire on
                         * the next call to [v]write1.
                         * What's a fella to do if
                         * getting the time fails?
                         */
                           isc_time_settoepoch(&new->time);

                    ISC_LIST_APPEND(lctx->messages,
                            new, link);
                }
            }
        }

        switch (channel->type) {
        case ISC_LOG_TOFILE:
            if (FILE_STREAM(channel) == NULL) {
                result = isc_log_open(channel);
                if (result != ISC_R_SUCCESS)
                    break;
                /*
                 * Probably something more meaningful should be
                 * done with an error.
                 */
            }
            /* FALLTHROUGH */

        case ISC_LOG_TOFILEDESC:
            fprintf(FILE_STREAM(channel), "%s%s%s%s%s%s%s\n",
                (channel->flags & ISC_LOG_PRINTTIME) ?
                    time_string : "",
                (channel->flags & ISC_LOG_PRINTCATEGORY) ?
                    category->name : "",
                (channel->flags & ISC_LOG_PRINTCATEGORY) ?
                    ": " : "",
                (channel->flags & ISC_LOG_PRINTMODULE) ?
                    (module != NULL ? module->name :
                                      "no_module")
                    : "",
                (channel->flags & ISC_LOG_PRINTMODULE) ?
                    ": " : "",
                (channel->flags & ISC_LOG_PRINTLEVEL) ?
                    level_string : "",
                lctx->buffer);

            fflush(FILE_STREAM(channel));

            /*
             * If the file now exceeds its maximum size
             * threshold, close it and mark it ready
             * for reopening the next time the channel is used.
             */
            if (FILE_MAXSIZE(channel) != 0) {
                INSIST(channel->type == ISC_LOG_TOFILE);

                /* XXXDCL NT fstat/fileno */
                /* XXXDCL complain if fstat fails? */
                if (fstat(fileno(FILE_STREAM(channel)),
                      &statbuf) >= 0 &&
                    statbuf.st_size > FILE_MAXSIZE(channel)) {
                    fclose(FILE_STREAM(channel));
                    FILE_STREAM(channel) = NULL;
                }
            }

            break;

        case ISC_LOG_TOSYSLOG:
            if (level > 0)
                syslog_level = LOG_DEBUG;
            else if (level < ISC_LOG_CRITICAL)
                syslog_level = LOG_CRIT;
            else
                syslog_level = syslog_map[-level];

            syslog(FACILITY(channel) | syslog_level,
                   "%s%s%s%s%s%s%s",
                   (channel->flags & ISC_LOG_PRINTTIME) ?
                        time_string : "",
                   (channel->flags & ISC_LOG_PRINTCATEGORY) ?
                        category->name : "",
                   (channel->flags & ISC_LOG_PRINTCATEGORY) ?
                        ": " : "",
                   (channel->flags & ISC_LOG_PRINTMODULE) ?
                    (module != NULL ? module->name :
                                      "no_module")
                        : "",
                   (channel->flags & ISC_LOG_PRINTMODULE) ?
                        ": " : "",
                   (channel->flags & ISC_LOG_PRINTLEVEL) ?
                        level_string : "",
                   lctx->buffer);
            break;

        case ISC_LOG_TONULL:
            break;

        }

    } while (1);

    UNLOCK(&lctx->lock);
}