source: trunk/src/core/logger.cc @ 365

// Copyright (C) 2011-2014 ChaosForge Ltd
// This file is part of NV Libraries.
// For conditions of distribution and use, see copyright notice in nv.hh

#include "nv/core/logger.hh"

#include "nv/core/common.hh"
#include "nv/core/time.hh"
#include <cstdio>
#if NV_PLATFORM == NV_WINDOWS
#define WIN32_LEAN_AND_MEAN
#include <Windows.h>
#endif

using namespace nv;

// log level names
static const char *log_level_names[] =
{
        "NONE",
        "FATAL",
        "CRITICAL",
        "ERROR",
        "WARNING",
        "NOTICE",
        "INFO",
        "INFO",
        "DEBUG",
        "DEBUG2",
        "TRACE"
};

// log level names
static const char *log_level_names_pad[] =
{
        "NONE    ",
        "FATAL   ",
        "CRITICAL",
        "ERROR   ",
        "WARNING ",
        "NOTICE  ",
        "INFO    ",
        "INFO    ",
        "DEBUG   ",
        "DEBUG2  ",
        "TRACE   "
};

// helper macro to access log_level_names
#define NV_LOG_LEVEL_NAME(level) (log_level_names[ (level) / 10 ])
#define NV_LOG_LEVEL_NAME_PAD(level) (log_level_names_pad[ (level) / 10 ])

#if NV_PLATFORM == NV_WINDOWS 
static unsigned short log_color[] =
{
        FOREGROUND_RED | FOREGROUND_BLUE | FOREGROUND_GREEN | FOREGROUND_INTENSITY,
        FOREGROUND_RED | FOREGROUND_INTENSITY,
        FOREGROUND_RED | FOREGROUND_INTENSITY,
        FOREGROUND_RED,
        FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_INTENSITY,
        FOREGROUND_GREEN | FOREGROUND_INTENSITY,
        FOREGROUND_GREEN,
        FOREGROUND_GREEN,
        FOREGROUND_INTENSITY,
        FOREGROUND_INTENSITY,
        FOREGROUND_INTENSITY
};
#else
static const char *log_color[] =
{
        "\33[37;1m",
        "\33[31;1m",
        "\33[31;1m",
        "\33[31m",
        "\33[33;1m",
        "\33[32;1m",
        "\33[32m",
        "\33[32m",
        "\33[30;1m",
        "\33[30;1m",
        "\33[30;1m"
};
#endif

// log function
void logger::log( log_level level, const string_ref& message )
{
        for ( auto& sink_info : m_log_sinks )
        {
                if ( sink_info.sink && (sink_info.level >= (uint32)level) )
                {
                        // log and iterate
                        sink_info.sink->log( level, message );
                }
        }
}

// add a new sink
void logger::add_sink( log_sink* sink, int level )
{
        // add a sink
        for ( auto& sink_info : m_log_sinks )
        {
                if ( sink_info.sink == nullptr )
                {
                        sink_info.sink  = sink;
                        sink_info.level = (uint32)level;
                        return;
                }
        }
        NV_ASSERT( false, "ran out of log sink space!" );
}

// remove existing sink
bool logger::remove_sink( log_sink* sink )
{
        for ( auto& sink_info : m_log_sinks )
        {
                if ( sink_info.sink == sink )
                {
                        delete sink_info.sink;
                        sink_info.sink = nullptr;
                        return true;
                }
        }
        // not found, return false
        return false;
}

// destructor
logger::~logger()
{
        // delete all sinks
        for ( auto& sink_info : m_log_sinks )
        {
                delete sink_info.sink;
        }
}


// console logging
void log_console_sink::log( log_level level, const string_ref& message )
{
#if NV_PLATFORM == NV_WINDOWS 
        if ( m_color ) SetConsoleTextAttribute( m_handle, FOREGROUND_INTENSITY );
        string_ref stamp( timestamp() );
        WriteConsole( m_handle, stamp.data(), stamp.size(), nullptr, nullptr );
        WriteConsole( m_handle, " [", 2, nullptr, nullptr );
        if (m_color) SetConsoleTextAttribute( m_handle, log_color[( level ) / 10] );
        WriteConsole( m_handle, NV_LOG_LEVEL_NAME_PAD( level ), 8, nullptr, nullptr );
        if ( m_color ) SetConsoleTextAttribute( m_handle, FOREGROUND_INTENSITY );
        WriteConsole( m_handle, "] ", 2, nullptr, nullptr );
        if ( m_color ) SetConsoleTextAttribute( m_handle, FOREGROUND_INTENSITY | FOREGROUND_RED | FOREGROUND_GREEN | FOREGROUND_BLUE );
        WriteConsole( m_handle, message.data(), message.size(), nullptr, nullptr );
        WriteConsole( m_handle, "\n", 1, nullptr, nullptr );
#else
        if ( m_color ) fwrite( "\33[30;1m", 7, 1, stdout );
        fwrite( stamp.data(), stamp.size(), 1, stdout );
        fwrite( " [", 2, 1, stdout );
        if ( m_color )
        {
                const char* lcolor = log_color[( level ) / 10];
                fwrite( lcolor, strlen(lcolor), 1, stdout );
        }
        fwrite( NV_LOG_LEVEL_NAME_PAD( level ), 8, 1, stdout );
        if ( m_color )
                fwrite( "\33[30;1m] \33[37;1m", 16, 1, stdout );
        else
                fwrite( "] ", 2, 1, stdout );
        fwrite( stamp.data(), stamp.size(), 1, stdout );
        fwrite( "\n", 1, 1, stdout );
#endif
}

