ResInsight/ApplicationLibCode/Application/Tools/RiaLogging.cpp

/////////////////////////////////////////////////////////////////////////////////
//
//  Copyright (C) 2017     Statoil ASA
//
//  ResInsight is free software: you can redistribute it and/or modify
//  it under the terms of the GNU General Public License as published by
//  the Free Software Foundation, either version 3 of the License, or
//  (at your option) any later version.
//
//  ResInsight is distributed in the hope that it will be useful, but WITHOUT ANY
//  WARRANTY; without even the implied warranty of MERCHANTABILITY or
//  FITNESS FOR A PARTICULAR PURPOSE.
//
//  See the GNU General Public License at <http://www.gnu.org/licenses/gpl.html>
//  for more details.
//
/////////////////////////////////////////////////////////////////////////////////

#include "RiaLogging.h"
#include "RiaApplication.h"
#include "RiaPreferencesSystem.h"

#include <format>
#include <iostream>
#include <sstream>

#ifdef WIN32
#pragma warning( push )
#pragma warning( disable : 4668 )
// Define this one to tell windows.h to not define min() and max() as macros
#if defined WIN32 && !defined NOMINMAX
#define NOMINMAX
#endif
#include <windows.h>
#pragma warning( pop )
#else
#include <cstdio>
#include <cstring>
#endif

#include <QString>

//==================================================================================================
//
//
//
//==================================================================================================
class RiaDefaultConsoleLogger : public RiaLogger
{
public:
    RiaDefaultConsoleLogger();

