logger.cpp

Go to the documentation of this file.

/*
 *  Copyright (C) 2004-2025 Savoir-faire Linux Inc.
 *
 *  This program 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.
 *
 *  This program 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 for more details.
 *
 *  You should have received a copy of the GNU General Public License
 *  along with this program. If not, see <https://www.gnu.org/licenses/>.
 */
 
#include <cstdio>
#include <cstring>
#include <cerrno>
#include <ctime>
#include <ciso646> // fix windows compiler bug
 
#include "client/ring_signal.h"
 
#include <fmt/core.h>
#include <fmt/format.h>
#include <fmt/compile.h>
 
#ifdef _MSC_VER
#include <sys_time.h>
#else
#include <sys/time.h>
#endif
 
#include <atomic>
#include <condition_variable>
#include <functional>
#include <fstream>
#include <string>
#include <ios>
#include <mutex>
#include <thread>
#include <array>
 
#include "fileutils.h"
#include "logger.h"
 
#ifdef __linux__
#include <unistd.h>
#include <syslog.h>
#include <sys/syscall.h>
#endif // __linux__
 
#ifdef __ANDROID__
#ifndef APP_NAME
#define APP_NAME "libjami"
#endif /* APP_NAME */
#endif
 
#define END_COLOR     "\033[0m"
 
#ifndef _WIN32
#define RED    "\033[22;31m"
#define YELLOW "\033[01;33m"
#define CYAN   "\033[22;36m"
#else
#define FOREGROUND_WHITE 0x000f
#define RED              FOREGROUND_RED + 0x0008
#define YELLOW           FOREGROUND_RED + FOREGROUND_GREEN + 0x0008
#define CYAN             FOREGROUND_BLUE + FOREGROUND_GREEN + 0x0008
#define LIGHT_GREEN      FOREGROUND_GREEN + 0x0008
#endif // _WIN32
 
#define LOGFILE "jami"
 
namespace jami {
 
static constexpr auto ENDL = '\n';
 
#ifndef __GLIBC__
static const char*
check_error(int result, char* buffer)
{
    switch (result) {
    case 0:
        return buffer;
 
    case ERANGE: /* should never happen */
        return "unknown (too big to display)";
 
    default:
        return "unknown (invalid error number)";
    }
}
 
static const char*
check_error(char* result, char*)
{
    return result;
}
#endif
 
void
strErr()
{
#ifdef __GLIBC__
    JAMI_ERR("%m");
#else
    char buf[1000];
    JAMI_ERR("%s", check_error(strerror_r(errno, buf, sizeof(buf)), buf));
#endif
}
 
// extract the last component of a pathname (extract a filename from its dirname)
static const char*
stripDirName(const char* path)
{
    if (path) {
        const char* occur = strrchr(path, DIR_SEPARATOR_CH);
        return occur ? occur + 1 : path;
    } else return nullptr;
}
 
std::string
formatHeader(const char* const file, int line)
{
#ifdef __linux__
    auto tid = syscall(__NR_gettid) & 0xffff;
#else
    auto tid = std::this_thread::get_id();
#endif // __linux__
 
    unsigned int secs, milli;
    struct timeval tv;
    if (!gettimeofday(&tv, NULL)) {
        secs = tv.tv_sec;
        milli = tv.tv_usec / 1000; // suppose that milli < 1000
    } else {
        secs = time(NULL);
        milli = 0;
    }
 
    if (file) {
        return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}|{: <24s}:{: <4d}] "),
                           secs,
                           milli,
                           tid,
                           stripDirName(file),
                           line);
    } else {
        return fmt::format(FMT_COMPILE("[{: >3d}.{:0<3d}|{: >4}] "), secs, milli, tid);
    }
}
 
std::string
formatPrintfArgs(const char* format, va_list ap)
{
    std::string ret;
    /* A good guess of what we might encounter. */
    static constexpr size_t default_buf_size = 80;
 
    ret.resize(default_buf_size);
 
    /* Necessary if we don't have enough space in buf. */
    va_list cp;
    va_copy(cp, ap);
 
    int size = vsnprintf(ret.data(), ret.size(), format, ap);
 
    /* Not enough space?  Well try again. */
    if ((size_t) size >= ret.size()) {
        ret.resize(size + 1);
        vsnprintf((char*) ret.data(), ret.size(), format, cp);
    }
 
    ret.resize(size);
 
    va_end(cp);
 
    return ret;
}
 
