[GAIAPLAT-869] Is-log-level-enabled API #757

phillipov · 2021-06-23T23:02:10Z

This PR addresses GAIAPLAT-869 which provides functions to the logging API to check whether a certain log level is enabled.

This can prevent expensive calculations that are only used for logging purposes (if that log level is not used):

if (gaia_log::app().is_debug_enabled())
{
    int num = very_slow_function();
    gaia_log::app().debug("value: {}", num);
}

phillipov · 2021-06-23T23:07:43Z

production/common/tests/logging_configs/log_critical.conf

@@ -0,0 +1,92 @@
+global_pattern = "[%Y-%m-%dT%T.%e] [%l] [%P %t] <%n>: %v"


I made all these log_<level>.conf files to set the system to every log level for testing. I copied them from the original gaia_log.conf. If there is a better way to initialize the system at a specific log level, let me know.

Ah, can you add this comment in the Cmake file above?

Also, a better way is to use variable substitution. See https://cmake.org/cmake/help/latest/command/configure_file.html

You have a couple options that I think are preferable to creating a .conf file per log level:

There are six log levels. Coincidentally, we specify six loggers. I think it would be sufficient to have a single additional .conf file that sets each logger at a different log level. Then you could do your check that each logger had a particular log level. You'd still need another .conf file to test off.

Check out debug_logger.hpp. This is a logger specifically exposed for testing. This gives you access to the underlying spdlogger shared pointer. So, you could create a debug log, then set the level you want to check at runtime and then do your checking. No extra .conf files required.

I prefer option 2. You can look at test_rule_stats.cpp to show the use of the debug logger.

Ah right, the debug_logger is quite useful here, I'd go with that too.

daxhaw · 2021-06-23T23:23:02Z

production/inc/gaia/logger.hpp

+    /**
+     * Returns true if the log level is "trace".
+     */
+    bool trace()


I prefer the suggestion @simone-gaia had in GAIAPLAT-869. Namely these methods should follow the pattern of: is_<level>_enabled()? I.e. is_trace_enabled().

daxhaw · 2021-06-23T23:25:18Z

production/inc/gaia/logger.hpp

@@ -83,6 +99,14 @@ class logger_t
        m_spdlogger->debug(format, args...);
    }

+    /**
+     * Returns true if the log level is at or above "debug".


consider: `Returns true if the log level is at "debug" or higher.

daxhaw

See comments for details: please rename the methods for checking whether the log level is enabled. I also suggested an alternative to creating a .conf file per log level.

simone-gaia

Generally looks good, I would change the method names and use variable substitution for the config files.

Also, if you can do a quick search of .trace( and .debug( in the production/ folder, and wrap the calls that seem expensive with is_<level>_enabled(). I did a quick search myself and I did't see anything, maybe you can find something.

simone-gaia · 2021-06-23T23:26:20Z

production/common/CMakeLists.txt

@@ -41,6 +41,19 @@ set_target_properties(gaia_common PROPERTIES LINK_FLAGS "${GAIA_LINK_FLAGS}")
 # The logging unit test needs a logger configuration file.
 configure_file("${GAIA_LOG_CONFIG}" "${PROJECT_BINARY_DIR}/gaia_log.conf")

+set(LOG_LEVEL_CONFIGS_SRC_DIR "${CMAKE_CURRENT_LIST_DIR}/tests/logging_configs")


I don't quite get why we need one file per log level. What you usually have is a different file for each stage of the development process (eg. dev, beta, gamma, prod). The log level is tuned based on the requirement of each stage. Usually dev is the more verbose and prod is the least verbose. In Gaia's case, I don't think we need more than dev and prod.

I am gonna defer wrapping expensive log calls in production to a future JIRA ticket. That future PR will have a much larger blast radius, especially if speeding up non-logging code is going to expose race conditions (or something).

simone-gaia · 2021-06-23T23:26:53Z

production/common/tests/logging_configs/log_critical.conf

@@ -0,0 +1,92 @@
+global_pattern = "[%Y-%m-%dT%T.%e] [%l] [%P %t] <%n>: %v"


Ah, can you add this comment in the Cmake file above?

simone-gaia · 2021-06-23T23:28:46Z

production/common/tests/logging_configs/log_critical.conf

@@ -0,0 +1,92 @@
+global_pattern = "[%Y-%m-%dT%T.%e] [%l] [%P %t] <%n>: %v"


Also, a better way is to use variable substitution. See https://cmake.org/cmake/help/latest/command/configure_file.html

simone-gaia · 2021-06-23T23:29:32Z

production/common/tests/test_logging.cpp

+    gaia_log::shutdown();
+}
+
+TEST(logger_test, is_log_level_enabled)


Ok, I see the point of all the files above. Good job!

Those files have been removed as part of the refactoring for debug_logger_t.

daxhaw · 2021-06-29T02:09:41Z

production/common/tests/test_logging.cpp

+
+TEST(logger_test, is_log_level_enabled)
+{
+    // Trace is the deepest log level, so every log level must be active.


nit: maybe "deepest" to "most verbose"?

daxhaw · 2021-06-29T02:23:24Z

production/common/tests/test_logging.cpp

+    return debug_logger_ptr;
+}
+
+void verify_log_levels(gaia_spdlog::level::level_enum log_level, bool trace_status, bool debug_status, bool info_status, bool warn_status, bool error_status, bool critical_status)


Instead of passing all these flags, which makes (IMO) the calling test code less comprehensible, consider omitting all the bool flags and instead moving that logic into this helper function. I.e.:

// pseudo code only, but note deliberate fallthrough. ftrace=fdebug=finfo=fwarn=ferror=fcritical=false; switch (log_level) case trace: ftrace = true; case debug: fdebug=true; case info: finfo=true; case warn: fwarn=true; case error: finfo=true; case critical: fcritical=true; break;

Then your EXPECT_EQ as follows.

production/rules/event_manager/tests/test_rule_stats.cpp

simone-gaia

LGTM

simone-gaia · 2021-06-29T13:34:59Z

production/common/tests/test_logging.cpp

+
+    verify_log_levels(gaia_spdlog::level::err, false, false, false, false, true, true);
+
+    // Critical is the shallowest log level, so all other log levels must be inactive.


Along the lines of Dax's comment, "shallowest" to "least verbose"

simone-gaia · 2021-06-29T13:38:48Z

production/inc/gaia/logger.hpp

+     */
+    bool is_trace_enabled()
+    {
+        return m_spdlogger->level() == gaia_spdlog::level::level_enum::trace;


Spdlog has a should_log API, consider using it (unless it isn't convenient for some reason).

It works perfectly, thank you for the suggestion!

simone-gaia

Still LGMT.

daxhaw

Looks good!

Implemented log level checking and a test for it

697de24

phillipov requested review from daxhaw and simone-gaia June 23, 2021 23:02

phillipov commented Jun 23, 2021

View reviewed changes

daxhaw reviewed Jun 23, 2021

View reviewed changes

daxhaw suggested changes Jun 23, 2021

View reviewed changes

simone-gaia reviewed Jun 23, 2021

View reviewed changes

Renamed to is_level_enabled(), refactored tests for debug_logger_t

1255cd0

daxhaw reviewed Jun 29, 2021

View reviewed changes

production/rules/event_manager/tests/test_rule_stats.cpp Show resolved Hide resolved

simone-gaia approved these changes Jun 29, 2021

View reviewed changes

Refactored logging tests, is_log_level_enabled() now uses should_log()

9ef3229

simone-gaia reviewed Jun 29, 2021

View reviewed changes

daxhaw approved these changes Jun 29, 2021

View reviewed changes

phillipov merged commit c246b54 into master Jun 30, 2021

LaurentiuCristofor deleted the phillip/is_log_level branch October 15, 2021 20:13

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[GAIAPLAT-869] Is-log-level-enabled API #757

[GAIAPLAT-869] Is-log-level-enabled API #757

phillipov commented Jun 23, 2021 •

edited

Loading

phillipov Jun 23, 2021

simone-gaia Jun 23, 2021

simone-gaia Jun 23, 2021

daxhaw Jun 23, 2021 •

edited

Loading

simone-gaia Jun 23, 2021

daxhaw Jun 23, 2021

daxhaw Jun 23, 2021 •

edited

Loading

daxhaw left a comment

simone-gaia left a comment

simone-gaia Jun 23, 2021

phillipov Jun 29, 2021

simone-gaia Jun 23, 2021

simone-gaia Jun 23, 2021

simone-gaia Jun 23, 2021

phillipov Jun 29, 2021

daxhaw Jun 29, 2021

daxhaw Jun 29, 2021

simone-gaia left a comment

simone-gaia Jun 29, 2021

simone-gaia Jun 29, 2021

phillipov Jun 29, 2021

simone-gaia left a comment

daxhaw left a comment

		@@ -0,0 +1,92 @@
		global_pattern = "[%Y-%m-%dT%T.%e] [%l] [%P %t] <%n>: %v"


		verify_log_levels(gaia_spdlog::level::err, false, false, false, false, true, true);

		// Critical is the shallowest log level, so all other log levels must be inactive.

[GAIAPLAT-869] Is-log-level-enabled API #757

[GAIAPLAT-869] Is-log-level-enabled API #757

Conversation

phillipov commented Jun 23, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

daxhaw Jun 23, 2021 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

daxhaw Jun 23, 2021 • edited Loading

Choose a reason for hiding this comment

daxhaw left a comment

Choose a reason for hiding this comment

simone-gaia left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

simone-gaia left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

simone-gaia left a comment

Choose a reason for hiding this comment

daxhaw left a comment

Choose a reason for hiding this comment

phillipov commented Jun 23, 2021 •

edited

Loading

daxhaw Jun 23, 2021 •

edited

Loading

daxhaw Jun 23, 2021 •

edited

Loading