From: Michal 'vorner' Vaner <michal.vaner@nic.cz>
Date: Fri, 25 May 2012 10:48:34 +0000 (+0200)
Subject: [1944] Deactivate logger on exception
X-Git-Tag: trac2351_base~226^2~64^2^2~2^2~1
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=b94f49bf264e058dac14287eca360c82edb0071d;p=thirdparty%2Fkea.git

[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 fc6020308b..eebdb1a026 100644
--- 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 83fc0629f8..435b200979 100644
--- 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 ed053984d2..69e70b727e 100644
--- 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;
     }