BIND 10 experiments/stephen-bind9log, updated. 1a8cccd0bf7c43b281bd5ed6a7edf9131a2eb536 [experiments/stephen-bind9log] Changes to get logger using BIND 9 logging

BIND 10 source code commits bind10-changes at lists.isc.org
Tue Apr 26 11:50:30 UTC 2011


The branch, experiments/stephen-bind9log has been updated
       via  1a8cccd0bf7c43b281bd5ed6a7edf9131a2eb536 (commit)
      from  a31f9ccb9b7c2f2ddd4bbd1df4fb087211cf0392 (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 1a8cccd0bf7c43b281bd5ed6a7edf9131a2eb536
Author: Stephen Morris <stephen at isc.org>
Date:   Tue Apr 26 12:49:21 2011 +0100

    [experiments/stephen-bind9log] Changes to get logger using BIND 9 logging

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

Summary of changes:
 src/lib/bind9/Makefile.am  |    2 +-
 src/lib/log/logger_impl.cc |  201 +++++++++++++++++++++++++++++++-------------
 src/lib/log/logger_impl.h  |   69 ++++++++-------
 3 files changed, 182 insertions(+), 90 deletions(-)

-----------------------------------------------------------------------
diff --git a/src/lib/bind9/Makefile.am b/src/lib/bind9/Makefile.am
index 871efee..a078295 100644
--- a/src/lib/bind9/Makefile.am
+++ b/src/lib/bind9/Makefile.am
@@ -5,7 +5,7 @@ AM_CFLAGS  += -I$(top_srcdir)/src/lib/bind9/include
 AM_CFLAGS  += -I$(top_srcdir)/src/lib/bind9/unix/include
 AM_CFLAGS  += -I$(top_srcdir)/src/lib/bind9/nothreads/include
 AM_CFLAGS  += -I$(top_srcdir)/src/lib/bind9/x86_32/include
-AM_CFLAGS  += -Wformat -Wpointer-arith -Wmissing-prototypes
+AM_CFLAGS  += -g -Wformat -Wpointer-arith -Wmissing-prototypes
 
 CLEANFILES = *.gcno *.gcda
 
diff --git a/src/lib/log/logger_impl.cc b/src/lib/log/logger_impl.cc
index de909be..222c741 100644
--- a/src/lib/log/logger_impl.cc
+++ b/src/lib/log/logger_impl.cc
@@ -12,12 +12,12 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE
 
-#include <iostream>
 #include <algorithm>
 #include <cassert>
 
 #include <stdarg.h>
 #include <stdio.h>
+#include <string.h>
 #include <boost/lexical_cast.hpp>
 
 #include <log/debug_levels.h>
@@ -28,6 +28,8 @@
 #include <log/message_types.h>
 #include <log/root_logger_name.h>
 
+#include <isc/log.h>
+
 #include <util/strutil.h>
 
 using namespace std;
@@ -35,15 +37,43 @@ using namespace std;
 namespace isc {
 namespace log {
 
-// Static initializations
+// Static variables.  To avoid the static initialization fiasco, all the
+// static variables are accessed through functions which declare them static
+// inside. (The variables are created the first time the function is called.)
+
+LoggerImpl::LoggerInfo&
+LoggerImpl::rootLoggerInfo() {
+    static LoggerInfo root_logger_info(isc::log::INFO, 0);
+    return root_logger_info;
+}
+
+LoggerImpl::LoggerInfoMap&
+LoggerImpl::loggerInfo() {
+    static LoggerInfoMap logger_info;
+    return logger_info;
+}
 
-LoggerImpl::LoggerInfoMap LoggerImpl::logger_info_;
-LoggerImpl::LoggerInfoMap LoggerImpl::bind9_info_;
-LoggerImpl::LoggerInfo LoggerImpl::root_logger_info_(isc::log::INFO, 0);
+LoggerImpl::LoggerInfoMap&
+LoggerImpl::bind9Info() {
+    static LoggerInfoMap bind9_info;
+    return bind9_info;
+}
+
+// The following is a temporary function purely for the validation of BIND 9
+// logging in BIND 10.  It is used in the unit tests to determine if the
+// default channel - write to stderr and print all information - has been
+// created.
+
+bool&
+LoggerImpl::channelCreated() {
+    static bool created(false);
+    return created;
+}
 
 // Constructor
 LoggerImpl::LoggerImpl(const std::string& name, bool) : mctx_(0), lctx_(0), lcfg_(0)
 {
+
     // Regardless of anything else, category is the unadorned name of
     // the logger.
     category_ = name;
@@ -71,8 +101,8 @@ LoggerImpl::LoggerImpl(const std::string& name, bool) : mctx_(0), lctx_(0), lcfg
         name_ = name;
 
         // See if it has already been initialized.
-        initialized = root_logger_info_.init;
-        root_logger_info_.init = true;
+        initialized = rootLoggerInfo().init;
+        rootLoggerInfo().init = true;
 
     } else {
 
@@ -81,22 +111,60 @@ LoggerImpl::LoggerImpl(const std::string& name, bool) : mctx_(0), lctx_(0), lcfg
         name_ = getRootLoggerName() + "." + name;
 
         // Has a copy of this module already been initialized?
-        LoggerInfoMap::iterator i = bind9_info_.find(name_);
-        if (i != bind9_info_.end()) {
+        LoggerInfoMap::iterator i = bind9Info().find(name_);
+        if (i != bind9Info().end()) {
             // Yes!
             initialized = true;
         } else {
 
             // No - add information to the map.
             initialized = false;
-            bind9_info_[name_] =
-                LoggerInfo(isc::log::INFO, MIN_DEBUG_LEVEL, true);
+            bind9Info()[name_].reset(
+                new LoggerInfo(isc::log::INFO, MIN_DEBUG_LEVEL, true));
         }
     }
 
     if (! initialized) {
         bind9LogInit();
+
+        // Create a default channel (called "def_channel") if required.  This
+        // logs to stdout and prints all information (time, module, category
+        if (! channelCreated()) {
+            isc_logdestination destination;
+            memset(&destination, 0, sizeof(destination));
+            destination.file.stream = stdout;
+            if (! lcfg_) {
+                std::cerr << "Logging config is NULL\n";
+            }
+            isc_result_t result = isc_log_createchannel(lcfg_, "def_channel",
+                ISC_LOG_TOFILEDESC, ISC_LOG_INFO, &destination, ISC_LOG_PRINTALL);
+            if (result != ISC_R_SUCCESS) {
+                std::cout << "ERROR: Unable to create def_channel\n";
+            }
+
+            result = isc_log_usechannel(lcfg_, "def_channel", NULL, NULL);
+            if (result != ISC_R_SUCCESS) {
+                std::cout << "ERROR: Unable to use def_channel\n";
+            }
+        }
+                
+        // Save memory and logging context for later retrieval
+        if (is_root_) {
+            rootLoggerInfo().lctx = lctx_;
+            rootLoggerInfo().lcfg = lcfg_;
+            rootLoggerInfo().mctx = mctx_;
+        } else {
+            bind9Info()[name_]->lctx = lctx_;
+            bind9Info()[name_]->lcfg = lcfg_;
+            bind9Info()[name_]->mctx = mctx_;
+        }
+    } else {
+        // Restore context from saved BIND 9 information
+        mctx_ = bind9Info()[name_]->mctx;
+        lctx_ = bind9Info()[name_]->lctx;
+        lcfg_ = bind9Info()[name_]->lcfg;
     }
+
 }
 
 // Do BIND 9 Logging initialization
@@ -106,11 +174,12 @@ LoggerImpl::bind9LogInit() {
 
     if ((isc_mem_create(0, 0, &mctx_) != ISC_R_SUCCESS) ||
         (isc_log_create(mctx_, &lctx_, &lcfg_) != ISC_R_SUCCESS)) {
-        std::cout << "Unable to create BIND 9 context\n";
+        std::cout << "ERROR: Unable to create BIND 9 context\n";
     }
 
     isc_log_registercategories(lctx_, categories_);
     isc_log_registermodules(lctx_, modules_);
+
 }
 
 
@@ -120,6 +189,8 @@ LoggerImpl::~LoggerImpl() {
     // Free up space for BIND 9 strings
     free(const_cast<void*>(static_cast<const void*>(modules_[0].name))); modules_[0].name = NULL;
     free(const_cast<void*>(static_cast<const void*>(categories_[0].name))); categories_[0].name = NULL;
+
+    // Free up the logging context
 }
 
 // Set the severity for logging.
@@ -135,22 +206,22 @@ LoggerImpl::setSeverity(isc::log::Severity severity, int dbglevel) {
         // Can only set severity for the root logger, you can't disable it.
         // Any attempt to do so is silently ignored.
         if (severity != isc::log::DEFAULT) {
-            root_logger_info_ = LoggerInfo(severity, debug_level);
+            rootLoggerInfo() = LoggerInfo(severity, debug_level);
         }
 
     } else if (severity == isc::log::DEFAULT) {
 
         // Want to set to default; this means removing the information
-        // about this logger from the logger_info_ if it is set.
-        LoggerInfoMap::iterator i = logger_info_.find(name_);
-        if (i != logger_info_.end()) {
-            logger_info_.erase(i);
+        // about this logger from the loggerInfo() if it is set.
+        LoggerInfoMap::iterator i = loggerInfo().find(name_);
+        if (i != loggerInfo().end()) {
+            loggerInfo().erase(i);
         }
 
     } else {
 
         // Want to set this information
-        logger_info_[name_] = LoggerInfo(severity, debug_level);
+        loggerInfo()[name_].reset(new LoggerInfo(severity, debug_level));
     }
 }
 
@@ -160,12 +231,12 @@ isc::log::Severity
 LoggerImpl::getSeverity() {
 
     if (is_root_) {
-        return (root_logger_info_.severity);
+        return (rootLoggerInfo().severity);
     }
     else {
-        LoggerInfoMap::iterator i = logger_info_.find(name_);
-        if (i != logger_info_.end()) {
-           return ((i->second).severity);
+        LoggerInfoMap::iterator i = loggerInfo().find(name_);
+        if (i != loggerInfo().end()) {
+           return ((i->second)->severity);
         }
         else {
             return (isc::log::DEFAULT);
@@ -179,21 +250,21 @@ LoggerImpl::getSeverity() {
 isc::log::Severity
 LoggerImpl::getEffectiveSeverity() {
 
-    if (!is_root_ && !logger_info_.empty()) {
+    if (!is_root_ && !loggerInfo().empty()) {
 
         // Not root logger and there is at least one item in the info map for a
         // logger.
-        LoggerInfoMap::iterator i = logger_info_.find(name_);
-        if (i != logger_info_.end()) {
+        LoggerInfoMap::iterator i = loggerInfo().find(name_);
+        if (i != loggerInfo().end()) {
 
             // Found, so return the severity.
-            return ((i->second).severity);
+            return ((i->second)->severity);
         }
     }
 
     // Must be the root logger, or this logger is defaulting to the root logger
     // settings.
-    return (root_logger_info_.severity);
+    return (rootLoggerInfo().severity);
 }
 
 // Get the debug level.  This returns 0 unless the severity is DEBUG.
@@ -201,16 +272,16 @@ LoggerImpl::getEffectiveSeverity() {
 int
 LoggerImpl::getDebugLevel() {
 
-    if (!is_root_ && !logger_info_.empty()) {
+    if (!is_root_ && !loggerInfo().empty()) {
 
         // Not root logger and there is something in the map, check if there
         // is a setting for this one.
-        LoggerInfoMap::iterator i = logger_info_.find(name_);
-        if (i != logger_info_.end()) {
+        LoggerInfoMap::iterator i = loggerInfo().find(name_);
+        if (i != loggerInfo().end()) {
 
             // Found, so return the debug level.
-            if ((i->second).severity == isc::log::DEBUG) {
-                return ((i->second).dbglevel);
+            if ((i->second)->severity == isc::log::DEBUG) {
+                return ((i->second)->dbglevel);
             } else {
                 return (0);
             }
@@ -219,8 +290,8 @@ LoggerImpl::getDebugLevel() {
 
     // Must be the root logger, or this logger is defaulting to the root logger
     // settings.
-    if (root_logger_info_.severity == isc::log::DEBUG) {
-        return (root_logger_info_.dbglevel);
+    if (rootLoggerInfo().severity == isc::log::DEBUG) {
+        return (rootLoggerInfo().dbglevel);
     } else {
         return (0);
     }
@@ -233,16 +304,16 @@ LoggerImpl::getDebugLevel() {
 bool
 LoggerImpl::isDebugEnabled(int dbglevel) {
 
-    if (!is_root_ && !logger_info_.empty()) {
+    if (!is_root_ && !loggerInfo().empty()) {
 
         // Not root logger and there is something in the map, check if there
         // is a setting for this one.
-        LoggerInfoMap::iterator i = logger_info_.find(name_);
-        if (i != logger_info_.end()) {
+        LoggerInfoMap::iterator i = loggerInfo().find(name_);
+        if (i != loggerInfo().end()) {
 
             // Found, so return the debug level.
-            if ((i->second).severity <= isc::log::DEBUG) {
-                return ((i->second).dbglevel >= dbglevel);
+            if ((i->second)->severity <= isc::log::DEBUG) {
+                return ((i->second)->dbglevel >= dbglevel);
             } else {
                 return (false); // Nothing lower than debug
             }
@@ -251,36 +322,50 @@ LoggerImpl::isDebugEnabled(int dbglevel) {
 
     // Must be the root logger, or this logger is defaulting to the root logger
     // settings.
-    if (root_logger_info_.severity <= isc::log::DEBUG) {
-        return (root_logger_info_.dbglevel >= dbglevel);
+    if (rootLoggerInfo().severity <= isc::log::DEBUG) {
+        return (rootLoggerInfo().dbglevel >= dbglevel);
     } else {
        return (false);
     }
 }
 
-// Output a general message
+// Output message of a specific severity.
+void
+LoggerImpl::debug(const MessageID& ident, va_list ap) {
+    output(ISC_LOG_DEBUG(getDebugLevel()), ident, ap);
+}
 
 void
-LoggerImpl::output(const char* sev_text, const MessageID& ident,
-    va_list ap)
-{
-    char message[512];      // Should be large enough for any message
+LoggerImpl::info(const MessageID& ident, va_list ap) {
+    output(ISC_LOG_INFO, ident, ap);
+}
 
-    // Obtain text of the message and substitute arguments.
-    const string format = MessageDictionary::globalDictionary().getText(ident);
-    vsnprintf(message, sizeof(message), format.c_str(), ap);
+void
+LoggerImpl::warn(const MessageID& ident, va_list ap) {
+    output(ISC_LOG_WARNING, ident, ap);
+}
+
+void
+LoggerImpl::error(const MessageID& ident, va_list ap) {
+    output(ISC_LOG_ERROR, ident, ap);
+}
+
+void
+LoggerImpl::fatal(const MessageID& ident, va_list ap) {
+    output(ISC_LOG_CRITICAL, ident, ap);
+}
 
-    // Get the time in a struct tm format, and convert to text
-    time_t t_time;
-    time(&t_time);
-    struct tm* tm_time = localtime(&t_time);
 
-    char chr_time[32];
-    (void) strftime(chr_time, sizeof(chr_time), "%Y-%m-%d %H:%M:%S", tm_time);
+// Output a general message
+
+void
+LoggerImpl::output(int sev, const MessageID& ident, va_list ap) {
+
+    // Obtain text of the message and substitute arguments.
+    const string format = static_cast<string>(ident) + ", " + MessageDictionary::globalDictionary().getText(ident);
 
-    // Now output.
-    std::cout << chr_time << " " << sev_text << " [" << getName() << "] " <<
-        ident << ", " << message << "\n";
+    // Write the message
+    isc_log_vwrite(lctx_, &categories_[0], &modules_[0], sev, format.c_str(), ap);
 }
 
 } // namespace log
diff --git a/src/lib/log/logger_impl.h b/src/lib/log/logger_impl.h
index 6aaab31..d0fdb60 100644
--- a/src/lib/log/logger_impl.h
+++ b/src/lib/log/logger_impl.h
@@ -23,6 +23,8 @@
 #include <map>
 #include <utility>
 
+#include <boost/shared_ptr.hpp>
+
 #include <log/debug_levels.h>
 #include <log/logger.h>
 #include <log/message_types.h>
@@ -57,10 +59,14 @@ public:
         isc::log::Severity  severity;
         int                 dbglevel;
         bool                init;       ///< Initialized?
+        isc_mem_t*          mctx;       ///< Memory context for this logger
+        isc_log_t*          lctx;       ///< Logging context for this logger
+        isc_logconfig_t*    lcfg;       ///< Logging configuration
 
         LoggerInfo(isc::log::Severity sev = isc::log::INFO,
             int dbg = MIN_DEBUG_LEVEL, bool initialized = false) :
-            severity(sev), dbglevel(dbg), init(initialized)
+            severity(sev), dbglevel(dbg), init(initialized),
+            mctx(NULL), lctx(NULL)
         {}
     };
 
@@ -71,7 +77,7 @@ public:
     /// is held in a map, linking name of the logger (excluding the root
     /// name component) and its set severity and debug levels.  The root
     /// logger information is held separately.
-    typedef std::map<std::string, LoggerInfo>   LoggerInfoMap;
+    typedef std::map<std::string, boost::shared_ptr<LoggerInfo> > LoggerInfoMap;
 
 
     /// \brief Constructor
@@ -125,7 +131,7 @@ public:
     /// \brief Return DEBUG Level
     ///
     /// \return Current setting of debug level.  This is returned regardless of
-    /// whether the
+    /// whether debug is enabled.
     virtual int getDebugLevel();
 
 
@@ -167,8 +173,8 @@ public:
     /// to take longer and look up the information in the map holding the
     /// logging details.
     virtual bool isEnabled(isc::log::Severity severity) {
-        if (logger_info_.empty()) {
-            return (root_logger_info_.severity <= severity);
+        if (loggerInfo().empty()) {
+            return (rootLoggerInfo().severity <= severity);
         }
         else {
             return (getSeverity() <= severity);
@@ -181,10 +187,10 @@ public:
     /// The message is formatted to include the date and time, the severity
     /// and the logger generating the message.
     ///
-    /// \param sev_text Severity level as a text string
+    /// \param sev BIND 9 severity level
     /// \param ident Message identification
     /// \param ap Variable argument list holding message arguments
-    void output(const char* sev_text, const MessageID& ident,
+    void output(int sev, const MessageID& ident,
         va_list ap);
 
 
@@ -193,9 +199,7 @@ public:
     /// \param ident Message identification.
     /// \param text Text to log
     /// \param ap Variable argument list holding message arguments
-    void debug(const MessageID& ident, va_list ap) {
-        output("DEBUG", ident, ap);
-    }
+    void debug(const MessageID& ident, va_list ap);
 
 
     /// \brief Output Informational Message
@@ -203,36 +207,28 @@ public:
     /// \param ident Message identification.
     /// \param text Text to log
     /// \param ap Variable argument list holding message arguments
-    void info(const MessageID& ident, va_list ap) {
-        output("INFO ", ident, ap);
-    }
+    void info(const MessageID& ident, va_list ap);
 
     /// \brief Output Warning Message
     ///
     /// \param ident Message identification.
     /// \param text Text to log
     /// \param ap Variable argument list holding message arguments
-    void warn(const MessageID& ident, va_list ap) {
-        output("WARN ", ident, ap);
-    }
+    void warn(const MessageID& ident, va_list ap);
 
     /// \brief Output Error Message
     ///
     /// \param ident Message identification.
     /// \param text Text to log
     /// \param ap Variable argument list holding message arguments
-    void error(const MessageID& ident, va_list ap) {
-        output("ERROR", ident, ap);
-    }
+    void error(const MessageID& ident, va_list ap);
 
     /// \brief Output Fatal Message
     ///
     /// \param ident Message identification.
     /// \param text Text to log
     /// \param ap Variable argument list holding message arguments
-    void fatal(const MessageID& ident, va_list ap) {
-        output("FATAL", ident, ap);
-    }
+    void fatal(const MessageID& ident, va_list ap);
 
     /// \brief Equality
     ///
@@ -250,8 +246,8 @@ public:
     /// Only used for testing, this clears all the logger information and
     /// resets it back to default values.
     static void reset() {
-        root_logger_info_ = LoggerInfo(isc::log::INFO, MIN_DEBUG_LEVEL);
-        logger_info_.clear();
+        rootLoggerInfo() = LoggerInfo(isc::log::INFO, MIN_DEBUG_LEVEL);
+        loggerInfo().clear();
     }
 
     // Initialize BIND 9 logging
@@ -262,14 +258,25 @@ private:
     std::string         name_;              ///< Name of this logger
     std::string         category_;          ///< Category of logger
 
-    // Split the status of the root logger from this logger.  If - is will
-    // probably be the usual case - no per-logger setting is enabled, a
-    // quick check of logger_info_.empty() will return true and we can quickly
-    // return the root logger status without a length lookup in the map.
 
-    static LoggerInfo       root_logger_info_;  ///< Status of root logger
-    static LoggerInfoMap    logger_info_;       ///< Store of debug levels etc.
-    static LoggerInfoMap    bind9_info_;        ///< Parallel store for bind 9 stuff
+    /// \brief Root Logger Infomation
+    ///
+    /// Split the status of the root logger from this logger.  If - is will
+    /// probably be the usual case - no per-logger setting is enabled, a
+    /// quick check of loggerInfo().empty() will return true and we can quickly
+    /// return the root logger status without a lengthy lookup in the map.
+    ///
+    /// \return Reference to the root logger information
+    static LoggerInfo& rootLoggerInfo();
+
+    /// \return Returns a map of information about all loggers in the system.
+    static LoggerInfoMap& loggerInfo();
+
+    /// \return Reference to parallel store for BIND 9 information
+    static LoggerInfoMap& bind9Info();
+
+    /// \return TEMP - say if default channel has been created
+    static bool& channelCreated();
 
     // Categories and modules.  Each logger only has one category (the
     // the logger name) and one module (the name of the root logger).




More information about the bind10-changes mailing list