[1944] Deactivate logger on exception

We want to disable the logger if there was an exception while putting
the parameters in. While we can't detect all possible ones, we can
detect some and reduce some false positives of the strict log checker
and not output mangled messages.

diff --git a/src/lib/log/log_formatter.h b/src/lib/log/log_formatter.h
index fc6020308bbf0dad281d48e27a3a593dc00b5e38..eebdb1a026065f9e59ef3b0bed40596f83b7e7e1 100644 (file)
--- a/src/lib/log/log_formatter.h
+++ b/src/lib/log/log_formatter.h
@@ -197,7 +197,9 @@ public:
             try {
                 return (arg(boost::lexical_cast<std::string>(value)));
             } catch (const boost::bad_lexical_cast& ex) {
-
+                // The formatting of the log message got wrong, we don't want
+                // to output it.
+                deactivate();
                 // A bad_lexical_cast during a conversion to a string is
                 // *extremely* unlikely to fail.  However, there is nothing
                 // in the documentation that rules it out, so we need to handle
@@ -229,10 +231,35 @@ public:
             // occurrences of "%2" with 42. (Conversely, the sequence
             // .arg(42).arg("%1") would return "42 %1" - there are no recursive
             // replacements).
-            replacePlaceholder(message_, arg, ++nextPlaceholder_ );
+            try {
+                replacePlaceholder(message_, arg, ++nextPlaceholder_ );
+            }
+            catch (...) {
+                // Something went wrong here, the log message is broken, so
+                // we don't want to output it, nor we want to check all the
+                // placeholders were used (because they won't be).
+                deactivate();
+                throw;
+            }
         }
         return (*this);
     }
+
+    /// \brief Turn off the output of this logger.
+    ///
+    /// If the logger would output anything at the end, now it won't.
+    /// Also, this turns off the strict checking of placeholders, if
+    /// it is compiled in.
+    ///
+    /// The expected use is when there was an exception processing
+    /// the arguments for the message.
+    void deactivate() {
+        if (logger_) {
+            delete message_;
+            message_ = NULL;
+            logger_ = NULL;
+        }
+    }
 };
 
 }

diff --git a/src/lib/log/tests/log_formatter_unittest.cc b/src/lib/log/tests/log_formatter_unittest.cc
index 83fc0629f8cd0cab3ca2ad28d7d0aa2b3adab73d..435b20097954d12ba03e6c895f2da8fd5eacbd71 100644 (file)
--- a/src/lib/log/tests/log_formatter_unittest.cc
+++ b/src/lib/log/tests/log_formatter_unittest.cc
@@ -81,6 +81,14 @@ TEST_F(FormatterTest, stringArg) {
     }
 }
 
+// Test the .deactivate() method
+TEST_F(FormatterTest, deactivate) {
+    Formatter(isc::log::INFO, s("Text of message"), this).deactivate();
+    // If there was no .deactivate, it should have output it.
+    // But not now.
+    ASSERT_EQ(0, outputs.size());
+}
+
 // Can convert to string
 TEST_F(FormatterTest, intArg) {
     Formatter(isc::log::INFO, s("The answer is %1"), this).arg(42);
@@ -117,15 +125,12 @@ TEST_F(FormatterTest, mismatchedPlaceholders) {
             arg("only one");
     }, ".*");
 
-    // Mixed case of above two: the exception will be thrown due to the missing
-    // placeholder, but before even it's caught the program will be aborted
-    // due to the unused placeholder as a result of the exception.
-    EXPECT_DEATH({
-        isc::util::unittests::dontCreateCoreDumps();
-        Formatter(isc::log::INFO, s("Missing the first %2"), this).
-            arg("missing").arg("argument");
-    }, ".*");
 #endif /* EXPECT_DEATH */
+    // Mixed case of above two: the exception will be thrown due to the missing
+    // placeholder. The other check is disabled due to that.
+    EXPECT_THROW(Formatter(isc::log::INFO, s("Missing the first %2"), this).
+                 arg("missing").arg("argument"),
+                 isc::log::MismatchedPlaceholders);
 }
 
 #else

diff --git a/src/lib/python/isc/log/log.cc b/src/lib/python/isc/log/log.cc
index ed053984d2c689afe3b0c64d93324b006dda09d7..69e70b727e0b4356ea49d2b0c7649059954b8ff9 100644 (file)
--- a/src/lib/python/isc/log/log.cc
+++ b/src/lib/python/isc/log/log.cc
@@ -541,8 +541,14 @@ Logger_performOutput(Function function, PyObject* args, bool dbgLevel) {
         // into the formatter. It will print itself in the end.
         for (size_t i(start); i < number; ++ i) {
             PyObjectContainer param_container(PySequence_GetItem(args, i));
-            formatter = formatter.arg(objectToStr(param_container.get(),
-                                                  true));
+            try {
+                formatter = formatter.arg(objectToStr(param_container.get(),
+                                                      true));
+            }
+            catch (...) {
+                formatter.deactivate();
+                throw;
+            }
         }
         Py_RETURN_NONE;
     }