This is an automated email from the ASF dual-hosted git repository.
laiyingchun pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/incubator-pegasus.git
The following commit(s) were added to refs/heads/master by this push:
new b39e18b74 refactor(logging): Minor refactor on logging module (#2022)
b39e18b74 is described below
commit b39e18b742e112e2d5abdfa84a3b2a54346a0dab
Author: Yingchun Lai <[email protected]>
AuthorDate: Fri May 24 17:26:00 2024 +0800
refactor(logging): Minor refactor on logging module (#2022)
Mainly including:
- Using fmt::format/print instead of sprintf/printf, which is more
convenient
and faster
- Add some configuration validators
- Encapsulate print_header(), print_long_header() and print_body() for
screen_logger and simple_logger
- Add more comments
- Naming improvment
---
src/runtime/service_api_c.cpp | 106 ++++++++++++++++------------------
src/utils/simple_logger.cpp | 131 ++++++++++++++++++++++++++++++------------
src/utils/simple_logger.h | 19 +++++-
3 files changed, 162 insertions(+), 94 deletions(-)
diff --git a/src/runtime/service_api_c.cpp b/src/runtime/service_api_c.cpp
index f2195f95a..fb4e5154e 100644
--- a/src/runtime/service_api_c.cpp
+++ b/src/runtime/service_api_c.cpp
@@ -76,6 +76,7 @@
#include "utils/join_point.h"
#include "utils/logging_provider.h"
#include "utils/process_utils.h"
+#include "utils/string_conv.h"
#include "utils/strings.h"
#include "utils/sys_exit_hook.h"
#include "utils/threadpool_spec.h"
@@ -343,45 +344,29 @@ inline void dsn_global_init()
static std::string dsn_log_prefixed_message_func()
{
- std::string res;
- res.resize(100);
- char *prefixed_message = const_cast<char *>(res.c_str());
-
- int tid = dsn::utils::get_current_tid();
- auto t = dsn::task::get_current_task_id();
+ const int tid = dsn::utils::get_current_tid();
+ const auto t = dsn::task::get_current_task_id();
if (t) {
if (nullptr != dsn::task::get_current_worker2()) {
- sprintf(prefixed_message,
- "%6s.%7s%d.%016" PRIx64 ": ",
- dsn::task::get_current_node_name(),
- dsn::task::get_current_worker2()->pool_spec().name.c_str(),
- dsn::task::get_current_worker2()->index(),
- t);
+ return fmt::format("{}.{}{}.{:016}: ",
+ dsn::task::get_current_node_name(),
+
dsn::task::get_current_worker2()->pool_spec().name,
+ dsn::task::get_current_worker2()->index(),
+ t);
} else {
- sprintf(prefixed_message,
- "%6s.%7s.%05d.%016" PRIx64 ": ",
- dsn::task::get_current_node_name(),
- "io-thrd",
- tid,
- t);
+ return fmt::format(
+ "{}.io-thrd.{}.{:016}: ", dsn::task::get_current_node_name(),
tid, t);
}
} else {
if (nullptr != dsn::task::get_current_worker2()) {
- sprintf(prefixed_message,
- "%6s.%7s%u: ",
- dsn::task::get_current_node_name(),
- dsn::task::get_current_worker2()->pool_spec().name.c_str(),
- dsn::task::get_current_worker2()->index());
+ return fmt::format("{}.{}{}: ",
+ dsn::task::get_current_node_name(),
+
dsn::task::get_current_worker2()->pool_spec().name,
+ dsn::task::get_current_worker2()->index());
} else {
- sprintf(prefixed_message,
- "%6s.%7s.%05d: ",
- dsn::task::get_current_node_name(),
- "io-thrd",
- tid);
+ return fmt::format("{}.io-thrd.{}: ",
dsn::task::get_current_node_name(), tid);
}
}
-
- return res;
}
bool run(const char *config_file,
@@ -457,14 +442,14 @@ bool run(const char *config_file,
}
dsn::utils::filesystem::create_directory(spec.log_dir);
- // init tools
+ // Initialize tools.
dsn_all.tool.reset(::dsn::utils::factory_store<::dsn::tools::tool_app>::create(
spec.tool.c_str(), ::dsn::PROVIDER_TYPE_MAIN, spec.tool.c_str()));
dsn_all.tool->install(spec);
- // init app specs
+ // Initialize app specs.
if (!spec.init_app_specs()) {
- printf("error in config file %s, exit ...\n", config_file);
+ fmt::print(stderr, "error in config file {}, exit ...\n", config_file);
return false;
}
@@ -475,7 +460,7 @@ bool run(const char *config_file,
// init logging
dsn_log_init(spec.logging_factory_name, spec.log_dir,
dsn_log_prefixed_message_func);
- // prepare minimum necessary
+ // Prepare the minimum necessary.
::dsn::service_engine::instance().init_before_toollets(spec);
LOG_INFO("process({}) start: {}, date: {}",
@@ -483,10 +468,10 @@ bool run(const char *config_file,
dsn::utils::process_start_millis(),
dsn::utils::process_start_date_time_mills());
- // init toollets
- for (auto it = spec.toollets.begin(); it != spec.toollets.end(); ++it) {
- auto tlet =
- dsn::tools::internal_use_only::get_toollet(it->c_str(),
::dsn::PROVIDER_TYPE_MAIN);
+ // Initialize toollets.
+ for (const auto &toollet_name : spec.toollets) {
+ auto tlet =
dsn::tools::internal_use_only::get_toollet(toollet_name.c_str(),
+
::dsn::PROVIDER_TYPE_MAIN);
CHECK_NOTNULL(tlet, "toolet not found");
tlet->install(spec);
}
@@ -517,29 +502,37 @@ bool run(const char *config_file,
}
}
- // split app_name and app_index
- std::list<std::string> applistkvs;
- ::dsn::utils::split_args(app_list.c_str(), applistkvs, ';');
-
// init apps
for (auto &sp : spec.app_specs) {
- if (!sp.run)
+ if (!sp.run) {
continue;
+ }
bool create_it = false;
-
// create all apps
- if (app_list == "") {
+ if (app_list.empty()) {
create_it = true;
} else {
- for (auto &kv : applistkvs) {
- std::list<std::string> argskvs;
- ::dsn::utils::split_args(kv.c_str(), argskvs, '@');
- if (std::string("apps.") + argskvs.front() ==
sp.config_section) {
- if (argskvs.size() < 2)
+ // Extract app_names.
+ std::list<std::string> app_names_and_indexes;
+ ::dsn::utils::split_args(app_list.c_str(), app_names_and_indexes,
';');
+ for (const auto &app_name_and_index : app_names_and_indexes) {
+ std::vector<std::string> name_and_index;
+ ::dsn::utils::split_args(app_name_and_index.c_str(),
name_and_index, '@');
+ CHECK(!name_and_index.empty(),
+ "app_name should be specified in '{}'",
+ app_name_and_index);
+ if (std::string("apps.") + name_and_index.front() ==
sp.config_section) {
+ if (name_and_index.size() < 2) {
create_it = true;
- else
- create_it = (std::stoi(argskvs.back()) == sp.index);
+ } else {
+ int32_t index = 0;
+ const auto index_str = name_and_index.back();
+ CHECK(dsn::buf2int32(index_str, index),
+ "'{}' is not a valid index",
+ index_str);
+ create_it = (index == sp.index);
+ }
break;
}
}
@@ -550,10 +543,11 @@ bool run(const char *config_file,
}
}
- if (dsn::service_engine::instance().get_all_nodes().size() == 0) {
- printf("no app are created, usually because \n"
- "app_name is not specified correctly, should be 'xxx' in
[apps.xxx]\n"
- "or app_index (1-based) is greater than specified count in
config file\n");
+ if (dsn::service_engine::instance().get_all_nodes().empty()) {
+ fmt::print(stderr,
+ "no app are created, usually because \n"
+ "app_name is not specified correctly, should be 'xxx' in
[apps.xxx]\n"
+ "or app_index (1-based) is greater than specified count in
config file\n");
exit(1);
}
diff --git a/src/utils/simple_logger.cpp b/src/utils/simple_logger.cpp
index d54e03025..0234cee6f 100644
--- a/src/utils/simple_logger.cpp
+++ b/src/utils/simple_logger.cpp
@@ -28,10 +28,11 @@
// IWYU pragma: no_include <ext/alloc_traits.h>
#include <fmt/core.h>
-#include <stdint.h>
+#include <fmt/printf.h>
+#include <cstdint>
#include <functional>
#include <memory>
-#include <sstream>
+#include <ostream>
#include <vector>
#include "absl/strings/string_view.h"
@@ -44,7 +45,6 @@
#include "utils/ports.h"
#include "utils/process_utils.h"
#include "utils/string_conv.h"
-#include "utils/strings.h"
#include "utils/time_utils.h"
DSN_DEFINE_bool(tools.simple_logger, fast_flush, false, "Whether to flush logs
immediately");
@@ -60,23 +60,27 @@ DSN_DEFINE_uint64(
max_number_of_log_files_on_disk,
20,
"The maximum number of log files to be reserved on disk, older logs are
deleted automatically");
+DSN_DEFINE_validator(max_number_of_log_files_on_disk,
+ [](int32_t value) -> bool { return value > 0; });
DSN_DEFINE_string(
tools.simple_logger,
stderr_start_level,
"LOG_LEVEL_WARNING",
"The lowest level of log messages to be copied to stderr in addition to
log files");
-DSN_DEFINE_validator(stderr_start_level, [](const char *level) -> bool {
- return !dsn::utils::equals(level, "LOG_LEVEL_INVALID");
+DSN_DEFINE_validator(stderr_start_level, [](const char *value) -> bool {
+ const auto level = enum_from_string(value, LOG_LEVEL_INVALID);
+ return LOG_LEVEL_DEBUG <= level && level <= LOG_LEVEL_FATAL;
});
DSN_DECLARE_string(logging_start_level);
namespace dsn {
namespace tools {
-static void print_header(FILE *fp, log_level_t log_level)
+namespace {
+int print_header(FILE *fp, log_level_t stderr_start_level, log_level_t
log_level)
{
- // The leading character of each log lines, corresponding to the log level
+ // The leading character of each log line, corresponding to the log level
// D: Debug
// I: Info
// W: Warning
@@ -89,16 +93,43 @@ static void print_header(FILE *fp, log_level_t log_level)
dsn::utils::time_ms_to_string(ts / 1000000, time_str);
int tid = dsn::utils::get_current_tid();
- fmt::print(fp,
- "{}{} ({} {}) {}",
- s_level_char[log_level],
- time_str,
- ts,
- tid,
- log_prefixed_message_func().c_str());
+ const auto header = fmt::format(
+ "{}{} ({} {}) {}", s_level_char[log_level], time_str, ts, tid,
log_prefixed_message_func());
+ const int written_size = fmt::fprintf(fp, "%s", header.c_str());
+ if (log_level >= stderr_start_level) {
+ fmt::fprintf(stderr, "%s", header.c_str());
+ }
+ return written_size;
}
-namespace {
+int print_long_header(FILE *fp,
+ const char *file,
+ const char *function,
+ const int line,
+ bool short_header,
+ log_level_t stderr_start_level,
+ log_level_t log_level)
+{
+ if (short_header) {
+ return 0;
+ }
+
+ const auto long_header = fmt::format("{}:{}:{}(): ", file, line, function);
+ const int written_size = fmt::fprintf(fp, "%s", long_header.c_str());
+ if (log_level >= stderr_start_level) {
+ fmt::fprintf(stderr, "%s", long_header.c_str());
+ }
+ return written_size;
+}
+
+int print_body(FILE *fp, const char *body, log_level_t stderr_start_level,
log_level_t log_level)
+{
+ const int written_size = fmt::fprintf(fp, "%s\n", body);
+ if (log_level >= stderr_start_level) {
+ fmt::fprintf(stderr, "%s\n", body);
+ }
+ return written_size;
+}
inline void process_fatal_log(log_level_t log_level)
{
@@ -122,19 +153,33 @@ inline void process_fatal_log(log_level_t log_level)
screen_logger::screen_logger(bool short_header) : _short_header(short_header)
{}
-screen_logger::~screen_logger(void) {}
+void screen_logger::print_header(log_level_t log_level)
+{
+ ::dsn::tools::print_header(stdout, LOG_LEVEL_COUNT, log_level);
+}
+
+void screen_logger::print_long_header(const char *file,
+ const char *function,
+ const int line,
+ log_level_t log_level)
+{
+ ::dsn::tools::print_long_header(
+ stdout, file, function, line, _short_header, LOG_LEVEL_COUNT,
log_level);
+}
+
+void screen_logger::print_body(const char *body, log_level_t log_level)
+{
+ ::dsn::tools::print_body(stdout, body, LOG_LEVEL_COUNT, log_level);
+}
void screen_logger::log(
const char *file, const char *function, const int line, log_level_t
log_level, const char *str)
{
utils::auto_lock<::dsn::utils::ex_lock_nr> l(_lock);
- print_header(stdout, log_level);
- if (!_short_header) {
- printf("%s:%d:%s(): ", file, line, function);
- }
- printf("%s\n", str);
-
+ print_header(log_level);
+ print_long_header(file, function, line, log_level);
+ print_body(str, log_level);
if (log_level >= LOG_LEVEL_ERROR) {
::fflush(stdout);
}
@@ -222,8 +267,10 @@ simple_logger::simple_logger(const char *log_dir)
void simple_logger::create_log_file()
{
+ // Close the current log file if it is opened.
if (_log != nullptr) {
::fclose(_log);
+ _log = nullptr;
}
_lines = 0;
@@ -246,41 +293,53 @@ void simple_logger::create_log_file()
}
}
-simple_logger::~simple_logger(void)
+simple_logger::~simple_logger()
{
utils::auto_lock<::dsn::utils::ex_lock> l(_lock);
::fclose(_log);
+ _log = nullptr;
}
void simple_logger::flush()
{
utils::auto_lock<::dsn::utils::ex_lock> l(_lock);
::fflush(_log);
+ ::fflush(stderr);
::fflush(stdout);
}
+void simple_logger::print_header(log_level_t log_level)
+{
+ ::dsn::tools::print_header(_log, _stderr_start_level, log_level);
+}
+
+void simple_logger::print_long_header(const char *file,
+ const char *function,
+ const int line,
+ log_level_t log_level)
+{
+ ::dsn::tools::print_long_header(
+ _log, file, function, line, FLAGS_short_header, _stderr_start_level,
log_level);
+}
+
+void simple_logger::print_body(const char *body, log_level_t log_level)
+{
+ ::dsn::tools::print_body(_log, body, _stderr_start_level, log_level);
+}
+
void simple_logger::log(
const char *file, const char *function, const int line, log_level_t
log_level, const char *str)
{
utils::auto_lock<::dsn::utils::ex_lock> l(_lock);
- print_header(_log, log_level);
- if (!FLAGS_short_header) {
- fprintf(_log, "%s:%d:%s(): ", file, line, function);
- }
- fprintf(_log, "%s\n", str);
+ CHECK_NOTNULL(_log, "Log file hasn't been initialized yet");
+ print_header(log_level);
+ print_long_header(file, function, line, log_level);
+ print_body(str, log_level);
if (FLAGS_fast_flush || log_level >= LOG_LEVEL_ERROR) {
::fflush(_log);
}
- if (log_level >= _stderr_start_level) {
- print_header(stdout, log_level);
- if (!FLAGS_short_header) {
- printf("%s:%d:%s(): ", file, line, function);
- }
- printf("%s\n", str);
- }
-
process_fatal_log(log_level);
if (++_lines >= 200000) {
diff --git a/src/utils/simple_logger.h b/src/utils/simple_logger.h
index e9657a801..7da324139 100644
--- a/src/utils/simple_logger.h
+++ b/src/utils/simple_logger.h
@@ -43,7 +43,7 @@ class screen_logger : public logging_provider
{
public:
explicit screen_logger(bool short_header);
- ~screen_logger() override;
+ ~screen_logger() override = default;
void log(const char *file,
const char *function,
@@ -54,6 +54,13 @@ public:
virtual void flush();
private:
+ static void print_header(log_level_t log_level);
+ void print_long_header(const char *file,
+ const char *function,
+ const int line,
+ log_level_t log_level);
+ static void print_body(const char *body, log_level_t log_level);
+
::dsn::utils::ex_lock_nr _lock;
const bool _short_header;
};
@@ -77,17 +84,25 @@ public:
void flush() override;
private:
+ void print_header(log_level_t log_level);
+ void print_long_header(const char *file,
+ const char *function,
+ const int line,
+ log_level_t log_level);
+ void print_body(const char *body, log_level_t log_level);
+
void create_log_file();
private:
::dsn::utils::ex_lock _lock; // use recursive lock to avoid dead lock when
flush() is called
// in signal handler if cored for bad logging
format reason.
+ // The directory to store log files.
const std::string _log_dir;
FILE *_log;
int _start_index;
int _index;
int _lines;
- log_level_t _stderr_start_level;
+ const log_level_t _stderr_start_level;
};
} // namespace tools
} // namespace dsn
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