// handle logging
void log_handle_sink::log( log_level level, const string_ref& message )
{
        string_ref stamp( timestamp() );
#if 0 // NV_PLATFORM == NV_WINDOWS
        // Turns out WriteFile on Windows is unbuffered and quite slower than fwrite 
        // due to this fact -- especially UNUSABLE with manual FlushFileBuffers
        // If we want to get rid of C runtime, this would need a buffered I/O layer.
        DWORD unused = 0;
        WriteFile( m_handle, stamp.data(), stamp.size(), &unused, nullptr );
        WriteFile( m_handle, " [", 2, &unused, nullptr );
        WriteFile( m_handle, NV_LOG_LEVEL_NAME_PAD( level ), 8, &unused, nullptr );
        WriteFile( m_handle, "] ", 2, &unused, nullptr );
        WriteFile( m_handle, message.data(), message.size(), &unused, nullptr );
        WriteFile( m_handle, "\n", 1, &unused, nullptr );
        //if ( m_flush ) FlushFileBuffers( m_handle );
#else
        fwrite( stamp.data(), stamp.size(), 1, (FILE*)m_handle );
        fwrite( " [", 2, 1, (FILE*)m_handle );
        fwrite( NV_LOG_LEVEL_NAME_PAD( level ), 8, 1, (FILE*)m_handle );
        fwrite( "] ", 2, 1, (FILE*)m_handle );
        fwrite( message.data(), message.size(), 1, (FILE*)m_handle );
        fwrite( "\n", 1, 1, (FILE*)m_handle );
        if ( m_flush ) fflush( (FILE*)m_handle );
#endif
}

nv::log_file_sink::log_file_sink( const string_ref& file_name, bool flush_always /*= true */ )
        : log_handle_sink( nullptr, flush_always )
{
#if 0 // NV_PLATFORM == NV_WINDOWS
        // See comments in log_handle_sink
        HANDLE handle = CreateFile( file_name.data(), GENERIC_WRITE, 0, nullptr, CREATE_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr );
        if ( INVALID_HANDLE_VALUE == handle )
        {
                NV_ASSERT( false, "invalid log handle" );
        }
        m_handle = handle;
#else
        m_handle = fopen( file_name.data(), "w" );
#endif
}

nv::log_file_sink::~log_file_sink()
{
#if 0 // NV_PLATFORM == NV_WINDOWS
        // See comments in log_handle_sink
        CloseHandle( m_handle );
#else
        fclose( (FILE*) m_handle );
#endif
}


nv::log_console_sink::log_console_sink( bool coloring )
        : m_color( coloring )
{
#if NV_PLATFORM == NV_WINDOWS 
        m_handle = GetStdHandle( STD_OUTPUT_HANDLE );
#else
  NV_UNUSED( m_handle );
#endif
}

string_ref nv::log_sink::timestamp() const
{
        uint32 ms = get_system_ms();
        unsigned int secs = (unsigned int)(ms / 1000);
        unsigned int mm   = (unsigned int)( ms * 100 / 1000 ) % 100;
        unsigned int h    = (unsigned int)(secs / (60*60));
        unsigned int m    = (unsigned int)(secs / 60) % 60;
        unsigned int s    = secs % 60;
        static char buffer[16];
#if NV_PLATFORM == NV_WINDOWS 
        sprintf_s( buffer, 16, "%02d:%02d:%02d.%02d", h, m, s, mm );
#else
        snprintf( buffer, 16, "%02d:%02d:%02d.%02d", h, m, s, mm );
#endif
        buffer[11] = '\0';
        return string_ref( buffer, 10 );
}

string_ref nv::log_sink::level_name( log_level level ) const
{
        return NV_LOG_LEVEL_NAME( level );
}

string_ref nv::log_sink::padded_level_name( log_level level ) const
{
        return string_ref( NV_LOG_LEVEL_NAME_PAD( level ), 8 );
}