BIND 10 master, updated. 3336f575aee4072d1d88b05f7db79712384ef2d8 Merge branch 'work/log/datasrc'

BIND 10 source code commits bind10-changes at lists.isc.org
Thu May 12 16:33:40 UTC 2011


The branch, master has been updated
       via  3336f575aee4072d1d88b05f7db79712384ef2d8 (commit)
       via  25c5c37094f9845be826f91bf5901068415891f6 (commit)
       via  9df5e254832c5c65ddf4a0895c09256e8386820f (commit)
       via  2b521f9674a0d9aea7fb06d71b008e64c40922aa (commit)
       via  8d9debda3a88cb20d19d23dbdfe106b3132a4ead (commit)
       via  6eba2b45ef54d671c674d7d840dc99208eb5d00c (commit)
       via  d65686925bbd04cbbfa3ca2705f54696b76beb45 (commit)
       via  4f6b51bc00d3f37b8938951217cd1f3564bedcd8 (commit)
       via  80c0a2c3eec3ac5d3ac862f9b4c5926f0eece6ed (commit)
       via  11439c030741ce402c52ad9d3cd1a407d45a443e (commit)
       via  e564debcb683454296d3e3cf478748daa0b08cbc (commit)
       via  fba4ec1d7269284b48042b1a7ea084b531bf8d9c (commit)
       via  cccc20cac1d91951bd9b707c3dfb532e9ad8686b (commit)
       via  68c9545bb7d57933e514ef55779abfd06c38145b (commit)
       via  2cf390147f147dfab2c8c63c470177189799ed20 (commit)
       via  287ee379ad62f9043699c936dc1204b6a906f52c (commit)
       via  c83d4bea0e9abc94b84315eb42c8ed7a879c8899 (commit)
       via  7e9ea719c8fda75f346eb87daae58cf06c8070e0 (commit)
       via  04c515e17a08b41c9dbf241e3983148596353d2c (commit)
       via  96d1613a474602b833af953a364fb045fcfee776 (commit)
       via  6f8490fe9ce1d6dbef326d75f9eab79c09e83462 (commit)
       via  38cddfdc23f6d2aa31be24173f9d7c1df2e3c4bc (commit)
       via  e2e13d0bd0856496a3571ba6b7f35f41e6534859 (commit)
       via  ea1f2d6e96715f0821df5d096be46b2454e6073a (commit)
       via  1151e49bcec0ac69fe01d084e10f106481337dea (commit)
       via  47dc61713d6bcfc16410fdb657c41dbbef85fb2c (commit)
       via  9713a50748616587ca32f17e9931c752aa1e5d3d (commit)
       via  fe141c14e201993b5e0efe848c2a47e0a4b553bc (commit)
      from  f15bdf8420351828159c0d7847d4f653388bf53c (commit)

Those revisions listed above that are new to this repository have
not appeared on any other notification email; so we list those
revisions in full, below.

- Log -----------------------------------------------------------------
commit 3336f575aee4072d1d88b05f7db79712384ef2d8
Merge: f15bdf8420351828159c0d7847d4f653388bf53c 25c5c37094f9845be826f91bf5901068415891f6
Author: Michal 'vorner' Vaner <michal.vaner at nic.cz>
Date:   Thu May 12 11:49:47 2011 +0200

    Merge branch 'work/log/datasrc'

-----------------------------------------------------------------------

Summary of changes:
 src/lib/datasrc/Makefile.am                        |   15 +-
 src/lib/datasrc/cache.cc                           |   23 +-
 src/lib/datasrc/data_source.cc                     |   76 +++-
 .../tests/run_unittests.cc => datasrc/logger.cc}   |   11 +-
 src/lib/{config/config_log.h => datasrc/logger.h}  |   40 +-
 src/lib/datasrc/memory_datasrc.cc                  |   60 +++
 src/lib/datasrc/messagedef.mes                     |  498 ++++++++++++++++++++
 src/lib/datasrc/sqlite3_datasrc.cc                 |   37 ++-
 src/lib/datasrc/static_datasrc.cc                  |    5 +
 src/lib/datasrc/tests/Makefile.am                  |    6 +-
 .../tests/logger_unittest.cc}                      |   21 +-
 src/lib/log/log_formatter.h                        |    6 +-
 12 files changed, 757 insertions(+), 41 deletions(-)
 copy src/lib/{util/io/tests/run_unittests.cc => datasrc/logger.cc} (85%)
 copy src/lib/{config/config_log.h => datasrc/logger.h} (55%)
 create mode 100644 src/lib/datasrc/messagedef.mes
 copy src/lib/{nsas/tests/fetchable_unittest.cc => datasrc/tests/logger_unittest.cc} (69%)

-----------------------------------------------------------------------
diff --git a/src/lib/datasrc/Makefile.am b/src/lib/datasrc/Makefile.am
index adb1d41..e028186 100644
--- a/src/lib/datasrc/Makefile.am
+++ b/src/lib/datasrc/Makefile.am
@@ -7,7 +7,7 @@ AM_CPPFLAGS += $(SQLITE_CFLAGS)
 
 AM_CXXFLAGS = $(B10_CXXFLAGS)
 
-CLEANFILES = *.gcno *.gcda
+CLEANFILES = *.gcno *.gcda messagedef.h messagedef.cc
 
 lib_LTLIBRARIES = libdatasrc.la
 libdatasrc_la_SOURCES = data_source.h data_source.cc
@@ -20,3 +20,16 @@ libdatasrc_la_SOURCES += zonetable.h zonetable.cc
 libdatasrc_la_SOURCES += memory_datasrc.h memory_datasrc.cc
 libdatasrc_la_SOURCES += zone.h
 libdatasrc_la_SOURCES += result.h
+libdatasrc_la_SOURCES += logger.h logger.cc
+nodist_libdatasrc_la_SOURCES = messagedef.h messagedef.cc
+
+libdatasrc_la_LIBADD = $(top_builddir)/src/lib/exceptions/libexceptions.la
+libdatasrc_la_LIBADD += $(top_builddir)/src/lib/dns/libdns++.la
+libdatasrc_la_LIBADD += $(top_builddir)/src/lib/log/liblog.la
+libdatasrc_la_LIBADD += $(top_builddir)/src/lib/cc/libcc.la
+
+BUILT_SOURCES = messagedef.h messagedef.cc
+messagedef.h messagedef.cc: Makefile messagedef.mes
+	$(top_builddir)/src/lib/log/compiler/message $(top_srcdir)/src/lib/datasrc/messagedef.mes
+
+EXTRA_DIST = messagedef.mes
diff --git a/src/lib/datasrc/cache.cc b/src/lib/datasrc/cache.cc
index 6fff754..8e9487d 100644
--- a/src/lib/datasrc/cache.cc
+++ b/src/lib/datasrc/cache.cc
@@ -24,6 +24,7 @@
 #include <list>
 
 #include <datasrc/cache.h>
+#include <datasrc/logger.h>
 
 using namespace std;
 using namespace isc::dns;
@@ -204,16 +205,21 @@ public:
 // HotCacheImpl constructor
 HotCacheImpl::HotCacheImpl(int slots, bool enabled) :
     enabled_(enabled), slots_(slots), count_(0)
-{}
+{
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_CACHE_CREATE);
+}
 
 // Insert a cache node into the cache
 inline void
 HotCacheImpl::insert(const CacheNodePtr node) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_INSERT).
+        arg(node->getRRset()->getName());
     std::map<Question, CacheNodePtr>::const_iterator iter;
     iter = map_.find(node->question);
     if (iter != map_.end()) {
         CacheNodePtr old = iter->second;
         if (old && old->isValid()) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_OLD_FOUND);
             remove(old);
         }
     }
@@ -225,6 +231,7 @@ HotCacheImpl::insert(const CacheNodePtr node) {
     ++count_;
 
     if (slots_ != 0 && count_ > slots_) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_FULL);
         remove(lru_.back());
     }
 }
@@ -245,6 +252,8 @@ HotCacheImpl::promote(CacheNodePtr node) {
 // Remove a node from the LRU list and the map
 void
 HotCacheImpl::remove(ConstCacheNodePtr node) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_REMOVE).
+        arg(node->getRRset()->getName());
     lru_.erase(node->lru_entry_);
     map_.erase(node->question);
     --count_;
@@ -257,6 +266,7 @@ HotCache::HotCache(const int slots) {
 
 // HotCache destructor
 HotCache::~HotCache() {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_CACHE_DESTROY);
     delete impl_;
 }
 
@@ -303,18 +313,21 @@ HotCache::retrieve(const Name& n, const RRClass& c, const RRType& t,
     std::map<Question, CacheNodePtr>::const_iterator iter;
     iter = impl_->map_.find(Question(n, c, t));
     if (iter == impl_->map_.end()) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_NOT_FOUND).arg(n);
         return (false);
     }
 
     CacheNodePtr node = iter->second;
 
     if (node->isValid()) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_FOUND).arg(n);
         impl_->promote(node);
         rrset = node->getRRset();
         flags = node->getFlags();
         return (true);
     }
 
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_CACHE_EXPIRED).arg(n);
     impl_->remove(node);
     return (false);
 }
@@ -328,6 +341,9 @@ HotCache::setSlots(const int slots) {
         return;
     }
 
