libucore/src/logging.c

#include <pthread.h>
#include <unistd.h>
#include <stdarg.h>
#include <stdlib.h>
#include <string.h>
#include <limits.h>
#include <stdio.h>
#include <errno.h>
#include <syslog.h>
#include <sys/queue.h>
#include "ucore/tailq.h"
#include "ucore/logging.h"
#include "ucore/utils.h"

/** Max suffixes we'll try to apply to a log file when rotating before 
 * giving up
 */
#define UC_MAX_RENAME_CNT (128)

//used to realise per destination settings
struct UCLogModule_setting {
    int log_level;
};

struct UCLogDestination {
    struct TailQ entry;
    enum UC_LOG_DESTINATION dest_type;
    //log level for this destination
    int log_level;
    //Whether to log the source file name and line number 
    int log_location;
    struct UCLogModule_setting *module_settings;
    union {
        //for syslog openlog()
        struct {
            char *ident; 
            int facility; 
        } syslog;
        //for stderr and files
        struct {
            FILE* file; 
            char *file_name; //NULL for stderr destinaton. If rotate policy is in place
                             //this is the base file name (e.g. witout a date or count)
            size_t size; //keeps track of no of bytes written
            struct UCLogRotateSettings rotate;
        } file;
    } type;
};

/* Helper struct for arguments to our main logging function */
struct UCLogArgs {
    struct UCLogDestination *dest;
    const struct UCLogModule *module;
    int log_level;
    const char *location;
    int raw;
};


//Global lock for the logging system, as logging could be performed from any thread. All operations must grab
//this lock before accessing any the global data.
static pthread_mutex_t g_log_lock = PTHREAD_MUTEX_INITIALIZER;

static struct UCLogModules g_modules;

static const struct UCLogModule g_unknown_module = {
    .id = -1,
    .short_name = "UNKNOWN",
    .long_name = "Unknown log module",
    .log_level = UC_LL_DEBUG,
};


//All destinations. The g_log_lock must be held while accessing
//this list an anything contained within it.
static UC_TAILQ_HEAD(g_destinations);
static int uc_log_reopen_file(struct UCLogDestination *dest);
//Uses enum UC_LOG_LEVEL as index
static const char *const g_log_levels[] = {
    "UNKNOWN_0",
    "DEBUG",
    "UNKNOWN_2",
    "INFO",
    "UNKNOWN_4",
    "WARNING",
    "UNKNOWN_6",
    "ERROR",
    "UNKNOWN_8",
    "NONE"
};

const char *uc_ll_2_str(enum UC_LOG_LEVEL l)
{
    if (l < ARRAY_SIZE(g_log_levels)) {
        return g_log_levels[l];
    } else {
        return "???";
    }
}

//returns  if the string is not a known log level
static int uc_str_2_ll(const char *str, size_t len)
{
    size_t i;

    for (i = 0; i < ARRAY_SIZE(g_log_levels); i++) {
        if (strncasecmp(str, g_log_levels[i], len) == 0) {
            return (int)i;
        }
    }

    return -1;
}

static inline int uc_ll_2_syslog(enum UC_LOG_LEVEL l)
{
    switch(l) {
        case UC_LL_DEBUG:
            return LOG_DEBUG;
        case UC_LL_INFO:
            return LOG_INFO;
        case UC_LL_WARNING:
            return LOG_WARNING;
        case UC_LL_ERROR:
            return LOG_ERR;
        case UC_LL_NONE:
            return LOG_CRIT; //Fishy, but this should never happen
        
    }

    return LOG_INFO;
}

//Note, this grabs the global lock
static int uc_log_init_common(struct UCLogDestination *dest)
{
    int i;
    int rc = -1;
    
    //copy over the log_level_settings
    pthread_mutex_lock(&g_log_lock);

    dest->module_settings = calloc(g_modules.cnt, sizeof *dest->module_settings);
    if (dest->module_settings != NULL) {
        for (i = 0; i < g_modules.cnt; i++) {
            dest->module_settings[i].log_level = g_modules.mods[i].log_level;
        }

        rc = 0;
    }

    pthread_mutex_unlock(&g_log_lock);

    uc_tailq_init(&dest->entry);

    return rc;
}

struct UCLogDestination *uc_log_new_stderr(int log_level, int log_location)
{
    struct UCLogDestination *dest = calloc(1, sizeof *dest);

    if(dest == NULL)
        return NULL;

    if (uc_log_init_common(dest) != 0) {
        free(dest);
        return NULL;
    }
    
    dest->dest_type = UC_LDEST_STDERR;
    dest->type.file.file = stderr;
    dest->type.file.size = 0;
    dest->log_level = log_level;;
    dest->log_location = log_location;

