From: Adam Simpkins Date: Thu, 22 Jun 2017 00:05:20 +0000 (-0700) Subject: logging: add more tests for fatal log messages X-Git-Tag: v2017.06.26.00~20 X-Git-Url: http://plrg.eecs.uci.edu/git/?p=folly.git;a=commitdiff_plain;h=cffc8a776b21a070f0af6ed0748452c329ad6e5f 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 --- diff --git a/folly/experimental/logging/test/FatalHelper.cpp b/folly/experimental/logging/test/FatalHelper.cpp index e89ef2cd..dbbaa4c2 100644 --- a/folly/experimental/logging/test/FatalHelper.cpp +++ b/folly/experimental/logging/test/FatalHelper.cpp @@ -16,6 +16,7 @@ #include #include #include +#include DEFINE_string(logging, "", "Logging category configuration string"); DEFINE_string( @@ -27,9 +28,37 @@ DEFINE_string( category, "", "Crash with a message to this category instead of the default"); +DEFINE_bool(crash, true, "Crash with a fatal log message."); 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. */ @@ -50,6 +79,10 @@ int main(int argc, char* argv[]) { FB_LOG(logger, FATAL, "crashing to category ", FLAGS_category); } + if (!FLAGS_crash) { + return 0; + } + XLOG(FATAL) << "test program crashing!"; // Even though main() is defined to return an integer, the compiler // should be able to detect that XLOG(FATAL) never returns. It shouldn't diff --git a/folly/experimental/logging/test/fatal_test.py b/folly/experimental/logging/test/fatal_test.py index de7274f9..132b708b 100644 --- a/folly/experimental/logging/test/fatal_test.py +++ b/folly/experimental/logging/test/fatal_test.py @@ -31,17 +31,23 @@ class FatalTests(unittest.TestCase): self.helper = os.path.join(build_dir, 'folly', 'experimental', 'logging', 'test', 'fatal_helper') - def run_helper(self, *args): + def run_helper(self, *args, **kwargs): ''' Run the helper. Check that it crashes with SIGABRT and prints nothing on stdout. 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.extend(args) p = subprocess.Popen(cmd, stdout=subprocess.PIPE, - stderr=subprocess.PIPE) + stderr=subprocess.PIPE, + env=env) out, err = p.communicate() status = p.returncode @@ -49,27 +55,32 @@ class FatalTests(unittest.TestCase): self.assertEqual(out, b'') return err - def glog_crash_regex(self): - return re.compile( - br'^C[0-9]{4} .* FatalHelper.cpp:[0-9]+\] test program crashing!$', - re.MULTILINE) + def get_crash_regex(self, msg=b'test program crashing!', glog=True): + if glog: + prefix = br'^C[0-9]{4} .* FatalHelper.cpp:[0-9]+\] ' + 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): 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): 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): # The fatal message should be printed directly to stderr when there # are no logging handlers configured. err = self.run_helper('--handler_style=none') - return re.compile( - br'^FATAL:.*/FatalHelper.cpp:[0-9]+: test program crashing!$', - re.MULTILINE) - self.assertRegex(err, self.glog_crash_regex()) + self.assertRegex(err, self.get_crash_regex(glog=False)) def test_other_category(self): err = self.run_helper('--category=foo.bar', @@ -79,3 +90,21 @@ class FatalTests(unittest.TestCase): br'crashing to category foo\.bar$', re.MULTILINE) 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)