+    logger.info(DATASRC_CACHE_SLOTS).arg(slots).arg(max(0, impl_->count_ -
+                                                        slots));
+
     while (impl_->slots_ != 0 && impl_->count_ > impl_->slots_) {
         impl_->remove(impl_->lru_.back());
     }
@@ -343,6 +359,11 @@ HotCache::getSlots() const {
 void
 HotCache::setEnabled(const bool e) {
     impl_->enabled_ = e;
+    if (e) {
+        logger.info(DATASRC_CACHE_ENABLE);
+    } else {
+        logger.info(DATASRC_CACHE_DISABLE);
+    }
 }
 
 /// Indicate whether the cache is enabled
diff --git a/src/lib/datasrc/data_source.cc b/src/lib/datasrc/data_source.cc
index 548a811..4e1fcde 100644
--- a/src/lib/datasrc/data_source.cc
+++ b/src/lib/datasrc/data_source.cc
@@ -25,6 +25,7 @@
 #include <datasrc/cache.h>
 #include <datasrc/data_source.h>
 #include <datasrc/query.h>
+#include <datasrc/logger.h>
 
 #include <util/encode/base32hex.h>
 #include <util/hash/sha1.h>
@@ -83,7 +84,7 @@ class ZoneInfo {
 public:
     ZoneInfo(DataSrc* ts,
              const isc::dns::Name& n,
-             const isc::dns::RRClass& c, 
+             const isc::dns::RRClass& c,
              const isc::dns::RRType& t = isc::dns::RRType::ANY()) :
         top_source_(ts),
         dsm_(((t == RRType::DS() && n.getLabelCount() != 1)
@@ -123,6 +124,8 @@ getAdditional(Query& q, ConstRRsetPtr rrset) {
         const Rdata& rd(it->getCurrent());
         if (rrset->getType() == RRType::NS()) {
             const generic::NS& ns = dynamic_cast<const generic::NS&>(rd);
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_GET_NS_ADDITIONAL).
+                arg(ns.getNSName()).arg(rrset->getName());
             q.tasks().push(QueryTaskPtr(
                                new QueryTask(q, ns.getNSName(),
                                              Message::SECTION_ADDITIONAL,
@@ -130,6 +133,8 @@ getAdditional(Query& q, ConstRRsetPtr rrset) {
                                              QueryTask::GETADDITIONAL)));
         } else if (rrset->getType() == RRType::MX()) {
             const generic::MX& mx = dynamic_cast<const generic::MX&>(rd);
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_GET_MX_ADDITIONAL).
+                arg(mx.getMXName()).arg(rrset->getName());
             q.tasks().push(QueryTaskPtr(
                                new QueryTask(q, mx.getMXName(),
                                              Message::SECTION_ADDITIONAL,
@@ -143,11 +148,14 @@ getAdditional(Query& q, ConstRRsetPtr rrset) {
 // understand DNAME
 void
 synthesizeCname(QueryTaskPtr task, RRsetPtr rrset, RRsetList& target) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_SYNTH_CNAME).
+        arg(rrset->getName());
     RdataIteratorPtr it = rrset->getRdataIterator();
 
     // More than one DNAME RR in the RRset is illegal, so we only have
     // to process the first one.
     if (it->isLast()) {
+        logger.error(DATASRC_QUERY_EMPTY_DNAME).arg(rrset->getName());
         return;
     }
 
@@ -171,16 +179,20 @@ synthesizeCname(QueryTaskPtr task, RRsetPtr rrset, RRsetList& target) {
 // to by a CNAME record
 void
 chaseCname(Query& q, QueryTaskPtr task, RRsetPtr rrset) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_FOLLOW_CNAME).
+        arg(rrset->getName());
     RdataIteratorPtr it = rrset->getRdataIterator();
 
     // More than one CNAME RR in the RRset is illegal, so we only have
     // to process the first one.
     if (it->isLast()) {
+        logger.error(DATASRC_QUERY_EMPTY_CNAME).arg(rrset->getName());
         return;
     }
 
     // Stop chasing CNAMES after 16 lookups, to prevent loops
     if (q.tooMany()) {
+        logger.error(DATASRC_QUERY_TOO_MANY_CNAMES).arg(rrset->getName());
         return;
     }
 
@@ -194,6 +206,8 @@ chaseCname(Query& q, QueryTaskPtr task, RRsetPtr rrset) {
 // Check the cache for data which can answer the current query task.
 bool
 checkCache(QueryTask& task, RRsetList& target) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_CHECK_CACHE).
+        arg(task.qname).arg(task.qtype);
     HotCache& cache = task.q.getCache();
     RRsetList rrsets;
     RRsetPtr rrset;
@@ -206,6 +220,9 @@ checkCache(QueryTask& task, RRsetList& target) {
         // ANY queries must be handled by the low-level data source,
         // or the results won't be guaranteed to be complete
         if (task.qtype == RRType::ANY() || task.qclass == RRClass::ANY()) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA,
+                      DATASRC_QUERY_NO_CACHE_ANY_SIMPLE).arg(task.qname).
+                arg(task.qtype).arg(task.qclass);
             break;
         }
 
@@ -235,6 +252,8 @@ checkCache(QueryTask& task, RRsetList& target) {
 
     case QueryTask::AUTH_QUERY:         // Find exact RRset or CNAME
         if (task.qtype == RRType::ANY() || task.qclass == RRClass::ANY()) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_NO_CACHE_ANY_AUTH).
+                arg(task.qname).arg(task.qtype).arg(task.qclass);
             break;
         }
 
@@ -353,6 +372,8 @@ DataSrc::Result
 doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
     HotCache& cache = task.q.getCache();
     RRsetPtr rrset;
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_DO_QUERY).arg(task.qname).
+        arg(task.qtype);
 
     // First off, make sure at least we have a matching zone in some data
     // source.  We must do this before checking the cache, because it can
@@ -363,11 +384,14 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
     const Name* const zonename = zoneinfo.getEnclosingZone();
     if (ds == NULL) {
         task.flags |= DataSrc::NO_SUCH_ZONE;
+        logger.info(DATASRC_QUERY_NO_ZONE).arg(task.qname).arg(task.qclass);
         return (DataSrc::SUCCESS);
     }
 
     // Then check the cache for matching data
     if (checkCache(task, target)) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_CACHED).
+            arg(task.qname).arg(task.qtype);
         return (DataSrc::SUCCESS);
     }
 
@@ -378,10 +402,13 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
     DataSrc::Result result;
     switch (task.op) {
     case QueryTask::SIMPLE_QUERY:
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_IS_SIMPLE).
+            arg(task.qname).arg(task.qtype);
         result = ds->findExactRRset(task.qname, task.qclass, task.qtype,
                                     target, task.flags, zonename);
 
         if (result != DataSrc::SUCCESS) {
+            logger.error(DATASRC_QUERY_SIMPLE_FAIL).arg(result);
             return (result);
         }
 
@@ -403,10 +430,13 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
         return (result);
 
     case QueryTask::AUTH_QUERY:
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_IS_AUTH).
+            arg(task.qname).arg(task.qtype);
         result = ds->findRRset(task.qname, task.qclass, task.qtype,
                                target, task.flags, zonename);
 
         if (result != DataSrc::SUCCESS) {
+            logger.error(DATASRC_QUERY_AUTH_FAIL).arg(result);
             return (result);
         }
 
@@ -439,10 +469,16 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
 
     case QueryTask::GLUE_QUERY:
     case QueryTask::NOGLUE_QUERY:
+        LOG_DEBUG(logger, DBG_TRACE_DATA, task.op == QueryTask::GLUE_QUERY ?
+                     DATASRC_QUERY_IS_GLUE : DATASRC_QUERY_IS_NOGLUE).
+            arg(task.qname).arg(task.qtype);
         result = ds->findAddrs(task.qname, task.qclass, target,
                                task.flags, zonename);
 
         if (result != DataSrc::SUCCESS) {
+            logger.error(task.op == QueryTask::GLUE_QUERY ?
+                         DATASRC_QUERY_GLUE_FAIL : DATASRC_QUERY_NOGLUE_FAIL).
+                arg(result);
             return (result);
         }
 
@@ -468,10 +504,13 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
         return (result);
 
     case QueryTask::REF_QUERY:
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_IS_REF).
+            arg(task.qname).arg(task.qtype);
         result = ds->findReferral(task.qname, task.qclass, target,
                                  task.flags, zonename);
 
         if (result != DataSrc::SUCCESS) {
+            logger.error(DATASRC_QUERY_REF_FAIL).arg(result);
             return (result);
         }
 
@@ -505,6 +544,7 @@ doQueryTask(QueryTask& task, ZoneInfo& zoneinfo, RRsetList& target) {
     }
 
     // Not reached
+    logger.error(DATASRC_QUERY_INVALID_OP);
     return (DataSrc::ERROR);
 }
 
@@ -516,6 +556,8 @@ inline void
 addToMessage(Query& q, const Message::Section sect, RRsetPtr rrset,
              bool no_dnssec = false)
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_ADD_RRSET).
+        arg(rrset->getName()).arg(rrset->getType());
     Message& m = q.message();
     if (no_dnssec) {
         if (rrset->getType() == RRType::RRSIG() ||
@@ -534,6 +576,7 @@ addToMessage(Query& q, const Message::Section sect, RRsetPtr rrset,
 // Copy referral information into the authority section of a message
 inline void
 copyAuth(Query& q, RRsetList& auth) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_COPY_AUTH);
     BOOST_FOREACH(RRsetPtr rrset, auth) {
         if (rrset->getType() == RRType::DNAME()) {
             continue;
@@ -571,6 +614,9 @@ refQuery(const Query& q, const Name& name, ZoneInfo& zoneinfo,
 // they'll be handled in a normal lookup in the zone.
 inline bool
 hasDelegation(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_DELEGATION).
+        arg(task->qname);
+
     const Name* const zonename = zoneinfo.getEnclosingZone();
     if (zonename == NULL) {
         if (task->state == QueryTask::GETANSWER) {
@@ -636,6 +682,7 @@ addSOA(Query& q, ZoneInfo& zoneinfo) {
     RRsetList soa;
 
     const Name* const zonename = zoneinfo.getEnclosingZone();
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_ADD_SOA).arg(*zonename);
     QueryTask newtask(q, *zonename, RRType::SOA(), QueryTask::SIMPLE_QUERY);
     RETERR(doQueryTask(newtask, zoneinfo, soa));
     if (newtask.flags != 0) {
@@ -649,6 +696,7 @@ addSOA(Query& q, ZoneInfo& zoneinfo) {
 
 inline DataSrc::Result
 addNSEC(Query& q, const Name& name, ZoneInfo& zoneinfo) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_ADD_NSEC).arg(name);
     RRsetList nsec;
 
     QueryTask newtask(q, name, RRType::NSEC(), QueryTask::SIMPLE_QUERY); 
@@ -665,9 +713,11 @@ inline DataSrc::Result
 getNsec3(Query& q, ZoneInfo& zoneinfo, string& hash, RRsetPtr& target) {
     const DataSrc* ds = zoneinfo.getDataSource();
     const Name* const zonename = zoneinfo.getEnclosingZone();
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_ADD_NSEC3).arg(*zonename);
 
     if (ds == NULL) {
         q.message().setRcode(Rcode::SERVFAIL());
+        logger.error(DATASRC_QUERY_NO_DS_NSEC3).arg(*zonename);
         return (DataSrc::ERROR);
     }
 
@@ -770,6 +820,7 @@ proveNX(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, const bool wildcard) {
             const DataSrc* ds = zoneinfo.getDataSource();
             if (ds == NULL) {
                 m.setRcode(Rcode::SERVFAIL());
+                logger.error(DATASRC_QUERY_NO_DS_NSEC).arg(*zonename);
                 return (DataSrc::ERROR);
             }
             ds->findPreviousName(task->qname, nsecname, zonename);
@@ -798,6 +849,7 @@ proveNX(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, const bool wildcard) {
 // Attempt a wildcard lookup
 inline DataSrc::Result
 tryWildcard(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, bool& found) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_QUERY_WILDCARD).arg(task->qname);
     Message& m = q.message();
     DataSrc::Result result;
     found = false;
@@ -851,6 +903,8 @@ tryWildcard(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, bool& found) {
             result = proveNX(q, task, zoneinfo, true);
             if (result != DataSrc::SUCCESS) {
                 m.setRcode(Rcode::SERVFAIL());
+                logger.error(DATASRC_QUERY_WILDCARD_PROVENX_FAIL).
+                    arg(task->qname).arg(result);
                 return (DataSrc::ERROR);
             }
         }
@@ -873,6 +927,8 @@ tryWildcard(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, bool& found) {
 
             RRsetList auth;
             if (!refQuery(q, *zonename, zoneinfo, auth)) {
+                logger.error(DATASRC_QUERY_WILDCARD_REFERRAL).arg(task->qname).
+                    arg(result);
                 return (DataSrc::ERROR);
             }
 
@@ -888,6 +944,8 @@ tryWildcard(Query& q, QueryTaskPtr task, ZoneInfo& zoneinfo, bool& found) {
 // 
 void
 DataSrc::doQuery(Query& q) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_QUERY_PROCESS).arg(q.qname()).
+        arg(q.qclass());
     Message& m = q.message();
     vector<RRsetPtr> additional;
 
@@ -905,6 +963,7 @@ DataSrc::doQuery(Query& q) {
         // Can't query directly for RRSIG.
         if (task->qtype == RRType::RRSIG()) {
             m.setRcode(Rcode::REFUSED());
+            logger.warn(DATASRC_QUERY_RRSIG).arg(task->qname);
             return;
         }
 
@@ -912,6 +971,7 @@ DataSrc::doQuery(Query& q) {
         if (task->op == QueryTask::SIMPLE_QUERY ||
             task->op == QueryTask::REF_QUERY) {
             m.setRcode(Rcode::SERVFAIL());
+            logger.error(DATASRC_QUERY_MISPLACED_TASK);
             return;
         }
 
@@ -931,6 +991,7 @@ DataSrc::doQuery(Query& q) {
         result = doQueryTask(*task, zoneinfo, data);
         if (result != SUCCESS) {
             m.setRcode(Rcode::SERVFAIL());
+            logger.error(DATASRC_QUERY_TASK_FAIL).arg(result);
             return;
         }
 
@@ -940,6 +1001,7 @@ DataSrc::doQuery(Query& q) {
         if (task->flags == NO_SUCH_ZONE) {
             if (task->state == QueryTask::GETANSWER) {
                 m.setRcode(Rcode::REFUSED());
+                // No need to log it here, it was already logged in doQueryTask
                 return;
             }
             continue;
@@ -981,6 +1043,7 @@ DataSrc::doQuery(Query& q) {
                     RRsetList auth;
                     if (!refQuery(q, Name(*zonename), zoneinfo, auth) ||
                         !findRRsetFromList(auth, RRType::NS())) {
+                        logger.error(DATASRC_QUERY_MISSING_NS).arg(*zonename);
                         isc_throw(DataSourceError,
                                   "NS RR not found in " << *zonename << "/" <<
                                   q.qclass());
@@ -1005,10 +1068,12 @@ DataSrc::doQuery(Query& q) {
                 continue;
 
             default:
+                logger.error(DATASRC_UNEXPECTED_QUERY_STATE);
                 isc_throw (Unexpected, "unexpected query state");
             }
         } else if (result == ERROR || result == NOT_IMPLEMENTED) {
             m.setRcode(Rcode::SERVFAIL());
+            logger.error(DATASRC_QUERY_FAIL);
             return;
         } else if ((task->flags & CNAME_FOUND) != 0) {
             // The qname node contains a CNAME.  Add a new task to the
@@ -1026,6 +1091,7 @@ DataSrc::doQuery(Query& q) {
                 m.setHeaderFlag(Message::HEADERFLAG_AA, false);
                 if (!refQuery(q, task->qname, zoneinfo, auth)) {
                     m.setRcode(Rcode::SERVFAIL());
+                    logger.error(DATASRC_QUERY_BAD_REFERRAL).arg(task->qname);
                     return;
                 }
                 BOOST_FOREACH (RRsetPtr rrset, auth) {
@@ -1057,6 +1123,7 @@ DataSrc::doQuery(Query& q) {
             result = tryWildcard(q, task, zoneinfo, wildcard_found);
             if (result != SUCCESS) {
                 m.setRcode(Rcode::SERVFAIL());
+                logger.error(DATASRC_QUERY_WILDCARD_FAIL).arg(task->qname);
                 return;
             }
 
@@ -1078,6 +1145,7 @@ DataSrc::doQuery(Query& q) {
 
                 result = addSOA(q, zoneinfo);
                 if (result != SUCCESS) {
+                    logger.error(DATASRC_QUERY_MISSING_SOA).arg(*zonename);
                     isc_throw(DataSourceError,
                               "SOA RR not found in " << *zonename <<
                               "/" << q.qclass());
@@ -1094,6 +1162,7 @@ DataSrc::doQuery(Query& q) {
                 result = proveNX(q, task, zoneinfo, false);
                 if (result != DataSrc::SUCCESS) {
                     m.setRcode(Rcode::SERVFAIL());
+                    logger.error(DATASRC_QUERY_PROVENX_FAIL).arg(task->qname);
                     return;
                 }
             }
@@ -1102,6 +1171,7 @@ DataSrc::doQuery(Query& q) {
         } else {
             // Should never be reached!
             m.setRcode(Rcode::SERVFAIL());
+            logger.error(DATASRC_QUERY_UNKNOWN_RESULT);
             return;
         }
     }
@@ -1197,7 +1267,10 @@ DataSrc::findReferral(const Name& qname, const RRClass& qclass,
 
 void
 MetaDataSrc::addDataSrc(ConstDataSrcPtr data_src) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_META_ADD);
     if (getClass() != RRClass::ANY() && data_src->getClass() != getClass()) {
+        logger.error(DATASRC_META_ADD_CLASS_MISMATCH).
+            arg(data_src->getClass()).arg(getClass());
         isc_throw(Unexpected, "class mismatch");
     }
 
@@ -1206,6 +1279,7 @@ MetaDataSrc::addDataSrc(ConstDataSrcPtr data_src) {
 
 void
 MetaDataSrc::removeDataSrc(ConstDataSrcPtr data_src) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_META_REMOVE);
     std::vector<ConstDataSrcPtr>::iterator it, itr;
     for (it = data_sources.begin(); it != data_sources.end(); ++it) {
         if (*it == data_src) {
diff --git a/src/lib/datasrc/logger.cc b/src/lib/datasrc/logger.cc
new file mode 100644
index 0000000..846e43b
--- /dev/null
+++ b/src/lib/datasrc/logger.cc
@@ -0,0 +1,23 @@
+// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#include <datasrc/logger.h>
+
+namespace isc {
+namespace datasrc {
+
+isc::log::Logger logger("datasrc");
+
+}
+}
diff --git a/src/lib/datasrc/logger.h b/src/lib/datasrc/logger.h
new file mode 100644
index 0000000..7c2828d
--- /dev/null
+++ b/src/lib/datasrc/logger.h
@@ -0,0 +1,46 @@
+// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#ifndef __DATASRC_LOGGER_H
+#define __DATASRC_LOGGER_H
+
+#include <log/macros.h>
+#include <datasrc/messagedef.h>
+
+/// \file logger.h
+/// \brief Data Source library global logger
+///
+/// This holds the logger for the data source library. It is a private header
+/// and should not be included in any publicly used header, only in local
+/// cc files.
+
+namespace isc {
+namespace datasrc {
+
+/// \brief The logger for this library
+extern isc::log::Logger logger;
+
+enum {
+    /// \brief Trace basic operations
+    DBG_TRACE_BASIC = 10,
+    /// \brief Trace data changes and lookups as well
+    DBG_TRACE_DATA = 20,
+    /// \brief Detailed even about how the lookups happen
+    DBG_TRACE_DETAILED = 50
+};
+
+}
+}
+
+#endif
diff --git a/src/lib/datasrc/memory_datasrc.cc b/src/lib/datasrc/memory_datasrc.cc
index 5230ced..3c57d1b 100644
--- a/src/lib/datasrc/memory_datasrc.cc
+++ b/src/lib/datasrc/memory_datasrc.cc
@@ -24,6 +24,7 @@
 
 #include <datasrc/memory_datasrc.h>
 #include <datasrc/rbtree.h>
+#include <datasrc/logger.h>
 
 using namespace std;
 using namespace isc::dns;
@@ -94,6 +95,8 @@ struct MemoryZone::MemoryZoneImpl {
              l > origin_labels;
              --l, wname = wname.split(1)) {
             if (wname.isWildcard()) {
+                LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_ADD_WILDCARD).
+                    arg(name);
                 // Ensure a separate level exists for the "wildcarding" name,
                 // and mark the node as "wild".
                 DomainNode* node;
@@ -130,10 +133,13 @@ struct MemoryZone::MemoryZoneImpl {
             // (depending on how we support DNSSEC).  We should revisit it
             // at that point.
             if (!domain->empty()) {
+                LOG_ERROR(logger, DATASRC_MEM_CNAME_TO_NONEMPTY).
+                    arg(rrset->getName());
                 isc_throw(AddError, "CNAME can't be added with other data for "
                           << rrset->getName());
             }
         } else if (domain->find(RRType::CNAME()) != domain->end()) {
+            LOG_ERROR(logger, DATASRC_MEM_CNAME_COEXIST).arg(rrset->getName());
             isc_throw(AddError, "CNAME and " << rrset->getType() <<
                       " can't coexist for " << rrset->getName());
         }
@@ -151,6 +157,7 @@ struct MemoryZone::MemoryZoneImpl {
             (rrset->getType() == RRType::NS() &&
             domain->find(RRType::DNAME()) != domain->end())))
         {
+            LOG_ERROR(logger, DATASRC_MEM_DNAME_NS).arg(rrset->getName());
             isc_throw(AddError, "DNAME can't coexist with NS in non-apex "
                 "domain " << rrset->getName());
         }
@@ -172,6 +179,8 @@ struct MemoryZone::MemoryZoneImpl {
             // XXX: this is not only for CNAME or DNAME. We should generalize
             // this code for all other "singleton RR types" (such as SOA) in a
             // separate task.
+            LOG_ERROR(logger, DATASRC_MEM_SINGLETON).arg(rrset->getName()).
+                arg(rrset->getType());
             isc_throw(AddError, "multiple RRs of singleton type for "
                       << rrset->getName());
         }
@@ -180,6 +189,8 @@ struct MemoryZone::MemoryZoneImpl {
         if (compare.getRelation() != NameComparisonResult::SUPERDOMAIN &&
             compare.getRelation() != NameComparisonResult::EQUAL)
         {
+            LOG_ERROR(logger, DATASRC_MEM_OUT_OF_ZONE).arg(rrset->getName()).
+                arg(origin_);
             isc_throw(OutOfZone, "The name " << rrset->getName() <<
                 " is not contained in zone " << origin_);
         }
@@ -194,10 +205,14 @@ struct MemoryZone::MemoryZoneImpl {
         // behavior.
         if (rrset->getName().isWildcard()) {
             if (rrset->getType() == RRType::NS()) {
+                LOG_ERROR(logger, DATASRC_MEM_WILDCARD_NS).
+                    arg(rrset->getName());
                 isc_throw(AddError, "Invalid NS owner name (wildcard): " <<
                           rrset->getName());
             }
             if (rrset->getType() == RRType::DNAME()) {
+                LOG_ERROR(logger, DATASRC_MEM_WILDCARD_DNAME).
+                    arg(rrset->getName());
                 isc_throw(AddError, "Invalid DNAME owner name (wildcard): " <<
                           rrset->getName());
             }
@@ -210,6 +225,8 @@ struct MemoryZone::MemoryZoneImpl {
      */
     // Implementation of MemoryZone::add
     result::Result add(const ConstRRsetPtr& rrset, DomainTree* domains) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_ADD_RRSET).
+            arg(rrset->getName()).arg(rrset->getType()).arg(origin_);
         // Sanitize input
         addValidation(rrset);
 
@@ -271,6 +288,8 @@ struct MemoryZone::MemoryZoneImpl {
     void addFromLoad(const ConstRRsetPtr& set, DomainTree* domains) {
             switch (add(set, domains)) {
                 case result::EXIST:
+                    LOG_ERROR(logger, DATASRC_MEM_DUP_RRSET).
+                        arg(set->getName()).arg(set->getType());
                     isc_throw(dns::MasterLoadError, "Duplicate rrset: " <<
                         set->toText());
                 case result::SUCCESS:
@@ -307,6 +326,8 @@ struct MemoryZone::MemoryZoneImpl {
         const Domain::const_iterator foundDNAME(node.getData()->find(
             RRType::DNAME()));
         if (foundDNAME != node.getData()->end()) {
+            LOG_DEBUG(logger, DBG_TRACE_DETAILED,
+                      DATASRC_MEM_DNAME_ENCOUNTERED);
             state->dname_node_ = &node;
             state->rrset_ = foundDNAME->second;
             // No more processing below the DNAME (RFC 2672, section 3
@@ -328,6 +349,8 @@ struct MemoryZone::MemoryZoneImpl {
                 return (false);
             }
 
+            LOG_DEBUG(logger, DBG_TRACE_DETAILED, DATASRC_MEM_NS_ENCOUNTERED);
+
             // BIND 9 checks if this node is not the origin.  That's probably
             // because it can support multiple versions for dynamic updates
             // and IXFR, and it's possible that the callback is called at
@@ -363,6 +386,8 @@ struct MemoryZone::MemoryZoneImpl {
         rrset, bool rename)
     {
         if (rename) {
+            LOG_DEBUG(logger, DBG_TRACE_DETAILED, DATASRC_MEM_RENAME).
+                arg(rrset->getName()).arg(name);
             /*
              * We lose a signature here. But it would be wrong anyway, because
              * the name changed. This might turn out to be unimportant in
@@ -385,6 +410,8 @@ struct MemoryZone::MemoryZoneImpl {
     FindResult find(const Name& name, RRType type,
                     RRsetList* target, const FindOptions options) const
     {
+        LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_FIND).arg(name).
+            arg(type);
         // Get the node
         DomainNode* node(NULL);
         FindState state(options);
@@ -411,12 +438,16 @@ struct MemoryZone::MemoryZoneImpl {
                  * is NULL.
                  */
                 if (state.dname_node_ != NULL) {
+                    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_DNAME_FOUND).
+                        arg(state.rrset_->getName());
                     // We were traversing a DNAME node (and wanted to go
                     // lower below it), so return the DNAME
                     return (FindResult(DNAME, prepareRRset(name, state.rrset_,
                         rename)));
                 }
                 if (state.zonecut_node_ != NULL) {
+                    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_DELEG_FOUND).
+                        arg(state.rrset_->getName());
                     return (FindResult(DELEGATION, prepareRRset(name,
                         state.rrset_, rename)));
                 }
@@ -426,6 +457,8 @@ struct MemoryZone::MemoryZoneImpl {
                 // the zone but is empty.  Treat it as NXRRSET.
                 if (node_path.getLastComparisonResult().getRelation() ==
                     NameComparisonResult::SUPERDOMAIN) {
+                    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_SUPER_STOP).
+                        arg(node_path.getAbsoluteName()).arg(name);
                     return (FindResult(NXRRSET, ConstRRsetPtr()));
                 }
 
@@ -463,6 +496,8 @@ struct MemoryZone::MemoryZoneImpl {
                     if (node_path.getLastComparisonResult().getRelation() ==
                         NameComparisonResult::COMMONANCESTOR && node_path.
                         getLastComparisonResult().getCommonLabels() > 1) {
+                        LOG_DEBUG(logger, DBG_TRACE_DATA,
+                                     DATASRC_MEM_WILDCARD_CANCEL).arg(name);
                         return (FindResult(NXDOMAIN, ConstRRsetPtr()));
                     }
                     Name wildcard(Name("*").concatenate(
@@ -485,6 +520,8 @@ struct MemoryZone::MemoryZoneImpl {
 
                 // fall through
             case DomainTree::NOTFOUND:
+                LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_NOTFOUND).
+                    arg(name);
                 return (FindResult(NXDOMAIN, ConstRRsetPtr()));
             case DomainTree::EXACTMATCH: // This one is OK, handle it
                 break;
@@ -496,6 +533,8 @@ struct MemoryZone::MemoryZoneImpl {
         // If there is an exact match but the node is empty, it's equivalent
         // to NXRRSET.
         if (node->isEmpty()) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_DOMAIN_EMPTY).
+                arg(name);
             return (FindResult(NXRRSET, ConstRRsetPtr()));
         }
 
@@ -506,6 +545,8 @@ struct MemoryZone::MemoryZoneImpl {
         if (node->getFlag(DomainNode::FLAG_CALLBACK) && node != origin_data_) {
             found = node->getData()->find(RRType::NS());
             if (found != node->getData()->end()) {
+                LOG_DEBUG(logger, DBG_TRACE_DATA,
+                          DATASRC_MEM_EXACT_DELEGATION).arg(name);
                 return (FindResult(DELEGATION, prepareRRset(name,
                     found->second, rename)));
             }
@@ -521,23 +562,30 @@ struct MemoryZone::MemoryZoneImpl {
                     boost::const_pointer_cast<RRset>(prepareRRset(name,
                     found->second, rename)));
             }
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_ANY_SUCCESS).
+                arg(name);
             return (FindResult(SUCCESS, ConstRRsetPtr()));
         }
 
         found = node->getData()->find(type);
         if (found != node->getData()->end()) {
             // Good, it is here
+            LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_SUCCESS).arg(name).
+                arg(type);
             return (FindResult(SUCCESS, prepareRRset(name, found->second,
                 rename)));
         } else {
             // Next, try CNAME.
             found = node->getData()->find(RRType::CNAME());
             if (found != node->getData()->end()) {
+                LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_CNAME).arg(name);
                 return (FindResult(CNAME, prepareRRset(name, found->second,
                     rename)));
             }
         }
         // No exact match or CNAME.  Return NXRRSET.
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_NXRRSET).arg(type).
+            arg(name);
         return (FindResult(NXRRSET, ConstRRsetPtr()));
     }
 };
@@ -545,9 +593,13 @@ struct MemoryZone::MemoryZoneImpl {
 MemoryZone::MemoryZone(const RRClass& zone_class, const Name& origin) :
     impl_(new MemoryZoneImpl(zone_class, origin))
 {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_CREATE).arg(origin).
+        arg(zone_class);
 }
 
 MemoryZone::~MemoryZone() {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_DESTROY).arg(getOrigin()).
+        arg(getClass());
     delete impl_;
 }
 
@@ -576,6 +628,8 @@ MemoryZone::add(const ConstRRsetPtr& rrset) {
 
 void
 MemoryZone::load(const string& filename) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_LOAD).arg(getOrigin()).
+        arg(filename);
     // Load it into a temporary tree
     MemoryZoneImpl::DomainTree tmp;
     masterLoad(filename.c_str(), getOrigin(), getClass(),
@@ -588,6 +642,8 @@ MemoryZone::load(const string& filename) {
 
 void
 MemoryZone::swap(MemoryZone& zone) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_SWAP).arg(getOrigin()).
+        arg(zone.getOrigin());
     std::swap(impl_, zone.impl_);
 }
 
@@ -628,6 +684,9 @@ MemoryDataSrc::addZone(ZonePtr zone) {
                   "Null pointer is passed to MemoryDataSrc::addZone()");
     }
 
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_MEM_ADD_ZONE).
+        arg(zone->getOrigin()).arg(zone->getClass().toText());
+
     const result::Result result = impl_->zone_table.addZone(zone);
     if (result == result::SUCCESS) {
         ++impl_->zone_count;
@@ -637,6 +696,7 @@ MemoryDataSrc::addZone(ZonePtr zone) {
 
 MemoryDataSrc::FindResult
 MemoryDataSrc::findZone(const isc::dns::Name& name) const {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_MEM_FIND_ZONE).arg(name);
     return (FindResult(impl_->zone_table.findZone(name).code,
                        impl_->zone_table.findZone(name).zone));
 }
diff --git a/src/lib/datasrc/messagedef.mes b/src/lib/datasrc/messagedef.mes
new file mode 100644
index 0000000..2fc5c6b
--- /dev/null
+++ b/src/lib/datasrc/messagedef.mes
@@ -0,0 +1,498 @@
+# Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and/or distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+# REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+# AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+# LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+# OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+# PERFORMANCE OF THIS SOFTWARE.
+
+$PREFIX DATASRC_
+$NAMESPACE isc::datasrc
+
+# \brief Messages for the data source library
+
+% CACHE_CREATE creating the hotspot cache
+Debug information that the hotspot cache was created at startup.
+
+% CACHE_DESTROY destroying the hotspot cache
+Debug information. The hotspot cache is being destroyed.
+
+% CACHE_INSERT inserting item '%1' into the cache
+Debug information. It means a new item is being inserted into the hotspot
+cache.
+
+% CACHE_OLD_FOUND older instance of cache item found, replacing
+Debug information. While inserting an item into the hotspot cache, an older
+instance of an item with the same name was found. The old instance will be
+removed. This should be directly followed by CACHE_REMOVE.
+
+% CACHE_FULL cache is full, dropping oldest
+Debug information. After inserting an item into the hotspot cache, the
+maximum number of items was exceeded, so the least recently used item will
+be dropped. This should be directly followed by CACHE_REMOVE.
+
+% CACHE_REMOVE removing '%1' from the cache
+Debug information. An item is being removed from the hotspot cache.
+
+% CACHE_NOT_FOUND the item '%1' was not found
+Debug information. It was attempted to look up an item in the hotspot cache,
+but it is not there.
+
+% CACHE_FOUND the item '%1' was found
+Debug information. An item was successfully looked up in the hotspot cache.
+
+% CACHE_EXPIRED the item '%1' is expired
+Debug information. There was an attempt to look up an item in the hotspot
+cache. And the item was actually there, but it was too old, so it was removed
+instead and nothing is reported (the external behaviour is the same as with
+CACHE_NOT_FOUND).
+
+% CACHE_SLOTS setting the cache size to '%1', dropping '%2' items
+The maximum allowed number of items of the hotspot cache is set to the given
+number. If there are too many, some of them will be dropped. The size of 0
+means no limit.
+
+% CACHE_ENABLE enabling the cache
+The hotspot cache is enabled from now on.
+
+% CACHE_DISABLE disabling the cache
+The hotspot cache is disabled from now on. It is not going to store
+information or return anything.
+
+% QUERY_SYNTH_CNAME synthesizing CNAME from DNAME on '%1'
+Debug information. While answering a query, a DNAME was met. The DNAME itself
+will be returned, but along with it a CNAME for clients which don't understand
+DNAMEs will be synthesized.
+
+% QUERY_EMPTY_DNAME the DNAME on '%1' is empty
+During an attempt to synthesize CNAME from this DNAME it was discovered the
+DNAME is empty (it has no records). This indicates problem with supplied data.
+
+% QUERY_GET_NS_ADDITIONAL addition of A/AAAA for '%1' requested by NS '%2'
+Debug information. While processing a query, a NS record was met. It
+references the mentioned address, so A/AAAA records for it are looked up
+and put it into the additional section.
+
+% QUERY_GET_MX_ADDITIONAL addition of A/AAAA for '%1' requested by MX '%2'
+Debug information. While processing a query, a MX record was met. It
+references the mentioned address, so A/AAAA records for it are looked up
+and put it into the additional section.
+
+% QUERY_FOLLOW_CNAME following CNAME at '%1'
+Debug information. The domain is a CNAME (or a DNAME and we created a CNAME
+for it already), so it's being followed.
+
+% QUERY_EMPTY_CNAME cNAME at '%1' is empty
+There was an CNAME and it was being followed. But it contains no records,
+so there's nowhere to go. There will be no answer. This indicates a problem
+with supplied data.
+We tried to follow
+
+% QUERY_TOO_MANY_CNAMES cNAME chain limit exceeded at '%1'
+A CNAME led to another CNAME and it led to another, and so on. After 16
+CNAMEs, the software gave up. Long CNAME chains are discouraged, and this
+might possibly be a loop as well. Note that some of the CNAMEs might have
+been synthesized from DNAMEs. This indicates problem with supplied data.
+
+% QUERY_CHECK_CACHE checking cache for '%1/%2'
+Debug information. While processing a query, lookup to the hotspot cache
+is being made.
+
+% QUERY_NO_CACHE_ANY_SIMPLE ignoring cache for ANY query (%1/%2 in %3 class)
+Debug information. The hotspot cache is ignored for ANY queries for consistency
+reasons.
+
+% QUERY_NO_CACHE_ANY_AUTH ignoring cache for ANY query (%1/%2 in %3 class)
+Debug information. The hotspot cache is ignored for authoritative ANY queries
+for consistency reasons.
+
+% DO_QUERY handling query for '%1/%2'
+Debug information. We're processing some internal query for given name and
+type.
+
+% QUERY_NO_ZONE no zone containing '%1' in class '%2'
+Lookup of domain failed because the data have no zone that contain the
+domain. Maybe someone sent a query to the wrong server for some reason.
+
+% QUERY_CACHED data for %1/%2 found in cache
+Debug information. The requested data were found in the hotspot cache, so
+no query is sent to the real data source.
+
+% QUERY_IS_SIMPLE simple query (%1/%2)
+Debug information. The last DO_QUERY is a simple query.
+
+% QUERY_IS_AUTH auth query (%1/%2)
+Debug information. The last DO_QUERY is an auth query.
+
+% QUERY_IS_GLUE glue query (%1/%2)
+Debug information. The last DO_QUERY is query for glue addresses.
+
+% QUERY_IS_NOGLUE query for non-glue addresses (%1/%2)
+Debug information. The last DO_QUERY is query for addresses that are not
+glue.
+
+% QUERY_IS_REF query for referral (%1/%2)
+Debug information. The last DO_QUERY is query for referral information.
+
+% QUERY_SIMPLE_FAIL the underlying data source failed with %1
+The underlying data source failed to answer the simple query. 1 means some
+error, 2 is not implemented. The data source should have logged the specific
+error already.
+
+% QUERY_AUTH_FAIL the underlying data source failed with %1
+The underlying data source failed to answer the authoritative query. 1 means
+some error, 2 is not implemented. The data source should have logged the
+specific error already.
+
+% QUERY_GLUE_FAIL the underlying data source failed with %1
+The underlying data source failed to answer the glue query. 1 means some error,
+2 is not implemented. The data source should have logged the specific error
+already.
+
+% QUERY_NOGLUE_FAIL the underlying data source failed with %1
+The underlying data source failed to answer the no-glue query. 1 means some
+error, 2 is not implemented. The data source should have logged the specific
+error already.
+
+% QUERY_REF_FAIL the underlying data source failed with %1
+The underlying data source failed to answer the query for referral information.
+1 means some error, 2 is not implemented. The data source should have logged
+the specific error already.
+
+% QUERY_INVALID_OP invalid query operation requested
+This indicates a programmer error. The DO_QUERY was called with unknown
+operation code.
+
+% QUERY_ADD_RRSET adding RRset '%1/%2' to message
+Debug information. An RRset is being added to the response message.
+
+% QUERY_COPY_AUTH copying authoritative section into message
+Debug information. The whole referral information is being copied into the
+response message.
+
+% QUERY_DELEGATION looking for delegation on the path to '%1'
+Debug information. The software is trying to identify delegation points on the
+way down to the given domain.
+
+% QUERY_ADD_SOA adding SOA of '%1'
+Debug information. A SOA record of the given zone is being added to the
+authority section of the response message.
+
+% QUERY_ADD_NSEC adding NSEC record for '%1'
+Debug information. A NSEC record covering this zone is being added.
+
+% QUERY_ADD_NSEC3 adding NSEC3 record of zone '%1'
+Debug information. A NSEC3 record for the given zone is being added to the
+response message.
+
+% QUERY_NO_DS_NSEC3 there's no DS record in the '%1' zone
+An attempt to add a NSEC3 record into the message failed, because the zone does
+not have any DS record. This indicates problem with the provided data.
+
+% QUERY_NO_DS_NSEC there's no DS record in the '%1' zone
+An attempt to add a NSEC record into the message failed, because the zone does
+not have any DS record. This indicates problem with the provided data.
+
+% QUERY_WILDCARD looking for a wildcard covering '%1'
+Debug information. A direct match wasn't found, so a wildcard covering the
+domain is being looked for now.
+
+% QUERY_WILDCARD_PROVENX_FAIL unable to prove nonexistence of '%1' (%2)
+While processing a wildcard, it wasn't possible to prove nonexistence of the
+given domain or record.  The code is 1 for error and 2 for not implemented.
+
+% QUERY_WILDCARD_REFERRAL unable to find referral info for '%1' (%2)
+While processing a wildcard, a referral was met. But it wasn't possible to get
+enough information for it.  The code is 1 for error, 2 for not implemented.
+
+% QUERY_PROCESS processing query '%1/%2' in the '%3' class
+Debug information. A sure query is being processed now.
+
+% QUERY_RRSIG unable to answer RRSIG query
+The server is unable to answer a direct query for RRSIG type, but was asked
+to do so.
+
+% QUERY_MISPLACED_TASK task of this type should not be here
+This indicates a programming error. A task was found in the internal task
+queue, but this kind of task wasn't designed to be inside the queue (it should
+be handled right away, not queued).
+
+% QUERY_TASK_FAIL task failed with %1
+The query subtask failed. The reason should have been reported by the subtask
+already. The code is 1 for error, 2 for not implemented.
+
+% QUERY_MISSING_NS missing NS records for '%1'
+NS records should have been put into the authority section. However, this zone
+has none. This indicates problem with provided data.
+
+% UNEXPECTED_QUERY_STATE unexpected query state
+This indicates a programming error. An internal task of unknown type was
+generated.
+
+% QUERY_FAIL query failed
+Some subtask of query processing failed. The reason should have been reported
+already. We are returning SERVFAIL.
+
+% QUERY_BAD_REFERRAL bad referral to '%1'
+The domain lives in another zone. But it is not possible to generate referral
+information for it.
+
+% QUERY_WILDCARD_FAIL error processing wildcard for '%1'
+During an attempt to cover the domain by a wildcard an error happened. The
+exact kind was hopefully already reported.
+
+% QUERY_MISSING_SOA the zone '%1' has no SOA
+The answer should have been a negative one (eg. of nonexistence of something).
+To do so, a SOA record should be put into the authority section, but the zone
+does not have one. This indicates problem with provided data.
+
+% QUERY_PROVENX_FAIL unable to prove nonexistence of '%1'
+The user wants DNSSEC and we discovered the entity doesn't exist (either
+domain or the record). But there was an error getting NSEC/NSEC3 record
+to prove the nonexistence.
+
+% QUERY_UNKNOWN_RESULT unknown result of subtask
+This indicates a programmer error. The answer of subtask doesn't look like
+anything known.
+
+% META_ADD adding a data source into meta data source
+Debug information. Yet another data source is being added into the meta data
+source. (probably at startup or reconfiguration)
+
+% META_ADD_CLASS_MISMATCH mismatch between classes '%1' and '%2'
+It was attempted to add a data source into a meta data source. But their
+classes do not match.
+
+% META_REMOVE removing data source from meta data source
+Debug information. A data source is being removed from meta data source.
+
+% MEM_ADD_WILDCARD adding wildcards for '%1'
+Debug information. Some special marks above each * in wildcard name are needed.
+They are being added now for this name.
+
+% MEM_CNAME_TO_NONEMPTY can't add CNAME to domain with other data in '%1'
+Someone or something tried to add a CNAME into a domain that already contains
+some other data. But the protocol forbids coexistence of CNAME with anything
+(RFC 1034, section 3.6.2). This indicates a problem with provided data.
+
+% MEM_CNAME_COEXIST can't add data to CNAME in domain '%1'
+This is the same problem as in MEM_CNAME_TO_NONEMPTY, but it happened the
+other way around -- adding some outher data to CNAME.
+
+% MEM_DNAME_NS dNAME and NS can't coexist in non-apex domain '%1'
+It was requested for DNAME and NS records to be put into the same domain
+which is not the apex (the top of the zone). This is forbidden by RFC
+2672, section 3. This indicates a problem with provided data.
+
+% MEM_SINGLETON trying to add multiple RRs for domain '%1' and type '%2'
+Some resource types are singletons -- only one is allowed in a domain
+(for example CNAME or SOA). This indicates a problem with provided data.
+
+% MEM_OUT_OF_ZONE domain '%1' doesn't belong to zone '%2'
+It was attempted to add the domain into a zone that shouldn't have it
+(eg. the domain is not subdomain of the zone origin). This indicates a
+problem with provided data.
+
+% MEM_WILDCARD_NS nS record in wildcard domain '%1'
+The software refuses to load NS records into a wildcard domain.  It isn't
+explicitly forbidden, but the protocol is ambiguous about how this should
+behave and BIND 9 refuses that as well. Please describe your intention using
+different tools.
+
+% MEM_WILDCARD_DNAME dNAME record in wildcard domain '%1'
+The software refuses to load DNAME records into a wildcard domain.  It isn't
+explicitly forbidden, but the protocol is ambiguous about how this should
+behave and BIND 9 refuses that as well. Please describe your intention using
+different tools.
+
+% MEM_ADD_RRSET adding RRset '%1/%2' into zone '%3'
+Debug information. An RRset is being added to the in-memory data source.
+
+% MEM_DUP_RRSET duplicate RRset '%1/%2'
+An RRset is being inserted into in-memory data source for a second time.  The
+original version must be removed first. Note that loading master files where an
+RRset is split into multiple locations is not supported yet.
+
+% MEM_DNAME_ENCOUNTERED encountered a DNAME
+Debug information. While searching for the requested domain, a DNAME was
+encountered on the way.  This may lead to redirection to a different domain and
+stop the search.
+
+% MEM_NS_ENCOUNTERED encountered a NS
+Debug information. While searching for the requested domain, a NS was
+encountered on the way (a delegation). This may lead to stop of the search.
+
+% MEM_RENAME renaming RRset from '%1' to '%2'
+Debug information. A RRset is being generated from a different RRset (most
+probably a wildcard). So it must be renamed to whatever the user asked for. In
+fact, it's impossible to rename RRsets with our libraries, so a new one is
+created and all resource records are copied over.
+
+% MEM_FIND find '%1/%2'
+Debug information. A search for the requested RRset is being started.
+
+% MEM_DNAME_FOUND DNAME found at '%1'
+Debug information. A DNAME was found instead of the requested information.
+
+% MEM_DELEG_FOUND delegation found at '%1'
+Debug information. A delegation point was found above the requested record.
+
+% MEM_SUPER_STOP stopped at superdomain '%1', domain '%2' is empty
+Debug information. The search stopped at a superdomain of the requested
+domain. The domain is a empty nonterminal, therefore it is treated  as NXRRSET
+case (eg. the domain exists, but it doesn't have the requested record type).
+
+% MEM_WILDCARD_CANCEL wildcard match canceled for '%1'
+Debug information. A domain above wildcard was reached, but there's something
+below the requested domain. Therefore the wildcard doesn't apply here.  This
+behaviour is specified by RFC 1034, section 4.3.3
+
+% MEM_NOTFOUND requested domain '%1' not found
+Debug information. The requested domain does not exist.
+
+% MEM_DOMAIN_EMPTY requested domain '%1' is empty
+Debug information. The requested domain exists in the tree of domains, but
+it is empty. Therefore it doesn't contain the requested resource type.
+
+% MEM_EXACT_DELEGATION delegation at the exact domain '%1'
+Debug information. There's a NS record at the requested domain. This means
+this zone is not authoritative for the requested domain, but a delegation
+should be followed. The requested domain is an apex of some zone.
+
+% MEM_ANY_SUCCESS ANY query for '%1' successful
+Debug information. The domain was found and an ANY type query is being answered
+by providing everything found inside the domain.
+
+% MEM_SUCCESS query for '%1/%2' successful
+Debug information. The requested record was found.
+
+% MEM_CNAME CNAME at the domain '%1'
+Debug information. The requested domain is an alias to a different domain,
+returning the CNAME instead.
+
+% MEM_NXRRSET no such type '%1' at '%2'
+Debug information. The domain exists, but it doesn't hold any record of the
+requested type.
+
+% MEM_CREATE creating zone '%1' in '%2' class
+Debug information. A representation of a zone for the in-memory data source is
+being created.
+
+% MEM_DESTROY destroying zone '%1' in '%2' class
+Debug information. A zone from in-memory data source is being destroyed.
+
+% MEM_LOAD loading zone '%1' from file '%2'
+Debug information. The content of master file is being loaded into the memory.
+
+% MEM_SWAP swapping contents of two zone representations ('%1' and '%2')
+Debug information. The contents of two in-memory zones are being exchanged.
+This is usual practice to do some manipulation in exception-safe manner -- the
+new data are prepared in a different zone object and when it works, they are
+swapped. The old one contains the new data and the other one can be safely
+destroyed.
+
+% MEM_ADD_ZONE adding zone '%1/%2'
+Debug information. A zone is being added into the in-memory data source.
+
+% MEM_FIND_ZONE looking for zone '%1'
+Debug information. A zone object for this zone is being searched for in the
+in-memory data source.
+
+% STATIC_CREATE creating the static datasource
+Debug information. The static data source (the one holding stuff like
+version.bind) is being created.
+
+% STATIC_BAD_CLASS static data source can handle CH only
+For some reason, someone asked the static data source a query that is not in
+the CH class.
+
+% STATIC_FIND looking for '%1/%2'
+Debug information. This resource record set is being looked up in the static
+data source.
+
+% SQLITE_FINDREC looking for record '%1/%2'
+Debug information. The SQLite data source is looking up records of given name
+and type in the database.
+
+% SQLITE_ENCLOSURE looking for zone containing '%1'
+Debug information. The SQLite data source is trying to identify, which zone
+should hold this domain.
+
+% SQLITE_ENCLOSURE_BAD_CLASS class mismatch looking for a zone ('%1' and '%2')
+The SQLite data source can handle only one class at a time and it was asked
+to identify which zone is holding data of a different class.
+
+% SQLITE_ENCLOSURE_NOTFOUND no zone contains it
+Debug information. The last SQLITE_ENCLOSURE query was unsuccessful, there's
+no such zone in our data.
+
+% SQLITE_PREVIOUS looking for name previous to '%1'
+Debug information. We're trying to look up name preceding the supplied one.
+
+% SQLITE_PREVIOUS_NO_ZONE no zone containing '%1'
+The SQLite data source tried to identify name preceding this one. But this
+one is not contained in any zone in the data source.
+
+% SQLITE_FIND_NSEC3 looking for NSEC3 in zone '%1' for hash '%2'
+Debug information. We're trying to look up a NSEC3 record in the SQLite data
+source.
+
+% SQLITE_FIND_NSEC3_NO_ZONE no such zone '%1'
+The SQLite data source was asked to provide a NSEC3 record for given zone.
+But it doesn't contain that zone.
+
+% SQLITE_FIND looking for RRset '%1/%2'
+Debug information. The SQLite data source is looking up a resource record
+set.
+
+% SQLITE_FIND_BAD_CLASS class mismatch looking for an RRset ('%1' and '%2')
+The SQLite data source was looking up an RRset, but the data source contains
+different class than the query was for.
+
+% SQLITE_FINDEXACT looking for exact RRset '%1/%2'
+Debug information. The SQLite data source is looking up an exact resource
+record.
+
+% SQLITE_FINDEXACT_BAD_CLASS class mismatch looking for an RRset ('%1' and '%2')
+The SQLite data source was looking up an exact RRset, but the data source
+contains different class than the query was for.
+
+% SQLITE_FINDADDRS looking for A/AAAA addresses for '%1'
+Debug information. The data source is looking up the addresses for given
+domain name.
+
+% SQLITE_FINDADDRS_BAD_CLASS class mismatch looking for addresses ('%1' and '%2')
+The SQLite data source was looking up A/AAAA addresses, but the data source
+contains different class than the query was for.
+
+% SQLITE_FINDREF looking for referral at '%1'
+Debug information. The SQLite data source is identifying if this domain is
+a referral and where it goes.
+
+% SQLITE_FINDREF_BAD_CLASS class mismatch looking for referral ('%1' and '%2')
+The SQLite data source was trying to identify, if there's a referral. But
+it contains different class than the query was for.
+
+% SQLITE_CREATE sQLite data source created
+Debug information. An instance of SQLite data source is being created.
+
+% SQLITE_DESTROY sQLite data source destroyed
+Debug information. An instance of SQLite data source is being destroyed.
+
+% SQLITE_SETUP setting up SQLite database
+The database for SQLite data source was found empty. It is assumed this is the
+first run and it is being initialized with current schema.  It'll still contain
+no data, but it will be ready for use.
+
+% SQLITE_OPEN opening SQLite database '%1'
+Debug information. The SQLite data source is loading an SQLite database in
+the provided file.
+
+% SQLITE_CLOSE closing SQLite database
+Debug information. The SQLite data source is closing the database file.
diff --git a/src/lib/datasrc/sqlite3_datasrc.cc b/src/lib/datasrc/sqlite3_datasrc.cc
index ab910ba..22f035b 100644
--- a/src/lib/datasrc/sqlite3_datasrc.cc
+++ b/src/lib/datasrc/sqlite3_datasrc.cc
@@ -18,6 +18,7 @@
 #include <sqlite3.h>
 
 #include <datasrc/sqlite3_datasrc.h>
+#include <datasrc/logger.h>
 
 #include <dns/rrttl.h>
 #include <dns/rdata.h>
@@ -227,6 +228,8 @@ Sqlite3DataSrc::findRecords(const Name& name, const RRType& rdtype,
                             RRsetList& target, const Name* zonename,
                             const Mode mode, uint32_t& flags) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DETAILED, DATASRC_SQLITE_FINDREC).arg(name).
+        arg(rdtype);
     flags = 0;
     int zone_id = (zonename == NULL) ? findClosest(name, NULL) :
         findClosest(*zonename, NULL);
@@ -345,12 +348,17 @@ Sqlite3DataSrc::findClosest(const Name& name, unsigned int* position) const {
 
 void
 Sqlite3DataSrc::findClosestEnclosure(DataSrcMatch& match) const {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_ENCLOSURE).
+        arg(match.getName());
     if (match.getClass() != getClass() && match.getClass() != RRClass::ANY()) {
+        LOG_ERROR(logger, DATASRC_SQLITE_ENCLOSURE_BAD_CLASS).arg(getClass()).
+            arg(match.getClass());
         return;
     }
 
     unsigned int position;
     if (findClosest(match.getName(), &position) == -1) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_ENCLOSURE_NOTFOUND);
         return;
     }
 
@@ -362,9 +370,11 @@ Sqlite3DataSrc::findPreviousName(const Name& qname,
                                  Name& target,
                                  const Name* zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_PREVIOUS).arg(qname);
     const int zone_id = (zonename == NULL) ?
         findClosest(qname, NULL) : findClosest(*zonename, NULL);
     if (zone_id < 0) {
+        LOG_ERROR(logger, DATASRC_SQLITE_PREVIOUS_NO_ZONE).arg(qname.toText());
         return (ERROR);
     }
     
@@ -402,8 +412,11 @@ Sqlite3DataSrc::findCoveringNSEC3(const Name& zonename,
                                   string& hashstr,
                                   RRsetList& target) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_FIND_NSEC3).
+        arg(zonename).arg(hashstr);
     const int zone_id = findClosest(zonename, NULL);
     if (zone_id < 0) {
+        LOG_ERROR(logger, DATASRC_SQLITE_FIND_NSEC3_NO_ZONE).arg(zonename);
         return (ERROR);
     }
 
@@ -484,7 +497,11 @@ Sqlite3DataSrc::findRRset(const Name& qname,
                           uint32_t& flags,
                           const Name* zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_FIND).arg(qname).
+        arg(qtype);
     if (qclass != getClass() && qclass != RRClass::ANY()) {
+        LOG_ERROR(logger, DATASRC_SQLITE_FIND_BAD_CLASS).arg(getClass()).
+            arg(qclass);
         return (ERROR);
     }
     findRecords(qname, qtype, target, zonename, NORMAL, flags);
@@ -499,7 +516,11 @@ Sqlite3DataSrc::findExactRRset(const Name& qname,
                                uint32_t& flags,
                                const Name* zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_FINDEXACT).arg(qname).
+        arg(qtype);
     if (qclass != getClass() && qclass != RRClass::ANY()) {
+        LOG_ERROR(logger, DATASRC_SQLITE_FINDEXACT_BAD_CLASS).arg(getClass()).
+            arg(qclass);
         return (ERROR);
     }
     findRecords(qname, qtype, target, zonename, NORMAL, flags);
@@ -523,7 +544,10 @@ Sqlite3DataSrc::findAddrs(const Name& qname,
                           uint32_t& flags,
                           const Name* zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_FINDADDRS).arg(qname);
     if (qclass != getClass() && qclass != RRClass::ANY()) {
+        LOG_ERROR(logger, DATASRC_SQLITE_FINDADDRS_BAD_CLASS).arg(getClass()).
+            arg(qclass);
         return (ERROR);
     }
     findRecords(qname, RRType::ANY(), target, zonename, ADDRESS, flags);
@@ -537,8 +561,11 @@ Sqlite3DataSrc::findReferral(const Name& qname,
                              uint32_t& flags,
                              const Name* zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_SQLITE_FINDREF).arg(qname);
     if (qclass != getClass() && qclass != RRClass::ANY()) {
-            return (ERROR);
+        LOG_ERROR(logger, DATASRC_SQLITE_FINDREF_BAD_CLASS).arg(getClass()).
+            arg(qclass);
+        return (ERROR);
     }
     findRecords(qname, RRType::ANY(), target, zonename, DELEGATION, flags);
     return (SUCCESS);
@@ -546,9 +573,12 @@ Sqlite3DataSrc::findReferral(const Name& qname,
 
 Sqlite3DataSrc::Sqlite3DataSrc() :
     dbparameters(new Sqlite3Parameters)
-{}
+{
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_SQLITE_CREATE);
+}
 
 Sqlite3DataSrc::~Sqlite3DataSrc() {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_SQLITE_DESTROY);
     if (dbparameters->db_ != NULL) {
         close();
     }
@@ -635,6 +665,7 @@ checkAndSetupSchema(Sqlite3Initializer* initializer) {
         initializer->params_.version_ = sqlite3_column_int(prepared, 0);
         sqlite3_finalize(prepared);
     } else {
+        logger.info(DATASRC_SQLITE_SETUP);
         if (prepared != NULL) {
             sqlite3_finalize(prepared);
         }
@@ -664,6 +695,7 @@ checkAndSetupSchema(Sqlite3Initializer* initializer) {
 //
 void
 Sqlite3DataSrc::open(const string& name) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_SQLITE_OPEN).arg(name);
     if (dbparameters->db_ != NULL) {
         isc_throw(DataSourceError, "Duplicate SQLite open with " << name);
     }
@@ -683,6 +715,7 @@ Sqlite3DataSrc::open(const string& name) {
 //
 DataSrc::Result
 Sqlite3DataSrc::close(void) {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_SQLITE_CLOSE);
     if (dbparameters->db_ == NULL) {
         isc_throw(DataSourceError,
                   "SQLite data source is being closed before open");
diff --git a/src/lib/datasrc/static_datasrc.cc b/src/lib/datasrc/static_datasrc.cc
index 025078a..dee14b9 100644
--- a/src/lib/datasrc/static_datasrc.cc
+++ b/src/lib/datasrc/static_datasrc.cc
@@ -26,6 +26,7 @@
 
 #include <datasrc/data_source.h>
 #include <datasrc/static_datasrc.h>
+#include <datasrc/logger.h>
 
 using namespace std;
 using namespace isc::dns;
@@ -112,6 +113,7 @@ StaticDataSrcImpl::StaticDataSrcImpl() :
 }
 
 StaticDataSrc::StaticDataSrc() {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, DATASRC_STATIC_CREATE);
     setClass(RRClass::CH());
     impl_ = new StaticDataSrcImpl;
 }
@@ -155,8 +157,11 @@ StaticDataSrc::findRRset(const Name& qname,
                          RRsetList& target, uint32_t& flags,
                          const Name* const zonename) const
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, DATASRC_STATIC_FIND).arg(qname).
+        arg(qtype);
     flags = 0;
     if (qclass != getClass() && qclass != RRClass::ANY()) {
+        LOG_ERROR(logger, DATASRC_STATIC_BAD_CLASS);
         return (ERROR);
     }
 
diff --git a/src/lib/datasrc/tests/Makefile.am b/src/lib/datasrc/tests/Makefile.am
index f09b4b7..ad4374a 100644
--- a/src/lib/datasrc/tests/Makefile.am
+++ b/src/lib/datasrc/tests/Makefile.am
@@ -27,15 +27,17 @@ run_unittests_SOURCES += test_datasrc.h test_datasrc.cc
 run_unittests_SOURCES += rbtree_unittest.cc
 run_unittests_SOURCES += zonetable_unittest.cc
 run_unittests_SOURCES += memory_datasrc_unittest.cc
+run_unittests_SOURCES += logger_unittest.cc
 run_unittests_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES)
 run_unittests_LDFLAGS = $(AM_LDFLAGS) $(GTEST_LDFLAGS)
 run_unittests_LDADD = $(GTEST_LDADD)
 run_unittests_LDADD += $(SQLITE_LIBS)
-run_unittests_LDADD += $(top_builddir)/src/lib/testutils/libtestutils.la
 run_unittests_LDADD += $(top_builddir)/src/lib/datasrc/libdatasrc.la
 run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
-run_unittests_LDADD += $(top_builddir)/src/lib/cc/libcc.la
+run_unittests_LDADD += $(top_builddir)/src/lib/log/liblog.la
 run_unittests_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la
+run_unittests_LDADD += $(top_builddir)/src/lib/cc/libcc.la
+run_unittests_LDADD += $(top_builddir)/src/lib/testutils/libtestutils.la
 endif
 
 noinst_PROGRAMS = $(TESTS)
diff --git a/src/lib/datasrc/tests/logger_unittest.cc b/src/lib/datasrc/tests/logger_unittest.cc
new file mode 100644
index 0000000..df5a41c
--- /dev/null
+++ b/src/lib/datasrc/tests/logger_unittest.cc
@@ -0,0 +1,31 @@
+// Copyright (C) 2010  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#include <gtest/gtest.h>
+
+#include <datasrc/logger.h>
+
+using namespace isc::datasrc;
+
+namespace {
+
+TEST(CacheLogger, name) {
+    // This does not check the name only, but the fact the logger is created
+    // The dot is because of empty root logger
+    std::string name(logger.getName());
+    EXPECT_EQ(name.size() - 8, name.rfind(".datasrc")) <<
+        "Wrong logger name: " << name;
+}
+
+}
diff --git a/src/lib/log/log_formatter.h b/src/lib/log/log_formatter.h
index 07a024c..cda1d96 100644
--- a/src/lib/log/log_formatter.h
+++ b/src/lib/log/log_formatter.h
@@ -125,7 +125,11 @@ public:
     ///
     /// \param arg The argument to place into the placeholder.
     template<class Arg> Formatter& arg(const Arg& value) {
-        return (arg(boost::lexical_cast<std::string>(value)));
+        if (logger_) {
+            return (arg(boost::lexical_cast<std::string>(value)));
+        } else {
+            return (*this);
+        }
     }
     /// \brief String version of arg.
     Formatter& arg(const std::string& arg) {




More information about the bind10-changes mailing list