diff --git a/include/dsn/c/api_utilities.h b/include/dsn/c/api_utilities.h index 920ada21e3..828b1f9dc8 100644 --- a/include/dsn/c/api_utilities.h +++ b/include/dsn/c/api_utilities.h @@ -76,8 +76,11 @@ extern DSN_API void dsn_logf(const char *file, dsn_log_level_t log_level, const char *fmt, ...); -extern DSN_API void -dsn_log(const char *file, const char *function, const int line, dsn_log_level_t log_level); +extern DSN_API void dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str); extern DSN_API void dsn_coredump(); // __FILENAME__ macro comes from the cmake, in which we calculate a filename without path. diff --git a/include/dsn/dist/fmt_logging.h b/include/dsn/dist/fmt_logging.h index 6981f5b304..bad559f129 100644 --- a/include/dsn/dist/fmt_logging.h +++ b/include/dsn/dist/fmt_logging.h @@ -32,20 +32,33 @@ // instead we use fmt::format. // TODO(wutao1): prevent construction of std::string for each log. -#define dinfo_f(...) dinfo(fmt::format(__VA_ARGS__).c_str()) -#define ddebug_f(...) ddebug(fmt::format(__VA_ARGS__).c_str()) -#define dwarn_f(...) dwarn(fmt::format(__VA_ARGS__).c_str()) -#define derror_f(...) derror(fmt::format(__VA_ARGS__).c_str()) -#define dfatal_f(...) dfatal(fmt::format(__VA_ARGS__).c_str()) -#define dassert_f(x, ...) dassert(x, fmt::format(__VA_ARGS__).c_str()) +#define dlog_f(level, ...) \ + do { \ + if (level >= dsn_log_start_level) \ + dsn_log( \ + __FILENAME__, __FUNCTION__, __LINE__, level, fmt::format(__VA_ARGS__).c_str()); \ + } while (false) +#define dinfo_f(...) dlog_f(LOG_LEVEL_INFORMATION, __VA_ARGS__) +#define ddebug_f(...) dlog_f(LOG_LEVEL_DEBUG, __VA_ARGS__) +#define dwarn_f(...) dlog_f(LOG_LEVEL_WARNING, __VA_ARGS__) +#define derror_f(...) dlog_f(LOG_LEVEL_ERROR, __VA_ARGS__) +#define dfatal_f(...) dlog_f(LOG_LEVEL_FATAL, __VA_ARGS__) +#define dassert_f(x, ...) \ + do { \ + if (dsn_unlikely(!(x))) { \ + dlog_f(LOG_LEVEL_FATAL, "assertion expression: " #x); \ + dlog_f(LOG_LEVEL_FATAL, __VA_ARGS__); \ + dsn_coredump(); \ + } \ + } while (false) // Macros for writing log message prefixed by gpid and address. -#define dinfo_replica(...) dinfo_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); -#define ddebug_replica(...) ddebug_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); -#define dwarn_replica(...) dwarn_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); -#define derror_replica(...) derror_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); -#define dfatal_replica(...) dfatal_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); -#define dassert_replica(x, ...) dassert_f(x, "[{}] {}", replica_name(), fmt::format(__VA_ARGS__)); +#define dinfo_replica(...) dinfo_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) +#define ddebug_replica(...) ddebug_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) +#define dwarn_replica(...) dwarn_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) +#define derror_replica(...) derror_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) +#define dfatal_replica(...) dfatal_f("[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) +#define dassert_replica(x, ...) dassert_f(x, "[{}] {}", replica_name(), fmt::format(__VA_ARGS__)) // Macros to check expected condition. It will abort the application // and log a fatal message when the condition is not met. diff --git a/include/dsn/tool-api/logging_provider.h b/include/dsn/tool-api/logging_provider.h index d4d0e3057f..052fdf1eb5 100644 --- a/include/dsn/tool-api/logging_provider.h +++ b/include/dsn/tool-api/logging_provider.h @@ -67,6 +67,12 @@ class logging_provider const char *fmt, va_list args) = 0; + virtual void dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str) = 0; + virtual void flush() = 0; }; diff --git a/src/core/core/logging.cpp b/src/core/core/logging.cpp index b6ee0721bf..a98cd686d0 100644 --- a/src/core/core/logging.cpp +++ b/src/core/core/logging.cpp @@ -142,8 +142,16 @@ DSN_API void dsn_logf(const char *file, va_end(ap); } -DSN_API void -dsn_log(const char *file, const char *function, const int line, dsn_log_level_t log_level) +DSN_API void dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str) { - dsn_logf(file, function, line, log_level, ""); + ::dsn::logging_provider *logger = ::dsn::service_engine::instance().logging(); + if (logger != nullptr) { + logger->dsn_log(file, function, line, log_level, str); + } else { + printf("%s:%d:%s():%s\n", file, line, function, str); + } } diff --git a/src/core/tests/logging.cpp b/src/core/tests/logging.cpp index af5a0b5a56..35fe0c2498 100644 --- a/src/core/tests/logging.cpp +++ b/src/core/tests/logging.cpp @@ -36,6 +36,7 @@ #include #include #include +#include TEST(core, logging) { @@ -46,7 +47,7 @@ TEST(core, logging) __LINE__, dsn_log_level_t::LOG_LEVEL_DEBUG, "in TEST(core, logging)"); - dsn_log(__FILENAME__, __FUNCTION__, __LINE__, dsn_log_level_t::LOG_LEVEL_DEBUG); + dsn_log(__FILENAME__, __FUNCTION__, __LINE__, dsn_log_level_t::LOG_LEVEL_DEBUG, ""); } TEST(core, logging_big_log) @@ -59,3 +60,21 @@ TEST(core, logging_big_log) "write big str %s", big_str.c_str()); } + +TEST(core, dlog_f) +{ + struct test_case + { + enum dsn_log_level_t level; + std::string str; + } tests[] = {{dsn_log_level_t::LOG_LEVEL_DEBUG, "This is a test"}, + {dsn_log_level_t::LOG_LEVEL_DEBUG, "\\x00%d\\x00\\x01%n/nm"}, + {dsn_log_level_t::LOG_LEVEL_INFORMATION, "\\x00%d\\x00\\x01%n/nm"}, + {dsn_log_level_t::LOG_LEVEL_WARNING, "\\x00%d\\x00\\x01%n/nm"}, + {dsn_log_level_t::LOG_LEVEL_ERROR, "\\x00%d\\x00\\x01%n/nm"}, + {dsn_log_level_t::LOG_LEVEL_FATAL, "\\x00%d\\x00\\x01%n/nm"}}; + + for (auto test : tests) { + dlog_f(test.level, "sortkey = {}", test.str); + } +} diff --git a/src/core/tools/common/simple_logger.cpp b/src/core/tools/common/simple_logger.cpp index d2ff340368..c89e73cb85 100644 --- a/src/core/tools/common/simple_logger.cpp +++ b/src/core/tools/common/simple_logger.cpp @@ -251,5 +251,35 @@ void simple_logger::dsn_logv(const char *file, create_log_file(); } } + +void simple_logger::dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str) +{ + utils::auto_lock<::dsn::utils::ex_lock> l(_lock); + + print_header(_log, log_level); + if (!_short_header) { + fprintf(_log, "%s:%d:%s(): ", file, line, function); + } + fprintf(_log, "%s\n", str); + if (_fast_flush || log_level >= LOG_LEVEL_ERROR) { + ::fflush(_log); + } + + if (log_level >= _stderr_start_level) { + print_header(stdout, log_level); + if (!_short_header) { + printf("%s:%d:%s(): ", file, line, function); + } + printf("%s\n", str); + } + + if (++_lines >= 200000) { + create_log_file(); + } +} } } diff --git a/src/core/tools/common/simple_logger.h b/src/core/tools/common/simple_logger.h index 346ddb81bd..c58814727d 100644 --- a/src/core/tools/common/simple_logger.h +++ b/src/core/tools/common/simple_logger.h @@ -55,6 +55,12 @@ class screen_logger : public logging_provider const char *fmt, va_list args); + virtual void dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str){}; + virtual void flush(); private: @@ -75,6 +81,12 @@ class simple_logger : public logging_provider const char *fmt, va_list args); + virtual void dsn_log(const char *file, + const char *function, + const int line, + dsn_log_level_t log_level, + const char *str); + virtual void flush(); private: