Jungfraujoch/common/Logger.h

// SPDX-FileCopyrightText: 2024 Filip Leonarski, Paul Scherrer Institute <filip.leonarski@psi.ch>
// SPDX-License-Identifier: GPL-3.0-only

#pragma once

#include <cstdint>
#include <chrono>
#include <iostream>
#include <mutex>
#include <memory>
#include <string>

#include <spdlog/spdlog.h>
#include <spdlog/fmt/fmt.h>

namespace spdlog {
    class logger;
}

class LogBufferSink;

class Logger {
    std::shared_ptr<spdlog::logger> spdlog_logger;
    std::shared_ptr<LogBufferSink> buffer;   // only on a Buffered() logger
    explicit Logger(std::shared_ptr<LogBufferSink> sink);

    std::string service;
    std::string hostname;
public:
    Logger(const std::string &service_name, const std::string &file_name = "");
    void ErrorException(const std::exception &e);

    void Info(const std::string& msg) { spdlog_logger->info(msg); }
    void Warning(const std::string& msg) { spdlog_logger->warn(msg); }
    void Error(const std::string& msg) { spdlog_logger->error(msg); }
    void Debug(const std::string& msg) { spdlog_logger->debug(msg); }

    template<typename... Args>
    void Info(fmt::format_string<Args...> fmt, Args &&... args)  {
        spdlog_logger->info(fmt, std::forward<Args>(args)...);
    }

    template<typename... Args>
    void Error(fmt::format_string<Args...> fmt, Args &&... args)  {
        spdlog_logger->error(fmt, std::forward<Args>(args)...);
    }

    template<typename... Args>
    void Debug(fmt::format_string<Args...> fmt, Args &&... args)  {
        spdlog_logger->debug(fmt, std::forward<Args>(args)...);
    }

    template<typename... Args>
    void Warning(fmt::format_string<Args...> fmt, Args &&... args)  {
        spdlog_logger->warn(fmt, std::forward<Args>(args)...);
    }

    Logger& Verbose(bool input);

    // Every Logger made after this call writes to `sink` alone instead of the console, keeps every
    // level down to debug (the sink decides what it shows), and skips the version line each Logger
    // otherwise opens with. For a program that owns its terminal: rugnux sends the whole log to a file
    // next to its outputs and shows only warnings and errors among its own step lines.
    static void RouteAll(spdlog::sink_ptr sink);

    // Every Logger named `service` made after this call keeps only lines of `level` and above. For a program
    // that runs a library whose log is not its own: the broker keeps rugnux's processing log out of its
    // journal. Set at start-up, before any thread logs.
    static void ServiceLevel(const std::string &service, spdlog::level::level_enum level);

    // A logger that keeps its lines instead of printing them, for work run beside other work that
    // logs: ReplayInto hands them to `to` afterwards, in order and as one block, so the two do not
    // interleave.
    static Logger Buffered();
    void ReplayInto(Logger &to) const;
};

// An NVTX range named `name`, so a timed section shows up by name in an Nsight Systems trace. A start/end
// pair, not a push/pop, so a range may end on another thread and ranges on parallel threads may overlap.
// Without a profiler attached both calls return at once; without CUDA they do nothing.
uint64_t NvtxRangeStart(const std::string &name);
void NvtxRangeEnd(uint64_t id);

// Times one section of a run: logs "TIMING <section> <seconds>" at debug level when the section ends -
// at Stop(), or when the mark goes out of scope, whichever comes first. rugnux keeps debug lines off the
// terminal and in <prefix>_log.txt; tools/rugnux_timing.py turns them into a table. The section is also
// an NVTX range of the same name.
class TimingMark {
    Logger &logger;
    std::string section;
    std::chrono::steady_clock::time_point start = std::chrono::steady_clock::now();
    uint64_t nvtx_range = NvtxRangeStart(section);
    bool stopped = false;
public:
    TimingMark(Logger &in_logger, std::string in_section)
        : logger(in_logger), section(std::move(in_section)) {}
    TimingMark(const TimingMark &) = delete;
    TimingMark &operator=(const TimingMark &) = delete;
    ~TimingMark() { Stop(); }
    void Stop() {
        if (stopped)
            return;
        stopped = true;
        NvtxRangeEnd(nvtx_range);
        logger.Debug("TIMING {} {:.3f}", section,
                     std::chrono::duration<double>(std::chrono::steady_clock::now() - start).count());
    }
};