    int  level() const override;
    void setLevel( int logLevel ) override;
    void error( const char* message ) override;
    void warning( const char* message ) override;
    void info( const char* message ) override;
    void debug( const char* message ) override;

private:
    static void writeMessageToConsole( const char* prefix, const char* message );
    static void writeToConsole( const std::string& str );

private:
    int m_logLevel;
};

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
RiaDefaultConsoleLogger::RiaDefaultConsoleLogger()
    : m_logLevel( int( RILogLevel::RI_LL_WARNING ) )
{
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
int RiaDefaultConsoleLogger::level() const
{
    return m_logLevel;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::setLevel( int logLevel )
{
    m_logLevel = logLevel;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::error( const char* message )
{
    writeMessageToConsole( "ERROR: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::warning( const char* message )
{
    writeMessageToConsole( "warn:  ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::info( const char* message )
{
    writeMessageToConsole( "info:  ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::debug( const char* message )
{
    writeMessageToConsole( "debug: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::writeMessageToConsole( const char* prefix, const char* message )
{
    std::ostringstream oss;

    //    VF_ASSERT(prefix);
    oss << prefix;

    if ( message )
    {
        oss << message << std::endl;
    }
    else
    {
        oss << "<no message>" << std::endl;
    }

    writeToConsole( oss.str() );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaDefaultConsoleLogger::writeToConsole( const std::string& str )
{
#ifdef WIN32
    AllocConsole();
    HANDLE hStdOutputHandle = GetStdHandle( STD_OUTPUT_HANDLE );
    if ( hStdOutputHandle )
    {
        DWORD stringLength = static_cast<DWORD>( str.length() );

        unsigned long iDum = 0;
        WriteConsoleA( hStdOutputHandle, str.c_str(), stringLength, &iDum, nullptr );
    }
#else
    fputs( str.c_str(), stderr );
#endif
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::setLastMessage( std::string_view message )
{
#pragma omp critical( critical_section_logging )
    {
        sm_lastMessage.assign( message );
        sm_lastMessageTime = std::chrono::high_resolution_clock::now();
    }
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
bool RiaLogging::isSameMessage( std::string_view message )
{
    bool isSame = false;

#pragma omp critical( critical_section_logging )
    {
        if ( message == sm_lastMessage )
        {
            auto now      = std::chrono::high_resolution_clock::now();
            auto duration = std::chrono::duration_cast<std::chrono::milliseconds>( now - sm_lastMessageTime );

            if ( duration.count() < 1000 )
            {
                isSame = true;
            }
        }
    }

    return isSame;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
bool RiaLogging::isKeywordEnabled( std::string_view keyword )
{
    return RiaPreferencesSystem::current()->isLoggingActivatedForKeyword(
        QString::fromUtf8( keyword.data(), static_cast<qsizetype>( keyword.size() ) ) );
}

//==================================================================================================
//
//
//
//==================================================================================================

std::vector<std::unique_ptr<RiaLogger>>                     RiaLogging::sm_logger;
std::string                                                 RiaLogging::sm_lastMessage;
std::chrono::time_point<std::chrono::high_resolution_clock> RiaLogging::sm_lastMessageTime;

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
std::vector<RiaLogger*> RiaLogging::loggerInstances()
{
    std::vector<RiaLogger*> loggerInstances;
    for ( auto& logger : sm_logger )
    {
        loggerInstances.push_back( logger.get() );
    }

    return loggerInstances;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::appendLoggerInstance( std::unique_ptr<RiaLogger> loggerInstance )
{
    sm_logger.push_back( std::move( loggerInstance ) );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::flushPendingMessages()
{
    for ( const auto& logger : sm_logger )
    {
        logger->flushPendingMessages();
    }
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
RILogLevel RiaLogging::logLevelBasedOnPreferences()
{
    if ( RiaApplication::enableDevelopmentFeatures() ) return RILogLevel::RI_LL_DEBUG;

    return RILogLevel::RI_LL_INFO;
}

//--------------------------------------------------------------------------------------------------
/// Parse a log level string and return the corresponding enum value
/// @param logLevelString The string to parse (case-insensitive, whitespace is trimmed)
/// @return The corresponding RILogLevel enum value, or std::nullopt if the string is invalid
/// Valid values are: DISABLED, ERROR, WARNING, INFO, DEBUG
//--------------------------------------------------------------------------------------------------
std::optional<RILogLevel> RiaLogging::parseLogLevelString( const QString& logLevelString )
{
    QString upperString = logLevelString.toUpper().trimmed();

    if ( upperString == "DISABLED" ) return RILogLevel::RI_LL_DISABLED;
    if ( upperString == "ERROR" ) return RILogLevel::RI_LL_ERROR;
    if ( upperString == "WARNING" ) return RILogLevel::RI_LL_WARNING;
    if ( upperString == "INFO" ) return RILogLevel::RI_LL_INFO;
    if ( upperString == "DEBUG" ) return RILogLevel::RI_LL_DEBUG;

    // Return nullopt for invalid input
    return std::nullopt;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::error( std::string_view message, std::string_view logKeyword )
{
    if ( !isKeywordEnabled( logKeyword ) ) return;
    if ( isSameMessage( message ) ) return;
    const std::string buf{ message };
    for ( const auto& logger : sm_logger )
    {
        if ( logger && logger->level() >= int( RILogLevel::RI_LL_ERROR ) )
        {
#pragma omp critical( critical_section_logging )
            logger->error( buf.c_str() );
        }
    }
    setLastMessage( message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::warning( std::string_view message, std::string_view logKeyword )
{
    if ( !isKeywordEnabled( logKeyword ) ) return;
    if ( isSameMessage( message ) ) return;
    const std::string buf{ message };
    for ( const auto& logger : sm_logger )
    {
        if ( logger && logger->level() >= int( RILogLevel::RI_LL_WARNING ) )
        {
#pragma omp critical( critical_section_logging )
            logger->warning( buf.c_str() );
        }
    }
    setLastMessage( message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::info( std::string_view message, std::string_view logKeyword )
{
    if ( !isKeywordEnabled( logKeyword ) ) return;
    if ( isSameMessage( message ) ) return;
    const std::string buf{ message };
    for ( const auto& logger : sm_logger )
    {
        if ( logger && logger->level() >= int( RILogLevel::RI_LL_INFO ) )
        {
#pragma omp critical( critical_section_logging )
            logger->info( buf.c_str() );
        }
    }
    setLastMessage( message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::debug( std::string_view message, std::string_view logKeyword )
{
    if ( !isKeywordEnabled( logKeyword ) ) return;
    if ( isSameMessage( message ) ) return;
    const std::string buf{ message };
    for ( const auto& logger : sm_logger )
    {
        if ( logger && logger->level() >= int( RILogLevel::RI_LL_DEBUG ) )
        {
#pragma omp critical( critical_section_logging )
            logger->debug( buf.c_str() );
        }
    }
    setLastMessage( message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
std::chrono::time_point<std::chrono::high_resolution_clock> RiaLogging::currentTime()
{
    return std::chrono::high_resolution_clock::now();
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaLogging::logElapsedTime( std::string_view message, const std::chrono::time_point<std::chrono::high_resolution_clock>& startTime )
{
    auto end      = std::chrono::high_resolution_clock::now();
    auto duration = std::chrono::duration_cast<std::chrono::milliseconds>( end - startTime );
    auto totalMs  = duration.count();

    std::string text;
    if ( totalMs < 1000 )
    {
        text = std::format( "{} (duration: {} milliseconds)", message, totalMs );
    }
    else if ( totalMs < 60000 )
    {
        double seconds = totalMs / 1000.0;
        text           = std::format( "{} (duration: {:.1f} seconds)", message, seconds );
    }
    else
    {
        auto minutes          = totalMs / 60000;
        auto remainingSeconds = ( totalMs % 60000 ) / 1000.0;
        text                  = std::format( "{} (duration: {} minutes {:.1f} seconds)", message, minutes, remainingSeconds );
    }

    RiaLogging::debug( text );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
RiuMessageLoggerBase::RiuMessageLoggerBase()
    : m_logLevel( (int)RILogLevel::RI_LL_WARNING )
{
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
int RiuMessageLoggerBase::level() const
{
    return m_logLevel;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::setLevel( int logLevel )
{
    m_logLevel = logLevel;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::error( const char* message )
{
    writeMessageWithPrefixToLogger( "ERROR: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::warning( const char* message )
{
    writeMessageWithPrefixToLogger( "warning: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::info( const char* message )
{
    writeMessageWithPrefixToLogger( "info: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::debug( const char* message )
{
    writeMessageWithPrefixToLogger( "debug: ", message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiuMessageLoggerBase::writeMessageWithPrefixToLogger( const char* prefix, const char* message )
{
    std::ostringstream oss;

    oss << prefix;

    if ( message )
    {
        oss << message << std::endl;
    }
    else
    {
        oss << "<no message>" << std::endl;
    }

    writeMessageToLogger( oss.str() );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaStdOutLogger::writeMessageToLogger( const std::string& str )
{
    std::cout << str;
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaThreadSafeLogger::error( const QString& message )
{
#pragma omp critical( critical_section_logging )
    m_messages.push_back( "ERROR : " + message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaThreadSafeLogger::warning( const QString& message )
{
#pragma omp critical( critical_section_logging )
    m_messages.push_back( "WARNING : " + message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaThreadSafeLogger::info( const QString& message )
{
#pragma omp critical( critical_section_logging )
    m_messages.push_back( "INFO : " + message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
void RiaThreadSafeLogger::debug( const QString& message )
{
#pragma omp critical( critical_section_logging )
    m_messages.push_back( "DEBUG : " + message );
}

//--------------------------------------------------------------------------------------------------
///
//--------------------------------------------------------------------------------------------------
std::vector<QString> RiaThreadSafeLogger::messages() const
{
    return m_messages;
}