logging: Reducing log level in several places

INFO level is suppose to be used for informational messages that are
useful for ordinary user, but in several places we used it as a DEBUG
output.

In CS the level is reduced even more, to TRACE.

Change-Id: I9058e25d95de79661099dd4624d802cc33420983
diff --git a/daemon/table/cs-entry.cpp b/daemon/table/cs-entry.cpp
index c98a66c..044fd45 100644
--- a/daemon/table/cs-entry.cpp
+++ b/daemon/table/cs-entry.cpp
@@ -134,7 +134,7 @@
        it != m_layerIterators.end();
        ++it)
     {
-      NFD_LOG_DEBUG("[" << it->first << "]" << " " << &(*it->second));
+      NFD_LOG_TRACE("[" << it->first << "]" << " " << &(*it->second));
     }
 }
 
diff --git a/daemon/table/cs.cpp b/daemon/table/cs.cpp
index a4c0525..3dc788a 100644
--- a/daemon/table/cs.cpp
+++ b/daemon/table/cs.cpp
@@ -58,8 +58,8 @@
 std::pair< shared_ptr<cs::Entry>, bool>
 Cs::insertToSkipList(const Data& data, bool isUnsolicited)
 {
-  NFD_LOG_INFO("insertToSkipList() " << data.getName());
-  NFD_LOG_DEBUG("SkipList size " << size());
+  NFD_LOG_TRACE("insertToSkipList() " << data.getName() << ", "
+                << "skipList size " << size());
 
   shared_ptr<cs::Entry> entry = make_shared<cs::Entry>(data, isUnsolicited);
 
@@ -131,14 +131,14 @@
   //check if this is a duplicate packet
   if (isNameIdentical)
     {
-      NFD_LOG_DEBUG("Duplicate name (with digest)");
+      NFD_LOG_TRACE("Duplicate name (with digest)");
 
       (*head)->setData(data, entry->getDigest()); //updates stale time
 
       return std::make_pair(*head, false);
     }
 
-  NFD_LOG_DEBUG("Not a duplicate");
+  NFD_LOG_TRACE("Not a duplicate");
 
   size_t randomLayer = pickRandomLayer();
 
@@ -161,18 +161,18 @@
           --last;
           entry->setIterator(layer, last);
 
-          NFD_LOG_DEBUG("pushback " << &(*last));
+          NFD_LOG_TRACE("pushback " << &(*last));
         }
       else if (updateTable[layer] == (*i)->end() && insertInFront)
         {
           (*i)->push_front(entry);
           entry->setIterator(layer, (*i)->begin());
 
-          NFD_LOG_DEBUG("pushfront ");
+          NFD_LOG_TRACE("pushfront ");
         }
       else
         {
-          NFD_LOG_DEBUG("insertafter");
+          NFD_LOG_TRACE("insertafter");
           ++updateTable[layer]; // insert after
           SkipListLayer::iterator position = (*i)->insert(updateTable[layer], entry);
           entry->setIterator(layer, position); // save iterator where item was inserted
@@ -188,7 +188,7 @@
 bool
 Cs::insert(const Data& data, bool isUnsolicited)
 {
-  NFD_LOG_INFO("insert() " << data.getName());
+  NFD_LOG_TRACE("insert() " << data.getName());
 
   if (isFull())
     {
@@ -241,8 +241,8 @@
 bool
 Cs::eraseFromSkipList(shared_ptr<cs::Entry> entry)
 {
-  NFD_LOG_INFO("eraseFromSkipList() "  << entry->getName());
-  NFD_LOG_DEBUG("SkipList size " << size());
+  NFD_LOG_TRACE("eraseFromSkipList() "  << entry->getName());
+  NFD_LOG_TRACE("SkipList size " << size());
 
   bool isErased = false;
 
@@ -280,12 +280,12 @@
 bool
 Cs::evictItem()
 {
-  NFD_LOG_INFO("evictItem()");
+  NFD_LOG_TRACE("evictItem()");
 
   //because there is a possibility that this item is in a queue, but no longer in skiplist
   while ( !m_unsolicitedContent.empty() )
     {
-      NFD_LOG_DEBUG("Evict from unsolicited queue");
+      NFD_LOG_TRACE("Evict from unsolicited queue");
 
       shared_ptr<cs::Entry> entry = m_unsolicitedContent.front();
       m_unsolicitedContent.pop();
@@ -299,7 +299,7 @@
   int nIterations = size() * 0.01;  // 1% of the Content Store
   while ( !m_contentByStaleness.empty() )
     {
-      NFD_LOG_DEBUG("Evict from staleness queue");
+      NFD_LOG_TRACE("Evict from staleness queue");
 
       shared_ptr<cs::Entry> entry = m_contentByStaleness.top();
 
@@ -332,7 +332,7 @@
   //because there is a possibility that this item is in a queue, but no longer in skiplist
   while ( !m_contentByArrival.empty() )
     {
-      NFD_LOG_DEBUG("Evict from arrival queue");
+      NFD_LOG_TRACE("Evict from arrival queue");
 
       shared_ptr<cs::Entry> entry = m_contentByArrival.front();
       m_contentByArrival.pop();
@@ -348,7 +348,7 @@
 const Data*
 Cs::find(const Interest& interest) const
 {
-  NFD_LOG_INFO("find() " << interest.getName());
+  NFD_LOG_TRACE("find() " << interest.getName());
 
   bool isIterated = false;
   SkipList::const_reverse_iterator topLayer = m_skipList.rbegin();
@@ -385,7 +385,7 @@
 
                   while ( (*it)->getName() < interest.getName() )
                     {
-                      NFD_LOG_DEBUG((*it)->getName() << " < " << interest.getName());
+                      NFD_LOG_TRACE((*it)->getName() << " < " << interest.getName());
                       head = it;
                       isIterated = true;
 
@@ -425,7 +425,7 @@
       BOOST_ASSERT( (*startingPoint)->getName() < interest.getName() );
     }
 
-  NFD_LOG_INFO("selectChild() " << interest.getChildSelector() << " " << (*startingPoint)->getName());
+  NFD_LOG_TRACE("selectChild() " << interest.getChildSelector() << " " << (*startingPoint)->getName());
 
   bool hasLeftmostSelector = (interest.getChildSelector() <= 0);
   bool hasRightmostSelector = !hasLeftmostSelector;
@@ -496,7 +496,7 @@
                         {
                           // get prefix which is one component longer than Interest name (without digest)
                           const Name& childPrefix = (*rightmostCandidate)->getName().getPrefix(interest.getName().size());
-                          NFD_LOG_DEBUG("Child prefix" << childPrefix);
+                          NFD_LOG_TRACE("Child prefix" << childPrefix);
 
                           if ( currentChildPrefix.empty() || (childPrefix != currentChildPrefix) )
                             {
@@ -508,7 +508,7 @@
                         {
                           // get prefix which is one component longer than Interest name
                           const Name& childPrefix = (*rightmostCandidate)->getName().getPrefix(interest.getName().size() + 1);
-                          NFD_LOG_DEBUG("Child prefix" << childPrefix);
+                          NFD_LOG_TRACE("Child prefix" << childPrefix);
 
                           if ( currentChildPrefix.empty() || (childPrefix != currentChildPrefix) )
                             {
@@ -558,7 +558,7 @@
 bool
 Cs::doesComplyWithSelectors(const Interest& interest, shared_ptr<cs::Entry> entry) const
 {
-  NFD_LOG_INFO("doesComplyWithSelectors()");
+  NFD_LOG_TRACE("doesComplyWithSelectors()");
 
   /// \todo The following detection is not correct
   ///       1. If data name ends with 32-octet component doesn't mean that this component is digest
@@ -575,7 +575,7 @@
 
       if (std::memcmp(digest->buf(), last.value(), ndn::crypto::SHA256_DIGEST_SIZE) != 0)
         {
-          NFD_LOG_DEBUG("violates implicit digest");
+          NFD_LOG_TRACE("violates implicit digest");
           return false;
         }
     }
@@ -589,7 +589,7 @@
           bool isSatisfied = (minDataNameLength <= entry->getName().size());
           if ( !isSatisfied )
             {
-              NFD_LOG_DEBUG("violates minComponents");
+              NFD_LOG_TRACE("violates minComponents");
               return false;
             }
         }
@@ -601,7 +601,7 @@
           bool isSatisfied = (maxDataNameLength >= entry->getName().size());
           if ( !isSatisfied )
             {
-              NFD_LOG_DEBUG("violates maxComponents");
+              NFD_LOG_TRACE("violates maxComponents");
               return false;
             }
         }
@@ -609,7 +609,7 @@
 
   if (interest.getMustBeFresh() && entry->getStaleTime() < time::steady_clock::now())
     {
-      NFD_LOG_DEBUG("violates mustBeFresh");
+      NFD_LOG_TRACE("violates mustBeFresh");
       return false;
     }
 
@@ -621,7 +621,7 @@
         {
           if (interest.getExclude().isExcluded(lastComponent))
             {
-              NFD_LOG_DEBUG("violates exclusion");
+              NFD_LOG_TRACE("violates exclusion");
               return false;
             }
         }
@@ -636,15 +636,14 @@
             {
               if (interest.getExclude().isExcluded(nextComponent))
                 {
-                  NFD_LOG_DEBUG("violates exclusion");
+                  NFD_LOG_TRACE("violates exclusion");
                   return false;
                 }
             }
         }
     }
 
-
-  NFD_LOG_DEBUG("complies!");
+  NFD_LOG_TRACE("complies");
   return true;
 }
 
@@ -659,7 +658,7 @@
       const ndn::name::Component& last = interest.getName().get(-1);
       if (last.value_size() == ndn::crypto::SHA256_DIGEST_SIZE)
         {
-          NFD_LOG_DEBUG("digest recognized");
+          NFD_LOG_TRACE("digest recognized");
           return true;
         }
     }
@@ -670,8 +669,8 @@
 void
 Cs::erase(const Name& exactName)
 {
-  NFD_LOG_INFO("insert() " << exactName);
-  NFD_LOG_DEBUG("SkipList size " << size());
+  NFD_LOG_TRACE("insert() " << exactName << ", "
+                << "skipList size " << size());
 
   bool isIterated = false;
   SkipListLayer::iterator updateTable[SKIPLIST_MAX_LAYERS];
@@ -734,13 +733,13 @@
   bool isNameIdentical = false;
   if (!isCsEmpty && isInBoundaries)
     {
-      NFD_LOG_DEBUG("Identical? " << (*head)->getName());
+      NFD_LOG_TRACE("Identical? " << (*head)->getName());
       isNameIdentical = (*head)->getName() == exactName;
     }
 
   if (isNameIdentical)
     {
-      NFD_LOG_DEBUG("Found target " << (*head)->getName());
+      NFD_LOG_TRACE("Found target " << (*head)->getName());
       eraseFromSkipList(*head);
     }
 
@@ -750,14 +749,14 @@
 void
 Cs::printSkipList() const
 {
-  NFD_LOG_INFO("print()");
+  NFD_LOG_TRACE("print()");
   //start from the upper layer towards bottom
   int layer = m_skipList.size() - 1;
   for (SkipList::const_reverse_iterator rit = m_skipList.rbegin(); rit != m_skipList.rend(); ++rit)
     {
       for (SkipListLayer::iterator it = (*rit)->begin(); it != (*rit)->end(); ++it)
         {
-          NFD_LOG_DEBUG("Layer " << layer << " " << (*it)->getName());
+          NFD_LOG_TRACE("Layer " << layer << " " << (*it)->getName());
         }
       layer--;
     }
diff --git a/daemon/table/name-tree.cpp b/daemon/table/name-tree.cpp
index 1d2e211..b71c970 100644
--- a/daemon/table/name-tree.cpp
+++ b/daemon/table/name-tree.cpp
@@ -65,12 +65,12 @@
 std::pair<shared_ptr<name_tree::Entry>, bool>
 NameTree::insert(const Name& prefix)
 {
-  NFD_LOG_DEBUG("insert " << prefix);
+  NFD_LOG_TRACE("insert " << prefix);
 
   uint32_t hashValue = name_tree::hashName(prefix);
   uint32_t loc = hashValue % m_nBuckets;
 
-  NFD_LOG_DEBUG("Name " << prefix << " hash value = " << hashValue << "  location = " << loc);
+  NFD_LOG_TRACE("Name " << prefix << " hash value = " << hashValue << "  location = " << loc);
 
   // Check if this Name has been stored
   name_tree::Node* node = m_buckets[loc];
@@ -88,7 +88,7 @@
       nodePrev = node;
     }
 
-  NFD_LOG_DEBUG("Did not find " << prefix << ", need to insert it to the table");
+  NFD_LOG_TRACE("Did not find " << prefix << ", need to insert it to the table");
 
   // If no bucket is empty occupied, we need to create a new node, and it is
   // linked from nodePrev
@@ -117,7 +117,7 @@
 shared_ptr<name_tree::Entry>
 NameTree::lookup(const Name& prefix)
 {
-  NFD_LOG_DEBUG("lookup " << prefix);
+  NFD_LOG_TRACE("lookup " << prefix);
 
   shared_ptr<name_tree::Entry> entry;
   shared_ptr<name_tree::Entry> parent;
@@ -155,12 +155,12 @@
 shared_ptr<name_tree::Entry>
 NameTree::findExactMatch(const Name& prefix) const
 {
-  NFD_LOG_DEBUG("findExactMatch " << prefix);
+  NFD_LOG_TRACE("findExactMatch " << prefix);
 
   uint32_t hashValue = name_tree::hashName(prefix);
   uint32_t loc = hashValue % m_nBuckets;
 
-  NFD_LOG_DEBUG("Name " << prefix << " hash value = " << hashValue <<
+  NFD_LOG_TRACE("Name " << prefix << " hash value = " << hashValue <<
                 "  location = " << loc);
 
   shared_ptr<name_tree::Entry> entry;
@@ -189,7 +189,7 @@
 shared_ptr<name_tree::Entry>
 NameTree::findLongestPrefixMatch(const Name& prefix, const name_tree::EntrySelector& entrySelector) const
 {
-  NFD_LOG_DEBUG("findLongestPrefixMatch " << prefix);
+  NFD_LOG_TRACE("findLongestPrefixMatch " << prefix);
 
   shared_ptr<name_tree::Entry> entry;
 
@@ -222,7 +222,7 @@
 {
   BOOST_ASSERT(static_cast<bool>(entry));
 
-  NFD_LOG_DEBUG("eraseEntryIfEmpty " << entry->getPrefix());
+  NFD_LOG_TRACE("eraseEntryIfEmpty " << entry->getPrefix());
 
   // first check if this Entry can be erased
   if (entry->isEmpty())
@@ -291,7 +291,7 @@
 NameTree::const_iterator
 NameTree::fullEnumerate(const name_tree::EntrySelector& entrySelector) const
 {
-  NFD_LOG_DEBUG("fullEnumerate");
+  NFD_LOG_TRACE("fullEnumerate");
 
   // find the first eligible entry
   for (size_t i = 0; i < m_nBuckets; i++)
@@ -347,7 +347,7 @@
 NameTree::findAllMatches(const Name& prefix,
                          const name_tree::EntrySelector& entrySelector) const
 {
-  NFD_LOG_DEBUG("NameTree::findAllMatches" << prefix);
+  NFD_LOG_TRACE("NameTree::findAllMatches" << prefix);
 
   // As we are using Name Prefix Hash Table, and the current LPM() is
   // implemented as starting from full name, and reduce the number of
@@ -370,7 +370,7 @@
 void
 NameTree::resize(size_t newNBuckets)
 {
-  NFD_LOG_DEBUG("resize");
+  NFD_LOG_TRACE("resize");
 
   name_tree::Node** newBuckets = new name_tree::Node*[newNBuckets];
   size_t count = 0;
@@ -424,7 +424,7 @@
 void
 NameTree::dump(std::ostream& output) const
 {
-  NFD_LOG_DEBUG("dump()");
+  NFD_LOG_TRACE("dump()");
 
   name_tree::Node* node = 0;
   shared_ptr<name_tree::Entry> entry;
@@ -493,7 +493,7 @@
 NameTree::const_iterator
 NameTree::const_iterator::operator++()
 {
-  NFD_LOG_DEBUG("const_iterator::operator++()");
+  NFD_LOG_TRACE("const_iterator::operator++()");
 
   BOOST_ASSERT(m_entry != m_nameTree.m_end);
 
diff --git a/daemon/table/strategy-choice-entry.cpp b/daemon/table/strategy-choice-entry.cpp
index 9d3f218..7933f33 100644
--- a/daemon/table/strategy-choice-entry.cpp
+++ b/daemon/table/strategy-choice-entry.cpp
@@ -5,6 +5,10 @@
  */
 
 #include "strategy-choice-entry.hpp"
+#include "core/logger.hpp"
+#include "fw/strategy.hpp"
+
+NFD_LOG_INIT("StrategyChoiceEntry");
 
 namespace nfd {
 namespace strategy_choice {
@@ -19,6 +23,8 @@
 {
   BOOST_ASSERT(static_cast<bool>(strategy));
   m_strategy = strategy;
+
+  NFD_LOG_INFO("Set strategy " << strategy->getName() << " for " << m_prefix << " prefix");
 }
 
 } // namespace strategy_choice
diff --git a/daemon/table/strategy-choice.cpp b/daemon/table/strategy-choice.cpp
index ee63d04..11bf120 100644
--- a/daemon/table/strategy-choice.cpp
+++ b/daemon/table/strategy-choice.cpp
@@ -53,12 +53,12 @@
 
   if (static_cast<bool>(entry)) {
     if (entry->getStrategy().getName() == strategyName) {
-      NFD_LOG_INFO("insert(" << prefix << "," << strategyName << ") not changing");
+      NFD_LOG_TRACE("insert(" << prefix << "," << strategyName << ") not changing");
       return true;
     }
     oldStrategy = entry->getStrategy().shared_from_this();
-    NFD_LOG_INFO("insert(" << prefix << "," << strategyName << ") "
-                 "changing from " << oldStrategy->getName());
+    NFD_LOG_TRACE("insert(" << prefix << "," << strategyName << ") "
+                  "changing from " << oldStrategy->getName());
   }
 
   shared_ptr<Strategy> strategy = this->getStrategy(strategyName);
@@ -72,7 +72,7 @@
     entry = make_shared<Entry>(prefix);
     nameTreeEntry->setStrategyChoiceEntry(entry);
     ++m_nItems;
-    NFD_LOG_INFO("insert(" << prefix << "," << strategyName << ") new entry");
+    NFD_LOG_TRACE("insert(" << prefix << "," << strategyName << ") new entry");
   }
 
   this->changeStrategy(entry, oldStrategy, strategy);
@@ -184,7 +184,7 @@
   shared_ptr<Entry> entry = make_shared<Entry>(Name());
   nameTreeEntry->setStrategyChoiceEntry(entry);
   ++m_nItems;
-  NFD_LOG_INFO("setDefaultStrategy(" << strategy->getName() << ") new entry");
+  NFD_LOG_INFO("Set default strategy " << strategy->getName());
 
   entry->setStrategy(strategy);
 }