struct Logger::Msg
{
    Msg() = delete;
 
    Msg(int level, const char* file, int line, bool linefeed, std::string&& message)
        : file_(stripDirName(file))
        , line_(line)
        , payload_(std::move(message))
        , level_(level)
        , linefeed_(linefeed)
    {}
 
    Msg(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
        : file_(stripDirName(file))
        , line_(line)
        , payload_(formatPrintfArgs(fmt, ap))
        , level_(level)
        , linefeed_(linefeed)
    {}
 
    Msg(Msg&& other)
    {
        file_ = other.file_;
        line_ = other.line_;
        payload_ = std::move(other.payload_);
        level_ = other.level_;
        linefeed_ = other.linefeed_;
    }
 
    inline std::string header() const {
        return formatHeader(file_, line_);
    }
 
    const char* file_;
    unsigned line_;
    std::string payload_;
    int level_;
    bool linefeed_;
};
 
class Logger::Handler
{
public:
    virtual ~Handler() = default;
 
    virtual void consume(Msg& msg) = 0;
 
    void enable(bool en) { enabled_.store(en, std::memory_order_relaxed); }
    bool isEnable() { return enabled_.load(std::memory_order_relaxed); }
 
private:
    std::atomic_bool enabled_ {false};
};
 
class ConsoleLog : public Logger::Handler
{
public:
    static ConsoleLog& instance()
    {
        // Intentional memory leak:
        // Some thread can still be logging even during static destructors.
        static ConsoleLog* self = new ConsoleLog();
        return *self;
    }
 
#ifdef _WIN32
    void printLogImpl(Logger::Msg& msg, bool with_color)
    {
        // If we are using Visual Studio, we can use OutputDebugString to print
        // to the "Output" window. Otherwise, we just use fputs to stderr.
        static std::function<void(const char* str)> fputsFunc = [](const char* str) {
            fputs(str, stderr);
        };
        static std::function<void(const char* str)> outputDebugStringFunc = [](const char* str) {
            OutputDebugStringA(str);
        };
        static std::function<void()> putcFunc = []() {
            putc(ENDL, stderr);
        };
        // These next two functions will be used to print the message and line ending.
        static auto printFunc = IsDebuggerPresent() ? outputDebugStringFunc : fputsFunc;
        static auto endlFunc = IsDebuggerPresent() ? []() { OutputDebugStringA("\n"); } : putcFunc;
 
        WORD saved_attributes;
        static HANDLE hConsole = GetStdHandle(STD_OUTPUT_HANDLE);
        auto header = msg.header();
        if (with_color) {
            static WORD color_header = CYAN;
            WORD color_prefix = LIGHT_GREEN;
            CONSOLE_SCREEN_BUFFER_INFO consoleInfo;
 
            switch (msg.level_) {
            case LOG_ERR:
                color_prefix = RED;
                break;
 
            case LOG_WARNING:
                color_prefix = YELLOW;
                break;
            }
 
            GetConsoleScreenBufferInfo(hConsole, &consoleInfo);
            saved_attributes = consoleInfo.wAttributes;
            SetConsoleTextAttribute(hConsole, color_header);
 
            printFunc(header.c_str());
 
            SetConsoleTextAttribute(hConsole, saved_attributes);
            SetConsoleTextAttribute(hConsole, color_prefix);
        } else {
            printFunc(header.c_str());
        }
 
        printFunc(msg.payload_.c_str());
 
        if (msg.linefeed_) {
            endlFunc();
        }
 
        if (with_color) {
            SetConsoleTextAttribute(hConsole, saved_attributes);
        }
    }
#else
    void printLogImpl(const Logger::Msg& msg, bool with_color)
    {
        auto header = msg.header();
        if (with_color) {
            const char* color_header = CYAN;
            const char* color_prefix = "";
 
            switch (msg.level_) {
            case LOG_ERR:
                color_prefix = RED;
                break;
 
            case LOG_WARNING:
                color_prefix = YELLOW;
                break;
            }
 
            fputs(color_header, stderr);
            fwrite(header.c_str(), 1, header.size(), stderr);
            fputs(END_COLOR, stderr);
            fputs(color_prefix, stderr);
        } else {
            fwrite(header.c_str(), 1, header.size(), stderr);
        }
 
        fputs(msg.payload_.c_str(), stderr);
 
        if (with_color) {
            fputs(END_COLOR, stderr);
        }
        if (msg.linefeed_) {
            putc(ENDL, stderr);
        }
    }
#endif /* _WIN32 */
 