   return dest;
}

struct UCLogDestination *uc_log_new_syslog(const char *ident, int facility, int log_level, int log_location)
{
    struct UCLogDestination *dest = calloc(1, sizeof *dest);
    char *id;

    if (dest == NULL)
        return NULL;

    if (uc_log_init_common(dest) != 0) {
        free(dest);
        return NULL;
    }

    //copy the ident - though it's unused inside the struct for now
    id = strdup(ident);
    if (id == NULL) {
        free(dest->module_settings);
        free(dest);
        return NULL;
    }

   openlog(ident, LOG_NDELAY | LOG_PID, facility);

   dest->dest_type = UC_LDEST_SYSLOG;
   dest->type.syslog.ident = id;
   dest->type.syslog.facility = facility;
   dest->log_level = log_level;;
   dest->log_location = log_location;

   return dest;
}

struct UCLogDestination *uc_log_new_file(const char *filename, int log_level, int log_location)
{
    struct UCLogDestination *dest = calloc(1, sizeof *dest);
    FILE *f;
    char *name;

    if (dest == NULL)
        return NULL;

    if (uc_log_init_common(dest) != 0) {
        free(dest);
        return NULL;
    }

    name = strdup(filename);
    if (name == NULL) {
       free(dest->module_settings);
       free(dest);
       return NULL;
    }

    f = fopen(filename, "a"); 
    if (f == NULL) {
       int saved_errno = errno; 
       free(dest->module_settings);
       free(name);
       free(dest);
       errno = saved_errno;
       return NULL;
    }

    dest->dest_type = UC_LDEST_FILE;
    dest->type.file.file = f;
    dest->type.file.file_name = name;
    dest->type.file.size = 0;
    dest->log_level = log_level;;
    dest->log_location = log_location;

    dest->type.file.rotate.policy = UC_LOG_ROTATE_NONE;

   return dest;
}

//Check if a destination already exists (hold g_log_lock when calling this)
static int uc_log_dest_exists(struct UCLogDestination *dest)
{
    struct UCLogDestination *it;

    UC_TAILQ_FOREACH_CONTAINER(it, entry, &g_destinations) {
        if (dest == it) {
            return 1;
        }
    }

    return 0;
}

