Browse Source

Merge branch 'master' into trac1078

Stephen Morris 14 years ago
parent
commit
a2a8094104

+ 0 - 0
TODO


+ 14 - 14
src/bin/auth/tests/command_unittest.cc

@@ -48,9 +48,9 @@ using namespace isc::datasrc;
 using namespace isc::config;
 using namespace isc::config;
 
 
 namespace {
 namespace {
-class AuthConmmandTest : public ::testing::Test {
+class AuthCommandTest : public ::testing::Test {
 protected:
 protected:
-    AuthConmmandTest() : server(false, xfrout), rcode(-1) {
+    AuthCommandTest() : server(false, xfrout), rcode(-1) {
         server.setStatisticsSession(&statistics_session);
         server.setStatisticsSession(&statistics_session);
     }
     }
     void checkAnswer(const int expected_code) {
     void checkAnswer(const int expected_code) {
@@ -67,14 +67,14 @@ public:
     void stopServer();          // need to be public for boost::bind
     void stopServer();          // need to be public for boost::bind
 };
 };
 
 
-TEST_F(AuthConmmandTest, unknownCommand) {
+TEST_F(AuthCommandTest, unknownCommand) {
     result = execAuthServerCommand(server, "no_such_command",
     result = execAuthServerCommand(server, "no_such_command",
                                    ConstElementPtr());
                                    ConstElementPtr());
     parseAnswer(rcode, result);
     parseAnswer(rcode, result);
     EXPECT_EQ(1, rcode);
     EXPECT_EQ(1, rcode);
 }
 }
 
 
-TEST_F(AuthConmmandTest, DISABLED_unexpectedException) {
+TEST_F(AuthCommandTest, DISABLED_unexpectedException) {
     // execAuthServerCommand() won't catch standard exceptions.
     // execAuthServerCommand() won't catch standard exceptions.
     // Skip this test for now: ModuleCCSession doesn't seem to validate
     // Skip this test for now: ModuleCCSession doesn't seem to validate
     // commands.
     // commands.
@@ -83,7 +83,7 @@ TEST_F(AuthConmmandTest, DISABLED_unexpectedException) {
                  runtime_error);
                  runtime_error);
 }
 }
 
 
-TEST_F(AuthConmmandTest, sendStatistics) {
+TEST_F(AuthCommandTest, sendStatistics) {
     result = execAuthServerCommand(server, "sendstats", ConstElementPtr());
     result = execAuthServerCommand(server, "sendstats", ConstElementPtr());
     // Just check some message has been sent.  Detailed tests specific to
     // Just check some message has been sent.  Detailed tests specific to
     // statistics are done in its own tests.
     // statistics are done in its own tests.
@@ -92,15 +92,15 @@ TEST_F(AuthConmmandTest, sendStatistics) {
 }
 }
 
 
 void
 void
-AuthConmmandTest::stopServer() {
+AuthCommandTest::stopServer() {
     result = execAuthServerCommand(server, "shutdown", ConstElementPtr());
     result = execAuthServerCommand(server, "shutdown", ConstElementPtr());
     parseAnswer(rcode, result);
     parseAnswer(rcode, result);
     assert(rcode == 0); // make sure the test stops when something is wrong
     assert(rcode == 0); // make sure the test stops when something is wrong
 }
 }
 
 
-TEST_F(AuthConmmandTest, shutdown) {
+TEST_F(AuthCommandTest, shutdown) {
     isc::asiolink::IntervalTimer itimer(server.getIOService());
     isc::asiolink::IntervalTimer itimer(server.getIOService());
-    itimer.setup(boost::bind(&AuthConmmandTest::stopServer, this), 1);
+    itimer.setup(boost::bind(&AuthCommandTest::stopServer, this), 1);
     server.getIOService().run();
     server.getIOService().run();
     EXPECT_EQ(0, rcode);
     EXPECT_EQ(0, rcode);
 }
 }
@@ -165,7 +165,7 @@ newZoneChecks(AuthSrv& server) {
               find(Name("ns.test2.example"), RRType::AAAA()).code);
               find(Name("ns.test2.example"), RRType::AAAA()).code);
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadZone) {
+TEST_F(AuthCommandTest, loadZone) {
     configureZones(server);
     configureZones(server);
 
 
     ASSERT_EQ(0, system(INSTALL_PROG " " TEST_DATA_DIR
     ASSERT_EQ(0, system(INSTALL_PROG " " TEST_DATA_DIR
@@ -182,7 +182,7 @@ TEST_F(AuthConmmandTest, loadZone) {
     newZoneChecks(server);
     newZoneChecks(server);
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadBrokenZone) {
+TEST_F(AuthCommandTest, loadBrokenZone) {
     configureZones(server);
     configureZones(server);
 
 
     ASSERT_EQ(0, system(INSTALL_PROG " " TEST_DATA_DIR
     ASSERT_EQ(0, system(INSTALL_PROG " " TEST_DATA_DIR
@@ -195,7 +195,7 @@ TEST_F(AuthConmmandTest, loadBrokenZone) {
     zoneChecks(server);     // zone shouldn't be replaced
     zoneChecks(server);     // zone shouldn't be replaced
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadUnreadableZone) {
+TEST_F(AuthCommandTest, loadUnreadableZone) {
     configureZones(server);
     configureZones(server);
 
 
     // install the zone file as unreadable
     // install the zone file as unreadable
@@ -209,7 +209,7 @@ TEST_F(AuthConmmandTest, loadUnreadableZone) {
     zoneChecks(server);     // zone shouldn't be replaced
     zoneChecks(server);     // zone shouldn't be replaced
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadZoneWithoutDataSrc) {
+TEST_F(AuthCommandTest, loadZoneWithoutDataSrc) {
     // try to execute load command without configuring the zone beforehand.
     // try to execute load command without configuring the zone beforehand.
     // it should fail.
     // it should fail.
     result = execAuthServerCommand(server, "loadzone",
     result = execAuthServerCommand(server, "loadzone",
@@ -218,7 +218,7 @@ TEST_F(AuthConmmandTest, loadZoneWithoutDataSrc) {
     checkAnswer(1);
     checkAnswer(1);
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadSqlite3DataSrc) {
+TEST_F(AuthCommandTest, loadSqlite3DataSrc) {
     // For sqlite3 data source we don't have to do anything (the data source
     // For sqlite3 data source we don't have to do anything (the data source
     // (re)loads itself automatically)
     // (re)loads itself automatically)
     result = execAuthServerCommand(server, "loadzone",
     result = execAuthServerCommand(server, "loadzone",
@@ -228,7 +228,7 @@ TEST_F(AuthConmmandTest, loadSqlite3DataSrc) {
     checkAnswer(0);
     checkAnswer(0);
 }
 }
 
 
-TEST_F(AuthConmmandTest, loadZoneInvalidParams) {
+TEST_F(AuthCommandTest, loadZoneInvalidParams) {
     configureZones(server);
     configureZones(server);
 
 
     // null arg
     // null arg

+ 1 - 1
src/bin/xfrin/xfrin.py.in

@@ -152,7 +152,7 @@ class XfrinConnection(asyncore.dispatcher):
             self.connect(self._master_address)
             self.connect(self._master_address)
             return True
             return True
         except socket.error as e:
         except socket.error as e:
-            logger.error(CONNECT_MASTER, self._master_address, str(e))
+            logger.error(XFRIN_CONNECT_MASTER, self._master_address, str(e))
             return False
             return False
 
 
     def _create_query(self, query_type):
     def _create_query(self, query_type):

+ 10 - 0
src/lib/acl/dns.cc

@@ -25,6 +25,7 @@
 #include <acl/dns.h>
 #include <acl/dns.h>
 #include <acl/ip_check.h>
 #include <acl/ip_check.h>
 #include <acl/loader.h>
 #include <acl/loader.h>
+#include <acl/logic_check.h>
 
 
 using namespace std;
 using namespace std;
 using boost::shared_ptr;
 using boost::shared_ptr;
@@ -98,6 +99,15 @@ getRequestLoader() {
         // Register default check creator(s)
         // Register default check creator(s)
         loader_ptr->registerCreator(shared_ptr<internal::RequestCheckCreator>(
         loader_ptr->registerCreator(shared_ptr<internal::RequestCheckCreator>(
                                         new internal::RequestCheckCreator()));
                                         new internal::RequestCheckCreator()));
+        loader_ptr->registerCreator(
+            shared_ptr<NotCreator<RequestContext> >(
+                new NotCreator<RequestContext>("NOT")));
+        loader_ptr->registerCreator(
+            shared_ptr<LogicCreator<AnyOfSpec, RequestContext> >(
+                new LogicCreator<AnyOfSpec, RequestContext>("ANY")));
+        loader_ptr->registerCreator(
+            shared_ptr<LogicCreator<AllOfSpec, RequestContext> >(
+                new LogicCreator<AllOfSpec, RequestContext>("ALL")));
 
 
         // From this point there shouldn't be any exception thrown
         // From this point there shouldn't be any exception thrown
         loader = loader_ptr.release();
         loader = loader_ptr.release();

+ 80 - 0
src/lib/acl/logic_check.h

@@ -200,6 +200,86 @@ private:
     const std::string name_;
     const std::string name_;
 };
 };
 
 
+/**
+ * \brief The NOT operator for ACLs.
+ *
+ * This simply returns the negation of whatever returns the subexpression.
+ */
+template<typename Context>
+class NotOperator : public CompoundCheck<Context> {
+public:
+    /**
+     * \brief Constructor
+     *
+     * \param expr The subexpression to be negated by this NOT.
+     */
+    NotOperator(const boost::shared_ptr<Check<Context> >& expr) :
+        expr_(expr)
+    { }
+    /**
+     * \brief The list of subexpressions
+     *
+     * \return The vector will contain single value and it is the expression
+     *     passed by constructor.
+     */
+    virtual typename CompoundCheck<Context>::Checks getSubexpressions() const {
+        typename CompoundCheck<Context>::Checks result;
+        result.push_back(expr_.get());
+        return (result);
+    }
+    /// \brief The matching function
+    virtual bool matches(const Context& context) const {
+        return (!expr_->matches(context));
+    }
+private:
+    /// \brief The subexpression
+    const boost::shared_ptr<Check<Context> > expr_;
+};
+
+template<typename Context, typename Action = BasicAction>
+class NotCreator : public Loader<Context, Action>::CheckCreator {
+public:
+    /**
+     * \brief Constructor
+     *
+     * \param name The name of the NOT operator to be loaded as.
+     */
+    NotCreator(const std::string& name) :
+        name_(name)
+    { }
+    /**
+     * \brief List of the names this loads
+     *
+     * \return Single-value vector containing the name passed to the
+     *     constructor.
+     */
+    virtual std::vector<std::string> names() const {
+        std::vector<std::string> result;
+        result.push_back(name_);
+        return (result);
+    }
+    /// \brief Create the check.
+    virtual boost::shared_ptr<Check<Context> > create(const std::string&,
+                                                      data::ConstElementPtr
+                                                      definition,
+                                                      const Loader<Context,
+                                                      Action>& loader)
+    {
+        return (boost::shared_ptr<Check<Context> >(new NotOperator<Context>(
+                    loader.loadCheck(definition))));
+    }
+    /**
+     * \brief Or-abbreviated form.
+     *
+     * This returns false. In theory, the NOT operator could be used with
+     * the abbreviated form, but it would be confusing. Such syntax is
+     * therefore explicitly forbidden.
+     */
+    virtual bool allowListAbbreviation() const { return (false); }
+public:
+    const std::string name_;
+};
+
 }
 }
 }
 }
 
 

+ 18 - 0
src/lib/acl/tests/dns_test.cc

@@ -184,4 +184,22 @@ TEST_F(RequestCheckTest, checkIPv6) {
     EXPECT_FALSE(createIPCheck("32.1.13.184")->matches(getRequest6()));
     EXPECT_FALSE(createIPCheck("32.1.13.184")->matches(getRequest6()));
 }
 }
 
 
+// The following tests test only the creators are registered, they are tested
+// elsewhere
+
+TEST(DNSACL, notLoad) {
+    EXPECT_NO_THROW(getRequestLoader().loadCheck(isc::data::Element::fromJSON(
+        "{\"NOT\": {\"from\": \"192.0.2.1\"}}")));
+}
+
+TEST(DNSACL, allLoad) {
+    EXPECT_NO_THROW(getRequestLoader().loadCheck(isc::data::Element::fromJSON(
+        "{\"ALL\": [{\"from\": \"192.0.2.1\"}]}")));
+}
+
+TEST(DNSACL, anyLoad) {
+    EXPECT_NO_THROW(getRequestLoader().loadCheck(isc::data::Element::fromJSON(
+        "{\"ANY\": [{\"from\": \"192.0.2.1\"}]}")));
+}
+
 }
 }

+ 46 - 0
src/lib/acl/tests/logic_check_test.cc

@@ -93,6 +93,7 @@ public:
             LogicCreator<AllOfSpec, Log>("ALL")));
             LogicCreator<AllOfSpec, Log>("ALL")));
         loader_.registerCreator(CreatorPtr(new ThrowCreator));
         loader_.registerCreator(CreatorPtr(new ThrowCreator));
         loader_.registerCreator(CreatorPtr(new LogCreator));
         loader_.registerCreator(CreatorPtr(new LogCreator));
+        loader_.registerCreator(CreatorPtr(new NotCreator<Log>("NOT")));
     }
     }
     // To mark which parts of the check did run
     // To mark which parts of the check did run
     Log log_;
     Log log_;
@@ -242,4 +243,49 @@ TEST_F(LogicCreatorTest, nested) {
     log_.checkFirst(2);
     log_.checkFirst(2);
 }
 }
 
 
+void notTest(bool value) {
+    NotOperator<Log> notOp(shared_ptr<Check<Log> >(new ConstCheck(value, 0)));
+    Log log;
+    // It returns negated value
+    EXPECT_EQ(!value, notOp.matches(log));
+    // And runs the only one thing there
+    log.checkFirst(1);
+    // Check the getSubexpressions does sane things
+    ASSERT_EQ(1, notOp.getSubexpressions().size());
+    EXPECT_EQ(value, notOp.getSubexpressions()[0]->matches(log));
+}
+
+TEST(Not, trueValue) {
+    notTest(true);
+}
+
+TEST(Not, falseValue) {
+    notTest(false);
+}
+
+TEST_F(LogicCreatorTest, notInvalid) {
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": null}")),
+                 LoaderError);
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": \"hello\"}")),
+                 LoaderError);
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": true}")),
+                 LoaderError);
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": 42}")),
+                 LoaderError);
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": []}")),
+                 LoaderError);
+    EXPECT_THROW(loader_.loadCheck(Element::fromJSON("{\"NOT\": [{"
+                                                     "\"logcheck\": [0, true]"
+                                                     "}]}")),
+                 LoaderError);
+}
+
+TEST_F(LogicCreatorTest, notValid) {
+    shared_ptr<NotOperator<Log> > notOp(load<NotOperator<Log> >("{\"NOT\":"
+                                                                "  {\"logcheck\":"
+                                                                "     [0, true]}}"));
+    EXPECT_FALSE(notOp->matches(log_));
+    log_.checkFirst(1);
+}
+
 }
 }

+ 10 - 1
src/lib/cache/Makefile.am

@@ -31,5 +31,14 @@ libcache_la_SOURCES  += cache_entry_key.h cache_entry_key.cc
 libcache_la_SOURCES  += rrset_copy.h rrset_copy.cc
 libcache_la_SOURCES  += rrset_copy.h rrset_copy.cc
 libcache_la_SOURCES  += local_zone_data.h local_zone_data.cc
 libcache_la_SOURCES  += local_zone_data.h local_zone_data.cc
 libcache_la_SOURCES  += message_utility.h message_utility.cc
 libcache_la_SOURCES  += message_utility.h message_utility.cc
+libcache_la_SOURCES  += logger.h logger.cc
+nodist_libcache_la_SOURCES = cache_messages.cc cache_messages.h
 
 
-CLEANFILES = *.gcno *.gcda
+BUILT_SOURCES = cache_messages.cc cache_messages.h
+
+cache_messages.cc cache_messages.h: cache_messages.mes
+	$(top_builddir)/src/lib/log/compiler/message $(top_srcdir)/src/lib/cache/cache_messages.mes
+
+CLEANFILES = *.gcno *.gcda cache_messages.cc cache_messages.h
+
+EXTRA_DIST = cache_messages.mes

+ 148 - 0
src/lib/cache/cache_messages.mes

