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

logging: add more tests for fatal log messages

Summary:
Add some tests for fatal log messages during static initialization and
destruction.  Ideally most programs won't actually do much real work before or
after main, but make sure the logging framework behaves sanely in these
situations.

This also fixes a bug in the `test_none()` test, which previously caused it to
always succeed without testing the desired behavior.

Reviewed By: wez

Differential Revision: D5281718

fbshipit-source-id: ca838c098886e99418264acf9a4d651ea9e7502c
parent 703049c3
...@@ -16,6 +16,7 @@ ...@@ -16,6 +16,7 @@
#include <folly/experimental/logging/Init.h> #include <folly/experimental/logging/Init.h>
#include <folly/experimental/logging/xlog.h> #include <folly/experimental/logging/xlog.h>
#include <folly/init/Init.h> #include <folly/init/Init.h>
#include <folly/portability/Stdlib.h>
DEFINE_string(logging, "", "Logging category configuration string"); DEFINE_string(logging, "", "Logging category configuration string");
DEFINE_string( DEFINE_string(
...@@ -27,9 +28,37 @@ DEFINE_string( ...@@ -27,9 +28,37 @@ 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.");
using folly::LogLevel; using folly::LogLevel;
namespace {
/**
* Helper class to optionally log a fatal message during static initialization
* or destruction.
*
* Since command line arguments have not been processed during static
* initialization, we check an environment variable.
*/
class InitChecker {
public:
InitChecker() : value_{getenv("CRASH_DURING_INIT")} {
if (value_ && strcmp(value_, "shutdown") != 0) {
XLOG(FATAL) << "crashing during static initialization";
}
}
~InitChecker() {
if (value_) {
XLOG(FATAL) << "crashing during static destruction";
}
}
const char* value_{nullptr};
};
static InitChecker initChecker;
}
/* /*
* This is a simple helper program to exercise the LOG(FATAL) functionality. * This is a simple helper program to exercise the LOG(FATAL) functionality.
*/ */
...@@ -50,6 +79,10 @@ int main(int argc, char* argv[]) { ...@@ -50,6 +79,10 @@ int main(int argc, char* argv[]) {
FB_LOG(logger, FATAL, "crashing to category ", FLAGS_category); FB_LOG(logger, FATAL, "crashing to category ", FLAGS_category);
} }
if (!FLAGS_crash) {
return 0;
}
XLOG(FATAL) << "test program crashing!"; XLOG(FATAL) << "test program crashing!";
// Even though main() is defined to return an integer, the compiler // Even though main() is defined to return an integer, the compiler
// should be able to detect that XLOG(FATAL) never returns. It shouldn't // should be able to detect that XLOG(FATAL) never returns. It shouldn't
......
...@@ -31,17 +31,23 @@ class FatalTests(unittest.TestCase): ...@@ -31,17 +31,23 @@ class FatalTests(unittest.TestCase):
self.helper = os.path.join(build_dir, 'folly', 'experimental', self.helper = os.path.join(build_dir, 'folly', 'experimental',
'logging', 'test', 'fatal_helper') 'logging', 'test', 'fatal_helper')
def run_helper(self, *args): def run_helper(self, *args, **kwargs):
''' '''
Run the helper. 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.
''' '''
env = kwargs.pop('env', None)
if kwargs:
raise TypeError('unexpected keyword arguments: %r' %
(list(kwargs.keys())))
cmd = [self.helper] cmd = [self.helper]
cmd.extend(args) cmd.extend(args)
p = subprocess.Popen(cmd, p = subprocess.Popen(cmd,
stdout=subprocess.PIPE, stdout=subprocess.PIPE,
stderr=subprocess.PIPE) stderr=subprocess.PIPE,
env=env)
out, err = p.communicate() out, err = p.communicate()
status = p.returncode status = p.returncode
...@@ -49,27 +55,32 @@ class FatalTests(unittest.TestCase): ...@@ -49,27 +55,32 @@ class FatalTests(unittest.TestCase):
self.assertEqual(out, b'') self.assertEqual(out, b'')
return err return err
def glog_crash_regex(self): def get_crash_regex(self, msg=b'test program crashing!', glog=True):
return re.compile( if glog:
br'^C[0-9]{4} .* FatalHelper.cpp:[0-9]+\] test program crashing!$', prefix = br'^C[0-9]{4} .* FatalHelper.cpp:[0-9]+\] '
re.MULTILINE) else:
prefix = br'^FATAL:.*FatalHelper.cpp:[0-9]+: '
regex = prefix + re.escape(msg) + b'$'
return re.compile(regex, re.MULTILINE)
def test_no_crash(self):
# Simple sanity check that the program runs without
# crashing when requested
subprocess.check_output([self.helper, '--crash=no'])
def test_async(self): def test_async(self):
err = self.run_helper('--handler_style=async') err = self.run_helper('--handler_style=async')
self.assertRegex(err, self.glog_crash_regex()) self.assertRegex(err, self.get_crash_regex())
def test_immediate(self): def test_immediate(self):
err = self.run_helper('--handler_style=immediate') err = self.run_helper('--handler_style=immediate')
self.assertRegex(err, self.glog_crash_regex()) self.assertRegex(err, self.get_crash_regex())
def test_none(self): def test_none(self):
# The fatal message should be printed directly to stderr when there # The fatal message should be printed directly to stderr when there
# are no logging handlers configured. # are no logging handlers configured.
err = self.run_helper('--handler_style=none') err = self.run_helper('--handler_style=none')
return re.compile( self.assertRegex(err, self.get_crash_regex(glog=False))
br'^FATAL:.*/FatalHelper.cpp:[0-9]+: test program crashing!$',
re.MULTILINE)
self.assertRegex(err, self.glog_crash_regex())
def test_other_category(self): def test_other_category(self):
err = self.run_helper('--category=foo.bar', err = self.run_helper('--category=foo.bar',
...@@ -79,3 +90,21 @@ class FatalTests(unittest.TestCase): ...@@ -79,3 +90,21 @@ class FatalTests(unittest.TestCase):
br'crashing to category foo\.bar$', br'crashing to category foo\.bar$',
re.MULTILINE) re.MULTILINE)
self.assertRegex(err, regex) self.assertRegex(err, regex)
def test_static_init(self):
err = self.run_helper(env={'CRASH_DURING_INIT': '1'})
regex = self.get_crash_regex(br'crashing during static initialization',
glog=False)
self.assertRegex(err, regex)
def test_static_destruction(self):
err = self.run_helper('--crash=no',
env={'CRASH_DURING_INIT': 'shutdown'})
# When crashing during static destruction we may or may not see a
# glog-formatted message. This depends on whether the crashing
# destructor runs before or after the code that uninstalls the log
# handlers, and it is valid for that to occur in either order.
regex = re.compile(br'^(FATAL|C[0-9]{4}).*FatalHelper.cpp:.* '
br'crashing during static destruction$',
re.MULTILINE)
self.assertRegex(err, regex)
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