diff --git a/source/common/common/logger.h b/source/common/common/logger.h index 8fb1548f6628..ed09d5b49388 100644 --- a/source/common/common/logger.h +++ b/source/common/common/logger.h @@ -57,6 +57,21 @@ class Logger { std::string name() const { return logger_->name(); } void setLevel(spdlog::level::level_enum level) const { logger_->set_level(level); } + /* This is simple mapping between Logger severity levels and spdlog severity levels. + * The only reason for this mapping is to go around the fact that spdlog defines level as err + * but the method to log at err level is called LOGGER.error not LOGGER.err. All other level are + * fine spdlog::info corresponds to LOGGER.info method. + */ + typedef enum { + trace = spdlog::level::trace, + debug = spdlog::level::debug, + info = spdlog::level::info, + warn = spdlog::level::warn, + error = spdlog::level::err, + critical = spdlog::level::critical, + off = spdlog::level::off + } levels; + private: Logger(const std::string& name); @@ -176,18 +191,27 @@ template class Loggable { * Base logging macros. It is expected that users will use the convenience macros below rather than * invoke these directly. */ +// Compare levels before invoking logger +#define ENVOY_LOG_COMP_AND_LOG(LOGGER, LEVEL, ...) \ + do { \ + if (static_cast(Envoy::Logger::Logger::LEVEL) >= LOGGER.level()) { \ + LOGGER.LEVEL(LOG_PREFIX __VA_ARGS__); \ + } \ + } while (0) + #ifdef NVLOG #define ENVOY_LOG_trace_TO_LOGGER(LOGGER, ...) #define ENVOY_LOG_debug_TO_LOGGER(LOGGER, ...) #else -#define ENVOY_LOG_trace_TO_LOGGER(LOGGER, ...) LOGGER.trace(LOG_PREFIX __VA_ARGS__) -#define ENVOY_LOG_debug_TO_LOGGER(LOGGER, ...) LOGGER.debug(LOG_PREFIX __VA_ARGS__) +#define ENVOY_LOG_trace_TO_LOGGER(LOGGER, ...) ENVOY_LOG_COMP_AND_LOG(LOGGER, trace, ##__VA_ARGS__) +#define ENVOY_LOG_debug_TO_LOGGER(LOGGER, ...) ENVOY_LOG_COMP_AND_LOG(LOGGER, debug, ##__VA_ARGS__) #endif -#define ENVOY_LOG_info_TO_LOGGER(LOGGER, ...) LOGGER.info(LOG_PREFIX __VA_ARGS__) -#define ENVOY_LOG_warn_TO_LOGGER(LOGGER, ...) LOGGER.warn(LOG_PREFIX __VA_ARGS__) -#define ENVOY_LOG_error_TO_LOGGER(LOGGER, ...) LOGGER.error(LOG_PREFIX __VA_ARGS__) -#define ENVOY_LOG_critical_TO_LOGGER(LOGGER, ...) LOGGER.critical(LOG_PREFIX __VA_ARGS__) +#define ENVOY_LOG_info_TO_LOGGER(LOGGER, ...) ENVOY_LOG_COMP_AND_LOG(LOGGER, info, ##__VA_ARGS__) +#define ENVOY_LOG_warn_TO_LOGGER(LOGGER, ...) ENVOY_LOG_COMP_AND_LOG(LOGGER, warn, ##__VA_ARGS__) +#define ENVOY_LOG_error_TO_LOGGER(LOGGER, ...) ENVOY_LOG_COMP_AND_LOG(LOGGER, error, ##__VA_ARGS__) +#define ENVOY_LOG_critical_TO_LOGGER(LOGGER, ...) \ + ENVOY_LOG_COMP_AND_LOG(LOGGER, critical, ##__VA_ARGS__) /** * Convenience macro to log to a user-specified logger. diff --git a/source/common/http/filter/lua/lua_filter.cc b/source/common/http/filter/lua/lua_filter.cc index f7b2774069cd..50a945cbc629 100644 --- a/source/common/http/filter/lua/lua_filter.cc +++ b/source/common/http/filter/lua/lua_filter.cc @@ -481,17 +481,23 @@ void Filter::scriptError(const Envoy::Lua::LuaException& e) { void Filter::scriptLog(spdlog::level::level_enum level, const char* message) { switch (level) { case spdlog::level::trace: - return ENVOY_LOG(trace, "script log: {}", message); + ENVOY_LOG(trace, "script log: {}", message); + return; case spdlog::level::debug: - return ENVOY_LOG(debug, "script log: {}", message); + ENVOY_LOG(debug, "script log: {}", message); + return; case spdlog::level::info: - return ENVOY_LOG(info, "script log: {}", message); + ENVOY_LOG(info, "script log: {}", message); + return; case spdlog::level::warn: - return ENVOY_LOG(warn, "script log: {}", message); + ENVOY_LOG(warn, "script log: {}", message); + return; case spdlog::level::err: - return ENVOY_LOG(error, "script log: {}", message); + ENVOY_LOG(error, "script log: {}", message); + return; case spdlog::level::critical: - return ENVOY_LOG(critical, "script log: {}", message); + ENVOY_LOG(critical, "script log: {}", message); + return; case spdlog::level::off: NOT_IMPLEMENTED; } diff --git a/test/common/common/log_macros_test.cc b/test/common/common/log_macros_test.cc index 33f292c45f36..efff1387a295 100644 --- a/test/common/common/log_macros_test.cc +++ b/test/common/common/log_macros_test.cc @@ -37,4 +37,65 @@ TEST(Logger, All) { // Misc logging with no facility. ENVOY_LOG_MISC(info, "fake message"); } + +TEST(Logger, evaluateParams) { + uint32_t i = 1; + + // Set logger's level to low level. + // Log message with higher severity and make sure that params were evaluated. + GET_MISC_LOGGER().set_level(spdlog::level::info); + ENVOY_LOG_MISC(warn, "test message '{}'", i++); + EXPECT_THAT(i, testing::Eq(2)); +} + +TEST(Logger, doNotEvaluateParams) { + uint32_t i = 1; + + // Set logger's logging level high and log a message with lower severity + // params should not be evaluated. + GET_MISC_LOGGER().set_level(spdlog::level::critical); + ENVOY_LOG_MISC(error, "test message '{}'", i++); + EXPECT_THAT(i, testing::Eq(1)); +} + +TEST(Logger, logAsStatement) { + // Just log as part of if ... statement + uint32_t i = 1, j = 1; + + // Set logger's logging level to high + GET_MISC_LOGGER().set_level(spdlog::level::critical); + + // Make sure that if statement inside of LOGGER macro does not catch trailing + // else .... + if (true) + ENVOY_LOG_MISC(warn, "test message 1 '{}'", i++); + else + ENVOY_LOG_MISC(critical, "test message 2 '{}'", j++); + + EXPECT_THAT(i, testing::Eq(1)); + EXPECT_THAT(j, testing::Eq(1)); + + // Do the same with curly brackets + if (true) { + ENVOY_LOG_MISC(warn, "test message 3 '{}'", i++); + } else { + ENVOY_LOG_MISC(critical, "test message 4 '{}'", j++); + } + + EXPECT_THAT(i, testing::Eq(1)); + EXPECT_THAT(j, testing::Eq(1)); +} + +#ifdef NVLOG +TEST(Logger, doNotExpandTraceAndDebug) { + uint32_t i = 1; + + // The following two macros should be expanded to no-op if NVLOG compile flag is defined. + ENVOY_LOG_TO_LOGGER(nonExistingLogger, trace, "test message 5 '{}'", i++); + EXPECT_THAT(i, testing::Eq(1)); + + ENVOY_LOG_TO_LOGGER(nonExistingLogger, debug, "test message 6 '{}'", i++); + EXPECT_THAT(i, testing::Eq(1)); +} +#endif /* NVLOG */ } // namespace Envoy