@@ -0,0 +1,148 @@
+# 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.
+
+$NAMESPACE isc::cache
+
+% CACHE_ENTRY_MISSING_RRSET missing RRset to generate message for %1
+The cache tried to generate the complete answer message. It knows the structure
+of the message, but some of the RRsets to be put there are not in cache (they
+probably expired already). Therefore it pretends the message was not found.
+
+% CACHE_LOCALZONE_FOUND found entry with key %1 in local zone data
+Debug message, noting that the requested data was successfully found in the
+local zone data of the cache.
+
+% CACHE_LOCALZONE_UNKNOWN entry with key %1 not found in local zone data
+Debug message. The requested data was not found in the local zone data.
+
+% CACHE_LOCALZONE_UPDATE updating local zone element at key %1
+Debug message issued when there's update to the local zone section of cache.
+
+% CACHE_MESSAGES_DEINIT deinitialized message cache
+Debug message. It is issued when the server deinitializes the message cache.
+
+% CACHE_MESSAGES_EXPIRED found an expired message entry for %1 in the message cache
+Debug message. The requested data was found in the message cache, but it
+already expired. Therefore the cache removes the entry and pretends it found
+nothing.
+
+% CACHE_MESSAGES_FOUND found a message entry for %1 in the message cache
+Debug message. We found the whole message in the cache, so it can be returned
+to user without any other lookups.
+
+% CACHE_MESSAGES_INIT initialized message cache for %1 messages of class %2
+Debug message issued when a new message cache is issued. It lists the class
+of messages it can hold and the maximum size of the cache.
+
+% CACHE_MESSAGES_REMOVE removing old instance of %1/%2/%3 first
+Debug message. This may follow CACHE_MESSAGES_UPDATE and indicates that, while
+updating, the old instance is being removed prior of inserting a new one.
+
+% CACHE_MESSAGES_UNCACHEABLE not inserting uncacheable message %1/%2/%3
+Debug message, noting that the given message can not be cached. This is because
+there's no SOA record in the message. See RFC 2308 section 5 for more
+information.
+
+% CACHE_MESSAGES_UNKNOWN no entry for %1 found in the message cache
+Debug message. The message cache didn't find any entry for the given key.
+
+% CACHE_MESSAGES_UPDATE updating message entry %1/%2/%3
+Debug message issued when the message cache is being updated with a new
+message. Either the old instance is removed or, if none is found, new one
+is created.
+
+% CACHE_RESOLVER_DEEPEST looking up deepest NS for %1/%2
+Debug message. The resolver cache is looking up the deepest known nameserver,
+so the resolution doesn't have to start from the root.
+
+% CACHE_RESOLVER_INIT_INFO initializing resolver cache for class %1
+Debug message, the resolver cache is being created for this given class. The
+difference from CACHE_RESOLVER_INIT is only in different format of passed
+information, otherwise it does the same.
+
+% CACHE_RESOLVER_INIT initializing resolver cache for class %1
+Debug message. The resolver cache is being created for this given class.
+
+% CACHE_RESOLVER_LOCAL_MSG message for %1/%2 found in local zone data
+Debug message. The resolver cache found a complete message for the user query
+in the zone data.
+
+% CACHE_RESOLVER_LOCAL_RRSET RRset for %1/%2 found in local zone data
+Debug message. The resolver cache found a requested RRset in the local zone
+data.
+
+% CACHE_RESOLVER_LOOKUP_MSG looking up message in resolver cache for %1/%2
+Debug message. The resolver cache is trying to find a message to answer the
+user query.
+
+% CACHE_RESOLVER_LOOKUP_RRSET looking up RRset in resolver cache for %1/%2
+Debug message. The resolver cache is trying to find an RRset (which usually
+originates as internally from resolver).
+
+% CACHE_RESOLVER_NO_QUESTION answer message for %1/%2 has empty question section
+The cache tried to fill in found data into the response message. But it
+discovered the message contains no question section, which is invalid.
+This is likely a programmer error, please submit a bug report.
+
+% CACHE_RESOLVER_UNKNOWN_CLASS_MSG no cache for class %1
+Debug message. While trying to lookup a message in the resolver cache, it was
+discovered there's no cache for this class at all. Therefore no message is
+found.
+
+% CACHE_RESOLVER_UNKNOWN_CLASS_RRSET no cache for class %1
+Debug message. While trying to lookup an RRset in the resolver cache, it was
+discovered there's no cache for this class at all. Therefore no data is found.
+
+% CACHE_RESOLVER_UPDATE_MSG updating message for %1/%2/%3
+Debug message. The resolver is updating a message in the cache.
+
+% CACHE_RESOLVER_UPDATE_RRSET updating RRset for %1/%2/%3
+Debug message. The resolver is updating an RRset in the cache.
+
+% CACHE_RESOLVER_UPDATE_UNKNOWN_CLASS_MSG no cache for class %1
+Debug message. While trying to insert a message into the cache, it was
+discovered that there's no cache for the class of message. Therefore
+the message will not be cached.
+
+% CACHE_RESOLVER_UPDATE_UNKNOWN_CLASS_RRSET no cache for class %1
+Debug message. While trying to insert an RRset into the cache, it was
+discovered that there's no cache for the class of the RRset. Therefore
+the message will not be cached.
+
+% CACHE_RRSET_EXPIRED found expired RRset %1/%2/%3
+Debug message. The requested data was found in the RRset cache. However, it is
+expired, so the cache removed it and is going to pretend nothing was found.
+
+% CACHE_RRSET_INIT initializing RRset cache for %2 RRsets of class %1
+Debug message. The RRset cache to hold at most this many RRsets for the given
+class is being created.
+
+% CACHE_RRSET_LOOKUP looking up %1/%2/%3 in RRset cache
+Debug message. The resolver is trying to look up data in the RRset cache.
+
+% CACHE_RRSET_NOT_FOUND no RRset found for %1/%2/%3
+Debug message which can follow CACHE_RRSET_LOOKUP. This means the data is not
+in the cache.
+
+% CACHE_RRSET_REMOVE_OLD removing old RRset for %1/%2/%3 to make space for new one
+Debug message which can follow CACHE_RRSET_UPDATE. During the update, the cache
+removed an old instance of the RRset to replace it with the new one.
+
+% CACHE_RRSET_UNTRUSTED not replacing old RRset for %1/%2/%3, it has higher trust level
+Debug message which can follow CACHE_RRSET_UPDATE. The cache already holds the
+same RRset, but from more trusted source, so the old one is kept and new one
+ignored.
+
+% CACHE_RRSET_UPDATE updating RRset %1/%2/%3 in the cache
+Debug message. The RRset is updating its data with this given RRset.