void uc_log_add_destination(struct UCLogDestination *dest)
{
    int exists;

    if (dest == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    exists = uc_log_dest_exists(dest);
    //add if it isn't already in the list
    if (!exists) {
        uc_tailq_insert_head(&g_destinations, &dest->entry);
    }

    pthread_mutex_unlock(&g_log_lock);
}

//hold g_log_lock while calling this.
static inline void uc_log_remove_dest(struct UCLogDestination *dest)
{
    int exists;

    //check that it's not already removed
    exists = uc_log_dest_exists(dest);

    if (exists) {
        uc_tailq_remove(&dest->entry);
    }
}

void uc_log_remove_destination(struct UCLogDestination *dest)
{
    if (dest == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    uc_log_remove_dest(dest);

    pthread_mutex_unlock(&g_log_lock);
}

void uc_log_delete_destination(struct UCLogDestination *dest)
{
    if (dest == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    //remove it, it's ok if the destination is already removed
    uc_log_remove_dest(dest);

    //clean up, according to the type
    switch (dest->dest_type) {
        case UC_LDEST_SYSLOG:
            free(dest->type.syslog.ident);
            closelog();
            break;
        case UC_LDEST_STDERR: //nothing to do
            break; 
        case UC_LDEST_FILE:
            if(dest->type.file.file != NULL) {
                fclose(dest->type.file.file);
                dest->type.file.file = NULL;
            }

            free(dest->type.file.file_name);
            break;
    }
    free(dest->module_settings);

    free(dest);

    pthread_mutex_unlock(&g_log_lock);
}

void uc_log_destination_set_loglevel(struct UCLogDestination *dest, enum UC_LOG_LEVEL level)
{
    if (dest == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    dest->log_level = level;

    pthread_mutex_unlock(&g_log_lock);
}

void uc_log_destination_set_log_location(struct UCLogDestination *dest, int log_location)
{
    if (dest == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    dest->log_location = log_location;

    pthread_mutex_unlock(&g_log_lock);
}

void uc_log_destination_set_rotate_policy(struct UCLogDestination *dest, 
                                          const struct UCLogRotateSettings *settings)
{

    if (dest->dest_type != UC_LDEST_FILE) {
        return;
    }

    if (settings->policy != UC_LOG_ROTATE_NONE && settings->policy != UC_LOG_ROTATE_SIZE) {
        return;
    }

    pthread_mutex_lock(&g_log_lock);

    dest->type.file.rotate = *settings;
    if (dest->type.file.rotate.size_settings.num_files == 0) {
        dest->type.file.rotate.size_settings.num_files = 1;
    }

    pthread_mutex_unlock(&g_log_lock);

}

//hold g_log_lock while calling this
static int uc_log_reopen_file(struct UCLogDestination *dest)
{
    int rc = 0;

    if (dest == NULL)
        return -1;

    if (dest->type.file.file != NULL) {
        fclose(dest->type.file.file);
        dest->type.file.file = NULL;
    }

    if (dest->type.file.file_name != NULL) {
        dest->type.file.file = fopen(dest->type.file.file_name, "a");

        if (dest->type.file.file == NULL)
            rc = errno;
    }

    return rc;
}

int uc_log_reopen_files(void)
{
    struct UCLogDestination *dest;
    int rc = 0;

    pthread_mutex_lock(&g_log_lock);

    UC_TAILQ_FOREACH_CONTAINER(dest, entry, &g_destinations) {

        if (dest->dest_type == UC_LDEST_FILE) {
            rc = uc_log_reopen_file(dest);
            if (rc == 0) {
                dest->type.file.size = 0;
            }
        }
    }

    pthread_mutex_unlock(&g_log_lock);

    return rc;
}

void uc_log_init(struct UCLogModules *user_modules)
{
    g_modules = *user_modules;
}

//hold g_log_lock while calling this
static inline void uc_vlog_file(const struct UCLogArgs *args, time_t tstamp, const char *fmt, va_list ap)
{
    struct UCLogDestination *dest = args->dest;
    char time_buf[48];
    struct tm t;
    int rc = 0;

    if (dest->type.file.file == NULL)
        return;

    localtime_r(&tstamp, &t);
    if (!args->raw) {
        snprintf(time_buf, sizeof time_buf, "%04d-%02d-%02d %02d:%02d:%02d",
                                            t.tm_year + 1900,
                                            t.tm_mon + 1,
                                            t.tm_mday,
                                            t.tm_hour,
                                            t.tm_min,
                                            t.tm_sec);

        time_buf[sizeof time_buf -1] = 0;

        if (dest->log_location) {
            rc = fprintf(dest->type.file.file, "[%-7s] %s %s [%s] : ", 
                    uc_ll_2_str(args->log_level), time_buf, 
                    args->location, args->module->short_name);
        } else {
            rc = fprintf(dest->type.file.file, "[%-7s] %s [%s]: ", 
                uc_ll_2_str(args->log_level), time_buf, args->module->short_name);
        }
    }

    if (rc >= 0) {
        dest->type.file.size += rc;
        rc = vfprintf(dest->type.file.file, fmt, ap);
    }

    if (rc >= 0) {
        dest->type.file.size += rc;
        rc = fflush(dest->type.file.file); //strictly not needed for stderr
                                           // though stderr could be redirected to a file
    }
}

//hold g_log_lock while calling this
static inline void uc_vlog_syslog(const struct UCLogArgs *args, const char *fmt, va_list ap)
{
    struct UCLogDestination *dest = args->dest;
    
    int pri = uc_ll_2_syslog(args->log_level);


    if (!args->raw) {
        //go via a buffer as we must do just 1 syslog call
        char buf[4096];
        int offset = 0;
        int rc;

        buf[0] = 0;
        if (dest->log_location) {
            rc = snprintf(buf, sizeof buf, "%s ", args->location);
            if (rc < 0)
                goto log;
            offset += rc;
        }

        rc = snprintf(&buf[offset], sizeof buf - (size_t)offset, "[%s] ", 
                        args->module->short_name);
        if (rc < 0)
            goto log;
        offset +=rc;

log:
        vsnprintf(&buf[offset], sizeof buf - (size_t)offset, fmt, ap);
        syslog(pri, "%s", buf);

    } else { //raw logging

        vsyslog(pri, fmt, ap);

    }
}

void uc_log_destination_set_module_loglevel(
    struct UCLogDestination *dest, 
    int module,
    enum UC_LOG_LEVEL log_level
)
{
    if (dest == NULL) 
        return;

    pthread_mutex_lock(&g_log_lock);

    if (module >= 0 && module < g_modules.cnt)
        dest->module_settings[module].log_level = log_level;

    pthread_mutex_unlock(&g_log_lock);
}


void uc_log_destination_set_mask(
    struct UCLogDestination *dest, 
    const char *log_mask
)
{
    size_t module_len;

    if (dest == NULL || log_mask == NULL)
        return;

    pthread_mutex_lock(&g_log_lock);

    while ((module_len = strcspn(log_mask, "=")) != 0) {
        int i;
        int level_len;
        const char *level_str;
        int log_level;
        const char *module_str = log_mask;

        log_mask += module_len;
        if (log_mask[0] == '=')
            log_mask++;
        
        level_len = strcspn(log_mask, ":");
        if (level_len == 0)
            continue;

        level_str = log_mask;
        log_mask += level_len;
        if (log_mask[0] == ':')
            log_mask++;

        log_level = uc_str_2_ll(level_str, level_len);
        if (log_level == -1) 
            continue;

        for (i = 0; i < g_modules.cnt; i++) {
            size_t short_name_len;;

            if (g_modules.mods[i].short_name == NULL) 
                continue;

            short_name_len = strlen(g_modules.mods[i].short_name);
            module_len = UC_MAX(module_len, short_name_len);

            if (strncasecmp(g_modules.mods[i].short_name, 
                            module_str, module_len) == 0) {
                dest->module_settings[i].log_level = log_level;
            }
        }
    }

    pthread_mutex_unlock(&g_log_lock);
}

//assumes the destination is a UC_LDEST_FILE
//hold g_log_lock while calling this
static void uc_log_file_rotate_size(struct UCLogDestination *dest)
{
    char new_filename[_POSIX_PATH_MAX * 2];
    char old_filename[_POSIX_PATH_MAX * 2];
    unsigned int i;
    int rc;

    if (dest->type.file.file_name == NULL) {
        return;
    }

    //rotate existing .num files
    i = dest->type.file.rotate.size_settings.num_files -1;
    while (i > 0) {
        snprintf(new_filename, sizeof new_filename, "%s.%d", dest->type.file.file_name, i);
        snprintf(old_filename, sizeof old_filename, "%s.%d", dest->type.file.file_name, i - 1);
        rename(old_filename, new_filename);
        i--;
    }

    //rename current file
    sprintf(new_filename, "%s.0", dest->type.file.file_name);
    rename(dest->type.file.file_name, new_filename);

    //re-open current file
    rc = uc_log_reopen_file(dest); 
    if (rc == 0) {
        dest->type.file.size = 0;
    }

    return;
}

//assumes the destination is a UC_LDEST_FILE
//hold g_log_lock while calling this
static inline void uc_log_file_rotate_if_neeed(struct UCLogDestination *dest, time_t tstamp)
{
    struct UCLogRotateSettings *rotate = &dest->type.file.rotate;

    switch (rotate->policy) {
        case UC_LOG_ROTATE_NONE:
        //Nothing to do
            break;
        case UC_LOG_ROTATE_SIZE:
            if (dest->type.file.size >= rotate->size_settings.max_size) {
                uc_log_file_rotate_size(dest);
            }
            break;
    }
}

void uc_logf(int log_level, int module, int raw, 
    const char *location, const char *fmt, ...)
{
    va_list ap;
    struct UCLogDestination *dest;

    va_start(ap, fmt);

    pthread_mutex_lock(&g_log_lock);
    
    //do logging for each destination
    UC_TAILQ_FOREACH_CONTAINER(dest, entry, &g_destinations) {
        const struct UCLogModule *log_module;
        va_list apc;
        int module_log_level;


        //destnation level
        if (log_level < dest->log_level)
            continue;

        //Find the module doing the logging, or use the unknown module - 
        //the latter would indicate a bug somewhere in the application as it should
        //always specify a known module
        if (module >= 0 && module < g_modules.cnt) {
            module_log_level = dest->module_settings[module].log_level;
            log_module = &g_modules.mods[module];
        } else {
            log_module = &g_unknown_module;
            module_log_level = log_module->log_level;
        }

        if (log_level < module_log_level)
            continue;

        const struct UCLogArgs args = {
            .dest = dest,
            .module = log_module,
            .log_level = log_level,
            .location = location,
            .raw = raw
        }; 

        time_t tstamp;
        //log func will mess with the va_list,
        //so make a copy
        va_copy(apc, ap);

        switch (dest->dest_type) {
            case UC_LDEST_SYSLOG:
                uc_vlog_syslog(&args, fmt, apc);
                break;
            case UC_LDEST_STDERR:
                tstamp = time(NULL);
                uc_vlog_file(&args, tstamp,fmt, apc);
                break;
            case UC_LDEST_FILE:
                tstamp = time(NULL);
                uc_vlog_file(&args, tstamp, fmt, apc);
                uc_log_file_rotate_if_neeed(dest, tstamp);
                break;
        }

        va_end(apc);
    }

    pthread_mutex_unlock(&g_log_lock);
    va_end(ap);
}