[trac738] Update logging in command.cc

src/bin/auth/auth_log.h

@@ -27,12 +27,13 @@ namespace auth {
 /// the b10-auth program.  Higher numbers equate to more verbose (and detailed)
 /// output.
 
-// The first level traces normal operations - asking the AUTH for an address,
+// The first level traces start-up, recorded as every components starts.
-// and cancelling a lookup.  It also records when the AUTH calls back to the
-// resolver to resolve something.
 const int DBG_AUTH_START = 10;
 
-/// define the logger for the "auth" module part of b10-auth.  We could define
+// This level traces more detailed high-level operations.
+const int DBG_AUTH_OPS = 30;
+
+/// Define the logger for the "auth" module part of b10-auth.  We could define
 /// a logger in each file, but we would want to define a common name to avoid
 /// spelling mistakes, so it is just one small step from there to define a
 /// module-common logger.

src/bin/auth/auth_messages.mes

@@ -14,6 +14,10 @@
 
 $NAMESPACE isc::auth
 
+% AUTH_COMMAND_FAILED execution of command '%1' failed: %2
+Execution of the specified command by the authoritative server failed.  The
+message contains the reason for the failure.
+
 % AUTH_CONFIG_CHANNEL_CREATED configuration session channel created
 A debug message indicating that authoritative server has created the channel to
 the configuration manager.
@@ -41,9 +45,21 @@ created.
 A debug message indicating that the authoritiative server has successfully
 accessed the keyring holding TSIG keys.
 
+% AUTH_LOAD_ZONE loaded zone %1/%2
+The authoritative server has loaded the named zone of the named class.
+
 % AUTH_NO_STATS_SESSION session interface for statistics is not available
 For some reason, no session to the statistics module is available.  This could
-be an error in configuration
+be an error in configuration.
+
+% AUTH_RECEIVED_COMMAND command '%1' received
+A debug message issues when the authoritative server has received a command.
+
+% AUTH_RECEIVED_SENDSTATS command 'sendstats' received
+A debug message issues when the authoritative server has received a command
+from the statistics module to send it the server's statistics data.  The
+'sendstats' command is handled differently to other commands, which is why
+the debug message associated with it has its own code.
 
 % AUTH_SERVER_CREATED   server created
 An informational message indicating that the authoritative server process has
@@ -59,6 +75,11 @@ reason for the failure is included in the message.
 Initialization of the authoritative server has completed successfully
 and it is entering the main loop, waiting for queries to arrive.
 
+% AUTH_SQLITE3 nothing to do for loading sqlite3
+A debug message indicating that the authoritative server has found that the
+data source it is loading is an SQLite3 data source, so no further validation is
+needed.
+
 % AUTH_STATS_CHANNEL_CREATED STATS session channel created
 A debug message indicating that the authoritative server has created a channel
 to the statistics process.

src/bin/auth/benchmarks/Makefile.am

@@ -12,6 +12,9 @@ query_bench_SOURCES += ../query.h  ../query.cc
 query_bench_SOURCES += ../auth_srv.h ../auth_srv.cc
 query_bench_SOURCES += ../auth_config.h ../auth_config.cc
 query_bench_SOURCES += ../statistics.h ../statistics.cc
+query_bench_SOURCES += ../auth_log.h ../auth_log.cc
+
+nodist_query_bench_SOURCES = ../auth_messages.h ../auth_messages.cc
 
 query_bench_LDADD = $(top_builddir)/src/lib/dns/libdns++.la
 query_bench_LDADD += $(top_builddir)/src/lib/exceptions/libexceptions.la

src/bin/auth/command.cc

@@ -27,16 +27,18 @@
 
 #include <config/ccsession.h>
 
+#include <auth/auth_log.h>
 #include <auth/auth_srv.h>
 #include <auth/command.h>
 
-using namespace std;
-using boost::shared_ptr;
 using boost::scoped_ptr;
-using namespace isc::dns;
+using boost::shared_ptr;
+using namespace isc::auth;
+using namespace isc::config;
 using namespace isc::data;
 using namespace isc::datasrc;
-using namespace isc::config;
+using namespace isc::dns;
+using namespace std;
 
 namespace {
 /// An exception that is thrown if an error occurs while handling a command
@@ -115,9 +117,7 @@ public:
 class SendStatsCommand : public AuthCommand {
 public:
     virtual void exec(AuthSrv& server, isc::data::ConstElementPtr) {
-        if (server.getVerbose()) {
+        LOG_DEBUG(auth_logger, DBG_AUTH_OPS, AUTH_RECEIVED_SENDSTATS);
-            cerr << "[b10-auth] command 'sendstats' received" << endl;
-        }
         server.submitStatistics();
     }
 };
@@ -140,11 +140,8 @@ public:
                                                       oldzone->getOrigin()));
         newzone->load(oldzone->getFileName());
         oldzone->swap(*newzone);
-
+        LOG_DEBUG(auth_logger, DBG_AUTH_OPS, AUTH_LOAD_ZONE)
-        if (server.getVerbose()) {
+                  .arg(newzone->getOrigin()).arg(newzone->getClass());
-            cerr << "[b10-auth] Loaded zone '" << newzone->getOrigin()
-                 << "'/" << newzone->getClass() << endl;
-        }
     }
 
 private:
@@ -164,10 +161,7 @@ private:
         ConstElementPtr datasrc_elem = args->get("datasrc");
         if (datasrc_elem) {
             if (datasrc_elem->stringValue() == "sqlite3") {
-                if (server.getVerbose()) {
+                LOG_DEBUG(auth_logger, DBG_AUTH_OPS, AUTH_SQLITE3);
-                    cerr << "[b10-auth] Nothing to do for loading sqlite3"
-                         << endl;
-                }
                 return (false);
             } else if (datasrc_elem->stringValue() != "memory") {
                 // (note: at this point it's guaranteed that datasrc_elem
@@ -233,18 +227,14 @@ ConstElementPtr
 execAuthServerCommand(AuthSrv& server, const string& command_id,
                       ConstElementPtr args)
 {
-    if (server.getVerbose()) {
+    LOG_DEBUG(auth_logger, DBG_AUTH_OPS, AUTH_RECEIVED_COMMAND).arg(command_id);
-        cerr << "[b10-auth] Received '" << command_id << "' command" << endl;
-    }
-
     try {
         scoped_ptr<AuthCommand>(createAuthCommand(command_id))->exec(server,
                                                                      args);
     } catch (const isc::Exception& ex) {
-        if (server.getVerbose()) {
+        // TODO: SHould this be LOG_ERROR?
-            cerr << "[b10-auth] Command '" << command_id
+        LOG_DEBUG(auth_logger, DBG_AUTH_OPS, AUTH_COMMAND_FAILED)
-                 << "' execution failed: " << ex.what() << endl;
+                  .arg(command_id).arg(ex.what());
-        }
         return (createAnswer(1, ex.what()));
     }