+ 4 - 0
src/lib/cache/local_zone_data.cc

@@ -16,6 +16,7 @@
 #include "local_zone_data.h"
 #include "local_zone_data.h"
 #include "cache_entry_key.h"
 #include "cache_entry_key.h"
 #include "rrset_copy.h"
 #include "rrset_copy.h"
+#include "logger.h"
 
 
 using namespace std;
 using namespace std;
 using namespace isc::dns;
 using namespace isc::dns;
@@ -33,8 +34,10 @@ LocalZoneData::lookup(const isc::dns::Name& name,
     string key = genCacheEntryName(name, type);
     string key = genCacheEntryName(name, type);
     RRsetMapIterator iter = rrsets_map_.find(key);
     RRsetMapIterator iter = rrsets_map_.find(key);
     if (iter == rrsets_map_.end()) {
     if (iter == rrsets_map_.end()) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_LOCALZONE_UNKNOWN).arg(key);
         return (RRsetPtr());
         return (RRsetPtr());
     } else {
     } else {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_LOCALZONE_FOUND).arg(key);
         return (iter->second);
         return (iter->second);
     }
     }
 }
 }
@@ -43,6 +46,7 @@ void
 LocalZoneData::update(const isc::dns::RRset& rrset) {
 LocalZoneData::update(const isc::dns::RRset& rrset) {
     //TODO Do we really need to recreate the rrset again?
     //TODO Do we really need to recreate the rrset again?
     string key = genCacheEntryName(rrset.getName(), rrset.getType());
     string key = genCacheEntryName(rrset.getName(), rrset.getType());
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_LOCALZONE_UPDATE).arg(key);
     RRset* rrset_copy = new RRset(rrset.getName(), rrset.getClass(),
     RRset* rrset_copy = new RRset(rrset.getName(), rrset.getClass(),
                                   rrset.getType(), rrset.getTTL());
                                   rrset.getType(), rrset.getTTL());
 
 

+ 23 - 0
src/lib/cache/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 <cache/logger.h>
+
+namespace isc {
+namespace cache {
+
+isc::log::Logger logger("cache");
+
+}
+}

+ 44 - 0
src/lib/cache/logger.h

@@ -0,0 +1,44 @@
+// 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 <cache/cache_messages.h>
+
+/// \file logger.h
+/// \brief Cache library global logger
+///
+/// This holds the logger for the cache library. It is a private header
+/// and should not be included in any publicly used header, only in local
+/// cc files.
+
+namespace isc {
+namespace cache {
+
+/// \brief The logger for this library
+extern isc::log::Logger logger;
+
+enum {
+    /// \brief Trace basic operations
+    DBG_TRACE_BASIC = 10,
+    /// \brief Trace data operations
+    DBG_TRACE_DATA = 40,
+};
+
+}
+}
+
+#endif

+ 20 - 0
src/lib/cache/message_cache.cc

@@ -1,6 +1,7 @@
 // Copyright (C) 2010  Internet Systems Consortium, Inc. ("ISC")
 // Copyright (C) 2010  Internet Systems Consortium, Inc. ("ISC")
 //
 //
 // Permission to use, copy, modify, and/or distribute this software for any
 // Permission to use, copy, modify, and/or distribute this software for any
+//
 // purpose with or without fee is hereby granted, provided that the above
 // purpose with or without fee is hereby granted, provided that the above
 // copyright notice and this permission notice appear in all copies.
 // copyright notice and this permission notice appear in all copies.
 //
 //
@@ -20,6 +21,7 @@
 #include "message_cache.h"
 #include "message_cache.h"
 #include "message_utility.h"
 #include "message_utility.h"
 #include "cache_entry_key.h"
 #include "cache_entry_key.h"
+#include "logger.h"
 
 
 namespace isc {
 namespace isc {
 namespace cache {
 namespace cache {
@@ -39,11 +41,14 @@ MessageCache::MessageCache(const RRsetCachePtr& rrset_cache,
     message_lru_((3 * cache_size),
     message_lru_((3 * cache_size),
                   new HashDeleter<MessageEntry>(message_table_))
                   new HashDeleter<MessageEntry>(message_table_))
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, CACHE_MESSAGES_INIT).arg(cache_size).
+        arg(RRClass(message_class));
 }
 }
 
 
 MessageCache::~MessageCache() {
 MessageCache::~MessageCache() {
     // Destroy all the message entries in the cache.
     // Destroy all the message entries in the cache.
     message_lru_.clear();
     message_lru_.clear();
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, CACHE_MESSAGES_DEINIT);
 }
 }
 
 
 bool
 bool
@@ -57,26 +62,38 @@ MessageCache::lookup(const isc::dns::Name& qname,
     if(msg_entry) {
     if(msg_entry) {
         // Check whether the message entry has expired.
         // Check whether the message entry has expired.
        if (msg_entry->getExpireTime() > time(NULL)) {
        if (msg_entry->getExpireTime() > time(NULL)) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_FOUND).
+                arg(entry_name);
             message_lru_.touch(msg_entry);
             message_lru_.touch(msg_entry);
             return (msg_entry->genMessage(time(NULL), response));
             return (msg_entry->genMessage(time(NULL), response));
         } else {
         } else {
             // message entry expires, remove it from hash table and lru list.
             // message entry expires, remove it from hash table and lru list.
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_EXPIRED).
+                arg(entry_name);
             message_table_.remove(entry_key);
             message_table_.remove(entry_key);
             message_lru_.remove(msg_entry);
             message_lru_.remove(msg_entry);
             return (false);
             return (false);
        }
        }
     }
     }
 
 
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_UNKNOWN).arg(entry_name);
     return (false);
     return (false);
 }
 }
 
 
 bool
 bool
 MessageCache::update(const Message& msg) {
 MessageCache::update(const Message& msg) {
     if (!canMessageBeCached(msg)){
     if (!canMessageBeCached(msg)){
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_UNCACHEABLE).
+            arg((*msg.beginQuestion())->getName()).
+            arg((*msg.beginQuestion())->getType()).
+            arg((*msg.beginQuestion())->getClass());
         return (false);
         return (false);
     }
     }
 
 
     QuestionIterator iter = msg.beginQuestion();
     QuestionIterator iter = msg.beginQuestion();
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_UPDATE).
+        arg((*iter)->getName()).arg((*iter)->getType()).
+        arg((*iter)->getClass());
     std::string entry_name = genCacheEntryName((*iter)->getName(),
     std::string entry_name = genCacheEntryName((*iter)->getName(),
                                                (*iter)->getType());
                                                (*iter)->getType());
     HashKey entry_key = HashKey(entry_name, RRClass(message_class_));
     HashKey entry_key = HashKey(entry_name, RRClass(message_class_));
