src/server/daemon/log.c

/*
 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS HEADER.
 *
 * Copyright 2013 Olaf Wintermann. All rights reserved.
 *
 * Redistribution and use in source and binary forms, with or without
 * modification, are permitted provided that the following conditions are met:
 *
 *   1. Redistributions of source code must retain the above copyright
 *      notice, this list of conditions and the following disclaimer.
 *
 *   2. Redistributions in binary form must reproduce the above copyright
 *      notice, this list of conditions and the following disclaimer in the
 *      documentation and/or other materials provided with the distribution.
 *
 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
 * AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
 * ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
 * LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
 * CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
 * SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
 * INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
 * CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
 * ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
 * POSSIBILITY OF SUCH DAMAGE.
 */

#ifdef __gnu_linux__
#define _GNU_SOURCE
#endif

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <aio.h>
#include <time.h>
#include <pthread.h>

#include "log.h"
#include "../util/strbuf.h"
#include "../util/io.h"
#include "../util/atomic.h"

#include <cx/hash_map.h>
#include <cx/linked_list.h>
#include <cx/compare.h>

static int is_initialized = 0;

static int log_file_fd;
static int log_level = 0;

static uint32_t log_dup_count = 0;
static CxList *log_dup_list = NULL;
static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER;

WSBool main_is_daemon(void);

/*
 * if the log file is uninitialized, output is written to the ui_buffer
 */
static sbuf_t *ui_buffer = NULL;

/*
 * access log file map
 */
static CxMap *access_log_files; // map of LogFile*


static char *log_date_month[] = {
    "Jan",
    "Feb",
    "Mar",
    "Apr",
    "May",
    "Jun",
    "Jul",
    "Aug",
    "Sep",
    "Oct",
    "Nov",
    "Dec"
};

static const char *log_levels[] = {
    "warning",
    "config",
    "security",
    "failure",
    "catastrophe",
    "info",
    "verbose",
    "debug"
};

static int can_log[] = {
    1, // warning
    1, // config
    1, // security
    1, // failure
    1, // catastrophe
    1, // info
    0, // verbose
    0  // debug
};

int init_log_file(LogConfig *cfg) {
    if(is_initialized) {
        return 0;
    }
    
    log_dup_list = cxPointerLinkedListCreate(cxDefaultAllocator, cx_cmp_ptr);
    
    /* open the log file */
    mode_t mode = S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH;
    log_file_fd = open(cfg->file, O_WRONLY | O_CREAT | O_APPEND, mode);
    if(log_file_fd == -1) {
        log_ereport(LOG_FAILURE, "Cannot open log file %s: %s", cfg->file, strerror(errno));
        return -1;
    }
    
    if(!strcmp(cfg->level, "ERROR")) {
        can_log[LOG_WARN] = 0;
        can_log[LOG_INFORM] = 0;
    } else if(!strcmp(cfg->level, "WARNING")) {
        can_log[LOG_INFORM] = 0;
    } else if(!strcmp(cfg->level, "VERBOSE")) {
        can_log[LOG_VERBOSE] = 1;
    } else if(!strcmp(cfg->level, "DEBUG")) {
        can_log[LOG_VERBOSE] = 1;
        can_log[LOG_DEBUG] = 1;
    }
    
    if(cfg->log_stdout) {
        // TODO
    }
    if(cfg->log_stderr) {
        // TODO
    }
    
    
    is_initialized = 1;
    
    /* if ui_buffer is not NULL, write it to the log file */
    if(ui_buffer) {
        size_t len = ui_buffer->length;
        size_t r;
        while(len > 0) {
            r = write(log_file_fd, ui_buffer->ptr, ui_buffer->length);
            len -= r;
        }
        
        sbuf_free(ui_buffer);
    }
    
    return 0;
}

void log_uninitialized_writeln(char *str, size_t len) {
    printf("%.*s\n", (int)len, str);
    
    if(ui_buffer == NULL) {
        ui_buffer = sbuf_new(1024);
        if(ui_buffer == NULL) {
            return; /* TODO: critical error, exit */
        }
    }
    
    cxstring s;
    s.ptr = str;
    s.length = len;
    
    sbuf_append(ui_buffer, s);
    sbuf_put(ui_buffer, '\n');
}

void log_file_writeln(char *str, size_t len) { 
    struct iovec io[] = {
        { str, len },
        { "\n", 1}
    };
    
    WSBool write_to_stdout = !main_is_daemon();
    if(is_initialized) {
        writev(log_file_fd, io, 2); /* TODO: aio? */
    } else {
        write_to_stdout = TRUE;
        log_uninitialized_writeln(str, len);
    }
    
    if(write_to_stdout) {
        writev(STDOUT_FILENO, io, 2);
    }
    
    if(log_dup_count > 0) {
        char *msg = malloc(len + 1);
        memcpy(msg, str, len);
        msg[len] = '\n';
        
        pthread_mutex_lock(&mutex);
        CxIterator i = cxListIterator(log_dup_list, 0);
        cx_foreach(LogDup *, dup, i) {
            dup->write(dup->cookie, msg, len + 1);
        }        
        pthread_mutex_unlock(&mutex);
        
        free(msg);
    }
}

