logger: macros evaluate logging level before invoking logger

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 <Id id> 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<spdlog::level::level_enum>(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.

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;
   }

test/common/common/log_macros_test.cc

@@ -37,4 +37,48 @@ 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++);
+  ASSERT_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++);
+  ASSERT_THAT(i, testing::Eq(1));
+}
+
+TEST(Logger, logAsStatement) {
+  // Just log as part of if ... statement
+
+  if (true)
+    ENVOY_LOG_MISC(critical, "test message 1");
+  else
+    ENVOY_LOG_MISC(critical, "test message 2");
+
+  // do the same with curly brackets
+  if (true) {
+    ENVOY_LOG_MISC(critical, "test message 3");
+  } else {
+    ENVOY_LOG_MISC(critical, "test message 4");
+  }
+}
+
+#ifdef NVLOG
+TEST(Logger, doNotExpandTraceAndDebug) {
+  // The following two macros should not be expanded to no-op if NVLOG compile flag is defined.
+  ENVOY_LOG_TO_LOGGER(nonExistingLogger, trace, "test message 5");
+  ENVOY_LOG_TO_LOGGER(nonExistingLogger, debug, "test message 6");
+}
+#endif /* NVLOG */
 } // namespace Envoy