@@ -88,6 +105,9 @@ MessageCache::update(const Message& msg) {
     // add the message entry, maybe there is one way to touch it once.
     // add the message entry, maybe there is one way to touch it once.
     MessageEntryPtr old_msg_entry = message_table_.get(entry_key);
     MessageEntryPtr old_msg_entry = message_table_.get(entry_key);
     if (old_msg_entry) {
     if (old_msg_entry) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_MESSAGES_REMOVE).
+            arg((*iter)->getName()).arg((*iter)->getType()).
+            arg((*iter)->getClass());
         message_lru_.remove(old_msg_entry);
         message_lru_.remove(old_msg_entry);
     }
     }
 
 

+ 1 - 1
src/lib/cache/message_cache.h

@@ -39,7 +39,7 @@ private:
     MessageCache& operator=(const MessageCache& source);
     MessageCache& operator=(const MessageCache& source);
 public:
 public:
     /// \param rrset_cache The cache that stores the RRsets that the
     /// \param rrset_cache The cache that stores the RRsets that the
-    ///        message entry will points to
+    ///        message entry will point to
     /// \param cache_size The size of message cache.
     /// \param cache_size The size of message cache.
     /// \param message_class The class of the message cache
     /// \param message_class The class of the message cache
     /// \param negative_soa_cache The cache that stores the SOA record
     /// \param negative_soa_cache The cache that stores the SOA record

+ 4 - 1
src/lib/cache/message_entry.cc

@@ -20,6 +20,7 @@
 #include "message_entry.h"
 #include "message_entry.h"
 #include "message_utility.h"
 #include "message_utility.h"
 #include "rrset_cache.h"
 #include "rrset_cache.h"
+#include "logger.h"
 
 
 using namespace isc::dns;
 using namespace isc::dns;
 using namespace std;
 using namespace std;
@@ -64,7 +65,7 @@ static uint32_t MAX_UINT32 = numeric_limits<uint32_t>::max();
 // tunable.  Values of one to three hours have been found to work well
 // tunable.  Values of one to three hours have been found to work well
 // and would make sensible a default.  Values exceeding one day have
 // and would make sensible a default.  Values exceeding one day have
 // been found to be problematic. (sec 5, RFC2308)
 // been found to be problematic. (sec 5, RFC2308)
-// The default value is 3 hourse (10800 seconds)
+// The default value is 3 hours (10800 seconds)
 // TODO:Give an option to let user configure
 // TODO:Give an option to let user configure
 static uint32_t MAX_NEGATIVE_CACHE_TTL = 10800;
 static uint32_t MAX_NEGATIVE_CACHE_TTL = 10800;
 
 
@@ -142,6 +143,8 @@ MessageEntry::genMessage(const time_t& time_now,
         // has expired, if it is, return false.
         // has expired, if it is, return false.
         vector<RRsetEntryPtr> rrset_entry_vec;
         vector<RRsetEntryPtr> rrset_entry_vec;
         if (false == getRRsetEntries(rrset_entry_vec, time_now)) {
         if (false == getRRsetEntries(rrset_entry_vec, time_now)) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_ENTRY_MISSING_RRSET).
+                arg(entry_name_);
             return (false);
             return (false);
         }
         }
 
 

+ 32 - 0
src/lib/cache/resolver_cache.cc

@@ -17,6 +17,7 @@
 #include "resolver_cache.h"
 #include "resolver_cache.h"
 #include "dns/message.h"
 #include "dns/message.h"
 #include "rrset_cache.h"
 #include "rrset_cache.h"
+#include "logger.h"
 #include <string>
 #include <string>
 #include <algorithm>
 #include <algorithm>
 
 
@@ -29,6 +30,7 @@ namespace cache {
 ResolverClassCache::ResolverClassCache(const RRClass& cache_class) :
 ResolverClassCache::ResolverClassCache(const RRClass& cache_class) :
     cache_class_(cache_class)
     cache_class_(cache_class)
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, CACHE_RESOLVER_INIT).arg(cache_class);
     local_zone_data_ = LocalZoneDataPtr(new LocalZoneData(cache_class_.getCode()));
     local_zone_data_ = LocalZoneDataPtr(new LocalZoneData(cache_class_.getCode()));
     rrsets_cache_ = RRsetCachePtr(new RRsetCache(RRSET_CACHE_DEFAULT_SIZE,
     rrsets_cache_ = RRsetCachePtr(new RRsetCache(RRSET_CACHE_DEFAULT_SIZE,
                                                  cache_class_.getCode()));
                                                  cache_class_.getCode()));
@@ -45,6 +47,8 @@ ResolverClassCache::ResolverClassCache(const RRClass& cache_class) :
 ResolverClassCache::ResolverClassCache(const CacheSizeInfo& cache_info) :
 ResolverClassCache::ResolverClassCache(const CacheSizeInfo& cache_info) :
     cache_class_(cache_info.cclass)
     cache_class_(cache_info.cclass)
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, CACHE_RESOLVER_INIT_INFO).
+        arg(cache_class_);
     uint16_t klass = cache_class_.getCode();
     uint16_t klass = cache_class_.getCode();
     // TODO We should find one way to load local zone data.
     // TODO We should find one way to load local zone data.
     local_zone_data_ = LocalZoneDataPtr(new LocalZoneData(klass));
     local_zone_data_ = LocalZoneDataPtr(new LocalZoneData(klass));
@@ -69,8 +73,11 @@ ResolverClassCache::lookup(const isc::dns::Name& qname,
                       const isc::dns::RRType& qtype,
                       const isc::dns::RRType& qtype,
                       isc::dns::Message& response) const
                       isc::dns::Message& response) const
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_LOOKUP_MSG).
+        arg(qname).arg(qtype);
     // message response should has question section already.
     // message response should has question section already.
     if (response.beginQuestion() == response.endQuestion()) {
     if (response.beginQuestion() == response.endQuestion()) {
+        LOG_ERROR(logger, CACHE_RESOLVER_NO_QUESTION).arg(qname).arg(qtype);
         isc_throw(MessageNoQuestionSection, "Message has no question section");
         isc_throw(MessageNoQuestionSection, "Message has no question section");
     }
     }
 
 
@@ -79,6 +86,8 @@ ResolverClassCache::lookup(const isc::dns::Name& qname,
     // answer section.
     // answer section.
     RRsetPtr rrset_ptr = local_zone_data_->lookup(qname, qtype);
     RRsetPtr rrset_ptr = local_zone_data_->lookup(qname, qtype);
     if (rrset_ptr) {
     if (rrset_ptr) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_LOCAL_MSG).
+            arg(qname).arg(qtype);
         response.addRRset(Message::SECTION_ANSWER, rrset_ptr);
         response.addRRset(Message::SECTION_ANSWER, rrset_ptr);
         return (true);
         return (true);
     }
     }
