util: Advanced filtering of the logging modules

refs: #3918

Change-Id: I766deb5ccd0d7f4472679d9955c8e55bad41f375
diff --git a/tests/unit-tests/util/log-filter-module.cpp b/tests/unit-tests/util/log-filter-module.cpp
new file mode 100644
index 0000000..4086b84
--- /dev/null
+++ b/tests/unit-tests/util/log-filter-module.cpp
@@ -0,0 +1,44 @@
+/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
+/*
+ * Copyright (c) 2013-2017 Regents of the University of California.
+ *
+ * This file is part of ndn-cxx library (NDN C++ library with eXperimental eXtensions).
+ *
+ * ndn-cxx library is free software: you can redistribute it and/or modify it under the
+ * terms of the GNU Lesser General Public License as published by the Free Software
+ * Foundation, either version 3 of the License, or (at your option) any later version.
+ *
+ * ndn-cxx library is distributed in the hope that it will be useful, but WITHOUT ANY
+ * WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A
+ * PARTICULAR PURPOSE.  See the GNU Lesser General Public License for more details.
+ *
+ * You should have received copies of the GNU General Public License and GNU Lesser
+ * General Public License along with ndn-cxx, e.g., in COPYING.md file.  If not, see
+ * <http://www.gnu.org/licenses/>.
+ *
+ * See AUTHORS.md for complete list of ndn-cxx authors and contributors.
+ */
+
+#include "util/logger.hpp"
+
+NDN_LOG_INIT(fm.FilterModule);
+
+namespace ndn {
+namespace util {
+namespace tests {
+
+void
+logFromFilterModule()
+{
+  NDN_LOG_TRACE("traceFM");
+  NDN_LOG_DEBUG("debugFM");
+  NDN_LOG_INFO("infoFM");
+  NDN_LOG_WARN("warnFM");
+  NDN_LOG_ERROR("errorFM");
+  NDN_LOG_FATAL("fatalFM");
+}
+
+} // namespace tests
+} // namespace util
+} // namespace ndn
+
diff --git a/tests/unit-tests/util/logger.t.cpp b/tests/unit-tests/util/logger.t.cpp
new file mode 100644
index 0000000..1443178
--- /dev/null
+++ b/tests/unit-tests/util/logger.t.cpp
@@ -0,0 +1,82 @@
+/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
+/*
+ * Copyright (c) 2013-2017 Regents of the University of California.
+ *
+ * This file is part of ndn-cxx library (NDN C++ library with eXperimental eXtensions).
+ *
+ * ndn-cxx library is free software: you can redistribute it and/or modify it under the
+ * terms of the GNU Lesser General Public License as published by the Free Software
+ * Foundation, either version 3 of the License, or (at your option) any later version.
+ *
+ * ndn-cxx library is distributed in the hope that it will be useful, but WITHOUT ANY
+ * WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A
+ * PARTICULAR PURPOSE.  See the GNU Lesser General Public License for more details.
+ *
+ * You should have received copies of the GNU General Public License and GNU Lesser
+ * General Public License along with ndn-cxx, e.g., in COPYING.md file.  If not, see
+ * <http://www.gnu.org/licenses/>.
+ *
+ * See AUTHORS.md for complete list of ndn-cxx authors and contributors.
+ */
+
+#include "util/logger.hpp"
+#include "util/logging.hpp"
+
+#include "boost-test.hpp"
+
+namespace ndn {
+namespace util {
+namespace tests {
+
+BOOST_AUTO_TEST_SUITE(Util)
+BOOST_AUTO_TEST_SUITE(TestLogger)
+
+BOOST_AUTO_TEST_CASE(LegalAlphanumeric)
+{
+  Logger logger("ndnTest123");
+  auto mNames = Logging::getLoggerNames();
+  BOOST_CHECK_EQUAL(mNames.count("ndnTest123"), 1);
+  BOOST_CHECK(logger.isLevelEnabled(LogLevel::NONE));
+  Logging::get().removeLogger(logger);
+}
+
+BOOST_AUTO_TEST_CASE(AllLegalSymbols)
+{
+  Logger logger("ndn.~#%.test_<check>1-2-3");
+  auto mNames = Logging::getLoggerNames();
+  BOOST_CHECK_EQUAL(mNames.count("ndn.~#%.test_<check>1-2-3"), 1);
+  BOOST_CHECK(logger.isLevelEnabled(LogLevel::NONE));
+  Logging::get().removeLogger(logger);
+}
+
+BOOST_AUTO_TEST_CASE(EmptyLogger)
+{
+  BOOST_CHECK_THROW(Logger logger(""), std::invalid_argument);
+}
+
+BOOST_AUTO_TEST_CASE(InvalidSymbol)
+{
+  BOOST_CHECK_THROW(Logger logger("ndn.test.*"), std::invalid_argument);
+}
+
+BOOST_AUTO_TEST_CASE(StartsWithPeriod)
+{
+  BOOST_CHECK_THROW(Logger logger(".ndn.test"), std::invalid_argument);
+}
+
+BOOST_AUTO_TEST_CASE(EndsWithPeriod)
+{
+  BOOST_CHECK_THROW(Logger logger("ndn.test."), std::invalid_argument);
+}
+
+BOOST_AUTO_TEST_CASE(ConsecutivePeriods)
+{
+  BOOST_CHECK_THROW(Logger logger("ndn..test"), std::invalid_argument);
+}
+
+BOOST_AUTO_TEST_SUITE_END() // TestLogger
+BOOST_AUTO_TEST_SUITE_END() // Util
+
+} // namespace tests
+} // namespace util
+} // namespace ndn
diff --git a/tests/unit-tests/util/logging.t.cpp b/tests/unit-tests/util/logging.t.cpp
index 3447968..cced73b 100644
--- a/tests/unit-tests/util/logging.t.cpp
+++ b/tests/unit-tests/util/logging.t.cpp
@@ -1,5 +1,5 @@
 /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
