Skip to content
This repository has been archived by the owner on Jun 23, 2022. It is now read-only.

Commit

Permalink
fix: fix log bug in fmt logging (#346)
Browse files Browse the repository at this point in the history
  • Loading branch information
zhao liwei authored and Wu Tao committed Dec 2, 2019
1 parent b904de6 commit d926d3a
Show file tree
Hide file tree
Showing 7 changed files with 109 additions and 18 deletions.
7 changes: 5 additions & 2 deletions include/dsn/c/api_utilities.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
37 changes: 25 additions & 12 deletions include/dsn/dist/fmt_logging.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
6 changes: 6 additions & 0 deletions include/dsn/tool-api/logging_provider.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
};

Expand Down
14 changes: 11 additions & 3 deletions src/core/core/logging.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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);
}
}
21 changes: 20 additions & 1 deletion src/core/tests/logging.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,7 @@
#include <dsn/service_api_c.h>
#include <gtest/gtest.h>
#include <iostream>
#include <dsn/dist/fmt_logging.h>

TEST(core, logging)
{
Expand All @@ -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)
Expand All @@ -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);
}
}
30 changes: 30 additions & 0 deletions src/core/tools/common/simple_logger.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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();
}
}
}
}
12 changes: 12 additions & 0 deletions src/core/tools/common/simple_logger.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand All @@ -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:
Expand Down

0 comments on commit d926d3a

Please sign in to comment.