Commit e8c31188 authored by Adam Simpkins's avatar Adam Simpkins Committed by Facebook Github Bot

logging: fix the behavior of XLOG_IF(FATAL, condition)

Summary:
Previously `XLOG_IF(FATAL, condition)` always crashed regardless of the
condition check.  When `XLOG_IF()` was added it did not update the checks used
to mark the statement as `[noreturn]` based on the log level.  As a result
`XLOG_IF(FATAL, ...)` always used the `[noreturn]` APIs, even though this code
can return if the condition is not true.

This splits the `XLOG()` and `XLOG_IF()` implementations so that `XLOG(FATAL)`
can still be marked as `noreturn` but `XLOG_IF(FATAL, ...)` is no `noreturn`.

Reviewed By: yfeldblum, mnv104

Differential Revision: D8817269

fbshipit-source-id: 47a493eaaac69c563cff07da0888dd423f7dc07d
parent 056e121f
...@@ -47,7 +47,11 @@ std::string loggingFormatPrintf( ...@@ -47,7 +47,11 @@ std::string loggingFormatPrintf(
* Log a message to the file's default log category using a printf-style format * Log a message to the file's default log category using a printf-style format
* string. * string.
*/ */
#define XLOGC(level, fmt, ...) XLOGC_IF(level, true, fmt, ##__VA_ARGS__) #define XLOGC(level, fmt, ...) \
XLOG_IMPL( \
::folly::LogLevel::level, \
::folly::LogStreamProcessor::APPEND, \
::folly::loggingFormatPrintf(fmt, ##__VA_ARGS__))
/** /**
* Log a message using a printf-style format string if and only if the * Log a message using a printf-style format string if and only if the
...@@ -55,7 +59,7 @@ std::string loggingFormatPrintf( ...@@ -55,7 +59,7 @@ std::string loggingFormatPrintf(
* is *only* evaluated if the log-level check passes. * is *only* evaluated if the log-level check passes.
*/ */
#define XLOGC_IF(level, cond, fmt, ...) \ #define XLOGC_IF(level, cond, fmt, ...) \
XLOG_IMPL( \ XLOG_IF_IMPL( \
::folly::LogLevel::level, \ ::folly::LogLevel::level, \
cond, \ cond, \
::folly::LogStreamProcessor::APPEND, \ ::folly::LogStreamProcessor::APPEND, \
......
...@@ -16,12 +16,21 @@ ...@@ -16,12 +16,21 @@
#include <folly/init/Init.h> #include <folly/init/Init.h>
#include <folly/logging/xlog.h> #include <folly/logging/xlog.h>
#include <folly/portability/Stdlib.h> #include <folly/portability/Stdlib.h>
#include <iostream>
DEFINE_string( DEFINE_string(
category, category,
"", "",
"Crash with a message to this category instead of the default"); "Crash with a message to this category instead of the default");
DEFINE_bool(crash, true, "Crash with a fatal log message."); DEFINE_bool(crash, true, "Crash with a fatal log message.");
DEFINE_bool(
check_debug,
false,
"Print whether this binary was built in debug mode "
"and then exit successfully");
DEFINE_bool(fail_fatal_xlog_if, false, "Fail an XLOG_IF(FATAL) check.");
DEFINE_bool(fail_dfatal_xlog_if, false, "Fail an XLOG_IF(DFATAL) check.");
using folly::LogLevel; using folly::LogLevel;
...@@ -83,6 +92,15 @@ std::string fbLogFatalCheck() { ...@@ -83,6 +92,15 @@ std::string fbLogFatalCheck() {
int main(int argc, char* argv[]) { int main(int argc, char* argv[]) {
auto init = folly::Init(&argc, &argv); auto init = folly::Init(&argc, &argv);
if (FLAGS_check_debug) {
std::cout << "DEBUG=" << static_cast<int>(folly::kIsDebug) << "\n";
return 0;
}
XLOG_IF(FATAL, FLAGS_fail_fatal_xlog_if) << "--fail_fatal_xlog_if specified!";
XLOG_IF(DFATAL, FLAGS_fail_dfatal_xlog_if)
<< "--fail_dfatal_xlog_if specified!";
// Do most of the work in a separate helper function. // Do most of the work in a separate helper function.
// //
// The main reason for putting this in a helper function is to ensure that // The main reason for putting this in a helper function is to ensure that
......
...@@ -33,11 +33,21 @@ class FatalTests(unittest.TestCase): ...@@ -33,11 +33,21 @@ class FatalTests(unittest.TestCase):
) )
def run_helper(self, *args, **kwargs): def run_helper(self, *args, **kwargs):
""" """Run the helper and verify it crashes.
Run the helper.
Check that it crashes with SIGABRT and prints nothing on stdout. Check that it crashes with SIGABRT and prints nothing on stdout.
Returns the data printed to stderr. Returns the data printed to stderr.
""" """
returncode, out, err = self.run_helper_nochecks(*args, **kwargs)
self.assertEqual(returncode, -signal.SIGABRT)
self.assertEqual(out, b"")
return err
def run_helper_nochecks(self, *args, **kwargs):
"""Run the helper.
Returns a tuple of [returncode, stdout_output, stderr_output]
"""
env = kwargs.pop("env", None) env = kwargs.pop("env", None)
if kwargs: if kwargs:
raise TypeError("unexpected keyword arguments: %r" % (list(kwargs.keys()))) raise TypeError("unexpected keyword arguments: %r" % (list(kwargs.keys())))
...@@ -48,11 +58,18 @@ class FatalTests(unittest.TestCase): ...@@ -48,11 +58,18 @@ class FatalTests(unittest.TestCase):
cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, env=env cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, env=env
) )
out, err = p.communicate() out, err = p.communicate()
status = p.returncode return p.returncode, out, err
self.assertEqual(status, -signal.SIGABRT) def is_debug_build(self):
self.assertEqual(out, b"") returncode, out, err = self.run_helper_nochecks("--check_debug")
return err self.assertEqual(b"", err)
self.assertEqual(0, returncode)
if out.strip() == b"DEBUG=1":
return True
elif out.strip() == b"DEBUG=0":
return False
else:
self.fail("unexpected output from --check_debug: {}".format(out))
def get_crash_regex(self, msg=b"test program crashing!", glog=True): def get_crash_regex(self, msg=b"test program crashing!", glog=True):
if glog: if glog:
...@@ -65,7 +82,10 @@ class FatalTests(unittest.TestCase): ...@@ -65,7 +82,10 @@ class FatalTests(unittest.TestCase):
def test_no_crash(self): def test_no_crash(self):
# Simple sanity check that the program runs without # Simple sanity check that the program runs without
# crashing when requested # crashing when requested
subprocess.check_output([self.helper, "--crash=no"]) returncode, out, err = self.run_helper_nochecks("--crash=no")
self.assertEqual(0, returncode)
self.assertEqual(b"", out)
self.assertEqual(b"", err)
def test_async(self): def test_async(self):
handler_setings = "default=stream:stream=stderr,async=true" handler_setings = "default=stream:stream=stderr,async=true"
...@@ -109,3 +129,22 @@ class FatalTests(unittest.TestCase): ...@@ -109,3 +129,22 @@ class FatalTests(unittest.TestCase):
re.MULTILINE, re.MULTILINE,
) )
self.assertRegex(err, regex) self.assertRegex(err, regex)
def test_fatal_xlog_if(self):
# Specify --crash=no to ensure that the XLOG_IF() check is actually what
# triggers the crash.
err = self.run_helper("--fail_fatal_xlog_if", "--crash=no")
self.assertRegex(err, self.get_crash_regex(b"--fail_fatal_xlog_if specified!"))
def test_dfatal_xlog_if(self):
returncode, out, err = self.run_helper_nochecks(
"--fail_dfatal_xlog_if", "--crash=no"
)
# The "--fail_dfatal_xlog_if" message should be logged regardless of which build
# type we are using. However, in debug builds it will not trigger a crash.
self.assertRegex(err, self.get_crash_regex(b"--fail_dfatal_xlog_if specified!"))
self.assertEqual(b"", out)
if self.is_debug_build():
self.assertEqual(-signal.SIGABRT, returncode)
else:
self.assertEqual(0, returncode)
...@@ -54,7 +54,11 @@ ...@@ -54,7 +54,11 @@
* best if you always invoke the compiler from the root directory of your * best if you always invoke the compiler from the root directory of your
* project repository. * project repository.
*/ */
#define XLOG(level, ...) XLOG_IF(level, true, ##__VA_ARGS__) #define XLOG(level, ...) \
XLOG_IMPL( \
::folly::LogLevel::level, \
::folly::LogStreamProcessor::APPEND, \
##__VA_ARGS__)
/** /**
* Log a message if and only if the specified condition predicate evaluates * Log a message if and only if the specified condition predicate evaluates
...@@ -62,7 +66,7 @@ ...@@ -62,7 +66,7 @@
* passes. * passes.
*/ */
#define XLOG_IF(level, cond, ...) \ #define XLOG_IF(level, cond, ...) \
XLOG_IMPL( \ XLOG_IF_IMPL( \
::folly::LogLevel::level, \ ::folly::LogLevel::level, \
cond, \ cond, \
::folly::LogStreamProcessor::APPEND, \ ::folly::LogStreamProcessor::APPEND, \
...@@ -70,8 +74,13 @@ ...@@ -70,8 +74,13 @@
/** /**
* Log a message to this file's default log category, using a format string. * Log a message to this file's default log category, using a format string.
*/ */
#define XLOGF(level, fmt, arg1, ...) \ #define XLOGF(level, fmt, arg1, ...) \
XLOGF_IF(level, true, fmt, arg1, ##__VA_ARGS__) XLOG_IMPL( \
::folly::LogLevel::level, \
::folly::LogStreamProcessor::FORMAT, \
fmt, \
arg1, \
##__VA_ARGS__)
/** /**
* Log a message using a format string if and only if the specified condition * Log a message using a format string if and only if the specified condition
...@@ -79,7 +88,7 @@ ...@@ -79,7 +88,7 @@
* if the log-level check passes. * if the log-level check passes.
*/ */
#define XLOGF_IF(level, cond, fmt, arg1, ...) \ #define XLOGF_IF(level, cond, fmt, arg1, ...) \
XLOG_IMPL( \ XLOG_IF_IMPL( \
::folly::LogLevel::level, \ ::folly::LogLevel::level, \
cond, \ cond, \
::folly::LogStreamProcessor::FORMAT, \ ::folly::LogStreamProcessor::FORMAT, \
...@@ -153,10 +162,17 @@ ...@@ -153,10 +162,17 @@
#define XLOG_FILENAME __FILE__ #define XLOG_FILENAME __FILE__
#endif #endif
#define XLOG_IMPL(level, type, ...) \
XLOG_ACTUAL_IMPL( \
level, true, ::folly::isLogLevelFatal(level), type, ##__VA_ARGS__)
#define XLOG_IF_IMPL(level, cond, type, ...) \
XLOG_ACTUAL_IMPL(level, cond, false, type, ##__VA_ARGS__)
/** /**
* Helper macro used to implement XLOG() and XLOGF() * Helper macro used to implement XLOG() and XLOGF()
* *
* Beware that the level argument is evalutated twice. * Beware that the level argument is evaluated twice.
* *
* This macro is somewhat tricky: * This macro is somewhat tricky:
* *
...@@ -196,29 +212,28 @@ ...@@ -196,29 +212,28 @@
* initialized. On all subsequent calls, disabled log statements can be * initialized. On all subsequent calls, disabled log statements can be
* skipped with just a single check of the LogLevel. * skipped with just a single check of the LogLevel.
*/ */
#define XLOG_IMPL(level, cond, type, ...) \ #define XLOG_ACTUAL_IMPL(level, cond, always_fatal, type, ...) \
(!XLOG_IS_ON_IMPL(level) || !(cond)) \ (!XLOG_IS_ON_IMPL(level) || !(cond)) \
? ::folly::logDisabledHelper( \ ? ::folly::logDisabledHelper(::folly::bool_constant<always_fatal>{}) \
::folly::bool_constant<::folly::isLogLevelFatal(level)>{}) \ : ::folly::LogStreamVoidify<::folly::isLogLevelFatal(level)>{} & \
: ::folly::LogStreamVoidify<::folly::isLogLevelFatal(level)>{} & \ ::folly::LogStreamProcessor( \
::folly::LogStreamProcessor( \ [] { \
[] { \ static ::folly::XlogCategoryInfo<XLOG_IS_IN_HEADER_FILE> \
static ::folly::XlogCategoryInfo<XLOG_IS_IN_HEADER_FILE> \ folly_detail_xlog_category; \
folly_detail_xlog_category; \ return folly_detail_xlog_category.getInfo( \
return folly_detail_xlog_category.getInfo( \ &xlog_detail::xlogFileScopeInfo); \
&xlog_detail::xlogFileScopeInfo); \ }(), \
}(), \ (level), \
(level), \ xlog_detail::getXlogCategoryName(XLOG_FILENAME, 0), \
xlog_detail::getXlogCategoryName(XLOG_FILENAME, 0), \ xlog_detail::isXlogCategoryOverridden(0), \
xlog_detail::isXlogCategoryOverridden(0), \ XLOG_FILENAME, \
XLOG_FILENAME, \ __LINE__, \
__LINE__, \ (type), \
(type), \ ##__VA_ARGS__) \
##__VA_ARGS__) \
.stream() .stream()
/** /**
* Check if and XLOG() statement with the given log level would be enabled. * Check if an XLOG() statement with the given log level would be enabled.
* *
* The level parameter must be an unqualified LogLevel enum value. * The level parameter must be an unqualified LogLevel enum value.
*/ */
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment