[1892] Conditionally throw an exception if logger placeholders are not matched

diff --git a/configure.ac b/configure.ac
index 56d2618c86470a987449ae9d53f496ac1527b8a3..d6eec68c9f8c3389cf4c7374485e7cb59a2df1dd 100644 (file)
--- a/configure.ac
+++ b/configure.ac
@@ -977,6 +977,11 @@ AC_ARG_ENABLE(install-configurations,
 
 AM_CONDITIONAL(INSTALL_CONFIGURATIONS, test x$install_configurations = xyes || test x$install_configurations = xtrue)
 
+AC_ARG_ENABLE(logger-checks, [AC_HELP_STRING([--enable-logger-checks],
+  [check logger messages [default=no]])], enable_logger_checks=$enableval, enable_logger_checks=no)
+AM_CONDITIONAL(ENABLE_LOGGER_CHECKS, test x$enable_logger_checks != xno)
+AM_COND_IF([ENABLE_LOGGER_CHECKS], [AC_DEFINE([ENABLE_LOGGER_CHECKS], [1], [Check logger messages?])])
+
 AC_CONFIG_FILES([Makefile
                  doc/Makefile
                  doc/guide/Makefile

diff --git a/src/lib/log/log_formatter.cc b/src/lib/log/log_formatter.cc
index 18c47419886818b2bc0618922c8e87bf2b1d3a6e..6081e53e5c72a89ab275216c54a1f0cac26d20d6 100644 (file)
--- a/src/lib/log/log_formatter.cc
+++ b/src/lib/log/log_formatter.cc
@@ -12,6 +12,7 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
+#include "config.h"
 #include <log/log_formatter.h>
 
 using namespace std;
@@ -31,11 +32,28 @@ replacePlaceholder(string* message, const string& arg,
             message->replace(pos, mark.size(), arg);
             pos = message->find(mark, pos + arg.size());
         } while (pos != string::npos);
-    } else {
-        // We're missing the placeholder, so add some complain
-        message->append(" @@Missing placeholder " + mark + " for '" + arg +
-                        "'@@");
     }
+#ifdef ENABLE_LOGGER_CHECKS
+    else {
+        // We're missing the placeholder, so throw an exception
+        isc_throw(MismatchedPlaceholders,
+                 "Missing logger placeholder in message: " << message);
+    }
+#endif /* ENABLE_LOGGER_CHECKS */
+}
+
+void
+checkExcessPlaceholders(string* message, unsigned int placeholder)
+{
+#ifdef ENABLE_LOGGER_CHECKS
+    string mark("%" + lexical_cast<string>(placeholder));
+    size_t pos(message->find(mark));
+    if (pos != string::npos) {
+        // Excess placeholders were found, so throw an exception
+        isc_throw(MismatchedPlaceholders,
+                 "Excess logger placeholders still exist in message: " << message);
+    }
+#endif /* ENABLE_LOGGER_CHECKS */
 }
 
 }

diff --git a/src/lib/log/log_formatter.h b/src/lib/log/log_formatter.h
index 7a9e5fa904ee56d596c9cc32e61825de95b9a806..fc6020308bbf0dad281d48e27a3a593dc00b5e38 100644 (file)
--- a/src/lib/log/log_formatter.h
+++ b/src/lib/log/log_formatter.h
@@ -39,6 +39,27 @@ public:
 };
 
 
+/// \brief Mismatched Placeholders
+///
+/// This exception is used when the number of placeholders do not match
+/// the number of arguments passed to the formatter.
+
+class MismatchedPlaceholders : public isc::Exception {
+public:
+    MismatchedPlaceholders(const char* file, size_t line, const char* what) :
+        isc::Exception(file, line, what)
+    {}
+};
+
+
+///
+/// \brief Internal excess placeholder checker
+///
+/// This is used internally by the Formatter to check for excess
+/// placeholders (and fewer arguments).
+void
+checkExcessPlaceholders(std::string* message, unsigned int placeholder);
+
 ///
 /// \brief The internal replacement routine
 ///
