From 929a105bd061f85803de5656e8e806fe1441860b Mon Sep 17 00:00:00 2001 From: han J <89577994+owny990312@users.noreply.github.com> Date: Thu, 31 Oct 2024 19:39:35 +0800 Subject: [PATCH] log format (#57) * log format * Modify the logic of log formatting output * Remove redundant parts. * log format: -Improve the log configuration documentation -More flexible log formatting output structure * log fotmat - Use std::string instead of fmt to achieve formatted output,; - add unit test - add exception checking. * Add estimated_size & optimize unit tests --------- Co-authored-by: hanjun --- document/sphinx-cn/tutorials/cfg/log.md | 69 +++-- src/common/util/time_util.h | 136 +++++++++ src/examples/cpp/logger/README.md | 3 + .../bin/cfg/examples_cpp_logger_cfg.yaml | 2 + .../core/logger/console_logger_backend.cc | 34 +-- .../core/logger/console_logger_backend.h | 5 + src/runtime/core/logger/formatter.h | 274 ++++++++++++++++++ src/runtime/core/logger/formatter_test.cc | 64 ++++ .../core/logger/rotate_file_logger_backend.cc | 23 +- .../core/logger/rotate_file_logger_backend.h | 4 + 10 files changed, 563 insertions(+), 51 deletions(-) create mode 100644 src/runtime/core/logger/formatter.h create mode 100644 src/runtime/core/logger/formatter_test.cc diff --git a/document/sphinx-cn/tutorials/cfg/log.md b/document/sphinx-cn/tutorials/cfg/log.md index cd7d2953b..ce5f31d71 100644 --- a/document/sphinx-cn/tutorials/cfg/log.md +++ b/document/sphinx-cn/tutorials/cfg/log.md @@ -5,13 +5,13 @@ `aimrt.log`配置项用于配置日志。其中的细节配置项说明如下： -| 节点 | 类型 | 是否可选| 默认值 | 作用 | -| ---- | ---- | ---- | ---- | ---- | -| core_lvl | string | 可选 | "Info" | 框架日志等级 | -| default_module_lvl | string | 可选 | "Info" | 默认的模块日志等级 | -| backends | array | 可选 | "" | 日志后端列表 | -| backends[i].type | string | 必选 | "" | 日志后端类型 | -| backends[i].options | map | 可选 | - | 具体日志后端的配置 | +| 节点 | 类型 | 是否可选 | 默认值 | 作用 | +| ------------------- | ------ | -------- | ------ | ------------------ | +| core_lvl | string | 可选 | "Info" | 框架日志等级 | +| default_module_lvl | string | 可选 | "Info" | 默认的模块日志等级 | +| backends | array | 可选 | "" | 日志后端列表 | +| backends[i].type | string | 必选 | "" | 日志后端类型 | +| backends[i].options | map | 可选 | - | 具体日志后端的配置 | 其中，日志等级可选项包括以下几种（不区分大小写）： - Trace @@ -53,11 +53,12 @@ aimrt: `console`日志后端是 AimRT 官方提供的一种日志后端，用于将日志打印到控制台上。其所有的配置项如下： -| 节点 | 类型 | 是否可选| 默认值 | 作用 | -| ---- | ---- | ---- | ---- | ---- | -| color | bool | 可选 | true | 是否要彩色打印 | -| module_filter | string | 可选 | "(.*)"| 模块过滤器 | -| log_executor_name | string | 可选 | "" | 日志执行器。默认使用主线程 | +| 节点 | 类型 | 是否可选 | 默认值 | 作用 | +| ----------------- | ------ | -------- | ------------------------------------- | -------------------------- | +| color | bool | 可选 | true | 是否要彩色打印 | +| module_filter | string | 可选 | "(.*)" | 模块过滤器 | +| log_executor_name | string | 可选 | "" | 日志执行器。默认使用主线程 | +| pattern | string | 可选 | "[%c.%f][%l][%t][%n][%g:%R:%C @%F]%v" | 日志的输出格式 | 使用注意点如下： @@ -65,6 +66,32 @@ aimrt: - `color`配置了是否要彩色打印。此项配置有可能在一些操作系统不支持。 - `module_filter`支持以正则表达式的形式，来配置哪些模块的日志可以通过本后端处理。这与模块日志等级不同，模块日志等级是全局的、先决的、影响所有日志后端的，而这里的配置只影响本后端。 - `log_executor_name`配置了日志执行器。要求日志执行器是线程安全的，如果没有配置，则默认使用主线程打印日志。 +- `pattern` 通过 `"%" + 字符` 的形式来进行格式化输出， 具体可输出格式如下： + + | 格式 | 解释 | 举例 | + | ----- | ------------------------ | ------------------------------- | + | %c | 完整日期和时间 | 2024-03-15 14:30:45 | + | %Y | 年份 | 2024 | + | %m | 月份 | 03 | + | %d | 日期 | 15 | + | %H | 小时 | 14 | + | %M | 分钟 | 30 | + | %S | 秒 | 45 | + | %D | 仅日期 | 2024-03-15 | + | %T | 仅时间 | 14:30:45 | + | %f | 微秒 | 123456 | + | %A | 星期几 | Sunday | + | %a | 星期几（简写） | Sun | + | %l | 日志级别 | Info | + | %t | 线程ID | 1234 | + | %n | 模块名 | test_module | + | %G | 文件名（只显示最后一级） | test_file.cpp | + | %g | 文件名（完整路径） | /XX/YY/ZZ/test_file.cpp | + | %R | 行号 | 20 | + | %C | 列号 | 20 | + | %F | 函数名 | TestFunc | + | %v | 日志消息内容 | "This is a log message" | + | %其他 | 只会把其他内容显示 | 如`%q` 只显示 `q`, `%%`只显示%` | 以下是一个简单的示例： @@ -93,15 +120,15 @@ aimrt: `rotate_file`日志后端是 AimRT 官方提供的一种日志后端，用于将日志打印到文件中。其所有的配置项如下： -| 节点 | 类型 | 是否可选| 默认值 | 作用 | -| ---- | ---- | ---- | ---- | ---- | -| path | string | 必选 | "./log" | 日志文件存放目录 | -| filename | string | 必选 | "aimrt.log" | 日志文件基础名称 | -| max_file_size_m | unsigned int | 可选 | 16 | 日志文件最大尺寸，单位：Mb | -| max_file_num | unsigned int | 可选 | 100 | 日志文件最大数量。0表示无上限 | -| module_filter | string | 可选 | "(.*)"| 模块过滤器 | -| log_executor_name | string | 可选 | "" | 日志执行器。默认使用主线程 | - +| 节点 | 类型 | 是否可选 | 默认值 | 作用 | +| ----------------- | ------------ | -------- | ------------------------------------- | ----------------------------- | +| path | string | 必选 | "./log" | 日志文件存放目录 | +| filename | string | 必选 | "aimrt.log" | 日志文件基础名称 | +| max_file_size_m | unsigned int | 可选 | 16 | 日志文件最大尺寸，单位：Mb | +| max_file_num | unsigned int | 可选 | 100 | 日志文件最大数量。0表示无上限 | +| module_filter | string | 可选 | "(.*)" | 模块过滤器 | +| log_executor_name | string | 可选 | "" | 日志执行器。默认使用主线程 | +| pattern | string | 可选 | "[%c.%f][%l][%t][%n][%g:%R:%C @%F]%v" | 日志的输出格式 | 使用注意点如下： diff --git a/src/common/util/time_util.h b/src/common/util/time_util.h index 945e6b4bf..0833f57e1 100644 --- a/src/common/util/time_util.h +++ b/src/common/util/time_util.h @@ -360,4 +360,140 @@ inline int32_t GetDayCount(time_t l_time, time_t r_time, int32_t time_zone) { return (l_time + time_zone - r_time) / kSecondPerDay; } +/** + * @brief get week day string + * + * @param t + * @return std::string_view + */ +inline std::string_view GetWeekDayStr(time_t t) { + static constexpr std::string_view kWeekDays[] = { + "Sunday", "Monday", "Tuesday", "Wednesday", "Thursday", "Friday", "Saturday"}; + struct tm st = TimeT2TmLocal(t); + return kWeekDays[st.tm_wday]; +} + +/** + * @brief get week-short day string + * + * @param t + * @return std::string_view + */ +inline std::string_view GetWeekDayStrShort(time_t t) { + static constexpr std::string_view kWeekDaysShort[] = { + "Sun", "Mon", "Tue", "Wed", "Thu", "Fri", "Sat"}; + struct tm st = TimeT2TmLocal(t); + return kWeekDaysShort[st.tm_wday]; +} + +/** + * @brief Get year string (4 digits) + * + * @param t timestamp + * @return std::string_view Format like "2024" + */ +inline std::string_view GetYearStr(time_t t) { + thread_local char buf[5]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%04d", (tm.tm_year + 1900) % 10000u); + return std::string_view(buf); +} + +/** + * @brief Get month string (2 digits) + * + * @param t timestamp + * @return std::string_view Format like "03" + */ +inline std::string_view GetMonthStr(time_t t) { + thread_local char buf[3]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d", (tm.tm_mon + 1) % 100u); + return std::string_view(buf); +} + +/** + * @brief Get day string (2 digits) + * + * @param t timestamp + * @return std::string_view Format like "15" + */ +inline std::string_view GetDayStr(time_t t) { + thread_local char buf[3]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d", tm.tm_mday % 100u); + return std::string_view(buf); +} + +/** + * @brief Get hour string (2 digits, 24-hour format) + * + * @param t timestamp + * @return std::string_view Format like "14" + */ +inline std::string_view GetHourStr(time_t t) { + thread_local char buf[3]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d", tm.tm_hour % 100u); + return std::string_view(buf); +} + +/** + * @brief Get minute string (2 digits) + * + * @param t timestamp + * @return std::string_view Format like "30" + */ +inline std::string_view GetMinuteStr(time_t t) { + thread_local char buf[3]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d", tm.tm_min % 100u); + return std::string_view(buf); +} + +/** + * @brief Get second string (2 digits) + * + * @param t timestamp + * @return std::string_view Format like "45" + */ +inline std::string_view GetSecondStr(time_t t) { + thread_local char buf[3]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d", tm.tm_sec % 100u); + return std::string_view(buf); +} + +/** + * @brief Get complete date string + * + * @param t timestamp + * @return std::string_view Format like "2024-03-15" + */ +inline std::string_view GetDateStr(time_t t) { + thread_local char buf[11]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%04d-%02d-%02d", + (tm.tm_year + 1900) % 10000u, + (tm.tm_mon + 1) % 100u, + tm.tm_mday % 100u); + return std::string_view(buf); +} + +/** + * @brief Get complete time string + * + * @param t timestamp + * @return std::string_view Format like "14:30:45" + */ +inline std::string_view GetClockStr(time_t t) { + thread_local char buf[9]; + auto tm = TimeT2TmLocal(t); + snprintf(buf, sizeof(buf), "%02d:%02d:%02d", + tm.tm_hour % 100u, + tm.tm_min % 100u, + tm.tm_sec % 100u); + return std::string_view(buf); +} + } // namespace aimrt::common::util diff --git a/src/examples/cpp/logger/README.md b/src/examples/cpp/logger/README.md index f0f136b2d..895a191f8 100644 --- a/src/examples/cpp/logger/README.md +++ b/src/examples/cpp/logger/README.md @@ -26,6 +26,9 @@ 说明： - 此示例创建了一个 `LoggerModule`，会在其 `Start` 的阶段循环打印各种等级的日志； - 此示例将 `LoggerModule` 集成到 `logger_pkg` 中，并在配置文件中加载此 Pkg； +- 在该例程的[配置文件]((./install/linux/bin/cfg/examples_cpp_logger_cfg.yaml))中，配置了 pattern 选项为 `"[%c.%f][%A][%l][%t][%n][%G] %v"`， 这是一个可以自定义输出格式的配置项。 + + ## logger rotate file diff --git a/src/examples/cpp/logger/install/linux/bin/cfg/examples_cpp_logger_cfg.yaml b/src/examples/cpp/logger/install/linux/bin/cfg/examples_cpp_logger_cfg.yaml index 24c7c6a60..9a242c1e7 100644 --- a/src/examples/cpp/logger/install/linux/bin/cfg/examples_cpp_logger_cfg.yaml +++ b/src/examples/cpp/logger/install/linux/bin/cfg/examples_cpp_logger_cfg.yaml @@ -6,6 +6,8 @@ aimrt: core_lvl: INFO # Trace/Debug/Info/Warn/Error/Fatal/Off backends: - type: console + options: + pattern: "[%c.%f][%A][%l][%t][%n][%G] %v" executor: executors: - name: work_executor diff --git a/src/runtime/core/logger/console_logger_backend.cc b/src/runtime/core/logger/console_logger_backend.cc index 0dc3dd3ee..fbb02242e 100644 --- a/src/runtime/core/logger/console_logger_backend.cc +++ b/src/runtime/core/logger/console_logger_backend.cc @@ -8,6 +8,7 @@ #include #include +#include "core/logger/formatter.h" #include "core/logger/log_level_tool.h" #include "util/exception.h" #include "util/format.h" @@ -95,6 +96,7 @@ struct convert { node["color"] = rhs.print_color; node["module_filter"] = rhs.module_filter; node["log_executor_name"] = rhs.log_executor_name; + node["pattern"] = rhs.pattern; return node; } @@ -107,6 +109,8 @@ struct convert { rhs.module_filter = node["module_filter"].as(); if (node["log_executor_name"]) rhs.log_executor_name = node["log_executor_name"].as(); + if (node["pattern"]) + rhs.pattern = node["pattern"].as(); return true; } @@ -134,6 +138,11 @@ void ConsoleLoggerBackend::Initialize(YAML::Node options_node) { "Log executor must be thread safe. Log executor name: " + options_.log_executor_name); } + if (!options_.pattern.empty()) { + pattern_ = options_.pattern; + } + formatter_.SetPattern(pattern_); + options_node = options_; run_flag_.store(true); @@ -147,18 +156,7 @@ void ConsoleLoggerBackend::Log(const LogDataWrapper& log_data_wrapper) noexcept if (!CheckLog(log_data_wrapper)) [[unlikely]] return; - auto log_data_str = ::aimrt_fmt::format( - "[{}.{:0>6}][{}][{}][{}][{}:{}:{} @{}]{}", - aimrt::common::util::GetTimeStr(std::chrono::system_clock::to_time_t(log_data_wrapper.t)), - (aimrt::common::util::GetTimestampUs(log_data_wrapper.t) % 1000000), - LogLevelTool::GetLogLevelName(log_data_wrapper.lvl), - log_data_wrapper.thread_id, - log_data_wrapper.module_name, - log_data_wrapper.file_name, - log_data_wrapper.line, - log_data_wrapper.column, - log_data_wrapper.function_name, - std::string_view(log_data_wrapper.log_data, log_data_wrapper.log_data_size)); + std::string log_data_str = formatter_.Format(log_data_wrapper); auto log_work = [this, lvl = log_data_wrapper.lvl, log_data_str{std::move(log_data_str)}]() { if (options_.print_color) { @@ -168,10 +166,10 @@ void ConsoleLoggerBackend::Log(const LogDataWrapper& log_data_wrapper) noexcept 0, CC_DBG, CC_INF, CC_WRN, CC_ERR, CC_FATAL}; if (color_array[lvl] == 0) { - std::cout << log_data_str; + std::cout.write(log_data_str.data(), log_data_str.size()); } else { SetConsoleTextAttribute(g_hConsole, color_array[lvl]); - std::cout << log_data_str; + std::cout.write(log_data_str.data(), log_data_str.size()); SetConsoleTextAttribute(g_hConsole, CC_DEFAULT); } @@ -181,13 +179,15 @@ void ConsoleLoggerBackend::Log(const LogDataWrapper& log_data_wrapper) noexcept "", CC_DBG, CC_INF, CC_WRN, CC_ERR, CC_FATAL}; if (kColorArray[lvl].empty()) { - std::cout << log_data_str; + std::cout.write(log_data_str.data(), log_data_str.size()); } else { - std::cout << kColorArray[lvl] << log_data_str << CC_NONE; + std::cout.write(kColorArray[lvl].data(), kColorArray[lvl].size()) + .write(log_data_str.data(), log_data_str.size()) + .write(CC_NONE, sizeof(CC_NONE) - 1); } #endif } else { - std::cout << log_data_str; + std::cout.write(log_data_str.data(), log_data_str.size()); } std::cout << std::endl; }; diff --git a/src/runtime/core/logger/console_logger_backend.h b/src/runtime/core/logger/console_logger_backend.h index 77d841af3..4a9e201fc 100644 --- a/src/runtime/core/logger/console_logger_backend.h +++ b/src/runtime/core/logger/console_logger_backend.h @@ -7,6 +7,7 @@ #include #include "aimrt_module_cpp_interface/executor/executor.h" +#include "core/logger/formatter.h" #include "core/logger/logger_backend_base.h" #include "util/string_util.h" @@ -18,6 +19,7 @@ class ConsoleLoggerBackend : public LoggerBackendBase { bool print_color = true; std::string module_filter = "(.*)"; std::string log_executor_name = ""; + std::string pattern; }; public: @@ -52,6 +54,9 @@ class ConsoleLoggerBackend : public LoggerBackendBase { std::unordered_map< std::string, bool, aimrt::common::util::StringHash, std::equal_to<>> module_filter_map_; + + LogFormatter formatter_; + std::string pattern_ = "[%c.%f][%l][%t][%n][%g:%R:%C @%F]%v"; }; } // namespace aimrt::runtime::core::logger diff --git a/src/runtime/core/logger/formatter.h b/src/runtime/core/logger/formatter.h new file mode 100644 index 000000000..5ca9bc1c5 --- /dev/null +++ b/src/runtime/core/logger/formatter.h @@ -0,0 +1,274 @@ +// Copyright (c) 2023, AgiBot Inc. +// All rights reserved. + +#pragma once + +#include +#include +#include +#include "core/logger/log_data_wrapper.h" +#include "core/logger/log_level_tool.h" +#include "util/exception.h" +#include "util/time_util.h" + +namespace aimrt::runtime::core::logger { + +class LogFormatter { + public: + std::string Format(const LogDataWrapper& log_data_wrapper) { + std::string buffer; + buffer.reserve(log_data_wrapper.log_data_size + estimated_size_); // reserve space for log data + for (const auto& handler : format_handlers_) { + handler(log_data_wrapper, buffer); + } + return buffer; + } + + void SetPattern(const std::string& pattern) { + if (pattern.empty()) [[unlikely]] { + throw aimrt::common::util::AimRTException("Invalid argument: Logger's pattern cannot be empty"); + } + + try { + format_handlers_.clear(); + + size_t pos = 0; + size_t last_text_pos = 0; + + while (pos < pattern.length()) { + if (pattern[pos] == '%' && pos + 1 < pattern.length()) { + // deal with normal text + if (pos > 0 && pattern[pos - 1] != '%') { + auto text = std::string_view(pattern.data() + last_text_pos, pos - last_text_pos); + if (!text.empty()) { + estimated_size_ += text.length(); + format_handlers_.emplace_back( + [text = std::string(text)](auto&, std::string& buffer) { + buffer.append(text); + }); + } + } + + // deal with format specifier + switch (pattern[pos + 1]) { + case 'c': // data and time (2024-03-15 14:30:45) + estimated_size_ += 19; + format_handlers_.emplace_back(format_time); + break; + case 'Y': // year (2024) + estimated_size_ += 4; + format_handlers_.emplace_back(format_year); + break; + case 'm': // month (03) + estimated_size_ += 2; + format_handlers_.emplace_back(format_month); + break; + case 'd': // day (15) + estimated_size_ += 2; + format_handlers_.emplace_back(format_day); + break; + case 'H': // hour (14) + estimated_size_ += 2; + format_handlers_.emplace_back(format_hour); + break; + case 'M': // minute (30) + estimated_size_ += 2; + format_handlers_.emplace_back(format_minute); + break; + case 'S': // second (45) + estimated_size_ += 2; + format_handlers_.emplace_back(format_second); + break; + case 'D': // date only (2024-03-15) + estimated_size_ += 10; + format_handlers_.emplace_back(format_date); + break; + case 'T': // clock only (14:30:45) + estimated_size_ += 8; + format_handlers_.emplace_back(format_clock); + break; + case 'f': // microseconds (123456) + estimated_size_ += 6; + format_handlers_.emplace_back(format_microseconds); + break; + case 'A': // weekay (Sunday) + estimated_size_ += 9; + format_handlers_.emplace_back(format_weekday); + break; + case 'a': // weekay-short (Sun) + estimated_size_ += 3; + format_handlers_.emplace_back(format_weekday_short); + break; + case 'l': // log level (Info) + estimated_size_ += 5; + format_handlers_.emplace_back(format_level); + break; + case 't': // thread id (1234) + estimated_size_ += 10; + format_handlers_.emplace_back(format_thread_id); + break; + case 'n': // module name (test_module) + estimated_size_ += 35; + format_handlers_.emplace_back(format_module); + break; + case 'G': // file name_short (test_module.cpp) + estimated_size_ += 35; + format_handlers_.emplace_back(format_file_short); + break; + case 'g': // file name (/XX/YY/ZZ/test_module.cpp) + estimated_size_ += 500; + format_handlers_.emplace_back(format_file); + break; + case 'R': // row number (20) + estimated_size_ += 6; + format_handlers_.emplace_back(format_line); + break; + case 'C': // column number (20) + estimated_size_ += 6; + format_handlers_.emplace_back(format_column); + break; + case 'F': // function name (TestFunc) + estimated_size_ += 30; + format_handlers_.emplace_back(format_function); + break; + case 'v': // message + format_handlers_.emplace_back(format_message); + break; + default: + format_handlers_.emplace_back( + [c = pattern[pos + 1]](const LogDataWrapper&, std::string& buffer) { + buffer.push_back(c); + }); + break; + } + pos += 2; + last_text_pos = pos; + } else { + ++pos; + } + } + + // deal with the last text + if (last_text_pos < pattern.length()) { + std::string_view text(pattern.data() + last_text_pos, pattern.length() - last_text_pos); + estimated_size_ += text.length(); + format_handlers_.emplace_back( + [text = std::string(text)](const LogDataWrapper&, std::string& buffer) { + buffer.append(text); + }); + } + } catch (const std::exception& e) { + throw aimrt::common::util::AimRTException("Error in LogFormatter::SetPattern: " + std::string(e.what())); + } + } + + private: + // format time + static void format_time(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetTimeStr(std::chrono::system_clock::to_time_t(data.t))); + } + + // format microseconds + static void format_microseconds(const LogDataWrapper& data, std::string& buffer) { + buffer.append(std::to_string(aimrt::common::util::GetTimestampUs(data.t) % 1000000)); + } + + static void format_year(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetYearStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_month(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetMonthStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_day(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetDayStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_hour(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetHourStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_minute(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetMinuteStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_second(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetSecondStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_date(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetDateStr(std::chrono::system_clock::to_time_t(data.t))); + } + + static void format_clock(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetClockStr(std::chrono::system_clock::to_time_t(data.t))); + } + + // format weekday + static void format_weekday(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetWeekDayStr(std::chrono::system_clock::to_time_t(data.t))); + } + + // format weekday-short + static void format_weekday_short(const LogDataWrapper& data, std::string& buffer) { + buffer.append(aimrt::common::util::GetWeekDayStrShort(std::chrono::system_clock::to_time_t(data.t))); + } + + // format log level + static void format_level(const LogDataWrapper& data, std::string& buffer) { + buffer.append(LogLevelTool::GetLogLevelName(data.lvl)); + } + + // format message + static void format_message(const LogDataWrapper& data, std::string& buffer) { + buffer.append(data.log_data, data.log_data_size); + } + + // format thread id + static void format_thread_id(const LogDataWrapper& data, std::string& buffer) { + buffer.append(std::to_string(data.thread_id)); + } + + // format module name + static void format_module(const LogDataWrapper& data, std::string& buffer) { + buffer.append(data.module_name); + } + + // format file name + static void format_file(const LogDataWrapper& data, std::string& buffer) { + buffer.append(data.file_name); + } + + // format file name (short) + static void format_file_short(const LogDataWrapper& data, std::string& buffer) { + const char* last_slash = strrchr(data.file_name, '/'); + if (last_slash) { + buffer.append(last_slash + 1); + } else { + buffer.append(data.file_name); + } + } + + // format line number + static void format_line(const LogDataWrapper& data, std::string& buffer) { + buffer.append(std::to_string(data.line)); + } + + // format column number + static void format_column(const LogDataWrapper& data, std::string& buffer) { + buffer.append(std::to_string(data.column)); + } + + // format function name + static void format_function(const LogDataWrapper& data, std::string& buffer) { + buffer.append(data.function_name); + } + + using FormatHandler = std::function; + std::vector format_handlers_; + + size_t estimated_size_ = 0; +}; + +} // namespace aimrt::runtime::core::logger \ No newline at end of file diff --git a/src/runtime/core/logger/formatter_test.cc b/src/runtime/core/logger/formatter_test.cc new file mode 100644 index 000000000..6377d5420 --- /dev/null +++ b/src/runtime/core/logger/formatter_test.cc @@ -0,0 +1,64 @@ +// Copyright (c) 2023, AgiBot Inc. +// All rights reserved. + +#include "formatter.h" +#include + +namespace aimrt::runtime::core::logger { + +// Test the GetRemappedFuncName function +TEST(FORMATTER_TEST, Format_test) { + auto date = std::chrono::year(2024) / std::chrono::month(10) / std::chrono::day(1); + auto time = std::chrono::hours(10) + + std::chrono::minutes(10) + + std::chrono::seconds(10) + + std::chrono::microseconds(123456); + + // // 2024-10-01 10:10:10.123456 + auto datatime = std::chrono::sys_days(date) + time - std::chrono::seconds(common::util::GetLocalTimeZone()); + + const char* test_msg = "test log message"; + LogDataWrapper log_data_wrapper{ + .module_name = "test_module", + .thread_id = 1234, + .t = datatime, + .lvl = AIMRT_LOG_LEVEL_INFO, + .line = 20, + .column = 10, + .file_name = "XX/YY/ZZ/test_file.cpp", + .function_name = "test_function", + .log_data = test_msg, + .log_data_size = strlen(test_msg) + + }; + + LogFormatter formatter; + std::string actual_output; + std::string expected_output; + + // Test the default pattern + formatter.SetPattern("[%c.%f][%l][%t][%n][%g:%R:%C @%F]%v"); + expected_output = "[2024-10-01 10:10:10.123456][Info][1234][test_module][XX/YY/ZZ/test_file.cpp:20:10 @test_function]test log message"; + actual_output = formatter.Format(log_data_wrapper); + EXPECT_EQ(actual_output, expected_output); + + // Test dividing the time into year, month, day, hour, minute, second, and weekday + actual_output.clear(); + formatter.SetPattern("[%Y/%m/%d %H:%M:%S.%f][%A][%a]%v"); + expected_output = "[2024/10/01 10:10:10.123456][Tuesday][Tue]test log message"; + actual_output = formatter.Format(log_data_wrapper); + EXPECT_EQ(actual_output, expected_output); + + // Test custom pattern + actual_output.clear(); + formatter.SetPattern("%%123456%%%q!@#$%^&*()+-*/12345678%%"); + expected_output = "%123456%q!@#$^&*()+-*/12345678%"; + actual_output = formatter.Format(log_data_wrapper); + EXPECT_EQ(actual_output, expected_output); + + // Test blank pattern + actual_output.clear(); + EXPECT_ANY_THROW(formatter.SetPattern("")); +} + +} // namespace aimrt::runtime::core::logger \ No newline at end of file diff --git a/src/runtime/core/logger/rotate_file_logger_backend.cc b/src/runtime/core/logger/rotate_file_logger_backend.cc index 427bffeb1..9660ac5de 100644 --- a/src/runtime/core/logger/rotate_file_logger_backend.cc +++ b/src/runtime/core/logger/rotate_file_logger_backend.cc @@ -28,6 +28,7 @@ struct convert { node["max_file_num"] = rhs.max_file_num; node["module_filter"] = rhs.module_filter; node["log_executor_name"] = rhs.log_executor_name; + node["pattern"] = rhs.pattern; return node; } @@ -45,6 +46,8 @@ struct convert { rhs.module_filter = node["module_filter"].as(); if (node["log_executor_name"]) rhs.log_executor_name = node["log_executor_name"].as(); + if (node["pattern"]) + rhs.pattern = node["pattern"].as(); return true; } @@ -83,6 +86,11 @@ void RotateFileLoggerBackend::Initialize(YAML::Node options_node) { "Log executor must be thread safe. Log executor name: " + options_.log_executor_name); } + if (!options_.pattern.empty()) { + pattern_ = options_.pattern; + } + formatter_.SetPattern(pattern_); + options_node = options_; run_flag_.store(true); @@ -96,24 +104,13 @@ void RotateFileLoggerBackend::Log(const LogDataWrapper& log_data_wrapper) noexce if (!CheckLog(log_data_wrapper)) [[unlikely]] return; - auto log_data_str = ::aimrt_fmt::format( - "[{}.{:0>6}][{}][{}][{}][{}:{}:{} @{}]{}", - aimrt::common::util::GetTimeStr(std::chrono::system_clock::to_time_t(log_data_wrapper.t)), - (aimrt::common::util::GetTimestampUs(log_data_wrapper.t) % 1000000), - LogLevelTool::GetLogLevelName(log_data_wrapper.lvl), - log_data_wrapper.thread_id, - log_data_wrapper.module_name, - log_data_wrapper.file_name, - log_data_wrapper.line, - log_data_wrapper.column, - log_data_wrapper.function_name, - std::string_view(log_data_wrapper.log_data, log_data_wrapper.log_data_size)); + std::string log_data_str = formatter_.Format(log_data_wrapper); auto log_work = [this, log_data_str{std::move(log_data_str)}]() { if (!ofs_.is_open() || ofs_.tellp() > options_.max_file_size_m * 1024 * 1024) { if (!OpenNewFile()) return; } - ofs_ << log_data_str << std::endl; + ofs_.write(log_data_str.data(), log_data_str.size()) << std::endl; }; log_executor_.Execute(std::move(log_work)); diff --git a/src/runtime/core/logger/rotate_file_logger_backend.h b/src/runtime/core/logger/rotate_file_logger_backend.h index 74903feff..824c5a64d 100644 --- a/src/runtime/core/logger/rotate_file_logger_backend.h +++ b/src/runtime/core/logger/rotate_file_logger_backend.h @@ -8,6 +8,7 @@ #include #include "aimrt_module_cpp_interface/executor/executor.h" +#include "core/logger/formatter.h" #include "core/logger/logger_backend_base.h" #include "util/string_util.h" @@ -22,6 +23,7 @@ class RotateFileLoggerBackend : public LoggerBackendBase { uint32_t max_file_num = 100; std::string module_filter = "(.*)"; std::string log_executor_name = ""; + std::string pattern; }; public: @@ -63,6 +65,8 @@ class RotateFileLoggerBackend : public LoggerBackendBase { std::unordered_map< std::string, bool, aimrt::common::util::StringHash, std::equal_to<>> module_filter_map_; + LogFormatter formatter_; + std::string pattern_ = "[%c.%f][%l][%t][%n][%g:%R:%C @%F]%v"; }; } // namespace aimrt::runtime::core::logger