feat(logger): add logger manager to provide unified logging (#1267)

Signed-off-by: k4yt3x <i@k4yt3x.com>
This commit is contained in:
K4YT3X
2024-12-19 23:46:10 -05:00
committed by GitHub
parent b8eb6de59b
commit 6676cd2439
25 changed files with 384 additions and 352 deletions

View File

@@ -5,10 +5,7 @@
// Structure to hold parsed arguments
struct Arguments {
video2x::logutils::Video2xLogLevel log_level = video2x::logutils::Video2xLogLevel::Info;
bool no_progress = false;
// General options
std::filesystem::path in_fname;
std::filesystem::path out_fname;
uint32_t vk_device_index = 0;

View File

@@ -1,17 +0,0 @@
#pragma once
#include <atomic>
#include <optional>
#include <libvideo2x/libvideo2x.h>
#include <spdlog/spdlog.h>
extern std::atomic<bool> newline_required;
void set_spdlog_level(video2x::logutils::Video2xLogLevel log_level);
std::optional<video2x::logutils::Video2xLogLevel> find_log_level_by_name(
const video2x::fsutils::StringType &log_level_name
);
void newline_safe_ffmpeg_log_callback(void *ptr, int level, const char *fmt, va_list vl);

View File

@@ -0,0 +1,22 @@
#pragma once
#include <atomic>
#include <spdlog/sinks/ansicolor_sink.h>
class newline_safe_sink : public spdlog::sinks::ansicolor_stdout_sink_mt {
public:
newline_safe_sink() = default;
~newline_safe_sink() = default;
newline_safe_sink(const newline_safe_sink &) = delete;
newline_safe_sink &operator=(const newline_safe_sink &) = delete;
void log(const spdlog::details::log_msg &msg);
void set_needs_newline(bool needs_newline) { needs_newline_.store(needs_newline); };
bool get_needs_newline() { return needs_newline_.load(); };
private:
std::atomic<bool> needs_newline_ = false;
};

View File

@@ -7,13 +7,13 @@
#include <cwchar>
#endif
#include <libvideo2x/logger_manager.h>
#include <libvideo2x/version.h>
#include <spdlog/spdlog.h>
#include <vulkan_utils.h>
#include <boost/program_options.hpp>
#include "logging.h"
#include "validators.h"
#include "vulkan_utils.h"
#ifdef _WIN32
#define BOOST_PROGRAM_OPTIONS_WCHAR_T
@@ -221,28 +221,27 @@ int parse_args(
}
if (vm.count("log-level")) {
std::optional<video2x::logutils::Video2xLogLevel> log_level =
find_log_level_by_name(vm["log-level"].as<video2x::fsutils::StringType>());
if (!log_level.has_value()) {
spdlog::critical("Invalid log level specified.");
if (!video2x::logger_manager::LoggerManager::instance().set_log_level(
wstring_to_u8string(vm["log-level"].as<video2x::fsutils::StringType>())
)) {
video2x::logger()->critical("Invalid log level specified.");
return -1;
}
arguments.log_level = log_level.value();
}
set_spdlog_level(arguments.log_level);
video2x::logger_manager::LoggerManager::instance().hook_ffmpeg_logging();
// Print program banner
spdlog::info("Video2X version {}", LIBVIDEO2X_VERSION_STRING);
// spdlog::info("Copyright (C) 2018-2024 K4YT3X and contributors.");
// spdlog::info("Licensed under GNU AGPL version 3.");
video2x::logger()->info("Video2X version {}", LIBVIDEO2X_VERSION_STRING);
// video2x::logger()->info("Copyright (C) 2018-2024 K4YT3X and contributors.");
// video2x::logger()->info("Licensed under GNU AGPL version 3.");
// Assign positional arguments
if (vm.count("input")) {
arguments.in_fname =
std::filesystem::path(vm["input"].as<video2x::fsutils::StringType>());
spdlog::info("Processing file: {}", arguments.in_fname.u8string());
video2x::logger()->info("Processing file: {}", arguments.in_fname.u8string());
} else {
spdlog::critical("Input file path is required.");
video2x::logger()->critical("Input file path is required.");
return -1;
}
@@ -250,7 +249,7 @@ int parse_args(
arguments.out_fname =
std::filesystem::path(vm["output"].as<video2x::fsutils::StringType>());
} else if (!arguments.benchmark) {
spdlog::critical("Output file path is required.");
video2x::logger()->critical("Output file path is required.");
return -1;
}
@@ -265,13 +264,13 @@ int parse_args(
} else if (processor_type_str == STR("rife")) {
proc_cfg.processor_type = video2x::processors::ProcessorType::RIFE;
} else {
spdlog::critical(
video2x::logger()->critical(
"Invalid processor specified. Must be 'libplacebo', 'realesrgan', or 'rife'."
);
return -1;
}
} else {
spdlog::critical("Processor type is required.");
video2x::logger()->critical("Processor type is required.");
return -1;
}
@@ -284,7 +283,7 @@ int parse_args(
arguments.hw_device_type =
av_hwdevice_find_type_by_name(wstring_to_u8string(hwaccel_str).c_str());
if (arguments.hw_device_type == AV_HWDEVICE_TYPE_NONE) {
spdlog::critical(
video2x::logger()->critical(
"Invalid hardware device type '{}'.", wstring_to_u8string(hwaccel_str)
);
return -1;
@@ -299,7 +298,9 @@ int parse_args(
const AVCodec *codec =
avcodec_find_encoder_by_name(wstring_to_u8string(codec_str).c_str());
if (codec == nullptr) {
spdlog::critical("Codec '{}' not found.", wstring_to_u8string(codec_str));
video2x::logger()->critical(
"Codec '{}' not found.", wstring_to_u8string(codec_str)
);
return -1;
}
enc_cfg.codec = codec->id;
@@ -316,7 +317,7 @@ int parse_args(
if (!pix_fmt_str.empty()) {
enc_cfg.pix_fmt = av_get_pix_fmt(wstring_to_u8string(pix_fmt_str).c_str());
if (enc_cfg.pix_fmt == AV_PIX_FMT_NONE) {
spdlog::critical(
video2x::logger()->critical(
"Invalid pixel format '{}'.", wstring_to_u8string(pix_fmt_str)
);
return -1;
@@ -334,7 +335,9 @@ int parse_args(
video2x::fsutils::StringType value = opt.substr(eq_pos + 1);
enc_cfg.extra_opts.push_back(std::make_pair(key, value));
} else {
spdlog::critical("Invalid extra AVOption format: {}", wstring_to_u8string(opt));
video2x::logger()->critical(
"Invalid extra AVOption format: {}", wstring_to_u8string(opt)
);
return -1;
}
}
@@ -344,11 +347,13 @@ int parse_args(
switch (proc_cfg.processor_type) {
case video2x::processors::ProcessorType::Libplacebo: {
if (!vm.count("libplacebo-shader")) {
spdlog::critical("Shader name/path must be set for libplacebo.");
video2x::logger()->critical("Shader name/path must be set for libplacebo.");
return -1;
}
if (proc_cfg.width <= 0 || proc_cfg.height <= 0) {
spdlog::critical("Output width and height must be set for libplacebo.");
video2x::logger()->critical(
"Output width and height must be set for libplacebo."
);
return -1;
}
@@ -361,12 +366,15 @@ int parse_args(
}
case video2x::processors::ProcessorType::RealESRGAN: {
if (!vm.count("realesrgan-model")) {
spdlog::critical("RealESRGAN model name must be set for RealESRGAN.");
video2x::logger()->critical("RealESRGAN model name must be set for RealESRGAN."
);
return -1;
}
if (proc_cfg.scaling_factor != 2 && proc_cfg.scaling_factor != 3 &&
proc_cfg.scaling_factor != 4) {
spdlog::critical("Scaling factor must be set to 2, 3, or 4 for RealESRGAN.");
video2x::logger()->critical(
"Scaling factor must be set to 2, 3, or 4 for RealESRGAN."
);
return -1;
}
@@ -380,11 +388,13 @@ int parse_args(
}
case video2x::processors::ProcessorType::RIFE: {
if (!vm.count("rife-model")) {
spdlog::critical("RIFE model name must be set for RIFE.");
video2x::logger()->critical("RIFE model name must be set for RIFE.");
return -1;
}
if (proc_cfg.frm_rate_mul < 2) {
spdlog::critical("Frame rate multiplier must be set to at least 2 for RIFE.");
video2x::logger()->critical(
"Frame rate multiplier must be set to at least 2 for RIFE."
);
return -1;
}
@@ -399,14 +409,16 @@ int parse_args(
break;
}
default:
spdlog::critical("Invalid processor type.");
video2x::logger()->critical("Invalid processor type.");
return -1;
}
} catch (const po::error &e) {
spdlog::critical("Error parsing arguments: {}", e.what());
video2x::logger()->critical("Error parsing arguments: {}", e.what());
return -1;
} catch (const std::exception &e) {
spdlog::critical("Unexpected exception caught while parsing options: {}", e.what());
video2x::logger()->critical(
"Unexpected exception caught while parsing options: {}", e.what()
);
return -1;
}
@@ -415,17 +427,19 @@ int parse_args(
int get_vulkan_dev_ret = get_vulkan_device_prop(arguments.vk_device_index, &dev_props);
if (get_vulkan_dev_ret != 0) {
if (get_vulkan_dev_ret == -2) {
spdlog::critical("Invalid Vulkan device ID specified.");
video2x::logger()->critical("Invalid Vulkan device ID specified.");
return -1;
} else {
spdlog::warn("Unable to validate Vulkan device ID.");
video2x::logger()->warn("Unable to validate Vulkan device ID.");
return -1;
}
} else {
// Warn if the selected device is a CPU
spdlog::info("Using Vulkan device: {} ({:#x})", dev_props.deviceName, dev_props.deviceID);
video2x::logger()->info(
"Using Vulkan device: {} ({:#x})", dev_props.deviceName, dev_props.deviceID
);
if (dev_props.deviceType == VK_PHYSICAL_DEVICE_TYPE_CPU) {
spdlog::warn("The selected Vulkan device is a CPU device.");
video2x::logger()->warn("The selected Vulkan device is a CPU device.");
}
}
return 0;

View File

@@ -1,81 +0,0 @@
#include "logging.h"
#include <algorithm>
#include <unordered_map>
extern "C" {
#include <libavutil/log.h>
}
std::atomic<bool> newline_required = false;
void set_spdlog_level(video2x::logutils::Video2xLogLevel log_level) {
switch (log_level) {
case video2x::logutils::Video2xLogLevel::Trace:
spdlog::set_level(spdlog::level::trace);
break;
case video2x::logutils::Video2xLogLevel::Debug:
spdlog::set_level(spdlog::level::debug);
break;
case video2x::logutils::Video2xLogLevel::Info:
spdlog::set_level(spdlog::level::info);
break;
case video2x::logutils::Video2xLogLevel::Warning:
spdlog::set_level(spdlog::level::warn);
break;
case video2x::logutils::Video2xLogLevel::Error:
spdlog::set_level(spdlog::level::err);
break;
case video2x::logutils::Video2xLogLevel::Critical:
spdlog::set_level(spdlog::level::critical);
break;
case video2x::logutils::Video2xLogLevel::Off:
spdlog::set_level(spdlog::level::off);
break;
default:
spdlog::set_level(spdlog::level::info);
break;
}
}
std::optional<video2x::logutils::Video2xLogLevel> find_log_level_by_name(
const video2x::fsutils::StringType &log_level_name
) {
// Static map to store the mapping
static const std::
unordered_map<video2x::fsutils::StringType, video2x::logutils::Video2xLogLevel>
log_level_map = {
{STR("trace"), video2x::logutils::Video2xLogLevel::Trace},
{STR("debug"), video2x::logutils::Video2xLogLevel::Debug},
{STR("info"), video2x::logutils::Video2xLogLevel::Info},
{STR("warning"), video2x::logutils::Video2xLogLevel::Warning},
{STR("warn"), video2x::logutils::Video2xLogLevel::Warning},
{STR("error"), video2x::logutils::Video2xLogLevel::Error},
{STR("critical"), video2x::logutils::Video2xLogLevel::Critical},
{STR("off"), video2x::logutils::Video2xLogLevel::Off},
{STR("none"), video2x::logutils::Video2xLogLevel::Off}
};
// Normalize the input to lowercase
video2x::fsutils::StringType normalized_name = log_level_name;
std::transform(
normalized_name.begin(), normalized_name.end(), normalized_name.begin(), ::tolower
);
// Lookup the log level in the map
auto it = log_level_map.find(normalized_name);
if (it != log_level_map.end()) {
return it->second;
}
return std::nullopt;
}
// Newline-safe log callback for FFmpeg
void newline_safe_ffmpeg_log_callback(void *ptr, int level, const char *fmt, va_list vl) {
if (level <= av_log_get_level() && newline_required.load()) {
putchar('\n');
newline_required.store(false);
}
av_log_default_callback(ptr, level, fmt, vl);
}

View File

@@ -0,0 +1,9 @@
#include "newline_safe_sink.h"
void newline_safe_sink::log(const spdlog::details::log_msg &msg) {
if (needs_newline_.exchange(false)) {
std::fputs("\n", stdout);
}
spdlog::sinks::ansicolor_stdout_sink_mt::log(msg);
}

View File

@@ -9,10 +9,10 @@
#include <unistd.h>
#endif
#include <spdlog/spdlog.h>
#include <libvideo2x/logger_manager.h>
#include "argparse.h"
#include "logging.h"
#include "newline_safe_sink.h"
#include "timer.h"
// Set UNIX terminal input to non-blocking mode
@@ -73,16 +73,13 @@ int main(int argc, char **argv) {
// Create video processor object
video2x::VideoProcessor video_processor = video2x::VideoProcessor(
proc_cfg,
enc_cfg,
arguments.vk_device_index,
arguments.hw_device_type,
arguments.log_level,
arguments.benchmark
proc_cfg, enc_cfg, arguments.vk_device_index, arguments.hw_device_type, arguments.benchmark
);
// Register a newline-safe log callback for FFmpeg
av_log_set_callback(newline_safe_ffmpeg_log_callback);
// Register a newline-safe log sink
std::shared_ptr<newline_safe_sink> logger_sink = std::make_shared<newline_safe_sink>();
std::vector<spdlog::sink_ptr> sinks = {logger_sink};
video2x::logger_manager::LoggerManager::instance().reconfigure_logger("video2x", sinks);
// Create a thread for video processing
int proc_ret = 0;
@@ -91,7 +88,7 @@ int main(int argc, char **argv) {
proc_ret = video_processor.process(arguments.in_fname, arguments.out_fname);
completed.store(true, std::memory_order_relaxed);
});
spdlog::info("Press [space] to pause/resume, [q] to abort.");
video2x::logger()->info("Press [space] to pause/resume, [q] to abort.");
// Setup timer
Timer timer;
@@ -140,15 +137,15 @@ int main(int argc, char **argv) {
std::cout.flush();
timer.resume();
}
newline_required.store(true);
logger_sink->set_needs_newline(true);
}
} else if (ch == 'q' || ch == 'Q') {
// Abort processing
if (newline_required.load()) {
if (logger_sink->get_needs_newline()) {
putchar('\n');
}
spdlog::warn("Aborting gracefully; press Ctrl+C to terminate forcefully.");
newline_required.store(false);
video2x::logger()->warn("Aborting gracefully; press Ctrl+C to terminate forcefully.");
logger_sink->set_needs_newline(false);
video_processor.abort();
break;
}
@@ -192,7 +189,7 @@ int main(int argc, char **argv) {
<< ":" << std::setw(2) << std::setfill('0') << minutes_remaining << ":"
<< std::setw(2) << std::setfill('0') << seconds_remaining;
std::cout.flush();
newline_required.store(true);
logger_sink->set_needs_newline(true);
}
}
@@ -209,20 +206,20 @@ int main(int argc, char **argv) {
processing_thread.join();
// Print a newline if progress bar was displayed
if (newline_required.load()) {
if (logger_sink->get_needs_newline()) {
std::cout << '\n';
}
// Print final message based on processing result
if (video_processor.get_state() == video2x::VideoProcessorState::Aborted) {
spdlog::warn("Video processing aborted");
video2x::logger()->warn("Video processing aborted");
return 2;
} else if (proc_ret != 0 ||
video_processor.get_state() == video2x::VideoProcessorState::Failed) {
spdlog::critical("Video processing failed with error code {}", proc_ret);
video2x::logger()->critical("Video processing failed with error code {}", proc_ret);
return 1;
} else {
spdlog::info("Video processed successfully");
video2x::logger()->info("Video processed successfully");
}
// Calculate statistics

View File

@@ -3,7 +3,7 @@
#include <iostream>
#include <vector>
#include <spdlog/spdlog.h>
#include <libvideo2x/logger_manager.h>
static int enumerate_vulkan_devices(VkInstance *instance, std::vector<VkPhysicalDevice> &devices) {
// Create a Vulkan instance
@@ -12,7 +12,7 @@ static int enumerate_vulkan_devices(VkInstance *instance, std::vector<VkPhysical
VkResult result = vkCreateInstance(&create_info, nullptr, instance);
if (result != VK_SUCCESS) {
spdlog::error("Failed to create Vulkan instance.");
video2x::logger()->error("Failed to create Vulkan instance.");
return -1;
}
@@ -20,7 +20,9 @@ static int enumerate_vulkan_devices(VkInstance *instance, std::vector<VkPhysical
uint32_t device_count = 0;
result = vkEnumeratePhysicalDevices(*instance, &device_count, nullptr);
if (result != VK_SUCCESS || device_count == 0) {
spdlog::error("Failed to enumerate Vulkan physical devices or no devices available.");
video2x::logger()->error(
"Failed to enumerate Vulkan physical devices or no devices available."
);
vkDestroyInstance(*instance, nullptr);
return -1;
}
@@ -28,7 +30,7 @@ static int enumerate_vulkan_devices(VkInstance *instance, std::vector<VkPhysical
devices.resize(device_count);
result = vkEnumeratePhysicalDevices(*instance, &device_count, devices.data());
if (result != VK_SUCCESS) {
spdlog::error("Failed to retrieve Vulkan physical devices.");
video2x::logger()->error("Failed to retrieve Vulkan physical devices.");
vkDestroyInstance(*instance, nullptr);
return -1;
}
@@ -96,7 +98,7 @@ int list_vulkan_devices() {
int get_vulkan_device_prop(uint32_t vk_device_index, VkPhysicalDeviceProperties *dev_props) {
if (dev_props == nullptr) {
spdlog::error("Invalid device properties pointer.");
video2x::logger()->error("Invalid device properties pointer.");
return -1;
}