@@ -142,6 +163,7 @@ public:
     /// This is the place where output happens if the formatter is active.
     ~ Formatter() {
         if (logger_) {
+            checkExcessPlaceholders(message_, ++nextPlaceholder_);
             logger_->output(severity_, *message_);
             delete message_;
         }

diff --git a/src/lib/log/tests/log_formatter_unittest.cc b/src/lib/log/tests/log_formatter_unittest.cc
index b91665dc80a8bb018dbe2d464706af53c9ed2118..d941849e814fb5d859f9b9bef9a7c8c6c461cfa3 100644 (file)
--- a/src/lib/log/tests/log_formatter_unittest.cc
+++ b/src/lib/log/tests/log_formatter_unittest.cc
@@ -12,6 +12,7 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
+#include "config.h"
 #include <gtest/gtest.h>
 #include <log/log_formatter.h>
 #include <log/logger_level.h>
@@ -94,16 +95,41 @@ TEST_F(FormatterTest, multiArg) {
     EXPECT_EQ("The arguments are switched", outputs[0].second);
 }
 
-// Can survive and complains if placeholder is missing
-TEST_F(FormatterTest, missingPlace) {
+#ifdef ENABLE_LOGGER_CHECKS
+
+#ifdef EXPECT_ABORT
+// Throws MismatchedPlaceholders exception if number of placeholders
+// don't match number of arguments. This causes it to abort.
+TEST_F(FormatterTest, mismatchedPlaceholders) {
+    EXPECT_ABORT({
+        Formatter(isc::log::INFO, s("Missing the first %2"), this).arg("missing").arg("argument");
+    }, ".*");
+
+    EXPECT_ABORT({
+       Formatter(isc::log::INFO, s("Too many arguments in %1 %2"), this).arg("only one");
+    }, ".*");
+}
+#endif /* EXPECT_ABORT */
+
+#else
+
+// If logger checks are not enabled, nothing is thrown
+TEST_F(FormatterTest, mismatchedPlaceholders) {
     EXPECT_NO_THROW(Formatter(isc::log::INFO, s("Missing the first %2"), this).
                     arg("missing").arg("argument"));
     ASSERT_EQ(1, outputs.size());
     EXPECT_EQ(isc::log::INFO, outputs[0].first);
-    EXPECT_EQ("Missing the first argument "
-              "@@Missing placeholder %1 for 'missing'@@", outputs[0].second);
+    EXPECT_EQ("Missing the first argument", outputs[0].second);
+
+    EXPECT_NO_THROW(Formatter(isc::log::INFO, s("Too many arguments in %1 %2"), this).
+                    arg("only one"));
+    ASSERT_EQ(2, outputs.size());
+    EXPECT_EQ(isc::log::INFO, outputs[1].first);
+    EXPECT_EQ("Too many arguments in only one %2", outputs[1].second);
 }
 
+#endif /* ENABLE_LOGGER_CHECKS */
+
 // Can replace multiple placeholders
 TEST_F(FormatterTest, multiPlaceholder) {
     Formatter(isc::log::INFO, s("The %1 is the %1"), this).

diff --git a/src/lib/log/tests/logger_manager_unittest.cc b/src/lib/log/tests/logger_manager_unittest.cc
index f2713b0f3ab9f8ef7db8f049781e7ccfb1591245..584d0f5677b62f5a485bec400afa84a40faf1d14 100644 (file)
--- a/src/lib/log/tests/logger_manager_unittest.cc
+++ b/src/lib/log/tests/logger_manager_unittest.cc
@@ -296,7 +296,7 @@ TEST_F(LoggerManagerTest, FileSizeRollover) {
     manager.process(spec);
     {
         Logger logger(file_spec.getLoggerName().c_str());
-        LOG_FATAL(logger, LOG_NO_MESSAGE_TEXT).arg(big_arg);
+        LOG_FATAL(logger, LOG_NO_MESSAGE_TEXT).arg("42").arg(big_arg);
     }
 
     LoggerManager::reset();     // Ensure files are closed

diff --git a/src/lib/log/tests/logger_support_unittest.cc b/src/lib/log/tests/logger_support_unittest.cc
index b4189061f6f28e90192104738ca841116ae1f846..c626c6dc50de735eb2e1404e8236d9ee975fecda 100644 (file)
--- a/src/lib/log/tests/logger_support_unittest.cc
+++ b/src/lib/log/tests/logger_support_unittest.cc
@@ -79,5 +79,5 @@ TEST_F(LoggerSupportTest, LoggingInitializationCheck) {
     // ... and check that they work when logging is initialized.
     setLoggingInitialized(true);
     EXPECT_NO_THROW(test_logger.isDebugEnabled());
-    EXPECT_NO_THROW(test_logger.info(LOG_INPUT_OPEN_FAIL));
+    EXPECT_NO_THROW(test_logger.info(LOG_INPUT_OPEN_FAIL).arg("foo").arg("bar"));
 }