Files
Jungfraujoch/common/Logger.h
T
leonarski_fandClaude Opus 5.5 fe4db26716 rugnux: an NVTX range per timed section and per console step
Every TimingMark ("TIMING <section>") and every rugnux step ("TIMING step ...") now
opens an NVTX v3 range of the same name, so Nsight Systems traces from different
machines can be lined up by pipeline step. Start/end ranges, not push/pop, so a
range may end on another thread and parallel arms may overlap. Header-only NVTX
(CUDA::nvtx3), a no-op without a profiler attached and compiled out without CUDA.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-14 21:49:37 +02:00

104 lines
3.9 KiB
C++

// 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);
// 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());
}
};