0__README.md

OpenCV 4.1.0 Logging Revamp - proof-of-concept design - 2019-01-25

Discussions and feedbacks

All discussions and feedback should be sent to:
opencv/opencv#11003

About this prototype code

This prototype tries to incorporate the latest round of comments:

• opencv/opencv#11003 (comment)
• opencv/opencv#11003 (comment)

1__LICENSE.txt

Copyright 2019 Ryan Wong

Permission is hereby granted, free of charge, to any person obtaining a copy of this software and 
associated documentation files (the "Software"), to deal in the Software without restriction, 
including without limitation the rights to use, copy, modify, merge, publish, distribute, sublicense, 
and/or sell copies of the Software, and to permit persons to whom the Software is furnished to do so, 
subject to the following conditions:

The above copyright notice and this permission notice shall be included in all copies or substantial 
portions of the Software.

THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT 
LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. 
IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, 
WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE 
SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.

2__Demo.cpp

// Logging_20190125.cpp : This file contains the 'main' function. Program execution begins and ends there.
//

#include "pch.h"
#include "MacroPlayground_20190125_1924pm.h"
#include "LoggingMacros.h"
#include "LogSinkManager.h"
#include "LogLevelManager.h"


extern constexpr int static_logging_level_breakfast_time = 1;


static int static_logging_level_dinner_time = 1;


int main()
{
    NEWLOG(NO_TAG, 3, "Hello three");
    NEWLOG(NO_TAG, 2, "Hello two");
    NEWLOG(NO_TAG, 1, "Hello one");
    NEWLOG(NO_TAG, 0, "Hello zero");

    NEWLOG(breakfast_time, 3, "Morning three");
    NEWLOG(breakfast_time, 2, "Morning two");
    NEWLOG(breakfast_time, 1, "Morning one");
    NEWLOG(breakfast_time, 0, "Morning zero");


    // ====== Exercise ======
    // Try swap the order of the next two statements.
    // In actual software, it is impossible to control which one will 
    // be called earlier.
    // ======

    logging_20190125::LogLevelManager::getInstance().registerLogLevel(
        "dinner_time", static_logging_level_dinner_time);

    logging_20190125::LogLevelManager::getInstance().setLogLevel(
        "dinner_time", 3);
    
    // Directly changing the log level variable is also allowed.

    static_logging_level_dinner_time = 3;

    NEWLOG(dinner_time, 3, "Nite three");
    NEWLOG(dinner_time, 2, "Nite two");
    NEWLOG(dinner_time, 1, "Nite one");
    NEWLOG(dinner_time, 0, "Nite zero");

    std::cout << "====== Program ended ======" << std::endl;
    std::string unused;
    std::getline(std::cin, unused);
    return 0;
}

3__LoggingMacros.h

#pragma once

extern constexpr int static_logging_level_no_tag = 2;

extern constexpr int static_logging_level_stripped = 4;


#define EXPAND_AS_STRING(content) #content


#define NO_TAG no_tag


#define CHECK_LEVEL(ARG_level) \
    if (ARG_level >= static_logging_level_stripped) { break; }