@@ -91,11 +100,15 @@ isc::dns::RRsetPtr
 ResolverClassCache::lookup(const isc::dns::Name& qname,
 ResolverClassCache::lookup(const isc::dns::Name& qname,
                const isc::dns::RRType& qtype) const
                const isc::dns::RRType& qtype) const
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_LOOKUP_RRSET).
+        arg(qname).arg(qtype);
     // Algorithm:
     // Algorithm:
     // 1. Search in local zone data first,
     // 1. Search in local zone data first,
     // 2. Then do search in rrsets_cache_.
     // 2. Then do search in rrsets_cache_.
     RRsetPtr rrset_ptr = local_zone_data_->lookup(qname, qtype);
     RRsetPtr rrset_ptr = local_zone_data_->lookup(qname, qtype);
     if (rrset_ptr) {
     if (rrset_ptr) {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_LOCAL_RRSET).
+            arg(qname).arg(qtype);
         return (rrset_ptr);
         return (rrset_ptr);
     } else {
     } else {
         RRsetEntryPtr rrset_entry = rrsets_cache_->lookup(qname, qtype);
         RRsetEntryPtr rrset_entry = rrsets_cache_->lookup(qname, qtype);
@@ -109,6 +122,10 @@ ResolverClassCache::lookup(const isc::dns::Name& qname,
 
 
 bool
 bool
 ResolverClassCache::update(const isc::dns::Message& msg) {
 ResolverClassCache::update(const isc::dns::Message& msg) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_UPDATE_MSG).
+        arg((*msg.beginQuestion())->getName()).
+        arg((*msg.beginQuestion())->getType()).
+        arg((*msg.beginQuestion())->getClass());
     return (messages_cache_->update(msg));
     return (messages_cache_->update(msg));
 }
 }
 
 
@@ -130,6 +147,9 @@ ResolverClassCache::updateRRsetCache(const isc::dns::ConstRRsetPtr& rrset_ptr,
 
 
 bool
 bool
 ResolverClassCache::update(const isc::dns::ConstRRsetPtr& rrset_ptr) {
 ResolverClassCache::update(const isc::dns::ConstRRsetPtr& rrset_ptr) {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_UPDATE_RRSET).
+        arg(rrset_ptr->getName()).arg(rrset_ptr->getType()).
+        arg(rrset_ptr->getClass());
     // First update local zone, then update rrset cache.
     // First update local zone, then update rrset cache.
     local_zone_data_->update((*rrset_ptr.get()));
     local_zone_data_->update((*rrset_ptr.get()));
     updateRRsetCache(rrset_ptr, rrsets_cache_);
     updateRRsetCache(rrset_ptr, rrsets_cache_);
@@ -166,6 +186,8 @@ ResolverCache::lookup(const isc::dns::Name& qname,
     if (cc) {
     if (cc) {
         return (cc->lookup(qname, qtype, response));
         return (cc->lookup(qname, qtype, response));
     } else {
     } else {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_UNKNOWN_CLASS_MSG).
+            arg(qclass);
         return (false);
         return (false);
     }
     }
 }
 }
@@ -179,6 +201,8 @@ ResolverCache::lookup(const isc::dns::Name& qname,
     if (cc) {
     if (cc) {
         return (cc->lookup(qname, qtype));
         return (cc->lookup(qname, qtype));
     } else {
     } else {
+        LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_UNKNOWN_CLASS_RRSET).
+            arg(qclass);
         return (RRsetPtr());
         return (RRsetPtr());
     }
     }
 }
 }
@@ -187,6 +211,8 @@ isc::dns::RRsetPtr
 ResolverCache::lookupDeepestNS(const isc::dns::Name& qname,
 ResolverCache::lookupDeepestNS(const isc::dns::Name& qname,
                                const isc::dns::RRClass& qclass) const
                                const isc::dns::RRClass& qclass) const
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RESOLVER_DEEPEST).arg(qname).
+        arg(qclass);
     isc::dns::RRType qtype = RRType::NS();
     isc::dns::RRType qtype = RRType::NS();
     ResolverClassCache* cc = getClassCache(qclass);
     ResolverClassCache* cc = getClassCache(qclass);
     if (cc) {
     if (cc) {
@@ -213,6 +239,9 @@ ResolverCache::update(const isc::dns::Message& msg) {
     if (cc) {
     if (cc) {
         return (cc->update(msg));
         return (cc->update(msg));
     } else {
     } else {
+        LOG_DEBUG(logger, DBG_TRACE_DATA,
+                  CACHE_RESOLVER_UPDATE_UNKNOWN_CLASS_MSG).
+            arg((*msg.beginQuestion())->getClass());
         return (false);
         return (false);
     }
     }
 }
 }
@@ -223,6 +252,9 @@ ResolverCache::update(const isc::dns::ConstRRsetPtr& rrset_ptr) {
     if (cc) {
     if (cc) {
         return (cc->update(rrset_ptr));
         return (cc->update(rrset_ptr));
     } else {
     } else {
+        LOG_DEBUG(logger, DBG_TRACE_DATA,
+                  CACHE_RESOLVER_UPDATE_UNKNOWN_CLASS_RRSET).
+            arg(rrset_ptr->getClass());
         return (false);
         return (false);
     }
     }
 }
 }

+ 24 - 3
src/lib/cache/rrset_cache.cc

@@ -14,8 +14,9 @@
 
 
 #include <config.h>
 #include <config.h>
 
 
-#include <string>
 #include "rrset_cache.h"
 #include "rrset_cache.h"
+#include "logger.h"
+#include <string>
 #include <nsas/nsas_entry_compare.h>
 #include <nsas/nsas_entry_compare.h>
 #include <nsas/hash_table.h>
 #include <nsas/hash_table.h>
 #include <nsas/hash_deleter.h>
 #include <nsas/hash_deleter.h>
@@ -34,20 +35,28 @@ RRsetCache::RRsetCache(uint32_t cache_size,
     rrset_lru_((3 * cache_size),
     rrset_lru_((3 * cache_size),
                   new HashDeleter<RRsetEntry>(rrset_table_))
                   new HashDeleter<RRsetEntry>(rrset_table_))
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_BASIC, CACHE_RRSET_INIT).arg(cache_size).
+        arg(RRClass(rrset_class));
 }
 }
 
 
 RRsetEntryPtr
 RRsetEntryPtr
 RRsetCache::lookup(const isc::dns::Name& qname,
 RRsetCache::lookup(const isc::dns::Name& qname,
                    const isc::dns::RRType& qtype)
                    const isc::dns::RRType& qtype)
 {
 {
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_LOOKUP).arg(qname).
+        arg(qtype).arg(RRClass(class_));
     const string entry_name = genCacheEntryName(qname, qtype);
     const string entry_name = genCacheEntryName(qname, qtype);
-    RRsetEntryPtr entry_ptr = rrset_table_.get(HashKey(entry_name, RRClass(class_)));
+
+    RRsetEntryPtr entry_ptr = rrset_table_.get(HashKey(entry_name,
+                                                       RRClass(class_)));
     if (entry_ptr) {
     if (entry_ptr) {
         if (entry_ptr->getExpireTime() > time(NULL)) {
         if (entry_ptr->getExpireTime() > time(NULL)) {
             // Only touch the non-expired rrset entries
             // Only touch the non-expired rrset entries
             rrset_lru_.touch(entry_ptr);
             rrset_lru_.touch(entry_ptr);
             return (entry_ptr);
             return (entry_ptr);
         } else {
         } else {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_EXPIRED).arg(qname).
+                arg(qtype).arg(RRClass(class_));
             // the rrset entry has expired, so just remove it from
             // the rrset entry has expired, so just remove it from
             // hash table and lru list.
             // hash table and lru list.
             rrset_table_.remove(entry_ptr->hashKey());
             rrset_table_.remove(entry_ptr->hashKey());
@@ -55,19 +64,31 @@ RRsetCache::lookup(const isc::dns::Name& qname,
         }
         }
     }
     }
 
 
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_NOT_FOUND).arg(qname).
+        arg(qtype).arg(RRClass(class_));
     return (RRsetEntryPtr());
     return (RRsetEntryPtr());
 }
 }
 
 
 RRsetEntryPtr
 RRsetEntryPtr
