source: trunk/src/core/logger.cc

// Copyright (C) 2011-2017 ChaosForge Ltd
// http://chaosforge.org/
//
// This file is part of Nova libraries. 
// For conditions of distribution and use, see copying.txt file in root folder.

#include "nv/core/logger.hh"

#include "nv/core/time.hh"
#include <cstdio>
#if NV_COMPILER == NV_MSVC 
#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_COMPILER == NV_MSVC 
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_view& message )
{
        for ( auto& sink_info : m_log_sinks )
        {
                if ( sink_info.sink && (sink_info.level >= static_cast<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 = static_cast<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_view& message )
{
        char stamp[16];
        uint32 ssize = timestamp( stamp );

#if NV_COMPILER == NV_MSVC 
        if ( m_color ) SetConsoleTextAttribute( m_handle, FOREGROUND_INTENSITY );
        WriteConsole( m_handle, stamp, ssize, 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, ssize, 1, stdout );
        fwrite( " [", 2, 1, stdout );
        if ( m_color )
        {
                const char* lcolor = log_color[( level ) / 10];
                fwrite( lcolor, nvstrlen(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( message.data(), message.size(), 1, stdout );
        fwrite( "\n", 1, 1, stdout );
#endif
}

// handle logging
void log_handle_sink::log( log_level level, const string_view& message )
{
        char stamp[16];
        uint32 ssize = timestamp( stamp );
#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, ssize, &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
        FILE* file = static_cast<FILE*>( m_handle );
        fwrite( stamp, ssize, 1, file );
        fwrite( " [", 2, 1, file );
        fwrite( NV_LOG_LEVEL_NAME_PAD( level ), 8, 1, file );
        fwrite( "] ", 2, 1, file );
        fwrite( message.data(), message.size(), 1, file );
        fwrite( "\n", 1, 1, file );
        if ( m_flush ) fflush( file );
#endif
}

nv::log_file_sink::log_file_sink( const string_view& 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( static_cast<FILE*>( m_handle ) );
#endif
}


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

nv::uint32 nv::log_sink::timestamp( char* buffer ) const
{
        uint32 ms = get_system_ms();
        unsigned int secs = static_cast<unsigned int>( ms / 1000 );
        unsigned int mm   = static_cast<unsigned int>( ms * 100 / 1000 ) % 100;
        unsigned int h    = static_cast<unsigned int>( secs / (60*60) );
        unsigned int m    = static_cast<unsigned int>( secs / 60 ) % 60;
        unsigned int s    = secs % 60;
#if NV_COMPILER == NV_MSVC 
        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
        return 11;
}

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

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