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 e89ef2cdaf7f32b444ef6e4dc71051efa9f59dc9..dbbaa4c2dc2ed2efe3ee69946631df6920922bae 100644 (file)
--- a/folly/experimental/logging/test/FatalHelper.cpp
+++ b/folly/experimental/logging/test/FatalHelper.cpp
@@ -16,6 +16,7 @@
 #include <folly/experimental/logging/Init.h>
 #include <folly/experimental/logging/xlog.h>
 #include <folly/init/Init.h>
+#include <folly/portability/Stdlib.h>
 
 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 de7274f98237109b3b1b3552b4bdc03360ecff1f..132b708bb922bedf6549e2d84abc13dfcf2fd485 100644 (file)
--- 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)