core: change LoggerFactory to log error on unknown module

refs: #1524

Change-Id: Ic61b361237429992e647ddf194a3c11f2dd2929b
diff --git a/core/logger-factory.cpp b/core/logger-factory.cpp
index 3a738eb..6bea7a6 100644
--- a/core/logger-factory.cpp
+++ b/core/logger-factory.cpp
@@ -26,6 +26,8 @@
 
 namespace nfd {
 
+NFD_LOG_INIT("LoggerFactory");
+
 LoggerFactory&
 LoggerFactory::getInstance()
 {
@@ -137,8 +139,8 @@
           LoggerMap::iterator loggerIt = m_loggers.find(item->first);
           if (loggerIt == m_loggers.end())
             {
-              throw LoggerFactory::Error("Invalid module name \"" +
-                                         item->first + "\" in configuration file");
+              NFD_LOG_DEBUG("Failed to configure logging level for module \"" <<
+                            item->first << "\" (module not found)");
             }
 
           if (!isDryRun)
diff --git a/tests/core/logger.cpp b/tests/core/logger.cpp
index 5a85d45..febadfc 100644
--- a/tests/core/logger.cpp
+++ b/tests/core/logger.cpp
@@ -125,18 +125,21 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -145,7 +148,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 
@@ -233,18 +236,20 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -253,7 +258,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }
@@ -350,18 +355,20 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -370,7 +377,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }
@@ -449,18 +456,20 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -469,11 +478,68 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }
 
+BOOST_FIXTURE_TEST_CASE(UnknownModule, LoggerFixture)
+{
+  using namespace ndn::time;
+  using std::string;
+
+  const ndn::time::microseconds::rep ONE_SECOND = 1000000;
+
+  const std::string LOG_CONFIG =
+    "log\n"
+    "{\n"
+    "  TestMadeUpModule INFO\n"
+    "}\n";
+
+  ConfigFile config;
+  LoggerFactory::getInstance().setDefaultLevel(LOG_ALL);
+  LoggerFactory::getInstance().setConfigFile(config);
+
+  const std::string EXPECTED = "DEBUG: [LoggerFactory] "
+    "Failed to configure logging level for module \"TestMadeUpModule\" (module not found)\n";
+
+  microseconds::rep before =
+    duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+
+  config.parse(LOG_CONFIG, false, "LOG_CONFIG");
+
+  microseconds::rep after =
+    duration_cast<microseconds>(system_clock::now().time_since_epoch()).count();
+
+  const string buffer = m_buffer.str();
+
+  const size_t firstSpace = buffer.find(" ");
+  BOOST_REQUIRE(firstSpace != string::npos);
+
+  const string timestamp = buffer.substr(0, firstSpace);
+  const string message = buffer.substr(firstSpace + 1);
+
+  size_t timeDelimiterPosition = timestamp.find(".");
+
+  BOOST_REQUIRE_NE(string::npos, timeDelimiterPosition);
+
+  string secondsString = timestamp.substr(0, timeDelimiterPosition);
+  string usecondsString = timestamp.substr(timeDelimiterPosition + 1);
+
+  microseconds::rep extractedTime =
+    ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
+    boost::lexical_cast<microseconds::rep>(usecondsString);
+
+  // std::cout << "before=" << before
+  //           << " extracted=" << extractedTime
+  //           << " after=" << after << std::endl;
+
+  BOOST_CHECK_LE(before, extractedTime);
+  BOOST_CHECK_LE(extractedTime, after);
+
+  BOOST_CHECK_EQUAL(message, EXPECTED);
+}
+
 static bool
 checkError(const LoggerFactory::Error& error, const std::string& expected)
 {
@@ -498,24 +564,6 @@
                                "Unsupported logging level \"TestMadeUpLevel\""));
 }
 
-BOOST_FIXTURE_TEST_CASE(UnknownOption, LoggerFixture)
-{
-  const std::string LOG_CONFIG =
-    "log\n"
-    "{\n"
-    "  TestMadeUpOption\n"
-    "}\n";
-
-  ConfigFile config;
-  LoggerFactory::getInstance().setConfigFile(config);
-
-  BOOST_REQUIRE_EXCEPTION(config.parse(LOG_CONFIG, false, "LOG_CONFIG"),
-                          LoggerFactory::Error,
-                          bind(&checkError,
-                               _1,
-                               "No logging level found for option \"TestMadeUpOption\""));
-}
-
 class InClassLogger : public LoggerFixture
 {
 public:
@@ -597,18 +645,20 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -617,7 +667,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }
@@ -705,18 +755,20 @@
         ONE_SECOND * boost::lexical_cast<microseconds::rep>(secondsString) +
         boost::lexical_cast<microseconds::rep>(usecondsString);
 
-      // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
+      // std::cout << "before=" << before
+      //           << " extracted=" << extractedTime
+      //           << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -725,7 +777,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }
@@ -788,16 +840,16 @@
 
       // std::cout << "before=" << before << " extracted=" << extractedTime << " after=" << after << std::endl;
 
-      BOOST_REQUIRE(before <= extractedTime);
-      BOOST_REQUIRE(extractedTime <= after);
+      BOOST_CHECK_LE(before, extractedTime);
+      BOOST_CHECK_LE(extractedTime, after);
 
       // LOG_LEVEL:
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
       // [ModuleName]
-      BOOST_REQUIRE_EQUAL(*componentIter, EXPECTED[i]);
+      BOOST_CHECK_EQUAL(*componentIter, EXPECTED[i]);
       ++componentIter;
       ++i;
 
@@ -806,7 +858,7 @@
       // std::cout << "message = " << message << std::endl;
 
       // add back the newline that we split on
-      BOOST_REQUIRE_EQUAL(message + "\n", EXPECTED[i]);
+      BOOST_CHECK_EQUAL(message + "\n", EXPECTED[i]);
       ++componentIter;
     }
 }