diff --git a/CMakeLists.txt b/CMakeLists.txt index 8a1aa4eb..b4a501a8 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -482,6 +482,7 @@ if(AARE_TESTS) ${CMAKE_CURRENT_SOURCE_DIR}/src/hist/PixelHistogram.test.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/hist/PedestalTrackingPixelHistogram.test.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/JungfrauDataFile.test.cpp + ${CMAKE_CURRENT_SOURCE_DIR}/src/logger.test.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/MultiThreadedFileReader.test.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/NumpyFile.test.cpp ${CMAKE_CURRENT_SOURCE_DIR}/src/NumpyHelpers.test.cpp diff --git a/include/aare/logger.hpp b/include/aare/logger.hpp index 278d4d7d..6374aeea 100644 --- a/include/aare/logger.hpp +++ b/include/aare/logger.hpp @@ -2,9 +2,12 @@ #pragma once /*Utility to log to console*/ +#include +#include +#include #include #include -#include +#include namespace aare { @@ -55,12 +58,53 @@ enum TLogLevel { #define __AT__ \ std::string(__FILE__) + std::string("::") + std::string(__func__) + \ std::string("(): ") -#define __SHORT_FORM_OF_FILE__ \ - (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILE__) +#define __SHORT_FORM_OF_FILE__ aare::short_file_name(__FILE__) #define __SHORT_AT__ \ std::string(__SHORT_FORM_OF_FILE__) + std::string("::") + \ std::string(__func__) + std::string("(): ") +/** + * @brief Strip the directory part of a path, accepting both '/' and '\\' as + * separators so that __FILE__ is shortened the same way on every platform. + */ +inline const char *short_file_name(const char *path) noexcept { + const char *base = path; + for (const char *p = path; *p != '\0'; ++p) { + if (*p == '/' || *p == '\\') + base = p + 1; + } + return base; +} + +/** + * @brief Local wall-clock time as HH:MM:SS.mmm (strftime "%X" plus + * milliseconds), built from std::chrono so it works on every platform. + */ +inline std::string log_timestamp() { + using namespace std::chrono; + const auto now = system_clock::now(); + const time_t t = system_clock::to_time_t(now); + const auto ms = duration_cast(now.time_since_epoch()) % 1000; + + tm local{}; +#if defined(_MSC_VER) + localtime_s(&local, &t); +#else + localtime_r(&t, &local); +#endif + + constexpr size_t buffer_len = 12; + char buffer[buffer_len]; + if (strftime(buffer, buffer_len, "%X", &local) == 0) + buffer[0] = '\0'; + + constexpr size_t result_len = 100; + char result[result_len]; + snprintf(result, result_len, "%s.%03d", buffer, + static_cast(ms.count())); + return result; +} + class Logger { std::ostringstream os; TLogLevel m_level = AARE_LOG_LEVEL; @@ -111,23 +155,7 @@ class Logger { return os; } - static std::string Timestamp() { - constexpr size_t buffer_len = 12; - char buffer[buffer_len]; - time_t t; - ::time(&t); - tm r; - strftime(buffer, buffer_len, "%X", localtime_r(&t, &r)); - buffer[buffer_len - 1] = '\0'; - struct timeval tv; - gettimeofday(&tv, nullptr); - constexpr size_t result_len = 100; - char result[result_len]; - snprintf(result, result_len, "%s.%03ld", buffer, - static_cast(tv.tv_usec) / 1000); - result[result_len - 1] = '\0'; - return result; - } + static std::string Timestamp() { return log_timestamp(); } }; // TODO! Do we need to keep the runtime option? diff --git a/src/logger.test.cpp b/src/logger.test.cpp new file mode 100644 index 00000000..17218d96 --- /dev/null +++ b/src/logger.test.cpp @@ -0,0 +1,41 @@ +// SPDX-License-Identifier: MPL-2.0 +#include "aare/logger.hpp" + +#include +#include + +#include +#include +#include + +using Catch::Matchers::EndsWith; +using Catch::Matchers::Matches; +using Catch::Matchers::StartsWith; + +TEST_CASE("Log timestamp is HH:MM:SS.mmm", "[logger]") { + const std::string ts = aare::Logger::Timestamp(); + REQUIRE_THAT(ts, Matches(R"(\d{2}:\d{2}:\d{2}\.\d{3})")); +} + +TEST_CASE("short_file_name strips both kinds of directory separators", + "[logger]") { + REQUIRE(std::string(aare::short_file_name("/a/b/File.cpp")) == "File.cpp"); + REQUIRE(std::string(aare::short_file_name("C:\\a\\b\\File.cpp")) == + "File.cpp"); + REQUIRE(std::string(aare::short_file_name("File.cpp")) == "File.cpp"); +} + +TEST_CASE("LOG writes one coloured line with timestamp and level", "[logger]") { + std::ostringstream captured; + auto *previous = std::clog.rdbuf(captured.rdbuf()); + LOG(aare::logWARNING) << "hello " << 42; + std::clog.rdbuf(previous); + + const std::string line = captured.str(); + // - HH:MM:SS.mmm WARNING: hello 42\n + REQUIRE_THAT(line, StartsWith(std::string(YELLOW BOLD) + "- ")); + REQUIRE_THAT(line, Matches(std::string("\x1b\\[33m\x1b\\[1m- ") + + R"(\d{2}:\d{2}:\d{2}\.\d{3} WARNING: hello 42)" + + "\x1b\\[0m\n")); + REQUIRE_THAT(line, EndsWith(std::string(RESET) + "\n")); +}