From 84d885b0da47f0a86005bba896baf4fb6be898b5 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Sat, 20 Sep 2025 00:08:58 +0000 Subject: [PATCH 01/17] Add basic logging functionality --- src/include/migraphx/logger.hpp | 107 ++++++++++++++++++++++++++++++++ 1 file changed, 107 insertions(+) create mode 100644 src/include/migraphx/logger.hpp diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp new file mode 100644 index 00000000000..589d9e835d3 --- /dev/null +++ b/src/include/migraphx/logger.hpp @@ -0,0 +1,107 @@ +/* + * The MIT License (MIT) + * + * Copyright (c) 2015-2025 Advanced Micro Devices, Inc. All rights reserved. + * + * 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. + */ +#ifndef MIGRAPHX_LOGGER_HPP +#define MIGRAPHX_LOGGER_HPP + +#include +#include +#include +#include +#include + +#ifndef _WIN32 +#include +#endif + +namespace migraphx { +inline namespace MIGRAPHX_INLINE_NS { + +MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_MIN_LEVEL) + +enum class Severity { TRACE, DEBUG, INFO, WARN, ERROR, FATAL }; + +inline size_t get_min_log_level() { + static auto log_level = value_of(MIGRAPHX_LOG_MIN_LEVEL{}, 2); // Default to INFO level + return log_level; +} + +class Logger : public std::basic_ostringstream { +public: + Logger(const char* file, int line, Severity severity) : file_(file), line_(line), severity_(severity) {} + ~Logger() override + { + std::string message = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + severity_str[static_cast(severity_)] + "] [" + file_ + ":" + std::to_string(line_) + "] " + this->str(); + #ifndef _WIN32 + static const bool use_color = isatty(STDERR_FILENO) != 0; + if (use_color) + { + switch(severity_) + { + case Severity::WARN: + message = "\033[33m" + message + "\033[0m"; // Yellow + break; + case Severity::ERROR: case Severity::FATAL: + message = "\033[31m" + message + "\033[0m"; // Red + break; + case Severity::TRACE: case Severity::DEBUG: case Severity::INFO: + break; // Prevents -Wswitch-enum warning during compilation + } + } + #endif + std::cerr << message << std::endl; + if(severity_ == Severity::FATAL) + std::abort(); + } +private: + std::string get_formatted_timestamp(std::chrono::time_point time) + { + auto now_in_time_t = std::chrono::system_clock::to_time_t(time); + auto* now_as_tm_date = std::localtime(&now_in_time_t); + std::stringstream ss; + ss << std::put_time(now_as_tm_date, "%Y-%m-%d %H:%M:%S"); + return ss.str(); + } + const char* file_; + int line_; + Severity severity_; + const char* severity_str[6] = {"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"}; +}; + +// NOP stream when log level is disabled +class NopStream { +public: + template + NopStream& operator<<(const T&) { return *this; } +}; + +#define LOG_TRACE if(static_cast(migraphx::Severity::TRACE) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::TRACE) +#define LOG_DEBUG if(static_cast(migraphx::Severity::DEBUG) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::DEBUG) +#define LOG_INFO if(static_cast(migraphx::Severity::INFO) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::INFO) +#define LOG_WARN if(static_cast(migraphx::Severity::WARN) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::WARN) +#define LOG_ERROR if(static_cast(migraphx::Severity::ERROR) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::ERROR) +#define LOG_FATAL if(static_cast(migraphx::Severity::FATAL) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::FATAL) + +} // namespace MIGRAPHX_INLINE_NS +} // namespace migraphx +#endif From 5203de7933d44ff80c83001ce586d35756fc1e64 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Sat, 20 Sep 2025 00:09:20 +0000 Subject: [PATCH 02/17] Formatting --- src/include/migraphx/logger.hpp | 112 ++++++++++++++++++++++---------- 1 file changed, 79 insertions(+), 33 deletions(-) diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index 589d9e835d3..997ad9e7c17 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -39,41 +39,59 @@ inline namespace MIGRAPHX_INLINE_NS { MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_MIN_LEVEL) -enum class Severity { TRACE, DEBUG, INFO, WARN, ERROR, FATAL }; +enum class Severity +{ + TRACE, + DEBUG, + INFO, + WARN, + ERROR, + FATAL +}; -inline size_t get_min_log_level() { +inline size_t get_min_log_level() +{ static auto log_level = value_of(MIGRAPHX_LOG_MIN_LEVEL{}, 2); // Default to INFO level return log_level; } -class Logger : public std::basic_ostringstream { -public: - Logger(const char* file, int line, Severity severity) : file_(file), line_(line), severity_(severity) {} - ~Logger() override +class Logger : public std::basic_ostringstream +{ + public: + Logger(const char* file, int line, Severity severity) + : file_(file), line_(line), severity_(severity) + { + } + ~Logger() override { - std::string message = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + severity_str[static_cast(severity_)] + "] [" + file_ + ":" + std::to_string(line_) + "] " + this->str(); - #ifndef _WIN32 - static const bool use_color = isatty(STDERR_FILENO) != 0; - if (use_color) + std::string message = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + + severity_str[static_cast(severity_)] + "] [" + file_ + ":" + + std::to_string(line_) + "] " + this->str(); +#ifndef _WIN32 + static const bool use_color = isatty(STDERR_FILENO) != 0; + if(use_color) + { + switch(severity_) { - switch(severity_) - { - case Severity::WARN: - message = "\033[33m" + message + "\033[0m"; // Yellow - break; - case Severity::ERROR: case Severity::FATAL: - message = "\033[31m" + message + "\033[0m"; // Red - break; - case Severity::TRACE: case Severity::DEBUG: case Severity::INFO: - break; // Prevents -Wswitch-enum warning during compilation - } + case Severity::WARN: + message = "\033[33m" + message + "\033[0m"; // Yellow + break; + case Severity::ERROR: + case Severity::FATAL: + message = "\033[31m" + message + "\033[0m"; // Red + break; + case Severity::TRACE: + case Severity::DEBUG: + case Severity::INFO: break; // Prevents -Wswitch-enum warning during compilation } - #endif + } +#endif std::cerr << message << std::endl; if(severity_ == Severity::FATAL) std::abort(); } -private: + + private: std::string get_formatted_timestamp(std::chrono::time_point time) { auto now_in_time_t = std::chrono::system_clock::to_time_t(time); @@ -89,18 +107,46 @@ class Logger : public std::basic_ostringstream { }; // NOP stream when log level is disabled -class NopStream { -public: - template - NopStream& operator<<(const T&) { return *this; } +class NopStream +{ + public: + template + NopStream& operator<<(const T&) + { + return *this; + } }; -#define LOG_TRACE if(static_cast(migraphx::Severity::TRACE) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::TRACE) -#define LOG_DEBUG if(static_cast(migraphx::Severity::DEBUG) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::DEBUG) -#define LOG_INFO if(static_cast(migraphx::Severity::INFO) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::INFO) -#define LOG_WARN if(static_cast(migraphx::Severity::WARN) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::WARN) -#define LOG_ERROR if(static_cast(migraphx::Severity::ERROR) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::ERROR) -#define LOG_FATAL if(static_cast(migraphx::Severity::FATAL) < migraphx::get_min_log_level()) migraphx::NopStream(); else migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::FATAL) +#define LOG_TRACE \ + if(static_cast(migraphx::Severity::TRACE) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::TRACE) +#define LOG_DEBUG \ + if(static_cast(migraphx::Severity::DEBUG) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::DEBUG) +#define LOG_INFO \ + if(static_cast(migraphx::Severity::INFO) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::INFO) +#define LOG_WARN \ + if(static_cast(migraphx::Severity::WARN) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::WARN) +#define LOG_ERROR \ + if(static_cast(migraphx::Severity::ERROR) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::ERROR) +#define LOG_FATAL \ + if(static_cast(migraphx::Severity::FATAL) < migraphx::get_min_log_level()) \ + migraphx::NopStream(); \ + else \ + migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::FATAL) } // namespace MIGRAPHX_INLINE_NS } // namespace migraphx From 625a6277898d1686140649c44792b8666f59b7e9 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Mon, 6 Oct 2025 20:16:22 +0000 Subject: [PATCH 03/17] Refactor logger to use variadic function and add record function --- src/CMakeLists.txt | 1 + src/driver/main.cpp | 13 +++ src/include/migraphx/logger.hpp | 167 +++++++++++++------------------- src/logger.cpp | 91 +++++++++++++++++ 4 files changed, 172 insertions(+), 100 deletions(-) create mode 100644 src/logger.cpp diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 75cac154e61..689aa17dbde 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -89,6 +89,7 @@ add_library(migraphx layout_convolution.cpp lexing.cpp load_save.cpp + logger.cpp make_op.cpp memory_coloring.cpp module.cpp diff --git a/src/driver/main.cpp b/src/driver/main.cpp index 31cb7472c27..e482bdcde7a 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -45,6 +45,7 @@ #include #include #include +#include #include #include @@ -1013,6 +1014,18 @@ int main(int argc, const char* argv[], const char* envp[]) if(m.count(cmd) > 0) { + migraphx::log::error()("Testing error logging"); + migraphx::log::warn()("Testing warn logging"); + migraphx::log::info()("Testing info logging"); + migraphx::log::debug()("Testing debug logging"); + migraphx::log::trace()("Testing trace logging"); + + migraphx::log::error() << "Testing error logging stream"; + migraphx::log::warn() << "Testing warn logging stream"; + migraphx::log::info() << "Testing info logging stream"; + migraphx::log::debug() << "Testing debug logging stream"; + migraphx::log::trace() << "Testing trace logging stream"; + std::string driver_invocation = std::string(argv[0]) + " " + migraphx::to_string_range(args, " "); std::cout << "Running [ " << get_version() << " ]: " << driver_invocation << std::endl; diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index 997ad9e7c17..1cc24ea6d2c 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -21,133 +21,100 @@ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN * THE SOFTWARE. */ -#ifndef MIGRAPHX_LOGGER_HPP -#define MIGRAPHX_LOGGER_HPP +#ifndef MIGRAPHX_GUARD_MIGRAPHX_LOGGER_HPP +#define MIGRAPHX_GUARD_MIGRAPHX_LOGGER_HPP #include +#include #include -#include -#include -#include - -#ifndef _WIN32 -#include -#endif namespace migraphx { +namespace log { inline namespace MIGRAPHX_INLINE_NS { -MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_MIN_LEVEL) - -enum class Severity +enum class severity { - TRACE, - DEBUG, - INFO, - WARN, + NONE, ERROR, - FATAL + WARN, + INFO, + DEBUG, + TRACE }; -inline size_t get_min_log_level() -{ - static auto log_level = value_of(MIGRAPHX_LOG_MIN_LEVEL{}, 2); // Default to INFO level - return log_level; -} +void record(severity s, std::string_view msg, source_location loc = source_location::current()); + +bool is_enabled(severity s); -class Logger : public std::basic_ostringstream +template +struct print { - public: - Logger(const char* file, int line, Severity severity) - : file_(file), line_(line), severity_(severity) + print(source_location ploc = source_location::current()) : loc(ploc) { } - ~Logger() override + + struct stream { - std::string message = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + - severity_str[static_cast(severity_)] + "] [" + file_ + ":" + - std::to_string(line_) + "] " + this->str(); -#ifndef _WIN32 - static const bool use_color = isatty(STDERR_FILENO) != 0; - if(use_color) + template + stream(severity ps, T&& x, source_location ploc = source_location::current()) : s(ps), loc(ploc), enabled(is_enabled(s)) { - switch(severity_) - { - case Severity::WARN: - message = "\033[33m" + message + "\033[0m"; // Yellow - break; - case Severity::ERROR: - case Severity::FATAL: - message = "\033[31m" + message + "\033[0m"; // Red - break; - case Severity::TRACE: - case Severity::DEBUG: - case Severity::INFO: break; // Prevents -Wswitch-enum warning during compilation - } + if(enabled) + ss << x; } -#endif - std::cerr << message << std::endl; - if(severity_ == Severity::FATAL) - std::abort(); - } - private: - std::string get_formatted_timestamp(std::chrono::time_point time) + template + stream& operator<<(T&& x) + { + if(enabled) + ss << x; + return *this; + } + + ~stream() + { + if(enabled) + record(s, ss.str(), loc); + } + + stream(const stream&) = delete; + stream& operator=(const stream&) = delete; + + severity s = severity::NONE; + source_location loc; + bool enabled; + std::ostringstream ss; + }; + + template + stream operator<<(T&& x) { - auto now_in_time_t = std::chrono::system_clock::to_time_t(time); - auto* now_as_tm_date = std::localtime(&now_in_time_t); - std::stringstream ss; - ss << std::put_time(now_as_tm_date, "%Y-%m-%d %H:%M:%S"); - return ss.str(); + return stream{Severity, x, loc}; } - const char* file_; - int line_; - Severity severity_; - const char* severity_str[6] = {"TRACE", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"}; -}; -// NOP stream when log level is disabled -class NopStream -{ - public: - template - NopStream& operator<<(const T&) + template + void operator()(Ts&& ... xs) const { - return *this; + if(is_enabled(Severity)) + { + std::ostringstream ss; + (ss << ... << xs); + record(Severity, ss.str(), loc); + } } + + print(const print&) = delete; + print& operator=(const print&) = delete; + + source_location loc; }; -#define LOG_TRACE \ - if(static_cast(migraphx::Severity::TRACE) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::TRACE) -#define LOG_DEBUG \ - if(static_cast(migraphx::Severity::DEBUG) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::DEBUG) -#define LOG_INFO \ - if(static_cast(migraphx::Severity::INFO) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::INFO) -#define LOG_WARN \ - if(static_cast(migraphx::Severity::WARN) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::WARN) -#define LOG_ERROR \ - if(static_cast(migraphx::Severity::ERROR) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::ERROR) -#define LOG_FATAL \ - if(static_cast(migraphx::Severity::FATAL) < migraphx::get_min_log_level()) \ - migraphx::NopStream(); \ - else \ - migraphx::Logger(__FILE__, __LINE__, migraphx::Severity::FATAL) +using error = print; +using warn = print; +using info = print; +using debug = print; +using trace = print; } // namespace MIGRAPHX_INLINE_NS +} // namespace log } // namespace migraphx #endif diff --git a/src/logger.cpp b/src/logger.cpp new file mode 100644 index 00000000000..184a5152aea --- /dev/null +++ b/src/logger.cpp @@ -0,0 +1,91 @@ +/* + * The MIT License (MIT) + * + * Copyright (c) 2015-2025 Advanced Micro Devices, Inc. All rights reserved. + * + * 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. + */ +#include +#include +#include +#include + +#ifndef _WIN32 +#include +#endif + +namespace migraphx { +namespace log { +inline namespace MIGRAPHX_INLINE_NS { + +MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_LEVEL) + +std::string get_formatted_timestamp(std::chrono::time_point time) +{ + auto now_in_time_t = std::chrono::system_clock::to_time_t(time); + auto us = std::chrono::duration_cast(time.time_since_epoch()) % + 1000000; + auto* now_as_tm_date = std::localtime(&now_in_time_t); + std::stringstream ss; + ss << std::put_time(now_as_tm_date, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') + << std::setw(6) << us.count(); + return ss.str(); +} + +void record(severity s, std::string_view msg, source_location loc) +{ + // Create log header + std::string header = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + "_EWIDT"[ + static_cast(s)] + "] [" + loc.file_name() + ":" + + std::to_string(loc.line()) + "] "; + std::string message = header + std::string(msg) + "\n"; + +#ifndef _WIN32 + // Add color if output is a terminal + static const bool use_color = isatty(STDERR_FILENO) != 0; + if(use_color) + { + switch(s) + { + case severity::WARN: + message = "\033[33m" + message + "\033[0m"; // Yellow + break; + case severity::ERROR: + message = "\033[31m" + message + "\033[0m"; // Red + break; + case severity::TRACE: + case severity::DEBUG: + case severity::INFO: + case severity::NONE: break; // Prevents -Wswitch-enum warning during compilation + } + } +#endif + + std::cerr << message; +} + +bool is_enabled(severity s) +{ + static auto level = value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::INFO)); + return static_cast(s) <= level; +} + +} // namespace MIGRAPHX_INLINE_NS +} // namespace logger +} // namespace migraphx From b4a6ff6bb02249fbdf0358fb0d1e2374642f38da Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Mon, 6 Oct 2025 20:16:33 +0000 Subject: [PATCH 04/17] Formatting --- src/include/migraphx/logger.hpp | 23 +++++++++++------------ src/logger.cpp | 16 ++++++++-------- 2 files changed, 19 insertions(+), 20 deletions(-) diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index 1cc24ea6d2c..edc7f9be1b2 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -46,23 +46,22 @@ void record(severity s, std::string_view msg, source_location loc = source_locat bool is_enabled(severity s); -template +template struct print { - print(source_location ploc = source_location::current()) : loc(ploc) - { - } + print(source_location ploc = source_location::current()) : loc(ploc) {} struct stream { - template - stream(severity ps, T&& x, source_location ploc = source_location::current()) : s(ps), loc(ploc), enabled(is_enabled(s)) + template + stream(severity ps, T&& x, source_location ploc = source_location::current()) + : s(ps), loc(ploc), enabled(is_enabled(s)) { if(enabled) ss << x; } - template + template stream& operator<<(T&& x) { if(enabled) @@ -76,7 +75,7 @@ struct print record(s, ss.str(), loc); } - stream(const stream&) = delete; + stream(const stream&) = delete; stream& operator=(const stream&) = delete; severity s = severity::NONE; @@ -85,14 +84,14 @@ struct print std::ostringstream ss; }; - template + template stream operator<<(T&& x) { return stream{Severity, x, loc}; } - template - void operator()(Ts&& ... xs) const + template + void operator()(Ts&&... xs) const { if(is_enabled(Severity)) { @@ -102,7 +101,7 @@ struct print } } - print(const print&) = delete; + print(const print&) = delete; print& operator=(const print&) = delete; source_location loc; diff --git a/src/logger.cpp b/src/logger.cpp index 184a5152aea..d7b47c56c20 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -38,24 +38,24 @@ MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_LEVEL) std::string get_formatted_timestamp(std::chrono::time_point time) { - auto now_in_time_t = std::chrono::system_clock::to_time_t(time); - auto us = std::chrono::duration_cast(time.time_since_epoch()) % - 1000000; + auto now_in_time_t = std::chrono::system_clock::to_time_t(time); + auto us = + std::chrono::duration_cast(time.time_since_epoch()) % 1000000; auto* now_as_tm_date = std::localtime(&now_in_time_t); std::stringstream ss; ss << std::put_time(now_as_tm_date, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') - << std::setw(6) << us.count(); + << std::setw(6) << us.count(); return ss.str(); } void record(severity s, std::string_view msg, source_location loc) { // Create log header - std::string header = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + "_EWIDT"[ - static_cast(s)] + "] [" + loc.file_name() + ":" + + std::string header = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + + "_EWIDT"[static_cast(s)] + "] [" + loc.file_name() + ":" + std::to_string(loc.line()) + "] "; std::string message = header + std::string(msg) + "\n"; - + #ifndef _WIN32 // Add color if output is a terminal static const bool use_color = isatty(STDERR_FILENO) != 0; @@ -87,5 +87,5 @@ bool is_enabled(severity s) } } // namespace MIGRAPHX_INLINE_NS -} // namespace logger +} // namespace log } // namespace migraphx From 213fe9ce1b7957583a60b53a6c164cb7bbd29802 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Mon, 3 Nov 2025 18:59:03 +0000 Subject: [PATCH 05/17] Add console and file logging using spdlog --- requirements.txt | 1 + src/driver/main.cpp | 112 ++++++++++++++++++++++++++++++++ src/include/migraphx/logger.hpp | 4 ++ src/logger.cpp | 74 +++++++++++++++++++-- 4 files changed, 187 insertions(+), 4 deletions(-) diff --git a/requirements.txt b/requirements.txt index f369feaf31b..673b52e8c97 100644 --- a/requirements.txt +++ b/requirements.txt @@ -30,3 +30,4 @@ msgpack/msgpack-c@cpp-3.3.0 -DMSGPACK_BUILD_TESTS=Off -DMSGPACK_BUILD_EXAMPLES=O sqlite3@3.43.2 -DCMAKE_POSITION_INDEPENDENT_CODE=On ROCm/composable_kernel@b7775add2d28251674d81e220cd4a857b90b997a -DCK_BUILD_JIT_LIB=On -DCMAKE_POSITION_INDEPENDENT_CODE=On ROCm/rocMLIR@3b46579fa760e2858f9a7409bc6aba00ddd03dce -DBUILD_FAT_LIBROCKCOMPILER=On -DLLVM_INCLUDE_TESTS=Off +gabime/spdlog@v1.16.0 diff --git a/src/driver/main.cpp b/src/driver/main.cpp index e482bdcde7a..a61fdca32aa 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -63,6 +63,7 @@ #include #include +#include namespace { std::vector @@ -92,6 +93,104 @@ std::string get_formatted_timestamp(std::chrono::time_point parse_log_level_string(const std::string& level_str) + { + if(level_str == "trace" || level_str == "5") + return migraphx::log::severity::TRACE; + else if(level_str == "debug" || level_str == "4") + return migraphx::log::severity::DEBUG; + else if(level_str == "info" || level_str == "3") + return migraphx::log::severity::INFO; + else if(level_str == "warn" || level_str == "warning" || level_str == "2") + return migraphx::log::severity::WARN; + else if(level_str == "error" || level_str == "1") + return migraphx::log::severity::ERROR; + else if(level_str == "none" || level_str == "off" || level_str == "0") + return migraphx::log::severity::NONE; + + return std::nullopt; + } +}; + +bool parse_and_apply_global_options(std::vector& args) +{ + // Extract only global option flags from args for parsing + std::vector global_args; + auto it = args.begin(); + while(it != args.end()) + { + if(*it == "--log-level" || *it == "--log-file") + { + global_args.push_back(*it); + it = args.erase(it); + // Also grab the value if present + if(it != args.end() && !it->empty() && (*it)[0] != '-') + { + global_args.push_back(*it); + it = args.erase(it); + } + } + else + { + ++it; + } + } + + if(!global_args.empty()) + { + global_options opts; + migraphx::driver::argument_parser ap; + opts.parse(ap); + + if(ap.parse(global_args)) + return false; + + opts.apply(); + } + + return true; +} } // namespace namespace migraphx { @@ -950,6 +1049,12 @@ struct main_command ap.help("Show MIGraphX version"), ap.show_help(version_str)); ap(nullptr, {"--ort-sha"}, ap.help("Show MIGraphX onnx runtime SHA")); + ap(log_level, + {"--log-level"}, + ap.help("Set log level (none/0, error/1, warn/2, info/3, debug/4, trace/5)")); + ap(log_file, + {"--log-file"}, + ap.help("Log to file")); // Trim command off of exe name ap.set_exe_name(ap.get_exe_name().substr(0, ap.get_exe_name().size() - 5)); @@ -958,6 +1063,8 @@ struct main_command std::vector wrong_commands{}; std::string exe_name = ""; + std::string log_level; + std::string log_file; void run() { @@ -992,6 +1099,11 @@ using namespace migraphx::driver; // NOLINT int main(int argc, const char* argv[], const char* envp[]) { std::vector args(argv + 1, argv + argc); + + // Parse and apply global options (--log-level, --log-file) + if(!parse_and_apply_global_options(args)) + return 1; + // no argument, print the help infomration by default if(args.empty()) { diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index edc7f9be1b2..a8c123dc46a 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -46,6 +46,10 @@ void record(severity s, std::string_view msg, source_location loc = source_locat bool is_enabled(severity s); +void set_log_level(severity s); + +void add_file_logger(std::string_view filename); + template struct print { diff --git a/src/logger.cpp b/src/logger.cpp index d7b47c56c20..6a9c368d0e1 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -25,9 +25,11 @@ #include #include #include +#include "spdlog/sinks/basic_file_sink.h" #ifndef _WIN32 #include +#include "spdlog/sinks/stdout_color_sinks.h" #endif namespace migraphx { @@ -36,6 +38,62 @@ inline namespace MIGRAPHX_INLINE_NS { MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_LEVEL) +static spdlog::logger* get_migraphx_logger() +{ + static std::vector sinks; + static spdlog::logger* migraphx_logger = new spdlog::logger("migraphx_logger", begin(sinks), end(sinks)); + return migraphx_logger; +} + +void add_file_logger(std::string_view filename) +{ + auto* logger = get_migraphx_logger(); + auto file_sink = std::make_shared(std::string(filename)); + file_sink->set_pattern("%v"); + logger->sinks().push_back(file_sink); +} + +static size_t& get_log_level() +{ + static size_t level = value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::INFO)); + return level; +} + +static spdlog::level::level_enum to_spdlog_level(severity s) +{ + // Convert migraphx severity to spdlog level + // migraphx: NONE(0) < ERROR(1) < WARN(2) < INFO(3) < DEBUG(4) < TRACE(5) + // spdlog: off(6) > critical(5) > err(4) > warn(3) > info(2) > debug(1) > trace(0) + switch(s) + { + case severity::NONE: return spdlog::level::off; + case severity::ERROR: return spdlog::level::err; + case severity::WARN: return spdlog::level::warn; + case severity::INFO: return spdlog::level::info; + case severity::DEBUG: return spdlog::level::debug; + case severity::TRACE: return spdlog::level::trace; + } + return spdlog::level::info; +} + +static void init_stderr_logger() +{ + static bool initialized = false; + if(!initialized) + { + auto* logger = get_migraphx_logger(); +#ifndef _WIN32 + auto stderr_sink = std::make_shared(); +#else + auto stderr_sink = std::make_shared(); +#endif + logger->sinks().push_back(stderr_sink); + logger->set_pattern("%v"); + logger->set_level(to_spdlog_level(static_cast(get_log_level()))); + initialized = true; + } +} + std::string get_formatted_timestamp(std::chrono::time_point time) { auto now_in_time_t = std::chrono::system_clock::to_time_t(time); @@ -54,7 +112,7 @@ void record(severity s, std::string_view msg, source_location loc) std::string header = get_formatted_timestamp(std::chrono::system_clock::now()) + " [" + "_EWIDT"[static_cast(s)] + "] [" + loc.file_name() + ":" + std::to_string(loc.line()) + "] "; - std::string message = header + std::string(msg) + "\n"; + std::string message = header + std::string(msg); #ifndef _WIN32 // Add color if output is a terminal @@ -77,15 +135,23 @@ void record(severity s, std::string_view msg, source_location loc) } #endif - std::cerr << message; + init_stderr_logger(); + auto* logger = get_migraphx_logger(); + logger->log(to_spdlog_level(s), message); } bool is_enabled(severity s) { - static auto level = value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::INFO)); - return static_cast(s) <= level; + return static_cast(s) <= get_log_level(); } +void set_log_level(severity s) +{ + get_log_level() = static_cast(s); + init_stderr_logger(); // Ensure logger is initialized + auto* logger = get_migraphx_logger(); + logger->set_level(to_spdlog_level(s)); +} } // namespace MIGRAPHX_INLINE_NS } // namespace log } // namespace migraphx From c818ecd94aec83ba620902aaac16f308d76dbb12 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Mon, 3 Nov 2025 18:59:19 +0000 Subject: [PATCH 06/17] Formatting --- src/driver/main.cpp | 25 ++++++++++++------------- src/logger.cpp | 10 ++++------ 2 files changed, 16 insertions(+), 19 deletions(-) diff --git a/src/driver/main.cpp b/src/driver/main.cpp index a61fdca32aa..5911ba19563 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -101,8 +101,8 @@ struct global_options void parse(migraphx::driver::argument_parser& ap) { - ap(log_level, - {"--log-level"}, + ap(log_level, + {"--log-level"}, ap.help("Set log level (none/0, error/1, warn/2, info/3, debug/4, trace/5)"), ap.validate([](auto&, auto&, auto& params) { if(!params.empty()) @@ -111,7 +111,7 @@ struct global_options if(!parse_log_level_string(level_str)) { throw std::runtime_error( - "Invalid log level: " + level_str + + "Invalid log level: " + level_str + ". Valid levels: none/0, error/1, warn/2, info/3, debug/4, trace/5"); } } @@ -133,8 +133,9 @@ struct global_options } } -private: - static std::optional parse_log_level_string(const std::string& level_str) + private: + static std::optional + parse_log_level_string(const std::string& level_str) { if(level_str == "trace" || level_str == "5") return migraphx::log::severity::TRACE; @@ -148,7 +149,7 @@ struct global_options return migraphx::log::severity::ERROR; else if(level_str == "none" || level_str == "off" || level_str == "0") return migraphx::log::severity::NONE; - + return std::nullopt; } }; @@ -176,19 +177,19 @@ bool parse_and_apply_global_options(std::vector& args) ++it; } } - + if(!global_args.empty()) { global_options opts; migraphx::driver::argument_parser ap; opts.parse(ap); - + if(ap.parse(global_args)) return false; - + opts.apply(); } - + return true; } } // namespace @@ -1052,9 +1053,7 @@ struct main_command ap(log_level, {"--log-level"}, ap.help("Set log level (none/0, error/1, warn/2, info/3, debug/4, trace/5)")); - ap(log_file, - {"--log-file"}, - ap.help("Log to file")); + ap(log_file, {"--log-file"}, ap.help("Log to file")); // Trim command off of exe name ap.set_exe_name(ap.get_exe_name().substr(0, ap.get_exe_name().size() - 5)); diff --git a/src/logger.cpp b/src/logger.cpp index 6a9c368d0e1..cd23874f144 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -41,13 +41,14 @@ MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_LEVEL) static spdlog::logger* get_migraphx_logger() { static std::vector sinks; - static spdlog::logger* migraphx_logger = new spdlog::logger("migraphx_logger", begin(sinks), end(sinks)); + static spdlog::logger* migraphx_logger = + new spdlog::logger("migraphx_logger", begin(sinks), end(sinks)); return migraphx_logger; } void add_file_logger(std::string_view filename) { - auto* logger = get_migraphx_logger(); + auto* logger = get_migraphx_logger(); auto file_sink = std::make_shared(std::string(filename)); file_sink->set_pattern("%v"); logger->sinks().push_back(file_sink); @@ -140,10 +141,7 @@ void record(severity s, std::string_view msg, source_location loc) logger->log(to_spdlog_level(s), message); } -bool is_enabled(severity s) -{ - return static_cast(s) <= get_log_level(); -} +bool is_enabled(severity s) { return static_cast(s) <= get_log_level(); } void set_log_level(severity s) { From b6599cadc120da342a2ba9a636158c78367dd7b9 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Mon, 3 Nov 2025 19:26:04 +0000 Subject: [PATCH 07/17] Add multi file logging; fix params not showing in logging --- src/driver/main.cpp | 35 +++++++++++++++++++++++------------ 1 file changed, 23 insertions(+), 12 deletions(-) diff --git a/src/driver/main.cpp b/src/driver/main.cpp index 5911ba19563..cc547ee281d 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -97,7 +97,7 @@ std::string get_formatted_timestamp(std::chrono::time_point log_files; void parse(migraphx::driver::argument_parser& ap) { @@ -116,7 +116,11 @@ struct global_options } } })); - ap(log_file, {"--log-file"}, ap.help("Log to file")); + ap(log_files, + {"--log-file"}, + ap.help("Log to file(s) (--log-file file1.log file2.log ...)"), + ap.append(), + ap.nargs(2)); } void apply() const @@ -127,7 +131,7 @@ struct global_options if(level) migraphx::log::set_log_level(*level); } - if(!log_file.empty()) + for(const auto& log_file : log_files) { migraphx::log::add_file_logger(log_file); } @@ -161,17 +165,28 @@ bool parse_and_apply_global_options(std::vector& args) auto it = args.begin(); while(it != args.end()) { - if(*it == "--log-level" || *it == "--log-file") + if(*it == "--log-level") { global_args.push_back(*it); it = args.erase(it); - // Also grab the value if present + // Grab the single value if present if(it != args.end() && !it->empty() && (*it)[0] != '-') { global_args.push_back(*it); it = args.erase(it); } } + else if(*it == "--log-file") + { + global_args.push_back(*it); + it = args.erase(it); + // Grab all values until the next flag (for unlimited log files) + while(it != args.end() && !it->empty() && (*it)[0] != '-') + { + global_args.push_back(*it); + it = args.erase(it); + } + } else { ++it; @@ -1050,10 +1065,6 @@ struct main_command ap.help("Show MIGraphX version"), ap.show_help(version_str)); ap(nullptr, {"--ort-sha"}, ap.help("Show MIGraphX onnx runtime SHA")); - ap(log_level, - {"--log-level"}, - ap.help("Set log level (none/0, error/1, warn/2, info/3, debug/4, trace/5)")); - ap(log_file, {"--log-file"}, ap.help("Log to file")); // Trim command off of exe name ap.set_exe_name(ap.get_exe_name().substr(0, ap.get_exe_name().size() - 5)); @@ -1062,8 +1073,6 @@ struct main_command std::vector wrong_commands{}; std::string exe_name = ""; - std::string log_level; - std::string log_file; void run() { @@ -1098,6 +1107,8 @@ using namespace migraphx::driver; // NOLINT int main(int argc, const char* argv[], const char* envp[]) { std::vector args(argv + 1, argv + argc); + // Save original args for display purposes before they get modified + const std::vector original_args = args; // Parse and apply global options (--log-level, --log-file) if(!parse_and_apply_global_options(args)) @@ -1138,7 +1149,7 @@ int main(int argc, const char* argv[], const char* envp[]) migraphx::log::trace() << "Testing trace logging stream"; std::string driver_invocation = - std::string(argv[0]) + " " + migraphx::to_string_range(args, " "); + std::string(argv[0]) + " " + migraphx::to_string_range(original_args, " "); std::cout << "Running [ " << get_version() << " ]: " << driver_invocation << std::endl; // Print start timestamp From 1fdb940c817e83ee5ce11844badd4d31d4e4dad4 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 4 Nov 2025 17:53:58 +0000 Subject: [PATCH 08/17] Fix color logging --- src/logger.cpp | 46 +++++++++++++++------------------------------- 1 file changed, 15 insertions(+), 31 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index cd23874f144..529e162e02c 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -28,7 +28,6 @@ #include "spdlog/sinks/basic_file_sink.h" #ifndef _WIN32 -#include #include "spdlog/sinks/stdout_color_sinks.h" #endif @@ -50,7 +49,7 @@ void add_file_logger(std::string_view filename) { auto* logger = get_migraphx_logger(); auto file_sink = std::make_shared(std::string(filename)); - file_sink->set_pattern("%v"); + file_sink->set_pattern("%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v"); logger->sinks().push_back(file_sink); } @@ -88,8 +87,14 @@ static void init_stderr_logger() #else auto stderr_sink = std::make_shared(); #endif + // Use spdlog pattern with colors for the color sink + // %^ ... %$ = wrap entire line with color based on log level + // %Y-%m-%d %H:%M:%S.%f = timestamp with microseconds + // [%L] = log level + // [%s:%#] = source file and line + // %v = the actual message + stderr_sink->set_pattern("%^%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v%$"); logger->sinks().push_back(stderr_sink); - logger->set_pattern("%v"); logger->set_level(to_spdlog_level(static_cast(get_log_level()))); initialized = true; } @@ -109,36 +114,15 @@ std::string get_formatted_timestamp(std::chrono::time_point(s)] + "] [" + loc.file_name() + ":" + - std::to_string(loc.line()) + "] "; - std::string message = header + std::string(msg); - -#ifndef _WIN32 - // Add color if output is a terminal - static const bool use_color = isatty(STDERR_FILENO) != 0; - if(use_color) - { - switch(s) - { - case severity::WARN: - message = "\033[33m" + message + "\033[0m"; // Yellow - break; - case severity::ERROR: - message = "\033[31m" + message + "\033[0m"; // Red - break; - case severity::TRACE: - case severity::DEBUG: - case severity::INFO: - case severity::NONE: break; // Prevents -Wswitch-enum warning during compilation - } - } -#endif - init_stderr_logger(); auto* logger = get_migraphx_logger(); - logger->log(to_spdlog_level(s), message); + + // Convert migraphx source_location to spdlog source_loc + spdlog::source_loc spdlog_loc{loc.file_name(), static_cast(loc.line()), ""}; + + // Use spdlog's log method with source location + // The pattern formatting handles timestamp, level, location, and colors + logger->log(spdlog_loc, to_spdlog_level(s), "{}", msg); } bool is_enabled(severity s) { return static_cast(s) <= get_log_level(); } From d8a8414885ea9ae867389ca4315f7562befcb62e Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 4 Nov 2025 18:39:05 +0000 Subject: [PATCH 09/17] Add windows color logger --- src/logger.cpp | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index 529e162e02c..12f32e88d52 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -27,7 +27,9 @@ #include #include "spdlog/sinks/basic_file_sink.h" -#ifndef _WIN32 +#ifdef _WIN32 +#include "spdlog/sinks/wincolor_sink.h" +#else #include "spdlog/sinks/stdout_color_sinks.h" #endif @@ -82,10 +84,10 @@ static void init_stderr_logger() if(!initialized) { auto* logger = get_migraphx_logger(); -#ifndef _WIN32 - auto stderr_sink = std::make_shared(); +#ifdef _WIN32 + auto stderr_sink = std::make_shared(); #else - auto stderr_sink = std::make_shared(); + auto stderr_sink = std::make_shared(); #endif // Use spdlog pattern with colors for the color sink // %^ ... %$ = wrap entire line with color based on log level @@ -94,6 +96,8 @@ static void init_stderr_logger() // [%s:%#] = source file and line // %v = the actual message stderr_sink->set_pattern("%^%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v%$"); + // Set info level to use default terminal color + stderr_sink->set_color(spdlog::level::info, ""); logger->sinks().push_back(stderr_sink); logger->set_level(to_spdlog_level(static_cast(get_log_level()))); initialized = true; From 0cd773c79717ae542668482589726e445629fd13 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Fri, 7 Nov 2025 21:38:50 +0000 Subject: [PATCH 10/17] Add file-specific severity option --- src/include/migraphx/logger.hpp | 2 +- src/logger.cpp | 17 +++++++++-------- 2 files changed, 10 insertions(+), 9 deletions(-) diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index a8c123dc46a..c676fd14f22 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -48,7 +48,7 @@ bool is_enabled(severity s); void set_log_level(severity s); -void add_file_logger(std::string_view filename); +void add_file_logger(std::string_view filename, severity s = severity::INFO); template struct print diff --git a/src/logger.cpp b/src/logger.cpp index 12f32e88d52..44bb81591e2 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -47,14 +47,6 @@ static spdlog::logger* get_migraphx_logger() return migraphx_logger; } -void add_file_logger(std::string_view filename) -{ - auto* logger = get_migraphx_logger(); - auto file_sink = std::make_shared(std::string(filename)); - file_sink->set_pattern("%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v"); - logger->sinks().push_back(file_sink); -} - static size_t& get_log_level() { static size_t level = value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::INFO)); @@ -78,6 +70,15 @@ static spdlog::level::level_enum to_spdlog_level(severity s) return spdlog::level::info; } +void add_file_logger(std::string_view filename, severity s) +{ + auto* logger = get_migraphx_logger(); + auto file_sink = std::make_shared(std::string(filename)); + file_sink->set_pattern("%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v"); + file_sink->set_level(to_spdlog_level(s)); + logger->sinks().push_back(file_sink); +} + static void init_stderr_logger() { static bool initialized = false; From 10a9ae10b0b67c8ef6d30f7f35a3ab642d2ee1c8 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Wed, 26 Nov 2025 00:02:34 +0000 Subject: [PATCH 11/17] Remove windows specific sinks, add unit tests --- src/logger.cpp | 9 -- test/logger_test.cpp | 196 +++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 196 insertions(+), 9 deletions(-) create mode 100644 test/logger_test.cpp diff --git a/src/logger.cpp b/src/logger.cpp index 44bb81591e2..4eb1bae7bd6 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -26,12 +26,7 @@ #include #include #include "spdlog/sinks/basic_file_sink.h" - -#ifdef _WIN32 -#include "spdlog/sinks/wincolor_sink.h" -#else #include "spdlog/sinks/stdout_color_sinks.h" -#endif namespace migraphx { namespace log { @@ -85,11 +80,7 @@ static void init_stderr_logger() if(!initialized) { auto* logger = get_migraphx_logger(); -#ifdef _WIN32 - auto stderr_sink = std::make_shared(); -#else auto stderr_sink = std::make_shared(); -#endif // Use spdlog pattern with colors for the color sink // %^ ... %$ = wrap entire line with color based on log level // %Y-%m-%d %H:%M:%S.%f = timestamp with microseconds diff --git a/test/logger_test.cpp b/test/logger_test.cpp new file mode 100644 index 00000000000..7d0fa27661a --- /dev/null +++ b/test/logger_test.cpp @@ -0,0 +1,196 @@ +/* + * The MIT License (MIT) + * + * Copyright (c) 2015-2025 Advanced Micro Devices, Inc. All rights reserved. + * + * 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. + */ + +#include +#include "test.hpp" + +TEST_CASE(logger_set_log_level) +{ + // Test setting different log levels + migraphx::log::set_log_level(migraphx::log::severity::ERROR); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); + + migraphx::log::set_log_level(migraphx::log::severity::INFO); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + + migraphx::log::set_log_level(migraphx::log::severity::TRACE); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::TRACE)); +} + +TEST_CASE(logger_is_enabled) +{ + // Set to INFO level + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Check severity ordering: ERROR < WARN < INFO < DEBUG < TRACE + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); +} + +TEST_CASE(logger_basic_logging) +{ + // Test that logging doesn't crash or throw + migraphx::log::set_log_level(migraphx::log::severity::TRACE); + + // Test stream operator + migraphx::log::error() << "Test error message"; + migraphx::log::warn() << "Test warn message"; + migraphx::log::info() << "Test info message"; + migraphx::log::debug() << "Test debug message"; + migraphx::log::trace() << "Test trace message"; + + // Test function call operator + migraphx::log::error()("Error message"); + migraphx::log::warn()("Warn message"); + migraphx::log::info()("Info message"); + migraphx::log::debug()("Debug message"); + migraphx::log::trace()("Trace message"); +} + +TEST_CASE(logger_stream_composition) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test composing multiple values in a single log message + int value = 42; + double pi = 3.14; + std::string text = "hello"; + + migraphx::log::info() << "Multiple values: " << value << ", " << pi << ", " << text; +} + +TEST_CASE(logger_function_call_multiple_args) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test function call operator with multiple arguments + migraphx::log::info()("Multiple", " ", "arguments"); + migraphx::log::error()("Error code: ", 404); +} + +TEST_CASE(logger_disabled_levels) +{ + // Set to ERROR level - only errors should be enabled + migraphx::log::set_log_level(migraphx::log::severity::ERROR); + + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); + + // These should not cause any output or crash + migraphx::log::warn() << "This should be suppressed"; + migraphx::log::info() << "This should be suppressed"; + migraphx::log::debug() << "This should be suppressed"; +} + +TEST_CASE(logger_none_level) +{ + // Set to NONE - nothing should be enabled + migraphx::log::set_log_level(migraphx::log::severity::NONE); + + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::ERROR)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); +} + +TEST_CASE(logger_severity_ordering) +{ + // Test that severity levels are properly ordered + // NONE(0) < ERROR(1) < WARN(2) < INFO(3) < DEBUG(4) < TRACE(5) + + EXPECT(static_cast(migraphx::log::severity::NONE) < + static_cast(migraphx::log::severity::ERROR)); + EXPECT(static_cast(migraphx::log::severity::ERROR) < + static_cast(migraphx::log::severity::WARN)); + EXPECT(static_cast(migraphx::log::severity::WARN) < + static_cast(migraphx::log::severity::INFO)); + EXPECT(static_cast(migraphx::log::severity::INFO) < + static_cast(migraphx::log::severity::DEBUG)); + EXPECT(static_cast(migraphx::log::severity::DEBUG) < + static_cast(migraphx::log::severity::TRACE)); +} + +TEST_CASE(logger_empty_messages) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test logging empty messages doesn't crash + migraphx::log::info() << ""; + migraphx::log::error()(""); +} + +TEST_CASE(logger_special_characters) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test logging special characters + migraphx::log::info() << "Special chars: \n\t\\"; + migraphx::log::info()("Unicode: ", "日本語"); +} + +TEST_CASE(logger_long_messages) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test logging a very long message + std::string long_msg(1000, 'x'); + migraphx::log::info() << "Long message: " << long_msg; +} + +TEST_CASE(logger_conditional_logging) +{ + migraphx::log::set_log_level(migraphx::log::severity::INFO); + + // Test conditional logging based on is_enabled + if(migraphx::log::is_enabled(migraphx::log::severity::DEBUG)) + { + // This should not execute + migraphx::log::debug() << "Should not appear"; + } + + if(migraphx::log::is_enabled(migraphx::log::severity::INFO)) + { + // This should execute + migraphx::log::info() << "Should appear"; + } +} + +int main(int argc, const char* argv[]) { test::run(argc, argv); } + From 5c1fcffef4423a3bd9a0253865e7bf6626379be2 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Wed, 26 Nov 2025 00:02:48 +0000 Subject: [PATCH 12/17] Formatting --- src/logger.cpp | 2 +- test/logger_test.cpp | 45 ++++++++++++++++++++++---------------------- 2 files changed, 23 insertions(+), 24 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index 4eb1bae7bd6..2db595b5324 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -79,7 +79,7 @@ static void init_stderr_logger() static bool initialized = false; if(!initialized) { - auto* logger = get_migraphx_logger(); + auto* logger = get_migraphx_logger(); auto stderr_sink = std::make_shared(); // Use spdlog pattern with colors for the color sink // %^ ... %$ = wrap entire line with color based on log level diff --git a/test/logger_test.cpp b/test/logger_test.cpp index 7d0fa27661a..0255ec85e82 100644 --- a/test/logger_test.cpp +++ b/test/logger_test.cpp @@ -51,7 +51,7 @@ TEST_CASE(logger_is_enabled) { // Set to INFO level migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Check severity ordering: ERROR < WARN < INFO < DEBUG < TRACE EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); @@ -64,14 +64,14 @@ TEST_CASE(logger_basic_logging) { // Test that logging doesn't crash or throw migraphx::log::set_log_level(migraphx::log::severity::TRACE); - + // Test stream operator migraphx::log::error() << "Test error message"; migraphx::log::warn() << "Test warn message"; migraphx::log::info() << "Test info message"; migraphx::log::debug() << "Test debug message"; migraphx::log::trace() << "Test trace message"; - + // Test function call operator migraphx::log::error()("Error message"); migraphx::log::warn()("Warn message"); @@ -83,19 +83,19 @@ TEST_CASE(logger_basic_logging) TEST_CASE(logger_stream_composition) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test composing multiple values in a single log message - int value = 42; - double pi = 3.14; + int value = 42; + double pi = 3.14; std::string text = "hello"; - + migraphx::log::info() << "Multiple values: " << value << ", " << pi << ", " << text; } TEST_CASE(logger_function_call_multiple_args) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test function call operator with multiple arguments migraphx::log::info()("Multiple", " ", "arguments"); migraphx::log::error()("Error code: ", 404); @@ -105,13 +105,13 @@ TEST_CASE(logger_disabled_levels) { // Set to ERROR level - only errors should be enabled migraphx::log::set_log_level(migraphx::log::severity::ERROR); - + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); - + // These should not cause any output or crash migraphx::log::warn() << "This should be suppressed"; migraphx::log::info() << "This should be suppressed"; @@ -122,7 +122,7 @@ TEST_CASE(logger_none_level) { // Set to NONE - nothing should be enabled migraphx::log::set_log_level(migraphx::log::severity::NONE); - + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::ERROR)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); @@ -134,23 +134,23 @@ TEST_CASE(logger_severity_ordering) { // Test that severity levels are properly ordered // NONE(0) < ERROR(1) < WARN(2) < INFO(3) < DEBUG(4) < TRACE(5) - - EXPECT(static_cast(migraphx::log::severity::NONE) < + + EXPECT(static_cast(migraphx::log::severity::NONE) < static_cast(migraphx::log::severity::ERROR)); - EXPECT(static_cast(migraphx::log::severity::ERROR) < + EXPECT(static_cast(migraphx::log::severity::ERROR) < static_cast(migraphx::log::severity::WARN)); - EXPECT(static_cast(migraphx::log::severity::WARN) < + EXPECT(static_cast(migraphx::log::severity::WARN) < static_cast(migraphx::log::severity::INFO)); - EXPECT(static_cast(migraphx::log::severity::INFO) < + EXPECT(static_cast(migraphx::log::severity::INFO) < static_cast(migraphx::log::severity::DEBUG)); - EXPECT(static_cast(migraphx::log::severity::DEBUG) < + EXPECT(static_cast(migraphx::log::severity::DEBUG) < static_cast(migraphx::log::severity::TRACE)); } TEST_CASE(logger_empty_messages) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test logging empty messages doesn't crash migraphx::log::info() << ""; migraphx::log::error()(""); @@ -159,7 +159,7 @@ TEST_CASE(logger_empty_messages) TEST_CASE(logger_special_characters) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test logging special characters migraphx::log::info() << "Special chars: \n\t\\"; migraphx::log::info()("Unicode: ", "日本語"); @@ -168,7 +168,7 @@ TEST_CASE(logger_special_characters) TEST_CASE(logger_long_messages) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test logging a very long message std::string long_msg(1000, 'x'); migraphx::log::info() << "Long message: " << long_msg; @@ -177,14 +177,14 @@ TEST_CASE(logger_long_messages) TEST_CASE(logger_conditional_logging) { migraphx::log::set_log_level(migraphx::log::severity::INFO); - + // Test conditional logging based on is_enabled if(migraphx::log::is_enabled(migraphx::log::severity::DEBUG)) { // This should not execute migraphx::log::debug() << "Should not appear"; } - + if(migraphx::log::is_enabled(migraphx::log::severity::INFO)) { // This should execute @@ -193,4 +193,3 @@ TEST_CASE(logger_conditional_logging) } int main(int argc, const char* argv[]) { test::run(argc, argv); } - From 60b64c82c29fcf920e57c08d8f70c7215be7ffb2 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Wed, 26 Nov 2025 00:25:09 +0000 Subject: [PATCH 13/17] Cleanup --- src/driver/main.cpp | 38 +++++++++++++------------------------- src/logger.cpp | 15 --------------- 2 files changed, 13 insertions(+), 40 deletions(-) diff --git a/src/driver/main.cpp b/src/driver/main.cpp index cc547ee281d..38074bed26e 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -94,7 +94,7 @@ std::string get_formatted_timestamp(std::chrono::time_point log_files; @@ -158,32 +158,32 @@ struct global_options } }; -bool parse_and_apply_global_options(std::vector& args) +bool parse_and_apply_logger_options(std::vector& args) { - // Extract only global option flags from args for parsing - std::vector global_args; + // Extract only logger option flags from args for parsing + std::vector logger_args; auto it = args.begin(); while(it != args.end()) { if(*it == "--log-level") { - global_args.push_back(*it); + logger_args.push_back(*it); it = args.erase(it); // Grab the single value if present if(it != args.end() && !it->empty() && (*it)[0] != '-') { - global_args.push_back(*it); + logger_args.push_back(*it); it = args.erase(it); } } else if(*it == "--log-file") { - global_args.push_back(*it); + logger_args.push_back(*it); it = args.erase(it); // Grab all values until the next flag (for unlimited log files) while(it != args.end() && !it->empty() && (*it)[0] != '-') { - global_args.push_back(*it); + logger_args.push_back(*it); it = args.erase(it); } } @@ -193,13 +193,13 @@ bool parse_and_apply_global_options(std::vector& args) } } - if(!global_args.empty()) + if(!logger_args.empty()) { - global_options opts; + logger_options opts; migraphx::driver::argument_parser ap; opts.parse(ap); - if(ap.parse(global_args)) + if(ap.parse(logger_args)) return false; opts.apply(); @@ -1110,8 +1110,8 @@ int main(int argc, const char* argv[], const char* envp[]) // Save original args for display purposes before they get modified const std::vector original_args = args; - // Parse and apply global options (--log-level, --log-file) - if(!parse_and_apply_global_options(args)) + // Parse and apply logger options (--log-level, --log-file) + if(!parse_and_apply_logger_options(args)) return 1; // no argument, print the help infomration by default @@ -1136,18 +1136,6 @@ int main(int argc, const char* argv[], const char* envp[]) if(m.count(cmd) > 0) { - migraphx::log::error()("Testing error logging"); - migraphx::log::warn()("Testing warn logging"); - migraphx::log::info()("Testing info logging"); - migraphx::log::debug()("Testing debug logging"); - migraphx::log::trace()("Testing trace logging"); - - migraphx::log::error() << "Testing error logging stream"; - migraphx::log::warn() << "Testing warn logging stream"; - migraphx::log::info() << "Testing info logging stream"; - migraphx::log::debug() << "Testing debug logging stream"; - migraphx::log::trace() << "Testing trace logging stream"; - std::string driver_invocation = std::string(argv[0]) + " " + migraphx::to_string_range(original_args, " "); std::cout << "Running [ " << get_version() << " ]: " << driver_invocation << std::endl; diff --git a/src/logger.cpp b/src/logger.cpp index 2db595b5324..5691171358f 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -22,9 +22,6 @@ * THE SOFTWARE. */ #include -#include -#include -#include #include "spdlog/sinks/basic_file_sink.h" #include "spdlog/sinks/stdout_color_sinks.h" @@ -96,18 +93,6 @@ static void init_stderr_logger() } } -std::string get_formatted_timestamp(std::chrono::time_point time) -{ - auto now_in_time_t = std::chrono::system_clock::to_time_t(time); - auto us = - std::chrono::duration_cast(time.time_since_epoch()) % 1000000; - auto* now_as_tm_date = std::localtime(&now_in_time_t); - std::stringstream ss; - ss << std::put_time(now_as_tm_date, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') - << std::setw(6) << us.count(); - return ss.str(); -} - void record(severity s, std::string_view msg, source_location loc) { init_stderr_logger(); From 66f1d10b8438d15ffdef078cf821762475e6dc74 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 2 Dec 2025 18:51:51 +0000 Subject: [PATCH 14/17] Remove spdlog usage, add thread safe access to sinks, update tests --- requirements.txt | 1 - src/driver/main.cpp | 14 +- src/include/migraphx/logger.hpp | 39 +++--- src/logger.cpp | 220 +++++++++++++++++++++++--------- test/logger_test.cpp | 206 ++++++++++++++++++++++-------- 5 files changed, 341 insertions(+), 139 deletions(-) diff --git a/requirements.txt b/requirements.txt index 0b44c6ef707..12f33a2374b 100644 --- a/requirements.txt +++ b/requirements.txt @@ -30,4 +30,3 @@ msgpack/msgpack-c@cpp-3.3.0 -DMSGPACK_BUILD_TESTS=Off -DMSGPACK_BUILD_EXAMPLES=O sqlite3@3.50.4 -DCMAKE_POSITION_INDEPENDENT_CODE=On ROCm/composable_kernel@b7775add2d28251674d81e220cd4a857b90b997a -DCK_BUILD_JIT_LIB=On -DCMAKE_POSITION_INDEPENDENT_CODE=On ROCm/rocMLIR@3a034fd4fa6c25ada90f1786700748b2f58aaf85 -DBUILD_FAT_LIBROCKCOMPILER=On -DLLVM_INCLUDE_TESTS=Off -gabime/spdlog@v1.16.0 \ No newline at end of file diff --git a/src/driver/main.cpp b/src/driver/main.cpp index 0a28b79f80e..f587d0f9a6c 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -132,7 +132,7 @@ struct logger_options { auto level = parse_log_level_string(log_level); if(level) - migraphx::log::set_log_level(*level); + migraphx::log::set_severity(*level); } for(const auto& log_file : log_files) { @@ -145,17 +145,17 @@ struct logger_options parse_log_level_string(const std::string& level_str) { if(level_str == "trace" || level_str == "5") - return migraphx::log::severity::TRACE; + return migraphx::log::severity::trace; else if(level_str == "debug" || level_str == "4") - return migraphx::log::severity::DEBUG; + return migraphx::log::severity::debug; else if(level_str == "info" || level_str == "3") - return migraphx::log::severity::INFO; + return migraphx::log::severity::info; else if(level_str == "warn" || level_str == "warning" || level_str == "2") - return migraphx::log::severity::WARN; + return migraphx::log::severity::warn; else if(level_str == "error" || level_str == "1") - return migraphx::log::severity::ERROR; + return migraphx::log::severity::error; else if(level_str == "none" || level_str == "off" || level_str == "0") - return migraphx::log::severity::NONE; + return migraphx::log::severity::none; return std::nullopt; } diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index c676fd14f22..3db09436799 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -26,29 +26,36 @@ #include #include +#include #include namespace migraphx { -namespace log { inline namespace MIGRAPHX_INLINE_NS { +namespace log { enum class severity { - NONE, - ERROR, - WARN, - INFO, - DEBUG, - TRACE + none, + error, + warn, + info, + debug, + trace }; +using sink = std::function; + void record(severity s, std::string_view msg, source_location loc = source_location::current()); bool is_enabled(severity s); -void set_log_level(severity s); +size_t add_sink(sink s, severity level = severity::info); + +void remove_sink(size_t id); -void add_file_logger(std::string_view filename, severity s = severity::INFO); +void set_severity(severity level, size_t id = 0); + +size_t add_file_logger(std::string_view filename, severity s = severity::info); template struct print @@ -82,7 +89,7 @@ struct print stream(const stream&) = delete; stream& operator=(const stream&) = delete; - severity s = severity::NONE; + severity s = severity::none; source_location loc; bool enabled; std::ostringstream ss; @@ -111,13 +118,13 @@ struct print source_location loc; }; -using error = print; -using warn = print; -using info = print; -using debug = print; -using trace = print; +using error = print; +using warn = print; +using info = print; +using debug = print; +using trace = print; -} // namespace MIGRAPHX_INLINE_NS } // namespace log +} // namespace MIGRAPHX_INLINE_NS } // namespace migraphx #endif diff --git a/src/logger.cpp b/src/logger.cpp index 5691171358f..59b69c2d50e 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -22,99 +22,195 @@ * THE SOFTWARE. */ #include -#include "spdlog/sinks/basic_file_sink.h" -#include "spdlog/sinks/stdout_color_sinks.h" +#include +#include +#include +#include +#include +#include +#include +#include namespace migraphx { -namespace log { inline namespace MIGRAPHX_INLINE_NS { +namespace log { MIGRAPHX_DECLARE_ENV_VAR(MIGRAPHX_LOG_LEVEL) -static spdlog::logger* get_migraphx_logger() +// Internal sink entry: stores sink callback and severity level +struct sink_entry { - static std::vector sinks; - static spdlog::logger* migraphx_logger = - new spdlog::logger("migraphx_logger", begin(sinks), end(sinks)); - return migraphx_logger; + sink callback; + severity level; +}; + +static std::string format_timestamp() +{ + auto now = std::chrono::system_clock::now(); + auto now_time_t = std::chrono::system_clock::to_time_t(now); + auto now_us = + std::chrono::duration_cast(now.time_since_epoch()) % 1000000; + auto* now_tm = std::localtime(&now_time_t); + std::ostringstream ss; + ss << std::put_time(now_tm, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') << std::setw(6) + << now_us.count(); + return ss.str(); } -static size_t& get_log_level() +static char severity_char(severity s) { - static size_t level = value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::INFO)); - return level; + switch(s) + { + case severity::none: return 'N'; + case severity::error: return 'E'; + case severity::warn: return 'W'; + case severity::info: return 'I'; + case severity::debug: return 'D'; + case severity::trace: return 'T'; + } + return '?'; } -static spdlog::level::level_enum to_spdlog_level(severity s) +static const char* severity_color(severity s) { - // Convert migraphx severity to spdlog level - // migraphx: NONE(0) < ERROR(1) < WARN(2) < INFO(3) < DEBUG(4) < TRACE(5) - // spdlog: off(6) > critical(5) > err(4) > warn(3) > info(2) > debug(1) > trace(0) switch(s) { - case severity::NONE: return spdlog::level::off; - case severity::ERROR: return spdlog::level::err; - case severity::WARN: return spdlog::level::warn; - case severity::INFO: return spdlog::level::info; - case severity::DEBUG: return spdlog::level::debug; - case severity::TRACE: return spdlog::level::trace; + case severity::none: return ""; + case severity::error: return "\033[31m"; // Red + case severity::warn: return "\033[33m"; // Yellow + case severity::info: return ""; // Default + case severity::debug: return "\033[36m"; // Cyan + case severity::trace: return "\033[37m"; // White/Gray } - return spdlog::level::info; + return ""; } -void add_file_logger(std::string_view filename, severity s) +static const char* reset_color() { return "\033[0m"; } + +// Create the default stderr sink +static sink make_stderr_sink() { - auto* logger = get_migraphx_logger(); - auto file_sink = std::make_shared(std::string(filename)); - file_sink->set_pattern("%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v"); - file_sink->set_level(to_spdlog_level(s)); - logger->sinks().push_back(file_sink); + return [](severity s, std::string_view msg, source_location loc) { + std::cerr << severity_color(s) << format_timestamp() << " [" << severity_char(s) << "] [" + << loc.file_name() << ":" << loc.line() << "] " << msg << reset_color() + << std::endl; + }; } -static void init_stderr_logger() +// Create a file sink +static sink make_file_sink(const std::string& filename) { - static bool initialized = false; - if(!initialized) - { - auto* logger = get_migraphx_logger(); - auto stderr_sink = std::make_shared(); - // Use spdlog pattern with colors for the color sink - // %^ ... %$ = wrap entire line with color based on log level - // %Y-%m-%d %H:%M:%S.%f = timestamp with microseconds - // [%L] = log level - // [%s:%#] = source file and line - // %v = the actual message - stderr_sink->set_pattern("%^%Y-%m-%d %H:%M:%S.%f [%L] [%s:%#] %v%$"); - // Set info level to use default terminal color - stderr_sink->set_color(spdlog::level::info, ""); - logger->sinks().push_back(stderr_sink); - logger->set_level(to_spdlog_level(static_cast(get_log_level()))); - initialized = true; - } + auto file = std::make_shared(filename, std::ios::app); + return [file](severity s, std::string_view msg, source_location loc) { + if(file->is_open()) + { + *file << format_timestamp() << " [" << severity_char(s) << "] [" << loc.file_name() + << ":" << loc.line() << "] " << msg << std::endl; + } + }; } -void record(severity s, std::string_view msg, source_location loc) +// Shared state for all sinks - must be outside template to ensure single instance +static std::mutex& get_sinks_mutex() { - init_stderr_logger(); - auto* logger = get_migraphx_logger(); + static std::mutex m; + return m; +} - // Convert migraphx source_location to spdlog source_loc - spdlog::source_loc spdlog_loc{loc.file_name(), static_cast(loc.line()), ""}; +static std::vector>& get_sinks() +{ + static auto sinks = []() { + auto level = static_cast( + value_of(MIGRAPHX_LOG_LEVEL{}, static_cast(severity::info))); + return std::vector>{sink_entry{make_stderr_sink(), level}}; + }(); + return sinks; +} - // Use spdlog's log method with source location - // The pattern formatting handles timestamp, level, location, and colors - logger->log(spdlog_loc, to_spdlog_level(s), "{}", msg); +// Thread-safe access to sinks (stderr sink is automatically initialized at index 0) +template +static void access_sinks(F f) +{ + std::lock_guard lock(get_sinks_mutex()); + f(get_sinks()); } -bool is_enabled(severity s) { return static_cast(s) <= get_log_level(); } +size_t add_sink(sink s, severity level) +{ + size_t id = 0; + access_sinks([&](std::vector>& sinks) { + // Find an empty slot or add a new one + for(size_t i = 0; i < sinks.size(); ++i) + { + if(not sinks[i].has_value()) + { + sinks[i] = sink_entry{std::move(s), level}; + id = i; + return; + } + } + id = sinks.size(); + sinks.push_back(sink_entry{std::move(s), level}); + }); + return id; +} -void set_log_level(severity s) +void remove_sink(size_t id) { - get_log_level() = static_cast(s); - init_stderr_logger(); // Ensure logger is initialized - auto* logger = get_migraphx_logger(); - logger->set_level(to_spdlog_level(s)); + access_sinks([&](std::vector>& sinks) { + if(id < sinks.size()) + { + sinks[id] = std::nullopt; + } + }); } -} // namespace MIGRAPHX_INLINE_NS + +void set_severity(severity level, size_t id) +{ + access_sinks([&](std::vector>& sinks) { + if(id < sinks.size() && sinks[id].has_value()) + { + sinks[id]->level = level; + } + }); +} + +size_t add_file_logger(std::string_view filename, severity s) +{ + return add_sink(make_file_sink(std::string(filename)), s); +} + +void record(severity s, std::string_view msg, source_location loc) +{ + access_sinks([&](std::vector>& sinks) { + for(auto& entry : sinks) + { + if(entry.has_value() && + static_cast(s) <= static_cast(entry->level)) + { + entry->callback(s, msg, loc); + } + } + }); +} + +bool is_enabled(severity s) +{ + bool result = false; + access_sinks([&](std::vector>& sinks) { + for(const auto& entry : sinks) + { + if(entry.has_value() && + static_cast(s) <= static_cast(entry->level)) + { + result = true; + return; + } + } + }); + return result; +} + } // namespace log +} // namespace MIGRAPHX_INLINE_NS } // namespace migraphx diff --git a/test/logger_test.cpp b/test/logger_test.cpp index 0255ec85e82..061c3013469 100644 --- a/test/logger_test.cpp +++ b/test/logger_test.cpp @@ -28,42 +28,42 @@ TEST_CASE(logger_set_log_level) { // Test setting different log levels - migraphx::log::set_log_level(migraphx::log::severity::ERROR); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); + migraphx::log::set_severity(migraphx::log::severity::error); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::info)); - migraphx::log::set_log_level(migraphx::log::severity::INFO); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); + migraphx::log::set_severity(migraphx::log::severity::info); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::info)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::debug)); - migraphx::log::set_log_level(migraphx::log::severity::TRACE); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::TRACE)); + migraphx::log::set_severity(migraphx::log::severity::trace); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::info)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::debug)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::trace)); } TEST_CASE(logger_is_enabled) { // Set to INFO level - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Check severity ordering: ERROR < WARN < INFO < DEBUG < TRACE - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::INFO)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::info)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::debug)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::trace)); } TEST_CASE(logger_basic_logging) { // Test that logging doesn't crash or throw - migraphx::log::set_log_level(migraphx::log::severity::TRACE); + migraphx::log::set_severity(migraphx::log::severity::trace); // Test stream operator migraphx::log::error() << "Test error message"; @@ -82,7 +82,7 @@ TEST_CASE(logger_basic_logging) TEST_CASE(logger_stream_composition) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Test composing multiple values in a single log message int value = 42; @@ -94,7 +94,7 @@ TEST_CASE(logger_stream_composition) TEST_CASE(logger_function_call_multiple_args) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Test function call operator with multiple arguments migraphx::log::info()("Multiple", " ", "arguments"); @@ -104,13 +104,13 @@ TEST_CASE(logger_function_call_multiple_args) TEST_CASE(logger_disabled_levels) { // Set to ERROR level - only errors should be enabled - migraphx::log::set_log_level(migraphx::log::severity::ERROR); + migraphx::log::set_severity(migraphx::log::severity::error); - EXPECT(migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); + EXPECT(migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::info)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::debug)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::trace)); // These should not cause any output or crash migraphx::log::warn() << "This should be suppressed"; @@ -121,13 +121,13 @@ TEST_CASE(logger_disabled_levels) TEST_CASE(logger_none_level) { // Set to NONE - nothing should be enabled - migraphx::log::set_log_level(migraphx::log::severity::NONE); + migraphx::log::set_severity(migraphx::log::severity::none); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::ERROR)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::WARN)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::INFO)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::DEBUG)); - EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::TRACE)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::error)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::warn)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::info)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::debug)); + EXPECT(not migraphx::log::is_enabled(migraphx::log::severity::trace)); } TEST_CASE(logger_severity_ordering) @@ -135,21 +135,21 @@ TEST_CASE(logger_severity_ordering) // Test that severity levels are properly ordered // NONE(0) < ERROR(1) < WARN(2) < INFO(3) < DEBUG(4) < TRACE(5) - EXPECT(static_cast(migraphx::log::severity::NONE) < - static_cast(migraphx::log::severity::ERROR)); - EXPECT(static_cast(migraphx::log::severity::ERROR) < - static_cast(migraphx::log::severity::WARN)); - EXPECT(static_cast(migraphx::log::severity::WARN) < - static_cast(migraphx::log::severity::INFO)); - EXPECT(static_cast(migraphx::log::severity::INFO) < - static_cast(migraphx::log::severity::DEBUG)); - EXPECT(static_cast(migraphx::log::severity::DEBUG) < - static_cast(migraphx::log::severity::TRACE)); + EXPECT(static_cast(migraphx::log::severity::none) < + static_cast(migraphx::log::severity::error)); + EXPECT(static_cast(migraphx::log::severity::error) < + static_cast(migraphx::log::severity::warn)); + EXPECT(static_cast(migraphx::log::severity::warn) < + static_cast(migraphx::log::severity::info)); + EXPECT(static_cast(migraphx::log::severity::info) < + static_cast(migraphx::log::severity::debug)); + EXPECT(static_cast(migraphx::log::severity::debug) < + static_cast(migraphx::log::severity::trace)); } TEST_CASE(logger_empty_messages) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Test logging empty messages doesn't crash migraphx::log::info() << ""; @@ -158,7 +158,7 @@ TEST_CASE(logger_empty_messages) TEST_CASE(logger_special_characters) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Test logging special characters migraphx::log::info() << "Special chars: \n\t\\"; @@ -167,29 +167,129 @@ TEST_CASE(logger_special_characters) TEST_CASE(logger_long_messages) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); - // Test logging a very long message + // Test logging a long message std::string long_msg(1000, 'x'); migraphx::log::info() << "Long message: " << long_msg; } TEST_CASE(logger_conditional_logging) { - migraphx::log::set_log_level(migraphx::log::severity::INFO); + migraphx::log::set_severity(migraphx::log::severity::info); // Test conditional logging based on is_enabled - if(migraphx::log::is_enabled(migraphx::log::severity::DEBUG)) + if(migraphx::log::is_enabled(migraphx::log::severity::debug)) { // This should not execute migraphx::log::debug() << "Should not appear"; } - if(migraphx::log::is_enabled(migraphx::log::severity::INFO)) + if(migraphx::log::is_enabled(migraphx::log::severity::info)) { // This should execute migraphx::log::info() << "Should appear"; } } +TEST_CASE(logger_custom_sink) +{ + migraphx::log::set_severity(migraphx::log::severity::info); + + // Track messages received by custom sink + std::vector messages; + + // Add a custom sink + auto sink_id = migraphx::log::add_sink( + [&](migraphx::log::severity, std::string_view msg, migraphx::source_location) { + messages.push_back(std::string(msg)); + }, + migraphx::log::severity::info); + + // Sink ID should be > 0 (stderr is 0) + EXPECT(sink_id > 0); + + // Log a message + migraphx::log::info() << "Test custom sink"; + + // Verify the custom sink received the message + EXPECT(not messages.empty()); + EXPECT(messages.back() == "Test custom sink"); + + // Remove the sink + migraphx::log::remove_sink(sink_id); + + // Log another message + messages.clear(); + migraphx::log::info() << "After removal"; + + // Custom sink should not receive this message + EXPECT(messages.empty()); +} + +TEST_CASE(logger_sink_level) +{ + migraphx::log::set_severity(migraphx::log::severity::trace); + + std::vector messages; + + // Add a custom sink with ERROR level only + auto sink_id = migraphx::log::add_sink( + [&](migraphx::log::severity, std::string_view msg, migraphx::source_location) { + messages.push_back(std::string(msg)); + }, + migraphx::log::severity::error); + + // INFO message should not go to this sink + migraphx::log::info() << "Info message"; + EXPECT(messages.empty()); + + // ERROR message should go to this sink + migraphx::log::error() << "Error message"; + EXPECT(not messages.empty()); + EXPECT(messages.back() == "Error message"); + + // Change sink level to INFO + messages.clear(); + migraphx::log::set_severity(migraphx::log::severity::info, sink_id); + + // Now INFO should work + migraphx::log::info() << "Info after level change"; + EXPECT(not messages.empty()); + EXPECT(messages.back() == "Info after level change"); + + migraphx::log::remove_sink(sink_id); +} + +TEST_CASE(logger_set_severity_default) +{ + // set_severity with default ID should change stderr sink (ID 0) + migraphx::log::set_severity(migraphx::log::severity::error); + + // Now only ERROR should go to stderr + // (This just tests it doesn't crash - actual filtering is internal) + migraphx::log::error() << "Error after set_severity"; + + // Reset for other tests + migraphx::log::set_severity(migraphx::log::severity::info); +} + +TEST_CASE(logger_file_sink_returns_id) +{ + migraphx::log::set_severity(migraphx::log::severity::info); + + // add_file_logger should return an ID > 0 + auto file_id = migraphx::log::add_file_logger("test_sink_log.txt", migraphx::log::severity::info); + EXPECT(file_id > 0); + + // Log something + migraphx::log::info() << "File sink test"; + + // Can modify the file sink level + migraphx::log::set_severity(migraphx::log::severity::error, file_id); + + // Can remove the file sink + migraphx::log::remove_sink(file_id); +} + int main(int argc, const char* argv[]) { test::run(argc, argv); } From 5fbc1966893955f733ab605083b3889e0830c673 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 2 Dec 2025 18:52:12 +0000 Subject: [PATCH 15/17] Formatting --- src/logger.cpp | 6 ++---- test/logger_test.cpp | 7 ++++--- 2 files changed, 6 insertions(+), 7 deletions(-) diff --git a/src/logger.cpp b/src/logger.cpp index 59b69c2d50e..0d530434ac7 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -185,8 +185,7 @@ void record(severity s, std::string_view msg, source_location loc) access_sinks([&](std::vector>& sinks) { for(auto& entry : sinks) { - if(entry.has_value() && - static_cast(s) <= static_cast(entry->level)) + if(entry.has_value() && static_cast(s) <= static_cast(entry->level)) { entry->callback(s, msg, loc); } @@ -200,8 +199,7 @@ bool is_enabled(severity s) access_sinks([&](std::vector>& sinks) { for(const auto& entry : sinks) { - if(entry.has_value() && - static_cast(s) <= static_cast(entry->level)) + if(entry.has_value() && static_cast(s) <= static_cast(entry->level)) { result = true; return; diff --git a/test/logger_test.cpp b/test/logger_test.cpp index 061c3013469..105998b6345 100644 --- a/test/logger_test.cpp +++ b/test/logger_test.cpp @@ -265,11 +265,11 @@ TEST_CASE(logger_set_severity_default) { // set_severity with default ID should change stderr sink (ID 0) migraphx::log::set_severity(migraphx::log::severity::error); - + // Now only ERROR should go to stderr // (This just tests it doesn't crash - actual filtering is internal) migraphx::log::error() << "Error after set_severity"; - + // Reset for other tests migraphx::log::set_severity(migraphx::log::severity::info); } @@ -279,7 +279,8 @@ TEST_CASE(logger_file_sink_returns_id) migraphx::log::set_severity(migraphx::log::severity::info); // add_file_logger should return an ID > 0 - auto file_id = migraphx::log::add_file_logger("test_sink_log.txt", migraphx::log::severity::info); + auto file_id = + migraphx::log::add_file_logger("test_sink_log.txt", migraphx::log::severity::info); EXPECT(file_id > 0); // Log something From 68898649b3d3627a52b563c4e37c8b2ad916d3fa Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 2 Dec 2025 19:30:12 +0000 Subject: [PATCH 16/17] Add doc comments, error messages, use linux specific timestamp, remove unused aliases --- src/driver/main.cpp | 26 ++++++++++---------- src/include/migraphx/logger.hpp | 42 +++++++++++++++++++++++++++++++-- src/logger.cpp | 17 ++++++++----- test/logger_test.cpp | 2 +- 4 files changed, 65 insertions(+), 22 deletions(-) diff --git a/src/driver/main.cpp b/src/driver/main.cpp index f587d0f9a6c..a7f788080d4 100644 --- a/src/driver/main.cpp +++ b/src/driver/main.cpp @@ -108,10 +108,10 @@ struct logger_options {"--log-level"}, ap.help("Set log level (none/0, error/1, warn/2, info/3, debug/4, trace/5)"), ap.validate([](auto&, auto&, auto& params) { - if(!params.empty()) + if(not params.empty()) { auto level_str = params.back(); - if(!parse_log_level_string(level_str)) + if(not parse_log_level_string(level_str)) { throw std::runtime_error( "Invalid log level: " + level_str + @@ -128,7 +128,7 @@ struct logger_options void apply() const { - if(!log_level.empty()) + if(not log_level.empty()) { auto level = parse_log_level_string(log_level); if(level) @@ -144,17 +144,17 @@ struct logger_options static std::optional parse_log_level_string(const std::string& level_str) { - if(level_str == "trace" || level_str == "5") + if(level_str == "trace" or level_str == "5") return migraphx::log::severity::trace; - else if(level_str == "debug" || level_str == "4") + else if(level_str == "debug" or level_str == "4") return migraphx::log::severity::debug; - else if(level_str == "info" || level_str == "3") + else if(level_str == "info" or level_str == "3") return migraphx::log::severity::info; - else if(level_str == "warn" || level_str == "warning" || level_str == "2") + else if(level_str == "warn" or level_str == "2") return migraphx::log::severity::warn; - else if(level_str == "error" || level_str == "1") + else if(level_str == "error" or level_str == "1") return migraphx::log::severity::error; - else if(level_str == "none" || level_str == "off" || level_str == "0") + else if(level_str == "none" or level_str == "0") return migraphx::log::severity::none; return std::nullopt; @@ -173,7 +173,7 @@ bool parse_and_apply_logger_options(std::vector& args) logger_args.push_back(*it); it = args.erase(it); // Grab the single value if present - if(it != args.end() && !it->empty() && (*it)[0] != '-') + if(it != args.end() and not it->empty() and (*it)[0] != '-') { logger_args.push_back(*it); it = args.erase(it); @@ -184,7 +184,7 @@ bool parse_and_apply_logger_options(std::vector& args) logger_args.push_back(*it); it = args.erase(it); // Grab all values until the next flag (for unlimited log files) - while(it != args.end() && !it->empty() && (*it)[0] != '-') + while(it != args.end() and not it->empty() and (*it)[0] != '-') { logger_args.push_back(*it); it = args.erase(it); @@ -196,7 +196,7 @@ bool parse_and_apply_logger_options(std::vector& args) } } - if(!logger_args.empty()) + if(not logger_args.empty()) { logger_options opts; migraphx::driver::argument_parser ap; @@ -1125,7 +1125,7 @@ int main(int argc, const char* argv[], const char* envp[]) const std::vector original_args = args; // Parse and apply logger options (--log-level, --log-file) - if(!parse_and_apply_logger_options(args)) + if(not parse_and_apply_logger_options(args)) return 1; // no argument, print the help infomration by default diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index 3db09436799..4cc183255f6 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -45,17 +45,55 @@ enum class severity using sink = std::function; +/** + * @brief Records a log message. This will invoke the callback for all sinks that are enabled at the given severity. + * + * @param s The severity of the log message + * @param msg The message to log + * @param loc The source location of the log message + */ void record(severity s, std::string_view msg, source_location loc = source_location::current()); -bool is_enabled(severity s); +/** + * @brief Checks if any sink is enabled at the given severity. + * + * @param level The severity to check + * @return true if any sink is enabled at the given severity, false otherwise + */ +bool is_enabled(severity level); +/** + * @brief Adds a sink to the logger. + * + * @param s The sink to add + * @param level The severity level of the sink + * @return The ID of the added sink + */ size_t add_sink(sink s, severity level = severity::info); +/** + * @brief Removes a sink from the logger. + * + * @param id The ID of the sink to remove + */ void remove_sink(size_t id); +/** + * @brief Sets the severity level for a specific sink. + * + * @param level The severity level to set + * @param id The ID of the sink to set the severity for; defaults to 0 for the stderr sink + */ void set_severity(severity level, size_t id = 0); -size_t add_file_logger(std::string_view filename, severity s = severity::info); +/** + * @brief Adds a file sink to the logger. + * + * @param filename The name of the file to log to + * @param level The severity level of the file logger + * @return The ID of the added file logger + */ +size_t add_file_logger(std::string_view filename, severity level = severity::info); template struct print diff --git a/src/logger.cpp b/src/logger.cpp index 0d530434ac7..26d2c72c241 100644 --- a/src/logger.cpp +++ b/src/logger.cpp @@ -50,9 +50,10 @@ static std::string format_timestamp() auto now_time_t = std::chrono::system_clock::to_time_t(now); auto now_us = std::chrono::duration_cast(now.time_since_epoch()) % 1000000; - auto* now_tm = std::localtime(&now_time_t); + std::tm now_tm{}; + localtime_r(&now_time_t, &now_tm); std::ostringstream ss; - ss << std::put_time(now_tm, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') << std::setw(6) + ss << std::put_time(&now_tm, "%Y-%m-%d %H:%M:%S") << "." << std::setfill('0') << std::setw(6) << now_us.count(); return ss.str(); } @@ -101,6 +102,10 @@ static sink make_stderr_sink() static sink make_file_sink(const std::string& filename) { auto file = std::make_shared(filename, std::ios::app); + if(not file->is_open()) + { + std::cerr << "Failed to open log file: " << filename << std::endl; + } return [file](severity s, std::string_view msg, source_location loc) { if(file->is_open()) { @@ -175,9 +180,9 @@ void set_severity(severity level, size_t id) }); } -size_t add_file_logger(std::string_view filename, severity s) +size_t add_file_logger(std::string_view filename, severity level) { - return add_sink(make_file_sink(std::string(filename)), s); + return add_sink(make_file_sink(std::string(filename)), level); } void record(severity s, std::string_view msg, source_location loc) @@ -193,13 +198,13 @@ void record(severity s, std::string_view msg, source_location loc) }); } -bool is_enabled(severity s) +bool is_enabled(severity level) { bool result = false; access_sinks([&](std::vector>& sinks) { for(const auto& entry : sinks) { - if(entry.has_value() && static_cast(s) <= static_cast(entry->level)) + if(entry.has_value() && static_cast(level) <= static_cast(entry->level)) { result = true; return; diff --git a/test/logger_test.cpp b/test/logger_test.cpp index 105998b6345..4454704f997 100644 --- a/test/logger_test.cpp +++ b/test/logger_test.cpp @@ -280,7 +280,7 @@ TEST_CASE(logger_file_sink_returns_id) // add_file_logger should return an ID > 0 auto file_id = - migraphx::log::add_file_logger("test_sink_log.txt", migraphx::log::severity::info); + migraphx::log::add_file_logger("/tmp/migraphx_test_log.txt", migraphx::log::severity::info); EXPECT(file_id > 0); // Log something From 38661568a2d9f07139eba6003b4fb2e21eea3483 Mon Sep 17 00:00:00 2001 From: Eddie Liao Date: Tue, 2 Dec 2025 19:30:29 +0000 Subject: [PATCH 17/17] Formatting --- src/include/migraphx/logger.hpp | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/src/include/migraphx/logger.hpp b/src/include/migraphx/logger.hpp index 4cc183255f6..0b5c12b0e9f 100644 --- a/src/include/migraphx/logger.hpp +++ b/src/include/migraphx/logger.hpp @@ -46,7 +46,8 @@ enum class severity using sink = std::function; /** - * @brief Records a log message. This will invoke the callback for all sinks that are enabled at the given severity. + * @brief Records a log message. This will invoke the callback for all sinks that are enabled at the + * given severity. * * @param s The severity of the log message * @param msg The message to log