    void consume(Logger::Msg& msg) override
    {
        static bool with_color = !(getenv("NO_COLOR") || getenv("NO_COLORS") || getenv("NO_COLOUR")
                                   || getenv("NO_COLOURS"));
 
        printLogImpl(msg, with_color);
    }
};
 
void
Logger::setConsoleLog(bool en)
{
    ConsoleLog::instance().enable(en);
#ifdef _WIN32
    static WORD original_attributes;
    if (en) {
        if (AttachConsole(ATTACH_PARENT_PROCESS) || AllocConsole()) {
            FILE *fpstdout = stdout, *fpstderr = stderr;
            freopen_s(&fpstdout, "CONOUT$", "w", stdout);
            freopen_s(&fpstderr, "CONOUT$", "w", stderr);
            // Save the original state of the console window(in case AttachConsole worked).
            CONSOLE_SCREEN_BUFFER_INFO consoleInfo;
            GetConsoleScreenBufferInfo(GetStdHandle(STD_OUTPUT_HANDLE), &consoleInfo);
            original_attributes = consoleInfo.wAttributes;
            SetConsoleCP(CP_UTF8);
            SetConsoleMode(GetStdHandle(STD_OUTPUT_HANDLE),
                           ENABLE_QUICK_EDIT_MODE | ENABLE_EXTENDED_FLAGS);
        }
    } else {
        // Restore the original state of the console window in case we attached.
        SetConsoleTextAttribute(GetStdHandle(STD_OUTPUT_HANDLE), original_attributes);
        FreeConsole();
    }
#endif
}
 
class SysLog : public Logger::Handler
{
public:
    static SysLog& instance()
    {
        // Intentional memory leak:
        // Some thread can still be logging even during static destructors.
        static SysLog* self = new SysLog();
        return *self;
    }
 
    SysLog()
    {
#ifdef _WIN32
        ::openlog(LOGFILE, WINLOG_PID, WINLOG_MAIL);
#else
#ifndef __ANDROID__
        ::openlog(LOGFILE, LOG_NDELAY, LOG_USER);
#endif
#endif /* _WIN32 */
    }
 
    void consume(Logger::Msg& msg) override
    {
#ifdef __ANDROID__
        __android_log_write(msg.level_, msg.file_, msg.payload_.c_str());
#else
        ::syslog(msg.level_, "%.*s", (int) msg.payload_.size(), msg.payload_.data());
#endif
    }
};
 
void
Logger::setSysLog(bool en)
{
    SysLog::instance().enable(en);
}
 
class MonitorLog : public Logger::Handler
{
public:
    static MonitorLog& instance()
    {
        // Intentional memory leak
        // Some thread can still be logging even during static destructors.
        static MonitorLog* self = new MonitorLog();
        return *self;
    }
 
    void consume(Logger::Msg& msg) override
    {
        auto message = msg.header() + msg.payload_;
        emitSignal<libjami::ConfigurationSignal::MessageSend>(message);
    }
};
 
void
Logger::setMonitorLog(bool en)
{
    MonitorLog::instance().enable(en);
}
 
class FileLog : public Logger::Handler
{
public:
    static FileLog& instance()
    {
        // Intentional memory leak:
        // Some thread can still be logging even during static destructors.
        static FileLog* self = new FileLog();
        return *self;
    }
 