// Requirement for using CHECK_TAG_STATIC
//
// This will be expanded into a C++ identifier name beginning with
// "static_logging_level_..." and ending with the tag name.
//
// This C++ identifier needs to be comparable to an integer value.
// If it is hard-coded, "constexpr int" is recommended.
// If it is static-lifetime mutable and configurable, there needs
// to be a piece of registration code:
//
//     int static_logging_level_your_tag_name = 1;
//     logging_20190125::LogLevelManager::getInstance().registerLogLevel(
//         "your_tag_name", static_logging_level_your_tag_name);
// 
#define CHECK_TAG_STATIC(ARG_level, ARG_tag) \
    if (ARG_level >= static_logging_level_##ARG_tag) { break; }


// Requirement for using CHECK_TAG_DYNAMIC
//
// No declaration necessary. The only requirement is to set the log level
// to some value.
//
//     logging_20190125::LogLevelManager::getInstance().setLogLevel(
//     "your_tag_name", 3);
//
#define CHECK_TAG_DYNAMIC(ARG_level, ARG_tag) \
    if (ARG_level >= logging_20190125::LogLevelManager::getInstance().getLogLevel( #ARG_tag )) { break; }


// Each compilation unit (cpp file) must decide whether it wants to use 
// CHECK_TAG_STATIC or CHECK_TAG_DYNAMIC, because there is no preprocessor
// mechanism to check whether a particular C++ identifier name exists 
// at the line of code where the macro is expanded.
//
// Compiler vendor-specific mechanisms might exist.
// https://docs.microsoft.com/en-us/cpp/cpp/if-exists-statement?view=vs-2017
// 
// Other mechanisms may require templates and SFINAE.
//
#if 1
#define CHECK_TAG(ARG_level, ARG_tag) CHECK_TAG_STATIC(ARG_level, ARG_tag)
#else
#define CHECK_TAG(ARG_level, ARG_tag) CHECK_TAG_DYNAMIC(ARG_level, ARG_tag)
#endif


// ====== TODO ======
// Replace mock code with real implementation
// ======
#define CHECK_LOC(ARG_level, ARG_tag, ARG_file, ARG_line, ARG_func) \
    if (false) { break; }


// ====== TODO ======
// Replace mock code with real implementation
// ======
#define LOG_GET_THREAD() \
    (std::hash<std::thread::id>()(std::this_thread::get_id()))


// ====== TODO ======
// Replace mock code with real implementation
// ======
#define LOG_GET_TIME() \
    (__rdtsc())


// ====== TODO ====== 
// Replace mock code with real implementation
// ======
#define LOG_FORMAT_ARGS(...) \
    []() -> std::string { \
        std::ostringstream strm; \
        strm << __VA_ARGS__; \
        return strm.str(); \
    }()


#define NEWLOG(ARG_tag, ARG_level, ...) \
    for(;;) { \
        CHECK_LEVEL(ARG_level); \
        CHECK_TAG(ARG_level, ARG_tag); \
        CHECK_LOC(ARG_level, ARG_tag, __FILE__, __LINE__, __FUNCTION__); \
        std::string s = LOG_FORMAT_ARGS(__VA_ARGS__); \
        logging_20190125::LogSinkManager::getInstance().send(\
            ARG_level, \
            EXPAND_AS_STRING(ARG_tag), \
            __FILE__, \
            __LINE__, \
            __FUNCTION__, \
            LOG_GET_TIME(), \
            LOG_GET_THREAD(), \
            s.c_str() ); \
        break; \
    }

4__LogLevelManager.h

#pragma once

namespace logging_20190125
{
    // A registry for log filtering thresholds.
    //
    // Two kinds of things are tracked:
    // - log level variables
    // - changes to log level values
    //
    // A log level variable is a piece of memory containing an integer value.
    // Once registered, any change to the log level will be written directly to that
    // memory. 
    //
    // Application code which knows of a particular log level variable can read 
    // from it directly, without going through LogLevelManager. This happens when
    // the log message macro is invoked.
    //
    // Changes to log level values can be made anytime. This class is responsible for
    // pushing the change into the log level variable, if the latter is registered.
    // If the latter is not yet registered, this class remembers the change, so that
    // it can be pushed later.
    //
    // The name string is matched exactly. There is no support for wildcard or prefix 
    // matching.
    //
    class LogLevelManager
    {
    private:
        LogLevelManager();
        ~LogLevelManager();

    public:
        static LogLevelManager& getInstance();

    public:
        // Associates a certain tag name with the address of a log level variable.
        //
        // Requirement: this log level variable need to have static (indefinite) lifetime. 
        // If the variable becomes invalid, undefined behavior (UB) can happen, including 
        // crash, memory corruption, or non-obvious abnormal behaviors.
        // 
        void registerLogLevel(const std::string& name, int& refLogLevel);

        // Configures a log level threshold value for the specified tag name.
        //
        void setLogLevel(const std::string& name, int logLevel);

        // Gets the log level.
        // If a variable has been registered, the variable's current value will be used.
        // If a variable hasn't been registered, the stored configured value will be used.
        //
        // Any application code that has direct access to the log level variable may 
        // directly read or write that variable, without going through LogLevelManager.
        //
        int getLogLevel(const std::string& name) const;

    private:
        using MutexType = std::recursive_mutex;
        using LockType = std::lock_guard<MutexType>;

    private:
        mutable MutexType m_mutex;
        std::unordered_map<std::string, int> m_configuredLogLevels;
        std::unordered_map<std::string, int*> m_registeredLogLevels;
    };
}

5__LogLevelManager.cpp

#include "pch.h"
#include "LogLevelManager.h"

namespace logging_20190125
{
    LogLevelManager::LogLevelManager()
        : m_mutex()
        , m_configuredLogLevels()
        , m_registeredLogLevels()
    {
    }

    LogLevelManager::~LogLevelManager()
    {
    }

    LogLevelManager& LogLevelManager::getInstance()
    {
        static LogLevelManager instance{};
        return instance;
    }

    void LogLevelManager::registerLogLevel(const std::string& name, int& refLogLevel)
    {
        LockType lock(m_mutex);
        auto regIter = m_registeredLogLevels.find(name);
        if (regIter == m_registeredLogLevels.end())
        {
            regIter = m_registeredLogLevels.emplace(name, std::addressof(refLogLevel)).first;
        }
        auto cfgIter = m_configuredLogLevels.find(name);
        if (cfgIter != m_configuredLogLevels.end())
        {
            *(regIter->second) = (cfgIter->second);
        }
    }
    
    void LogLevelManager::setLogLevel(const std::string& name, int logLevel)
    {
        LockType lock(m_mutex);
        auto cfgIter = m_configuredLogLevels.find(name);
        if (cfgIter == m_configuredLogLevels.end())
        {
            cfgIter = m_configuredLogLevels.emplace(name, logLevel).first;
        }
        else
        {
            cfgIter->second = logLevel;
        }
        auto regIter = m_registeredLogLevels.find(name);
        if (regIter != m_registeredLogLevels.end())
        {
            *(regIter->second) = (cfgIter->second);
        }
    }

    int LogLevelManager::getLogLevel(const std::string& name) const
    {
        LockType lock(m_mutex);
        const auto regIter = m_registeredLogLevels.find(name);
        if (regIter != m_registeredLogLevels.end())
        {
            return *(regIter->second);
        }
        const auto cfgIter = m_configuredLogLevels.find(name);
        if (cfgIter != m_configuredLogLevels.end())
        {
            return (cfgIter->second);
        }
        // ====== TODO ======
        return -1; // or something
    }
}

6__LogSinkManager.h

#pragma once

namespace logging_20190125
{
    class LogSinkManager
    {
    public:
        using CallbackPrototype = void(*)(
            int level, const char* name, const char* file, int line, const char* func,
            uint64_t time, uint64_t thread, const char* message);

    private:
        LogSinkManager(CallbackPrototype defaultFunc);
        ~LogSinkManager();

    public:
        static LogSinkManager& getInstance();

    public:
        void setCallback(CallbackPrototype func);
        
        CallbackPrototype getCallback() const;

    public:
        static void send(int level, const char* name, const char* file, int line, 
            const char* func, uint64_t time, uint64_t thread, const char* message);

    public:
        static void defaultCallback(int level, const char* name, const char* file, int line,
            const char* func, uint64_t time, uint64_t thread, const char* message);

    private:
        CallbackPrototype m_func;
    };
}

7__LogSinkManager.cpp

#include "pch.h"
#include "LogSinkManager.h"

namespace logging_20190125
{
    LogSinkManager::LogSinkManager(CallbackPrototype defaultFunc)
        : m_func(defaultFunc)
    {
    }

    LogSinkManager::~LogSinkManager()
    {
    }

    LogSinkManager& LogSinkManager::getInstance()
    {
        static LogSinkManager instance{ LogSinkManager::defaultCallback };
        return instance;
    }

    void LogSinkManager::setCallback(CallbackPrototype func)
    {
        if (func == &LogSinkManager::send)
        {
            throw std::invalid_argument("LogSinkManager::setCallback");
        }
        m_func = func;
    }

    LogSinkManager::CallbackPrototype LogSinkManager::getCallback() const
    {
        return m_func;
    }

    void LogSinkManager::send(int level, const char* name, const char* file, int line,
        const char* func, uint64_t time, uint64_t thread, const char* message)
    {
        getInstance().m_func(level, name, file, line, func, time, thread, message);
    }

    void LogSinkManager::defaultCallback(int level, const char* name, const char* file, int line,
        const char* func, uint64_t time, uint64_t thread, const char* message)
    {
        std::ostringstream strm;
        strm << time << "  [" << thread << "]  ";
        strm << name << ":" << level << "   ";
        if (file && file[0] && (line > 0) && func && func[0])
        {
            strm << "(" << file << ":" << line << ", " << func << ")   ";
        }
        strm << message << "\n";
        std::cout << strm.str() << std::flush;
    }
}