-/**
+/*
  * Copyright (c) 2013-2017 Regents of the University of California.
  *
  * This file is part of ndn-cxx library (NDN C++ library with eXperimental eXtensions).
@@ -21,10 +21,10 @@
 
 #include "util/logging.hpp"
 #include "util/logger.hpp"
+#include "../unit-test-time-fixture.hpp"
 
 #include "boost-test.hpp"
 #include <boost/test/output_test_stream.hpp>
-#include "../unit-test-time-fixture.hpp"
 
 namespace ndn {
 namespace util {
@@ -42,9 +42,11 @@
 logFromModule2();
 
 void
+logFromFilterModule();
+
+static void
 logFromNewLogger(const std::string& moduleName)
 {
-  // clang complains -Wreturn-stack-address on OSX-10.9 if Logger is allocated on stack
   auto loggerPtr = make_unique<Logger>(moduleName);
   Logger& logger = *loggerPtr;
 
@@ -67,7 +69,7 @@
 protected:
   explicit
   LoggingFixture()
-    : m_oldLevels(Logging::get().getLevels())
+    : m_oldEnabledLevel(Logging::get().getLevels())
     , m_oldDestination(Logging::get().getDestination())
   {
     this->systemClock->setNow(LOG_SYSTIME);
@@ -77,7 +79,7 @@
 
   ~LoggingFixture()
   {
-    Logging::setLevel(m_oldLevels);
+    Logging::get().setLevelImpl(m_oldEnabledLevel);
     Logging::setDestination(m_oldDestination);
   }
 
@@ -85,7 +87,7 @@
   output_test_stream os;
 
 private:
-  std::string m_oldLevels;
+  std::unordered_map<std::string, LogLevel> m_oldEnabledLevel;
   shared_ptr<std::ostream> m_oldDestination;
 };
 
@@ -291,7 +293,8 @@
 BOOST_AUTO_TEST_CASE(SetEmpty)
 {
   Logging::setLevel("");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 0);
   logFromModule1();
   logFromModule2();
 
@@ -305,7 +308,10 @@
 BOOST_AUTO_TEST_CASE(SetDefault)
 {
   Logging::setLevel("*=WARN");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "*=WARN");
+  const auto& prefixMap = Logging::get().getLevels();
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.size(), 1);
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::WARN);
   logFromModule1();
   logFromModule2();
 
@@ -323,7 +329,9 @@
 BOOST_AUTO_TEST_CASE(SetModule)
 {
   Logging::setLevel("Module1=ERROR");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "Module1=ERROR");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 1);
+  BOOST_CHECK_EQUAL(prefixMap.at("Module1"), LogLevel::ERROR);
   logFromModule1();
   logFromModule2();
 
@@ -338,7 +346,11 @@
 BOOST_AUTO_TEST_CASE(SetOverride)
 {
   Logging::setLevel("*=WARN:Module2=DEBUG");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "*=WARN:Module2=DEBUG");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 2);
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::WARN);
+  BOOST_CHECK_EQUAL(prefixMap.at("Module2"), LogLevel::DEBUG);
   logFromModule1();
   logFromModule2();
 
@@ -359,7 +371,11 @@
 {
   Logging::setLevel("*=WARN");
   Logging::setLevel("Module2=DEBUG");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "*=WARN:Module2=DEBUG");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 2);
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::WARN);
+  BOOST_CHECK_EQUAL(prefixMap.at("Module2"), LogLevel::DEBUG);
   logFromModule1();
   logFromModule2();
 
@@ -380,7 +396,10 @@
 {
   Logging::setLevel("Module2=DEBUG");
   Logging::setLevel("*=ERROR");
-  BOOST_CHECK_EQUAL(Logging::get().getLevels(), "*=ERROR");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 1);
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::ERROR);
   logFromModule1();
   logFromModule2();
 
@@ -399,6 +418,74 @@
   BOOST_CHECK_THROW(Logging::setLevel("Module1-MISSING-EQUAL-SIGN"), std::invalid_argument);
 }
 
+BOOST_AUTO_TEST_CASE(SetFilter)
+{
+  Logging::setLevel("*=FATAL:fm.*=DEBUG");
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 2);
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::FATAL);
+  // "name.*" is treated as "name." internally
+  BOOST_CHECK_EQUAL(prefixMap.at("fm."), LogLevel::DEBUG);
+  logFromModule1();
+  logFromFilterModule();
+
+  Logging::flush();
+  BOOST_CHECK(os.is_equal(
+    LOG_SYSTIME_STR + " FATAL: [Module1] fatal1\n" +
+    LOG_SYSTIME_STR + " DEBUG: [fm.FilterModule] debugFM\n" +
+    LOG_SYSTIME_STR + " INFO: [fm.FilterModule] infoFM\n" +
+    LOG_SYSTIME_STR + " WARNING: [fm.FilterModule] warnFM\n" +
+    LOG_SYSTIME_STR + " ERROR: [fm.FilterModule] errorFM\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.FilterModule] fatalFM\n"
+    ));
+}
+
+BOOST_AUTO_TEST_CASE(SetOverrideFilter)
+{
+  Logging::setLevel("*=FATAL:fm.FilterModule=DEBUG");
+  Logging::setLevel("fm.*", LogLevel::INFO);
+  const auto& prefixMap = Logging::get().getLevels();
+  BOOST_CHECK_EQUAL(prefixMap.size(), 2);
+  // "*" is treated as "" internally
+  BOOST_CHECK_EQUAL(prefixMap.at(""), LogLevel::FATAL);
+  // "name.*" is treated as "name." internally
+  BOOST_CHECK_EQUAL(prefixMap.at("fm."), LogLevel::INFO);
+  logFromModule1();
+  logFromFilterModule();
+
+  Logging::flush();
+  BOOST_CHECK(os.is_equal(
+    LOG_SYSTIME_STR + " FATAL: [Module1] fatal1\n" +
+    LOG_SYSTIME_STR + " INFO: [fm.FilterModule] infoFM\n" +
+    LOG_SYSTIME_STR + " WARNING: [fm.FilterModule] warnFM\n" +
+    LOG_SYSTIME_STR + " ERROR: [fm.FilterModule] errorFM\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.FilterModule] fatalFM\n"
+    ));
+}
+
+BOOST_AUTO_TEST_CASE(FindPrefixRule)
+{
+  Logging::setLevel("*=FATAL:fm.a.*=ERROR:fm.a.b=INFO");
+  logFromNewLogger("fm.a.b");
+  logFromNewLogger("fm.a.b.c");
+  logFromNewLogger("fm.a.b.d");
+  logFromNewLogger("fm.b");
+
+  Logging::flush();
+  BOOST_CHECK(os.is_equal(
+    LOG_SYSTIME_STR + " INFO: [fm.a.b] infofm.a.b\n" +
+    LOG_SYSTIME_STR + " WARNING: [fm.a.b] warnfm.a.b\n" +
+    LOG_SYSTIME_STR + " ERROR: [fm.a.b] errorfm.a.b\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.a.b] fatalfm.a.b\n" +
+    LOG_SYSTIME_STR + " ERROR: [fm.a.b.c] errorfm.a.b.c\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.a.b.c] fatalfm.a.b.c\n" +
+    LOG_SYSTIME_STR + " ERROR: [fm.a.b.d] errorfm.a.b.d\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.a.b.d] fatalfm.a.b.d\n" +
+    LOG_SYSTIME_STR + " FATAL: [fm.b] fatalfm.b\n"
+    ));
+}
+
 BOOST_AUTO_TEST_SUITE_END() // SeverityConfig
 
 BOOST_AUTO_TEST_CASE(ChangeDestination)