-RRsetCache::update(const isc::dns::RRset& rrset, const RRsetTrustLevel& level) {
+RRsetCache::update(const isc::dns::RRset& rrset,
+                   const RRsetTrustLevel& level)
+{
+    LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_UPDATE).arg(rrset.getName()).
+        arg(rrset.getType()).arg(rrset.getClass());
     // TODO: If the RRset is an NS, we should update the NSAS as well
     // TODO: If the RRset is an NS, we should update the NSAS as well
     // lookup first
     // lookup first
     RRsetEntryPtr entry_ptr = lookup(rrset.getName(), rrset.getType());
     RRsetEntryPtr entry_ptr = lookup(rrset.getName(), rrset.getType());
     if (entry_ptr) {
     if (entry_ptr) {
         if (entry_ptr->getTrustLevel() > level) {
         if (entry_ptr->getTrustLevel() > level) {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_UNTRUSTED).
+                arg(rrset.getName()).arg(rrset.getType()).
+                arg(rrset.getClass());
             // existed rrset entry is more authoritative, just return it
             // existed rrset entry is more authoritative, just return it
             return (entry_ptr);
             return (entry_ptr);
         } else {
         } else {
+            LOG_DEBUG(logger, DBG_TRACE_DATA, CACHE_RRSET_REMOVE_OLD).
+                arg(rrset.getName()).arg(rrset.getType()).
+                arg(rrset.getClass());
             // Remove the old rrset entry from the lru list.
             // Remove the old rrset entry from the lru list.
             rrset_lru_.remove(entry_ptr);
             rrset_lru_.remove(entry_ptr);
         }
         }

+ 1 - 0
src/lib/cache/tests/Makefile.am

@@ -53,6 +53,7 @@ run_unittests_LDADD += -lboost_thread
 endif
 endif
 
 
 run_unittests_LDADD += $(top_builddir)/src/lib/cache/libcache.la
 run_unittests_LDADD += $(top_builddir)/src/lib/cache/libcache.la
+run_unittests_LDADD += $(top_builddir)/src/lib/log/liblog.la
 run_unittests_LDADD += $(top_builddir)/src/lib/nsas/libnsas.la
 run_unittests_LDADD += $(top_builddir)/src/lib/nsas/libnsas.la
 run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
 run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
 run_unittests_LDADD += $(top_builddir)/src/lib/asiolink/libasiolink.la
 run_unittests_LDADD += $(top_builddir)/src/lib/asiolink/libasiolink.la

+ 4 - 0
src/lib/cache/tests/run_unittests.cc

@@ -19,11 +19,15 @@
 
 
 #include <dns/tests/unittest_util.h>
 #include <dns/tests/unittest_util.h>
 
 
+#include <log/logger_support.h>
+
 int
 int
 main(int argc, char* argv[]) {
 main(int argc, char* argv[]) {
     ::testing::InitGoogleTest(&argc, argv);
     ::testing::InitGoogleTest(&argc, argv);
     isc::UnitTestUtil::addDataPath(TEST_DATA_SRCDIR);
     isc::UnitTestUtil::addDataPath(TEST_DATA_SRCDIR);
     isc::UnitTestUtil::addDataPath(TEST_DATA_BUILDDIR);
     isc::UnitTestUtil::addDataPath(TEST_DATA_BUILDDIR);
 
 
+    isc::log::initLogger();
+
     return (isc::util::unittests::run_all());
     return (isc::util::unittests::run_all());
 }
 }

+ 1 - 1
src/lib/dns/tests/tsig_unittest.cc

@@ -440,7 +440,7 @@ TEST_F(TSIGTest, signUsingHMACSHA224) {
         0xef, 0x33, 0xa2, 0xda, 0xa1, 0x48, 0x71, 0xd3
         0xef, 0x33, 0xa2, 0xda, 0xa1, 0x48, 0x71, 0xd3
     };
     };
     {
     {
-        SCOPED_TRACE("Sign test using HMAC-SHA1");
+        SCOPED_TRACE("Sign test using HMAC-SHA224");
         commonSignChecks(createMessageAndSign(sha1_qid, test_name, &sha1_ctx),
         commonSignChecks(createMessageAndSign(sha1_qid, test_name, &sha1_ctx),
                          sha1_qid, 0x4dae7d5f, expected_mac,
                          sha1_qid, 0x4dae7d5f, expected_mac,
                          sizeof(expected_mac), 0, 0, NULL,
                          sizeof(expected_mac), 0, 0, NULL,

+ 31 - 1
src/lib/log/log_formatter.h

@@ -18,12 +18,28 @@
 #include <cstddef>
 #include <cstddef>
 #include <string>
 #include <string>
 #include <iostream>
 #include <iostream>
+
+#include <exceptions/exceptions.h>
 #include <boost/lexical_cast.hpp>
 #include <boost/lexical_cast.hpp>
 #include <log/logger_level.h>
 #include <log/logger_level.h>
 
 
 namespace isc {
 namespace isc {
 namespace log {
 namespace log {
 
 
+/// \brief Format Failure
+///
+/// This exception is used to wrap a bad_lexical_cast exception thrown during
+/// formatting an argument.
+
+class FormatFailure : public isc::Exception {
+public:
+    FormatFailure(const char* file, size_t line, const char* what) :
+        isc::Exception(file, line, what)
+    {}
+};
+
+
+///
 /// \brief The internal replacement routine
 /// \brief The internal replacement routine
 ///
 ///
 /// This is used internally by the Formatter. Replaces a placeholder
 /// This is used internally by the Formatter. Replaces a placeholder
@@ -156,7 +172,21 @@ public:
     /// \param arg The argument to place into the placeholder.
     /// \param arg The argument to place into the placeholder.
     template<class Arg> Formatter& arg(const Arg& value) {
     template<class Arg> Formatter& arg(const Arg& value) {
         if (logger_) {
         if (logger_) {
-            return (arg(boost::lexical_cast<std::string>(value)));
+            try {
+                return (arg(boost::lexical_cast<std::string>(value)));
+            } catch (const boost::bad_lexical_cast& ex) {
+
+                // A bad_lexical_cast during a conversion to a string is
+                // *extremely* unlikely to fail.  However, there is nothing
+                // in the documentation that rules it out, so we need to handle
+                // it.  As it is a potentially very serious problem, throw the
+                // exception detailing the problem with as much information as
+                // we can.  (Note that this does not include 'value' -
+                // boost::lexical_cast failed to convert it to a string, so an
+                // attempt to do so here would probably fail as well.)
+                isc_throw(FormatFailure, "bad_lexical_cast in call to "
+                          "Formatter::arg(): " << ex.what());
+            }
         } else {
         } else {
             return (*this);
             return (*this);
         }
         }

+ 1 - 1
src/lib/log/log_messages.cc

@@ -1,4 +1,4 @@
-// File created from log_messages.mes on Wed Jun 22 11:54:57 2011
+// File created from log_messages.mes on Thu Jul  7 15:32:06 2011
 
 
 #include <cstddef>
 #include <cstddef>
 #include <log/message_types.h>
 #include <log/message_types.h>

+ 1 - 1
src/lib/log/log_messages.h

@@ -1,4 +1,4 @@
-// File created from log_messages.mes on Wed Jun 22 11:54:57 2011
+// File created from log_messages.mes on Thu Jul  7 15:32:06 2011
 
 
 #ifndef __LOG_MESSAGES_H
 #ifndef __LOG_MESSAGES_H
 #define __LOG_MESSAGES_H
 #define __LOG_MESSAGES_H

+ 16 - 16
src/lib/log/log_messages.mes

@@ -28,23 +28,23 @@ destination should be one of "console", "file", or "syslog".
 
 
 % LOG_BAD_SEVERITY unrecognized log severity: %1
 % LOG_BAD_SEVERITY unrecognized log severity: %1
 A logger severity value was given that was not recognized. The severity
 A logger severity value was given that was not recognized. The severity
-should be one of "DEBUG", "INFO", "WARN", "ERROR", or "FATAL".
+should be one of "DEBUG", "INFO", "WARN", "ERROR", "FATAL" or "NONE".
 
 
 % LOG_BAD_STREAM bad log console output stream: %1
 % LOG_BAD_STREAM bad log console output stream: %1
-A log console output stream was given that was not recognized. The output
+Logging has been configured so that output is written to the terminal
-stream should be one of "stdout", or "stderr"
+(console) but the stream on which it is to be written is not recognised.
+Allowed values are "stdout" and "stderr".
 
 
 % LOG_DUPLICATE_MESSAGE_ID duplicate message ID (%1) in compiled code
 % LOG_DUPLICATE_MESSAGE_ID duplicate message ID (%1) in compiled code
-During start-up, BIND10 detected that the given message identification had
+During start-up, BIND 10 detected that the given message identification
-been defined multiple times in the BIND10 code.
+had been defined multiple times in the BIND 10 code.  This indicates a
-
+programming error; please submit a bug report.
-This has no ill-effects other than the possibility that an erronous
-message may be logged.  However, as it is indicative of a programming
-error, please log a bug report.
 
 
 % LOG_DUPLICATE_NAMESPACE line %1: duplicate $NAMESPACE directive found
 % LOG_DUPLICATE_NAMESPACE line %1: duplicate $NAMESPACE directive found
 When reading a message file, more than one $NAMESPACE directive was found.
 When reading a message file, more than one $NAMESPACE directive was found.
-Such a condition is regarded as an error and the read will be abandoned.
+(This directive is used to set a C++ namespace when generating header
+files during software development.)  Such a condition is regarded as an
+error and the read will be abandoned.
 
 
 % LOG_INPUT_OPEN_FAIL unable to open message file %1 for input: %2
 % LOG_INPUT_OPEN_FAIL unable to open message file %1 for input: %2
 The program was not able to open the specified input message file for
 The program was not able to open the specified input message file for
@@ -99,10 +99,10 @@ There may be several reasons why this message may appear:
 - The program outputting the message may not use that particular message
 - The program outputting the message may not use that particular message
 (e.g. it originates in a module not used by the program.)
 (e.g. it originates in a module not used by the program.)
 
 
-- The local file was written for an earlier version of the BIND10 software
+- The local file was written for an earlier version of the BIND 10 software
 and the later version no longer generates that message.
 and the later version no longer generates that message.
 
 
-Whatever the reason, there is no impact on the operation of BIND10.
+Whatever the reason, there is no impact on the operation of BIND 10.
 
 
 % LOG_OPEN_OUTPUT_FAIL unable to open %1 for output: %2
 % LOG_OPEN_OUTPUT_FAIL unable to open %1 for output: %2
 Originating within the logging code, the program was not able to open
 Originating within the logging code, the program was not able to open
@@ -115,7 +115,7 @@ This error is generated when the compiler finds a $PREFIX directive with
 more than one argument.
 more than one argument.
 
 
 Note: the $PREFIX directive is deprecated and will be removed in a future
 Note: the $PREFIX directive is deprecated and will be removed in a future
-version of BIND10.
+version of BIND 10.
 
 
 % LOG_PREFIX_INVALID_ARG line %1: $PREFIX directive has an invalid argument ('%2')
 % LOG_PREFIX_INVALID_ARG line %1: $PREFIX directive has an invalid argument ('%2')
 Within a message file, the $PREFIX directive takes a single argument,
 Within a message file, the $PREFIX directive takes a single argument,
@@ -123,13 +123,13 @@ a prefix to be added to the symbol names when a C++ file is created.
 As such, it must adhere to restrictions on C++ symbol names (e.g. may
 As such, it must adhere to restrictions on C++ symbol names (e.g. may
 only contain alphanumeric characters or underscores, and may nor start
 only contain alphanumeric characters or underscores, and may nor start
 with a digit).  A $PREFIX directive was found with an argument (given
 with a digit).  A $PREFIX directive was found with an argument (given
-in the message) that violates those restictions.
+in the message) that violates those restrictions.
 
 
 Note: the $PREFIX directive is deprecated and will be removed in a future
 Note: the $PREFIX directive is deprecated and will be removed in a future
-version of BIND10.
+version of BIND 10.
 
 
 % LOG_READING_LOCAL_FILE reading local message file %1
 % LOG_READING_LOCAL_FILE reading local message file %1
-This is an informational message output by BIND10 when it starts to read
+This is an informational message output by BIND 10 when it starts to read
 a local message file.  (A local message file may replace the text of
 a local message file.  (A local message file may replace the text of
 one of more messages; the ID of the message will not be changed though.)
 one of more messages; the ID of the message will not be changed though.)
 
 

+ 2 - 0
src/lib/log/tests/Makefile.am

@@ -51,6 +51,7 @@ logger_example_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES)
 logger_example_LDFLAGS = $(AM_LDFLAGS) $(LOG4CPLUS_LDFLAGS)
 logger_example_LDFLAGS = $(AM_LDFLAGS) $(LOG4CPLUS_LDFLAGS)
 logger_example_LDADD  = $(top_builddir)/src/lib/log/liblog.la
 logger_example_LDADD  = $(top_builddir)/src/lib/log/liblog.la
 logger_example_LDADD += $(top_builddir)/src/lib/util/libutil.la
 logger_example_LDADD += $(top_builddir)/src/lib/util/libutil.la
+logger_example_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la
 
 
 check_PROGRAMS += init_logger_test
 check_PROGRAMS += init_logger_test
 init_logger_test_SOURCES = init_logger_test.cc
 init_logger_test_SOURCES = init_logger_test.cc
@@ -58,6 +59,7 @@ init_logger_test_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES)
 init_logger_test_LDFLAGS = $(AM_LDFLAGS) $(LOG4CPLUS_LDFLAGS)
 init_logger_test_LDFLAGS = $(AM_LDFLAGS) $(LOG4CPLUS_LDFLAGS)
 init_logger_test_LDADD  = $(top_builddir)/src/lib/log/liblog.la
 init_logger_test_LDADD  = $(top_builddir)/src/lib/log/liblog.la
 init_logger_test_LDADD += $(top_builddir)/src/lib/util/libutil.la
 init_logger_test_LDADD += $(top_builddir)/src/lib/util/libutil.la
+init_logger_test_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la
 
 
 noinst_PROGRAMS = $(TESTS)
 noinst_PROGRAMS = $(TESTS)
 
 

+ 1 - 0
src/lib/server_common/tests/Makefile.am

@@ -41,6 +41,7 @@ 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/log/liblog.la
 run_unittests_LDADD += $(top_builddir)/src/lib/acl/libacl.la
 run_unittests_LDADD += $(top_builddir)/src/lib/acl/libacl.la
 run_unittests_LDADD += $(top_builddir)/src/lib/util/libutil.la
 run_unittests_LDADD += $(top_builddir)/src/lib/util/libutil.la
+run_unittests_LDADD += $(top_builddir)/src/lib/log/liblog.la
 run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
 run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
 run_unittests_LDADD += $(top_builddir)/src/lib/util/unittests/libutil_unittests.la
 run_unittests_LDADD += $(top_builddir)/src/lib/util/unittests/libutil_unittests.la
 run_unittests_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la
 run_unittests_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la