cxmutstr log_get_prefix_str(const char *level) {
    time_t t = time(NULL);
    
    cxmutstr d;
    d.ptr = NULL;
    d.length = 0;
    
    struct tm date;
    localtime_r(&t, &date);
    
    char *buf = malloc(64);
    int len = snprintf(
            buf,
            64,
            "[%02d/%s/%d:%02d:%02d:%02d] %s : ",
            date.tm_mday,
            log_date_month[date.tm_mon],
            1900 + date.tm_year,
            date.tm_hour,
            date.tm_min,
            date.tm_sec,
            level);
    
    if(len > 0) {
        d.ptr = buf;
        d.length = len;
    }
    
    return d;
}

cxmutstr log_get_prefix(int level) {
    return log_get_prefix_str(log_levels[level]);
}

void log_add_logdup(LogDup *dup) {
    pthread_mutex_lock(&mutex);  
    cxListAdd(log_dup_list, dup);
    ws_atomic_inc32(&log_dup_count);   
    pthread_mutex_unlock(&mutex);
}

void log_remove_logdup(LogDup *ldup) {
    pthread_mutex_lock(&mutex);
    CxMutIterator i = cxListMutIterator(log_dup_list, 0);
    WSBool finished = 0;
    cx_foreach(LogDup *, dup, i) {
        if(finished) break;
        if(dup == ldup) {
            cxIteratorFlagRemoval(i);
            finished = 1;
            ws_atomic_dec32(&log_dup_count);
        }
    }
    pthread_mutex_unlock(&mutex);
}


/*
 * log api functions
 */

int log_ereport(int degree, const char *format, ...) {
    va_list args;
    va_start(args, format);
    int ret = log_ereport_v(degree, format, args);
    va_end(args);
    return ret;
}

int log_ereport_v(int degree, const char *format, va_list args) { 
    if(degree < 0 || degree > 7) {
        return 0;
    }
    if(!can_log[degree]) {
        return 0;
    }
    
    cxmutstr lmsg;
    lmsg.ptr = NULL;
    
    /* create log message prefix */
    cxmutstr lpre = log_get_prefix(degree); 
    
    /* format message */
    int len = vasprintf(&lmsg.ptr, format, args);
    lmsg.length = len;
    
    /* create message string */
    cxmutstr message = cx_strcat(2, lpre, lmsg);
    
    /* write message to the log file */ 
    log_file_writeln(message.ptr, message.length);
    
    /* cleanup */
    free(lmsg.ptr);
    free(lpre.ptr);
    free(message.ptr);
    
    return 0;
}

int log_error(int degree, const char *func, Session *sn, Request *rq,
                       const char *format, ...)
{
    va_list args;
    va_start(args, format);
    int ret = log_error_v(degree, func, sn, rq, format, args);
    va_end(args);
    return ret;
}

int log_error_v(int degree, const char *func, Session *sn, Request *rq,
                       const char *format, va_list args)
{
    // TODO: implement
    return log_ereport(degree, format, args);
}

int log_message(const char *degree, const char *format, ...) {
    va_list args;
    va_start(args, format);
    int ret = log_message_v(degree, format, args);
    va_end(args);
    return ret;
}

int log_message_v(const char *degree, const char *format, va_list args) {
    cxmutstr lmsg;
    lmsg.ptr = NULL;
    
    cxmutstr lpre = log_get_prefix_str(degree); 
    
    /* format message */
    int len = vasprintf(&lmsg.ptr, format, args);
    lmsg.length = len;
    
    /* create message string */
    cxmutstr message = cx_strcat(2, lpre, lmsg);
    
    /* write message to the log file */ 
    log_file_writeln(message.ptr, message.length);
    
    /* cleanup */
    free(lmsg.ptr);
    free(lpre.ptr);
    free(message.ptr);
    
    return 0;
}


void ws_log_assert(const char *file, const char *func, int line) {
    log_ereport(
            LOG_CATASTROPHE,
            "assertion failed: %s: %s:%d",
            file,
            func,
            line);
    exit(-1);
}


/*
 * access log
 * This source file only manages access log files. IO is performed directly
 * by AddLog safs. 
 */
LogFile* get_access_log_file(cxstring file) {
    // TODO: this looks dubious
    
    if(!access_log_files) {
        access_log_files = cxHashMapCreate(cxDefaultAllocator, 4);
    }
    
    if(file.ptr == NULL || file.length == 0) {
        return NULL;
    }
    
    CxHashKey key = cx_hash_key_bytes((unsigned const char*)file.ptr, file.length);
    LogFile *log = cxMapGet(access_log_files, key);
    if(log != NULL) {
        ws_atomic_inc32(&log->ref);
        return log;
    }
    
    // the log file is not opened
    // check first if we can open it
    FILE *out = fopen(file.ptr, "a");
    if(out == NULL) {
        return NULL;
    }
    
    // create LogFile object
    log = calloc(1, sizeof(LogFile));
    log->file = out;
    log->ref = 1;
    
    // add access log to the map
    cxMapPut(access_log_files, key, log);
    
    return log;
}