    void setFile(const std::string& path)
    {
        if (thread_.joinable()) {
            notify([this] { enable(false); });
            thread_.join();
        }
 
        std::ofstream file;
        if (not path.empty()) {
            file.open(path, std::ofstream::out | std::ofstream::app);
            enable(true);
        } else {
            enable(false);
            return;
        }
 
        thread_ = std::thread([this, file = std::move(file)]() mutable {
            std::vector<Logger::Msg> pendingQ_;
            while (isEnable()) {
                {
                    std::unique_lock lk(mtx_);
                    cv_.wait(lk, [&] { return not isEnable() or not currentQ_.empty(); });
                    if (not isEnable())
                        break;
 
                    std::swap(currentQ_, pendingQ_);
                }
 
                do_consume(file, pendingQ_);
                pendingQ_.clear();
            }
            file.close();
        });
    }
 
    ~FileLog()
    {
        notify([=] { enable(false); });
        if (thread_.joinable())
            thread_.join();
    }
 
    void consume(Logger::Msg& msg) override
    {
        notify([&, this] { currentQ_.emplace_back(std::move(msg)); });
    }
 
private:
    template<typename T>
    void notify(T func)
    {
        std::lock_guard lk(mtx_);
        func();
        cv_.notify_one();
    }
 
    void do_consume(std::ofstream& file, const std::vector<Logger::Msg>& messages)
    {
        for (const auto& msg : messages) {
            file << msg.header() << msg.payload_;
            if (msg.linefeed_)
                file << ENDL;
        }
        file.flush();
    }
 
    std::vector<Logger::Msg> currentQ_;
    std::mutex mtx_;
    std::condition_variable cv_;
    std::thread thread_;
};
 
void
Logger::setFileLog(const std::string& path)
{
    FileLog::instance().setFile(path);
}
 
LIBJAMI_PUBLIC void
Logger::log(int level, const char* file, int line, bool linefeed, const char* fmt, ...)
{
    va_list ap;
 
    va_start(ap, fmt);
 
    vlog(level, file, line, linefeed, fmt, ap);
 
    va_end(ap);
}
 
template<typename T>
void
log_to_if_enabled(T& handler, Logger::Msg& msg)
{
    if (handler.isEnable()) {
        handler.consume(msg);
    }
}
 
static std::atomic_bool debugEnabled_ {false};
 
void
Logger::setDebugMode(bool enable)
{
    debugEnabled_.store(enable, std::memory_order_relaxed);
}
 
bool
Logger::debugEnabled()
{
    return debugEnabled_.load(std::memory_order_relaxed);
}
 
void
Logger::vlog(int level, const char* file, int line, bool linefeed, const char* fmt, va_list ap)
{
    if (level < LOG_WARNING and not debugEnabled_.load(std::memory_order_relaxed)) {
        return;
    }
 
    if (not(ConsoleLog::instance().isEnable() or SysLog::instance().isEnable()
            or MonitorLog::instance().isEnable() or FileLog::instance().isEnable())) {
        return;
    }
 
    /* Timestamp is generated here. */
    Msg msg(level, file, line, linefeed, fmt, ap);
 
    log_to_if_enabled(ConsoleLog::instance(), msg);
    log_to_if_enabled(SysLog::instance(), msg);
    log_to_if_enabled(MonitorLog::instance(), msg);
    log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
}
 
void
Logger::write(int level, const char* file, int line, bool linefeed, std::string&& message)
{
    /* Timestamp is generated here. */
    Msg msg(level, file, line, linefeed, std::move(message));
 
    log_to_if_enabled(ConsoleLog::instance(), msg);
    log_to_if_enabled(SysLog::instance(), msg);
    log_to_if_enabled(MonitorLog::instance(), msg);
    log_to_if_enabled(FileLog::instance(), msg); // Takes ownership of msg if enabled
}
 
void
Logger::fini()
{
    // Force close on file and join thread
    FileLog::instance().setFile({});
 
#ifdef _WIN32
    Logger::setConsoleLog(false);
#endif /* _WIN32 */
}
 
} // namespace jami