BIND 10 trac826, updated. a5589107286e49c71f0307937b3af8fcbf55c209 liblog first attempt

BIND 10 source code commits bind10-changes at lists.isc.org
Wed Jun 27 00:14:41 UTC 2012


The branch, trac826 has been updated
       via  a5589107286e49c71f0307937b3af8fcbf55c209 (commit)
      from  b3fb256784b0cc766a404d7e31313becdb4b6c36 (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 a5589107286e49c71f0307937b3af8fcbf55c209
Author: Francis Dupont <fdupont at isc.org>
Date:   Wed Jun 27 02:14:30 2012 +0200

    liblog first attempt

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

Summary of changes:
 src/lib/log/Makefile.am                |    8 +--
 src/lib/log/README                     |    5 ++
 src/lib/log/log_dbglevels.h            |   93 ++++++++++++++++++++++++++++++++
 src/lib/log/log_formatter.cc           |   43 +++++++++++++--
 src/lib/log/log_formatter.h            |   55 +++++++++++++++++--
 src/lib/log/logger.cc                  |    7 +++
 src/lib/log/logger.h                   |   66 +++++++++++++++++++++--
 src/lib/log/logger_impl.cc             |   35 +++++++++++-
 src/lib/log/logger_impl.h              |   18 ++++++-
 src/lib/log/logger_level_impl.h        |    2 +-
 src/lib/log/logger_manager.cc          |   14 ++++-
 src/lib/log/logger_manager_impl.h      |    2 -
 src/lib/log/logger_specification.h     |    2 +-
 src/lib/log/logger_unittest_support.cc |    3 ++
 src/lib/log/macros.h                   |    1 +
 src/lib/log/message_dictionary.cc      |    6 +--
 src/lib/log/message_dictionary.h       |    2 +-
 src/lib/log/message_exception.h        |   33 +++++++++---
 src/lib/log/message_initializer.cc     |   71 +++++++++++++++++++++---
 src/lib/log/message_initializer.h      |   56 +++++++++++++++----
 src/lib/log/message_reader.cc          |   40 +++++++++-----
 src/lib/log/message_reader.h           |    2 +-
 src/lib/log/output_option.h            |    2 +-
 23 files changed, 497 insertions(+), 69 deletions(-)
 create mode 100644 src/lib/log/log_dbglevels.h

-----------------------------------------------------------------------
diff --git a/src/lib/log/Makefile.am b/src/lib/log/Makefile.am
index 9f52724..ed23176 100644
--- a/src/lib/log/Makefile.am
+++ b/src/lib/log/Makefile.am
@@ -2,6 +2,7 @@ SUBDIRS = . compiler tests
 
 AM_CPPFLAGS = -I$(top_builddir)/src/lib -I$(top_srcdir)/src/lib
 AM_CPPFLAGS += $(BOOST_INCLUDES)
+AM_CPPFLAGS += -DTOP_BUILDDIR=\"${abs_top_builddir}\"
 
 CLEANFILES = *.gcno *.gcda
 
@@ -9,6 +10,7 @@ lib_LTLIBRARIES = liblog.la
 liblog_la_SOURCES  =
 liblog_la_SOURCES += dummylog.h dummylog.cc
 liblog_la_SOURCES += logimpl_messages.cc logimpl_messages.h
+liblog_la_SOURCES += log_dbglevels.h
 liblog_la_SOURCES += log_formatter.h log_formatter.cc
 liblog_la_SOURCES += logger.cc logger.h
 liblog_la_SOURCES += logger_impl.cc logger_impl.h
@@ -21,8 +23,8 @@ liblog_la_SOURCES += logger_name.cc logger_name.h
 liblog_la_SOURCES += logger_specification.h
 liblog_la_SOURCES += logger_support.cc logger_support.h
 liblog_la_SOURCES += logger_unittest_support.cc logger_unittest_support.h
-liblog_la_SOURCES += macros.h
 liblog_la_SOURCES += log_messages.cc log_messages.h
+liblog_la_SOURCES += macros.h
 liblog_la_SOURCES += message_dictionary.cc message_dictionary.h
 liblog_la_SOURCES += message_exception.h
 liblog_la_SOURCES += message_initializer.cc message_initializer.h
@@ -45,5 +47,5 @@ if USE_CLANGPP
 liblog_la_CXXFLAGS += -Wno-error
 endif
 liblog_la_CPPFLAGS = $(AM_CPPFLAGS) $(LOG4CPLUS_INCLUDES)
-liblog_la_LDFLAGS  = $(LOG4CPLUS_LDFLAGS)
-liblog_la_LIBADD   = $(top_builddir)/src/lib/util/libutil.la
+liblog_la_LIBADD   = $(top_builddir)/src/lib/util/libutil.la $(LOG4CPLUS_LIBS)
+liblog_la_LDFLAGS = -no-undefined -version-info 1:0:0
diff --git a/src/lib/log/README b/src/lib/log/README
index 3747cb1..3693abb 100644
--- a/src/lib/log/README
+++ b/src/lib/log/README
@@ -477,6 +477,11 @@ the severity system:
 When a particular severity is set, it - and all severities and/or debug
 levels above it - will be logged.
 
+To try to ensure that the information from different modules is roughly
+comparable for the same debug level, a set of standard debug levels has
+been defined for common type of debug output.  However, modules are free
+to set their own debug levels or define additional ones.
+
 Logging Sources v Logging Severities
 ------------------------------------
 When logging events, make a distinction between events related to the
diff --git a/src/lib/log/log_dbglevels.h b/src/lib/log/log_dbglevels.h
new file mode 100644
index 0000000..d713714
--- /dev/null
+++ b/src/lib/log/log_dbglevels.h
@@ -0,0 +1,93 @@
+// 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 __LOG_DBGLVLS_H
+#define __LOG_DBGLVLS_H
+
+/// \file
+///
+/// When a message is logged with DEBUG severity, the debug level associated
+/// with the message is also specified.  This debug level is a number
+/// ranging from 0 to 99; the idea is that the higher the debug level, the
+/// more detailed the message.
+///
+/// If debug messages are being logged, the logging system allows them to be
+/// filtered by debug level - only messages logged with a level equal to or
+/// less than the set debug level will be output.  (For example, if the
+/// filter is set to 30, only debug messages logged with levels in the range
+/// 0 to 30 will be output; messages logged with levels 31 to 99 will be
+/// suppressed.)
+///
+/// Levels of 30 or below are reserved for debug messages that are most
+/// likely to be useful for an administrator. Levels 31 to 99 are for use by
+/// someone familiar with the code. "Useful for an administrator" is,
+/// admittedly, a subjective term: it is loosely defined as messages helping
+/// someone diagnose a problem that they could solve without needing to dive
+/// into the code.  So it covers things like start-up steps and configuration
+/// messages.
+///
+/// In practice, this means that levels of 30 and below are most-likely to
+/// be used by the top-level programs, and 31 and above by the various
+/// libraries.
+///
+/// This file defines a set of standard debug levels for use across all loggers.
+/// In this way users can have some expection of what will be output when
+/// enabling debugging.  Symbols are prefixed DBGLVL so as not to clash with
+/// DBG_ symbols in the various modules.
+///
+/// \note If the names of debug constants are changed, or if ones are added or
+/// removed, edit the file src/lib/python/isc/log/log.cc to update the log
+/// level definitions available to Python.  The change does not need to be
+/// made if only the numeric values of constants are updated.
+
+namespace {
+
+/// Process startup/shutdown debug messages.  Note that these are _debug_
+/// messages, as other messages related to startup and shutdown may be output
+/// with another severity.  For example, when the authoritative server starts
+/// up, the "server started" message could be output at a severity of INFO.
+/// "Server starting" and messages indicating the stages in startup should be
+/// debug messages output at this severity.
+///
+/// This is given a value of 0 as that is the level selected if debugging is
+/// enabled without giving a level.
+const int DBGLVL_START_SHUT = 0;
+
+/// This debug level is reserved for logging the exchange of messages/commands
+/// between processes, including configuration messages.
+const int DBGLVL_COMMAND = 10;
+
+/// If the commands have associated data, this level is when they are printed.
+/// This includes configuration messages.
+const int DBGLVL_COMMAND_DATA = 20;
+
+// The following constants are suggested values for common operations.
+// Depending on the exact nature of the code, modules may or may not use these
+// levels.
+
+/// Trace basic operations.
+const int DBGLVL_TRACE_BASIC = 40;
+
+/// Trace data associated with the basic operations.
+const int DBGLVL_TRACE_BASIC_DATA = 45;
+
+/// Trace detailed operations.
+const int DBGLVL_TRACE_DETAIL = 50;
+
+/// Trace data associated with detailed operations.
+const int DBGLVL_TRACE_DETAIL_DATA = 55;
+
+}   // Anonymous namespace
+
+#endif // __LOG_DBGLVLS_H
diff --git a/src/lib/log/log_formatter.cc b/src/lib/log/log_formatter.cc
index 18c4741..9cd5cc7 100644
--- a/src/lib/log/log_formatter.cc
+++ b/src/lib/log/log_formatter.cc
@@ -12,8 +12,15 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
+#include "config.h"
 #include <log/log_formatter.h>
 
+#include <cassert>
+
+#ifdef ENABLE_LOGGER_CHECKS
+#include <iostream>
+#endif
+
 using namespace std;
 using namespace boost;
 
@@ -24,17 +31,45 @@ void
 replacePlaceholder(string* message, const string& arg,
                    const unsigned placeholder)
 {
-    string mark("%" + lexical_cast<string>(placeholder));
+    const string mark("%" + lexical_cast<string>(placeholder));
     size_t pos(message->find(mark));
     if (pos != string::npos) {
         do {
             message->replace(pos, mark.size(), arg);
             pos = message->find(mark, pos + arg.size());
         } while (pos != string::npos);
-    } else {
+    }
+#ifdef ENABLE_LOGGER_CHECKS
+    else {
+        // We're missing the placeholder, so throw an exception
+        isc_throw(MismatchedPlaceholders,
+		  "Missing logger placeholder in message: " << *message);
+    }
+#else
+    else {
         // We're missing the placeholder, so add some complain
-        message->append(" @@Missing placeholder " + mark + " for '" + arg +
-                        "'@@");
+        message->append(" @@Missing placeholder " + mark + " for '" + arg + "'@@");
+    }
+#endif /* ENABLE_LOGGER_CHECKS */
+}
+
+void
+checkExcessPlaceholders(string* message, unsigned int placeholder) {
+    const string mark("%" + lexical_cast<string>(placeholder));
+    const size_t pos(message->find(mark));
+    if (pos != string::npos) {
+        // Excess placeholders were found.  If we enable the harsh check,
+        // abort it.  Note: ideally we'd like to throw MismatchedPlaceholders,
+        // but we can't at least for now because this function is called from
+        // the Formatter's destructor.
+#ifdef ENABLE_LOGGER_CHECKS
+        // Also, make sure we print the message so we can identify which
+        // identifier has the problem.
+        cerr << "Message " << *message << endl;
+        assert("Excess logger placeholders still exist in message" == NULL);
+#else
+        message->append(" @@Excess logger placeholders still exist@@");
+#endif /* ENABLE_LOGGER_CHECKS */
     }
 }
 
diff --git a/src/lib/log/log_formatter.h b/src/lib/log/log_formatter.h
index ca23844..eebdb1a 100644
--- a/src/lib/log/log_formatter.h
+++ b/src/lib/log/log_formatter.h
@@ -39,6 +39,27 @@ public:
 };
 
 
+/// \brief Mismatched Placeholders
+///
+/// This exception is used when the number of placeholders do not match
+/// the number of arguments passed to the formatter.
+
+class MismatchedPlaceholders : public isc::Exception {
+public:
+    MismatchedPlaceholders(const char* file, size_t line, const char* what) :
+        isc::Exception(file, line, what)
+    {}
+};
+
+
+///
+/// \brief Internal excess placeholder checker
+///
+/// This is used internally by the Formatter to check for excess
+/// placeholders (and fewer arguments).
+void
+checkExcessPlaceholders(std::string* message, unsigned int placeholder);
+
 ///
 /// \brief The internal replacement routine
 ///
@@ -142,6 +163,7 @@ public:
     /// This is the place where output happens if the formatter is active.
     ~ Formatter() {
         if (logger_) {
+            checkExcessPlaceholders(message_, ++nextPlaceholder_);
             logger_->output(severity_, *message_);
             delete message_;
         }
@@ -169,13 +191,15 @@ public:
     /// Deactivates the current formatter. In case the formatter is not active,
     /// only produces another inactive formatter.
     ///
-    /// \param arg The argument to place into the placeholder.
+    /// \param value The argument to place into the placeholder.
     template<class Arg> Formatter& arg(const Arg& value) {
         if (logger_) {
             try {
                 return (arg(boost::lexical_cast<std::string>(value)));
             } catch (const boost::bad_lexical_cast& ex) {
-
+                // The formatting of the log message got wrong, we don't want
+                // to output it.
+                deactivate();
                 // 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
@@ -207,10 +231,35 @@ public:
             // occurrences of "%2" with 42. (Conversely, the sequence
             // .arg(42).arg("%1") would return "42 %1" - there are no recursive
             // replacements).
-            replacePlaceholder(message_, arg, ++nextPlaceholder_ );
+            try {
+                replacePlaceholder(message_, arg, ++nextPlaceholder_ );
+            }
+            catch (...) {
+                // Something went wrong here, the log message is broken, so
+                // we don't want to output it, nor we want to check all the
+                // placeholders were used (because they won't be).
+                deactivate();
+                throw;
+            }
         }
         return (*this);
     }
+
+    /// \brief Turn off the output of this logger.
+    ///
+    /// If the logger would output anything at the end, now it won't.
+    /// Also, this turns off the strict checking of placeholders, if
+    /// it is compiled in.
+    ///
+    /// The expected use is when there was an exception processing
+    /// the arguments for the message.
+    void deactivate() {
+        if (logger_) {
+            delete message_;
+            message_ = NULL;
+            logger_ = NULL;
+        }
+    }
 };
 
 }
diff --git a/src/lib/log/logger.cc b/src/lib/log/logger.cc
index 5deebed..c0af58a 100644
--- a/src/lib/log/logger.cc
+++ b/src/lib/log/logger.cc
@@ -183,6 +183,13 @@ Logger::fatal(const isc::log::MessageID& ident) {
     }
 }
 
+// Replace the interprocess synchronization object
+
+void
+Logger::setInterprocessSync(isc::util::InterprocessSync* sync) {
+    getLoggerPtr()->setInterprocessSync(sync);
+}
+
 // Comparison (testing only)
 
 bool
diff --git a/src/lib/log/logger.h b/src/lib/log/logger.h
index 96168c0..6405488 100644
--- a/src/lib/log/logger.h
+++ b/src/lib/log/logger.h
@@ -15,14 +15,18 @@
 #ifndef __LOGGER_H
 #define __LOGGER_H
 
+#include <cassert>
 #include <cstdlib>
 #include <string>
+#include <cstring>
 
 #include <exceptions/exceptions.h>
 #include <log/logger_level.h>
 #include <log/message_types.h>
 #include <log/log_formatter.h>
 
+#include <util/interprocess_sync.h>
+
 namespace isc {
 namespace log {
 
@@ -68,9 +72,19 @@ namespace log {
 /// is referred to using a symbolic name.  The logging code uses this name as
 /// a key in a dictionary from which the message text is obtained.  Such a
 /// system allows for the optional replacement of message text at run time.
-/// More details about the message disction (and the compiler used to create
+/// More details about the message dictionary (and the compiler used to create
 /// the symbol definitions) can be found in other modules in the src/lib/log
 /// directory.
+///
+/// \section LoggingApiImplementationIssues Implementation Issues
+/// Owing to the way that the logging is implemented, notably that loggers can
+/// be declared as static external objects, there is a restriction on the
+/// length of the name of a logger component (i.e. the length of
+/// the string passed to the Logger constructor) to a maximum of 31 characters.
+/// There is no reason for this particular value other than limiting the amount
+/// of memory used.  It is defined by the constant Logger::MAX_LOGGER_NAME_SIZE,
+/// and can be made larger (or smaller) if so desired.  Note however, using a
+/// logger name larger than this limit will cause an assertion failure.
 
 class LoggerImpl;   // Forward declaration of the implementation class
 
@@ -85,6 +99,17 @@ public:
     {}
 };
 
+/// \brief Bad Interprocess Sync
+///
+/// Exception thrown if a bad InterprocessSync object (such as NULL) is
+/// used.
+class BadInterprocessSync : public isc::Exception {
+public:
+    BadInterprocessSync(const char* file, size_t line, const char* what) :
+        isc::Exception(file, line, what)
+    {}
+};
+
 /// \brief Logger Class
 ///
 /// This class is the main class used for logging.  Use comprises:
@@ -99,6 +124,8 @@ public:
 
 class Logger {
 public:
+    /// Maximum size of a logger name
+    static const size_t MAX_LOGGER_NAME_SIZE = 31;
 
     /// \brief Constructor
     ///
@@ -107,8 +134,26 @@ public:
     /// \param name Name of the logger.  If the name is that of the root name,
     /// this creates an instance of the root logger; otherwise it creates a
     /// child of the root logger.
-    Logger(const std::string& name) : loggerptr_(NULL), name_(name)
-    {}
+    ///
+    /// \note The name of the logger may be no longer than MAX_LOGGER_NAME_SIZE
+    /// else the program will halt with an assertion failure.  This restriction
+    /// allows loggers to be declared statically: the name is stored in a
+    /// fixed-size array to avoid the need to allocate heap storage during
+    /// program initialization (which causes problems on some operating
+    /// systems).
+    ///
+    /// \note Note also that there is no constructor taking a std::string. This
+    /// minimises the possibility of initializing a static logger with a
+    /// string, so leading to problems mentioned above.
+    Logger(const char* name) : loggerptr_(NULL) {
+        assert(std::strlen(name) < sizeof(name_));
+        // Do the copy.  Note that the assertion above has checked that the
+        // contents of "name" and a trailing null will fit within the space
+        // allocated for name_, so we could use strcpy here and be safe.
+        // However, a bit of extra paranoia doesn't hurt.
+        std::strncpy(name_, name, sizeof(name_));
+        assert(name_[sizeof(name_) - 1] == '\0');
+    }
 
     /// \brief Destructor
     virtual ~Logger();
@@ -204,6 +249,17 @@ public:
     /// \param ident Message identification.
     Formatter fatal(const MessageID& ident);
 
+    /// \brief Replace the interprocess synchronization object
+    ///
+    /// If this method is called with NULL as the argument, it throws a
+    /// BadInterprocessSync exception.
+    ///
+    /// \param sync The logger uses this synchronization object for
+    /// synchronizing output of log messages. It should be deletable and
+    /// the ownership is transferred to the logger. If NULL is passed,
+    /// a BadInterprocessSync exception is thrown.
+    void setInterprocessSync(isc::util::InterprocessSync* sync);
+
     /// \brief Equality
     ///
     /// Check if two instances of this logger refer to the same stream.
@@ -256,8 +312,8 @@ private:
     /// \brief Initialize Underlying Implementation and Set loggerptr_
     void initLoggerImpl();
 
-    LoggerImpl*     loggerptr_;     ///< Pointer to the underlying logger
-    std::string     name_;          ///< Copy of the logger name
+    LoggerImpl* loggerptr_;                  ///< Pointer to underlying logger
+    char        name_[MAX_LOGGER_NAME_SIZE + 1]; ///< Copy of the logger name
 };
 
 } // namespace log
diff --git a/src/lib/log/logger_impl.cc b/src/lib/log/logger_impl.cc
index a6b42b6..f7c65fa 100644
--- a/src/lib/log/logger_impl.cc
+++ b/src/lib/log/logger_impl.cc
@@ -36,12 +36,14 @@
 #include <log/message_types.h>
 
 #include <util/strutil.h>
+#include <util/interprocess_sync_file.h>
 
 // Note: as log4cplus and the BIND 10 logger have many concepts in common, and
 // thus many similar names, to disambiguate types we don't "use" the log4cplus
 // namespace: instead, all log4cplus types are explicitly qualified.
 
 using namespace std;
+using namespace isc::util;
 
 namespace isc {
 namespace log {
@@ -51,14 +53,17 @@ namespace log {
 // one compiler requires that all member variables be constructed before the
 // constructor is run, but log4cplus::Logger (the type of logger_) has no
 // default constructor.
-LoggerImpl::LoggerImpl(const string& name) : name_(expandLoggerName(name)),
-    logger_(log4cplus::Logger::getInstance(name_))
+LoggerImpl::LoggerImpl(const string& name) :
+    name_(expandLoggerName(name)),
+    logger_(log4cplus::Logger::getInstance(name_)),
+    sync_(new InterprocessSyncFile("logger"))
 {
 }
 
 // Destructor. (Here because of virtual declaration.)
 
 LoggerImpl::~LoggerImpl() {
+    delete sync_;
 }
 
 // Set the severity for logging.
@@ -106,8 +111,30 @@ LoggerImpl::lookupMessage(const MessageID& ident) {
                        MessageDictionary::globalDictionary().getText(ident)));
 }
 
+// Replace the interprocess synchronization object
+
+void
+LoggerImpl::setInterprocessSync(isc::util::InterprocessSync* sync) {
+    if (sync == NULL) {
+        isc_throw(BadInterprocessSync,
+                  "NULL was passed to setInterprocessSync()");
+    }
+
+    delete sync_;
+    sync_ = sync;
+}
+
 void
 LoggerImpl::outputRaw(const Severity& severity, const string& message) {
+    // Use an interprocess sync locker for mutual exclusion from other
+    // processes to avoid log messages getting interspersed.
+
+    InterprocessSyncLocker locker(*sync_);
+
+    if (!locker.lock()) {
+        LOG4CPLUS_ERROR(logger_, "Unable to lock logger lockfile");
+    }
+
     switch (severity) {
         case DEBUG:
             LOG4CPLUS_DEBUG(logger_, message);
@@ -128,6 +155,10 @@ LoggerImpl::outputRaw(const Severity& severity, const string& message) {
         case FATAL:
             LOG4CPLUS_FATAL(logger_, message);
     }
+
+    if (!locker.unlock()) {
+        LOG4CPLUS_ERROR(logger_, "Unable to unlock logger lockfile");
+    }
 }
 
 } // namespace log
diff --git a/src/lib/log/logger_impl.h b/src/lib/log/logger_impl.h
index 90bd41a..10d3db4 100644
--- a/src/lib/log/logger_impl.h
+++ b/src/lib/log/logger_impl.h
@@ -32,6 +32,8 @@
 #include <log/logger_level_impl.h>
 #include <log/message_types.h>
 
+#include <util/interprocess_sync.h>
+
 namespace isc {
 namespace log {
 
@@ -167,6 +169,17 @@ public:
     /// This gets you the unformatted text of message for given ID.
     std::string* lookupMessage(const MessageID& id);
 
+    /// \brief Replace the interprocess synchronization object
+    ///
+    /// If this method is called with NULL as the argument, it throws a
+    /// BadInterprocessSync exception.
+    ///
+    /// \param sync The logger uses this synchronization object for
+    /// synchronizing output of log messages. It should be deletable and
+    /// the ownership is transferred to the logger implementation.
+    /// If NULL is passed, a BadInterprocessSync exception is thrown.
+    void setInterprocessSync(isc::util::InterprocessSync* sync);
+
     /// \brief Equality
     ///
     /// Check if two instances of this logger refer to the same stream.
@@ -178,8 +191,9 @@ public:
     }
 
 private:
-    std::string         name_;              ///< Full name of this logger
-    log4cplus::Logger   logger_;            ///< Underlying log4cplus logger
+    std::string                  name_;   ///< Full name of this logger
+    log4cplus::Logger            logger_; ///< Underlying log4cplus logger
+    isc::util::InterprocessSync* sync_;
 };
 
 } // namespace log
diff --git a/src/lib/log/logger_level_impl.h b/src/lib/log/logger_level_impl.h
index 9289a1d..c990796 100644
--- a/src/lib/log/logger_level_impl.h
+++ b/src/lib/log/logger_level_impl.h
@@ -83,7 +83,7 @@ public:
     /// The log4cplus log level may be non-standard in which case it is
     /// encoding a BIND 10 debug level as well.
     ///
-    /// \param level log4cplus log level
+    /// \param loglevel log4cplus log level
     ///
     /// \return Equivalent BIND 10 severity and debug level
     static
diff --git a/src/lib/log/logger_manager.cc b/src/lib/log/logger_manager.cc
index 1d5f40f..8431c2e 100644
--- a/src/lib/log/logger_manager.cc
+++ b/src/lib/log/logger_manager.cc
@@ -28,6 +28,7 @@
 #include <log/message_initializer.h>
 #include <log/message_reader.h>
 #include <log/message_types.h>
+#include "util/interprocess_sync_null.h"
 
 using namespace std;
 
@@ -95,6 +96,10 @@ void
 LoggerManager::init(const std::string& root, isc::log::Severity severity,
                     int dbglevel, const char* file)
 {
+    // Load in the messages declared in the program and registered by
+    // statically-declared MessageInitializer objects.
+    MessageInitializer::loadDictionary();
+
     // Save name, severity and debug level for later.  No need to save the
     // file name as once the local message file is read the messages will
     // not be lost.
@@ -144,6 +149,13 @@ LoggerManager::readLocalMessageFile(const char* file) {
 
     MessageDictionary& dictionary = MessageDictionary::globalDictionary();
     MessageReader reader(&dictionary);
+
+    // Turn off use of any lock files. This is because this logger can
+    // be used by standalone programs which may not have write access to
+    // the local state directory (to create lock files). So we switch to
+    // using a null interprocess sync object here.
+    logger.setInterprocessSync(new isc::util::InterprocessSyncNull("logger"));
+
     try {
 
         logger.info(LOG_READING_LOCAL_FILE).arg(file);
@@ -167,7 +179,7 @@ LoggerManager::readLocalMessageFile(const char* file) {
         // Log the variable number of arguments.  The actual message will be
         // logged when the error_message variable is destroyed.
         Formatter<isc::log::Logger> error_message = logger.error(ident);
-        for (unsigned int i = 0; i < args.size(); ++i) {
+        for (vector<string>::size_type i = 0; i < args.size(); ++i) {
             error_message = error_message.arg(args[i]);
         }
     }
diff --git a/src/lib/log/logger_manager_impl.h b/src/lib/log/logger_manager_impl.h
index fef47c9..42a98f1 100644
--- a/src/lib/log/logger_manager_impl.h
+++ b/src/lib/log/logger_manager_impl.h
@@ -59,8 +59,6 @@ public:
     /// This resets the hierachy of loggers back to their defaults.  This means
     /// that all non-root loggers (if they exist) are set to NOT_SET, and the
     /// root logger reset to logging informational messages.
-    ///
-    /// \param root_name BIND 10 name of the root logger
     static void processInit();
 
     /// \brief Process Specification
diff --git a/src/lib/log/logger_specification.h b/src/lib/log/logger_specification.h
index 75c48df..78df054 100644
--- a/src/lib/log/logger_specification.h
+++ b/src/lib/log/logger_specification.h
@@ -103,7 +103,7 @@ public:
 
     /// \brief Add output option.
     ///
-    /// \param Option to add to the list.
+    /// \param option Option to add to the list.
     void addOutputOption(const OutputOption& option) {
         options_.push_back(option);
     }
diff --git a/src/lib/log/logger_unittest_support.cc b/src/lib/log/logger_unittest_support.cc
index b7e6fbc..6afc539 100644
--- a/src/lib/log/logger_unittest_support.cc
+++ b/src/lib/log/logger_unittest_support.cc
@@ -164,6 +164,9 @@ void initLogger(isc::log::Severity severity, int dbglevel) {
     // Set the local message file
     const char* localfile = getenv("B10_LOGGER_LOCALMSG");
 
+    // Set a directory for creating lockfiles when running tests
+    setenv("B10_LOCKFILE_DIR_FROM_BUILD", TOP_BUILDDIR, 1);
+
     // Initialize logging
     initLogger(root, isc::log::DEBUG, isc::log::MAX_DEBUG_LEVEL, localfile);
 
diff --git a/src/lib/log/macros.h b/src/lib/log/macros.h
index 3128131..42fb42e 100644
--- a/src/lib/log/macros.h
+++ b/src/lib/log/macros.h
@@ -16,6 +16,7 @@
 #define __LOG_MACROS_H
 
 #include <log/logger.h>
+#include <log/log_dbglevels.h>
 
 /// \brief Macro to conveniently test debug output and log it
 #define LOG_DEBUG(LOGGER, LEVEL, MESSAGE) \
diff --git a/src/lib/log/message_dictionary.cc b/src/lib/log/message_dictionary.cc
index deb8232..3bfc56c 100644
--- a/src/lib/log/message_dictionary.cc
+++ b/src/lib/log/message_dictionary.cc
@@ -29,7 +29,7 @@ MessageDictionary::~MessageDictionary() {
 // Add message and note if ID already exists
 
 bool
-MessageDictionary::add(const string& ident, const string& text) {
+MessageDictionary::add(const std::string& ident, const std::string& text) {
     Dictionary::iterator i = dictionary_.find(ident);
     bool not_found = (i == dictionary_.end());
     if (not_found) {
@@ -44,7 +44,7 @@ MessageDictionary::add(const string& ident, const string& text) {
 // Add message and note if ID does not already exist
 
 bool
-MessageDictionary::replace(const string& ident, const string& text) {
+MessageDictionary::replace(const std::string& ident, const std::string& text) {
     Dictionary::iterator i = dictionary_.find(ident);
     bool found = (i != dictionary_.end());
     if (found) {
@@ -87,7 +87,7 @@ MessageDictionary::load(const char* messages[]) {
 // output.
 
 const string&
-MessageDictionary::getText(const string& ident) const {
+MessageDictionary::getText(const std::string& ident) const {
     static const string empty("");
     Dictionary::const_iterator i = dictionary_.find(ident);
     if (i == dictionary_.end()) {
diff --git a/src/lib/log/message_dictionary.h b/src/lib/log/message_dictionary.h
index 23f76d7..519986d 100644
--- a/src/lib/log/message_dictionary.h
+++ b/src/lib/log/message_dictionary.h
@@ -79,7 +79,7 @@ public:
     ///
     /// \return true if the message was added to the dictionary, false if the
     /// message existed and it was not added.
-    virtual bool add (const std::string& ident, const std::string& test);
+    virtual bool add (const std::string& ident, const std::string& text);
 
 
     /// \brief Replace Message
diff --git a/src/lib/log/message_exception.h b/src/lib/log/message_exception.h
index eebee89..8b9d58a 100644
--- a/src/lib/log/message_exception.h
+++ b/src/lib/log/message_exception.h
@@ -15,12 +15,14 @@
 #ifndef __MESSAGE_EXCEPTION_H
 #define __MESSAGE_EXCEPTION_H
 
+#include <exceptions/exceptions.h>
+#include <log/message_types.h>
+
 #include <stdexcept>
 #include <string>
 #include <vector>
 
 #include <boost/lexical_cast.hpp>
-#include <log/message_types.h>
 
 namespace isc {
 namespace log {
@@ -31,27 +33,36 @@ namespace log {
 /// code and its arguments to be encapsulated in an exception and thrown
 /// up the stack.
 
-class MessageException : public std::exception {
+class MessageException : public isc::Exception {
 public:
 
     /// \brief Constructor
     ///
+    /// \param file Filename where the exception occurred.
+    /// \param line Line where exception occurred.
+    /// \param what Text description of the problem.
     /// \param id Message identification.
     /// \param lineno Line number on which error occurred (if > 0).
-    MessageException(MessageID id, int lineno = 0) : id_(id)
+    MessageException(const char* file, size_t line, const char* what,
+                     MessageID id, int lineno)
+        : isc::Exception(file, line, what), id_(id), lineno_(lineno)
     {
-        if (lineno > 0) {
+        if (lineno_ > 0) {
             args_.push_back(boost::lexical_cast<std::string>(lineno));
         }
     }
 
     /// \brief Constructor
     ///
+    /// \param file Filename where the exception occurred.
+    /// \param line Line where exception occurred.
+    /// \param what Text description of the problem.
     /// \param id Message identification.
     /// \param arg1 First message argument.
     /// \param lineno Line number on which error occurred (if > 0).
-    MessageException(MessageID id, const std::string& arg1, int lineno = 0)
-        : id_(id)
+    MessageException(const char* file, size_t line, const char* what,
+                     MessageID id, const std::string& arg1, int lineno)
+        : isc::Exception(file, line, what), id_(id)
     {
         if (lineno > 0) {
             args_.push_back(boost::lexical_cast<std::string>(lineno));
@@ -61,12 +72,17 @@ public:
 
     /// \brief Constructor
     ///
+    /// \param file Filename where the exception occurred.
+    /// \param line Line where exception occurred.
+    /// \param what Text description of the problem.
     /// \param id Message identification.
     /// \param arg1 First message argument.
     /// \param arg2 Second message argument.
     /// \param lineno Line number on which error occurred (if > 0).
-    MessageException(MessageID id, const std::string& arg1,
-        const std::string& arg2, int lineno = 0) : id_(id)
+    MessageException(const char* file, size_t line, const char *what,
+                     MessageID id, const std::string& arg1,
+                     const std::string& arg2, int lineno)
+        : isc::Exception(file, line, what), id_(id)
     {
         if (lineno > 0) {
             args_.push_back(boost::lexical_cast<std::string>(lineno));
@@ -95,6 +111,7 @@ public:
 private:
     MessageID                   id_;        // Exception ID
     std::vector<std::string>    args_;      // Exception arguments
+    int lineno_;
 };
 
 } // namespace log
diff --git a/src/lib/log/message_initializer.cc b/src/lib/log/message_initializer.cc
index 0113497..3dd5da7 100644
--- a/src/lib/log/message_initializer.cc
+++ b/src/lib/log/message_initializer.cc
@@ -12,25 +12,80 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
+#include <cassert>
+#include <cstdlib>
 #include <log/message_dictionary.h>
 #include <log/message_initializer.h>
 
+
+// As explained in the header file, initialization of the message dictionary
+// is a two-stage process:
+// 1) In the MessageInitializer constructor, a pointer to the array of
+//    messages is stored in a pre-defined array.  Since the MessageInitializers
+//    are declared statically outside a program unit, this takes place before
+//    main() is called.  As no heap storage is allocated in this process, we
+//    should avoid the static initialization fiasco in cases where
+//    initialization of system libraries is also carried out at the same time.
+// 2) After main() starts executing, loadDictionary() is called.
+//
+//
+
+namespace {
+
+// Declare the array of pointers to value arrays.
+const char** logger_values[isc::log::MessageInitializer::MAX_MESSAGE_ARRAYS];
+
+// Declare the index used to access the array.  As this needs to be initialized
+// at first used, it is accessed it via a function.
+size_t& getIndex() {
+    static size_t index = 0;
+    return (index);
+}
+
+}
+
+
 namespace isc {
 namespace log {
 
-// Constructor.  Just retrieve the global dictionary and load the IDs and
-// associated text into it.
+// Constructor.  Add the pointer to the message array to the global array.
+// This method will trigger an assertion failure if the array overflows.
 
 MessageInitializer::MessageInitializer(const char* values[]) {
+    assert(getIndex() < MAX_MESSAGE_ARRAYS);
+    logger_values[getIndex()++] = values;
+}
+
+// Return the number of arrays registered but not yet loaded.
+
+size_t
+MessageInitializer::getPendingCount() {
+    return (getIndex());
+}
+
+// Load the messages in the arrays registered in the logger_values array
+// into the global dictionary.
+
+void
+MessageInitializer::loadDictionary() {
     MessageDictionary& global = MessageDictionary::globalDictionary();
-    std::vector<std::string> repeats = global.load(values);
 
-    // Append the IDs in the list just loaded (the "repeats") to the global list
-    // of duplicate IDs.
-    if (!repeats.empty()) {
-        std::vector<std::string>& duplicates = getDuplicates();
-        duplicates.insert(duplicates.end(), repeats.begin(), repeats.end());
+    for (size_t i = 0; i < getIndex(); ++i) {
+        std::vector<std::string> repeats = global.load(logger_values[i]);
+
+        // Append the IDs in the list just loaded (the "repeats") to the
+        // global list of duplicate IDs.
+        if (!repeats.empty()) {
+            std::vector<std::string>& duplicates = getDuplicates();
+            duplicates.insert(duplicates.end(), repeats.begin(),
+                              repeats.end());
+        }
     }
+
+    // ... and mark that the messages have been loaded.  (This avoids a lot
+    // of "duplicate message ID" messages in some of the unit tests where the
+    // logging initialization code may be called multiple times.)
+    getIndex() = 0;
 }
 
 // Return reference to duplicate array
diff --git a/src/lib/log/message_initializer.h b/src/lib/log/message_initializer.h
index 7516823..28b0e61 100644
--- a/src/lib/log/message_initializer.h
+++ b/src/lib/log/message_initializer.h
@@ -15,6 +15,7 @@
 #ifndef __MESSAGEINITIALIZER_H
 #define __MESSAGEINITIALIZER_H
 
+#include <cstdlib>
 #include <string>
 #include <vector>
 #include <log/message_dictionary.h>
@@ -37,28 +38,63 @@ namespace log {
 ///             :
 ///         NULL
 ///     };
-///     MessageDictionaryHelper xyz(values);
+///     MessageInitializer xyz(values);
 ///
-/// This will automatically add the message ID/text pairs to the global
-/// dictionary during initialization - all that is required is that the module
-/// containing the definition is included into the final executable.
+/// All that needed is for the module containing the definitions to be
+/// included in the execution unit.
 ///
-/// Messages are added via the MessageDictionary::add() method, so any
-/// duplicates are stored in the the global dictionary's overflow vector whence
-/// they can be retrieved at run-time.
+/// To avoid static initialization fiasco problems, the initialization is
+/// carried out in two stages:
+/// - The constructor adds a pointer to the values array to a pre-defined array
+///   of pointers.
+/// - During the run-time initialization of the logging system, the static
+///   method loadDictionary() is called to load the message dictionary.
+/// This way, no heap storage is allocated during the static initialization,
+/// something that may give problems on some operating systems.
+///
+/// \note The maximum number of message arrays that can be added to the
+/// dictionary in this way is defined by the constant
+/// MessageInitializer::MAX_MESSAGE_ARRAYS.  This is set to 256 as a compromise
+/// between wasted space and allowing for future expansion, but can be
+/// changed (by editing the source file) to any value desired.
+///
+/// When messages are added to the dictionary, the are added via the
+/// MessageDictionary::add() method, so any duplicates are stored in the
+/// global dictionary's overflow vector whence they can be retrieved at
+/// run-time.
 
 class MessageInitializer {
 public:
+    /// Maximum number of message arrays that can be initialized in this way
+    static const size_t MAX_MESSAGE_ARRAYS = 256;
 
     /// \brief Constructor
     ///
-    /// Adds the array of values to the global dictionary, and notes any
-    /// duplicates.
+    /// Adds a pointer to the array of messages to the global array of
+    /// pointers to message arrays.
     ///
     /// \param values NULL-terminated array of alternating identifier strings
-    /// and associated message text.
+    /// and associated message text. N.B. This object stores a pointer to the
+    /// passed array; the array MUST remain valid at least until
+    /// loadDictionary() has been called.
     MessageInitializer(const char* values[]);
 
+    /// \brief Obtain pending load count
+    ///
+    /// Returns the number of message arrays that will be loaded by the next
+    /// call to loadDictionary().
+    ///
+    /// \return Number of registered message arrays.  This is reset to zero
+    ///         when loadDictionary() is called.
+    static size_t getPendingCount();
+
+    /// \brief Run-Time Initialization
+    ///
+    /// Loops through the internal array of pointers to message arrays
+    /// and adds the messages to the internal dictionary.  This is called
+    /// during run-time initialization.
+    static void loadDictionary();
+
     /// \brief Return Duplicates
     ///
     /// When messages are added to the global dictionary, any duplicates are
diff --git a/src/lib/log/message_reader.cc b/src/lib/log/message_reader.cc
index 2710ab8..b5a4d35 100644
--- a/src/lib/log/message_reader.cc
+++ b/src/lib/log/message_reader.cc
@@ -48,7 +48,8 @@ MessageReader::readFile(const string& file, MessageReader::Mode mode) {
     // Open the file.
     ifstream infile(file.c_str());
     if (infile.fail()) {
-        throw MessageException(LOG_INPUT_OPEN_FAIL, file, strerror(errno));
+        isc_throw_4(MessageException, "Failed to open message file",
+                    LOG_INPUT_OPEN_FAIL, file, strerror(errno), 0);
     }
 
     // Loop round reading it.  As we process the file one line at a time,
@@ -65,7 +66,8 @@ MessageReader::readFile(const string& file, MessageReader::Mode mode) {
 
     // Why did the loop terminate?
     if (!infile.eof()) {
-        throw MessageException(LOG_READ_ERROR, file, strerror(errno));
+        isc_throw_4(MessageException, "Error reading message file",
+                    LOG_READ_ERROR, file, strerror(errno), 0);
     }
     infile.close();
 }
@@ -114,7 +116,9 @@ MessageReader::parseDirective(const std::string& text) {
     } else {
 
         // Unrecognised directive
-        throw MessageException(LOG_UNRECOGNISED_DIRECTIVE, tokens[0], lineno_);
+        isc_throw_3(MessageException, "Unrecognized directive",
+                    LOG_UNRECOGNISED_DIRECTIVE, tokens[0],
+                    lineno_);
     }
 }
 
@@ -138,13 +142,15 @@ MessageReader::parsePrefix(const vector<string>& tokens) {
         // and numeric characters (and underscores) and does not start with a
         // digit.
         if (invalidSymbol(prefix_)) {
-            throw MessageException(LOG_PREFIX_INVALID_ARG, prefix_, lineno_);
+            isc_throw_3(MessageException, "Invalid prefix",
+                        LOG_PREFIX_INVALID_ARG, prefix_, lineno_);
         }
 
     } else {
 
         // Too many arguments
-        throw MessageException(LOG_PREFIX_EXTRA_ARGS, lineno_);
+        isc_throw_2(MessageException, "Too many arguments",
+                    LOG_PREFIX_EXTRA_ARGS, lineno_);
     }
 }
 
@@ -172,10 +178,12 @@ MessageReader::parseNamespace(const vector<string>& tokens) {
 
     // Check argument count
     if (tokens.size() < 2) {
-        throw MessageException(LOG_NAMESPACE_NO_ARGS, lineno_);
+        isc_throw_2(MessageException, "No arguments", LOG_NAMESPACE_NO_ARGS,
+                    lineno_);
 
     } else if (tokens.size() > 2) {
-        throw MessageException(LOG_NAMESPACE_EXTRA_ARGS, lineno_);
+        isc_throw_2(MessageException, "Too many arguments",
+                    LOG_NAMESPACE_EXTRA_ARGS, lineno_);
 
     }
 
@@ -187,12 +195,14 @@ MessageReader::parseNamespace(const vector<string>& tokens) {
                                       "abcdefghijklmnopqrstuvwxyz"
                                       "0123456789_:";
     if (tokens[1].find_first_not_of(valid_chars) != string::npos) {
-        throw MessageException(LOG_NAMESPACE_INVALID_ARG, tokens[1], lineno_);
+        isc_throw_3(MessageException, "Invalid argument",
+                    LOG_NAMESPACE_INVALID_ARG, tokens[1], lineno_);
     }
 
     // All OK - unless the namespace has already been set.
     if (ns_.size() != 0) {
-        throw MessageException(LOG_DUPLICATE_NAMESPACE, lineno_);
+        isc_throw_2(MessageException, "Duplicate namespace",
+                    LOG_DUPLICATE_NAMESPACE, lineno_);
     }
 
     // Prefix has not been set, so set it and return success.
@@ -219,7 +229,8 @@ MessageReader::parseMessage(const std::string& text, MessageReader::Mode mode) {
 
     // A line comprising just the message introducer is not valid.
     if (text.size() == 1) {
-        throw MessageException(LOG_NO_MESSAGE_ID, text, lineno_);
+        isc_throw_3(MessageException, "No message ID", LOG_NO_MESSAGE_ID,
+                    text, lineno_);
     }
 
     // Strip off the introducer and any leading space after that.
@@ -230,7 +241,8 @@ MessageReader::parseMessage(const std::string& text, MessageReader::Mode mode) {
     if (first_delim == string::npos) {
 
         // Just a single token in the line - this is not valid
-        throw MessageException(LOG_NO_MESSAGE_TEXT, message_line, lineno_);
+        isc_throw_3(MessageException, "No message text", LOG_NO_MESSAGE_TEXT,
+                    message_line, lineno_);
     }
 
     // Extract the first token into the message ID, preceding it with the
@@ -240,7 +252,8 @@ MessageReader::parseMessage(const std::string& text, MessageReader::Mode mode) {
     string ident = prefix_ + message_line.substr(0, first_delim);
     if (prefix_.empty()) {
         if (invalidSymbol(ident)) {
-            throw MessageException(LOG_INVALID_MESSAGE_ID, ident, lineno_);
+            isc_throw_3(MessageException, "Invalid message ID",
+                        LOG_INVALID_MESSAGE_ID, ident, lineno_);
         }
     }
     isc::util::str::uppercase(ident);
@@ -252,7 +265,8 @@ MessageReader::parseMessage(const std::string& text, MessageReader::Mode mode) {
         // ?? This happens if there are trailing delimiters, which should not
         // occur as we have stripped trailing spaces off the line.  Just treat
         // this as a single-token error for simplicity's sake.
-        throw MessageException(LOG_NO_MESSAGE_TEXT, message_line, lineno_);
+        isc_throw_3(MessageException, "No message text", LOG_NO_MESSAGE_TEXT,
+                    message_line, lineno_);
     }
 
     // Add the result to the dictionary and to the non-added list if the add to
diff --git a/src/lib/log/message_reader.h b/src/lib/log/message_reader.h
index eded9c6..a468d43 100644
--- a/src/lib/log/message_reader.h
+++ b/src/lib/log/message_reader.h
@@ -61,7 +61,7 @@ public:
     /// The ownership of the dictionary object is not transferred - the caller
     /// is responsible for managing the lifetime of the dictionary.
     MessageReader(MessageDictionary* dictionary = NULL) :
-        dictionary_(dictionary)
+        dictionary_(dictionary), lineno_(0)
     {}
 
     /// \brief Virtual Destructor
diff --git a/src/lib/log/output_option.h b/src/lib/log/output_option.h
index cbb7e95..8dfdd70 100644
--- a/src/lib/log/output_option.h
+++ b/src/lib/log/output_option.h
@@ -60,7 +60,7 @@ struct OutputOption {
 
     /// \brief Constructor
     OutputOption() : destination(DEST_CONSOLE), stream(STR_STDERR),
-                     flush(false), facility("LOCAL0"), filename(""),
+                     flush(true), facility("LOCAL0"), filename(""),
                      maxsize(0), maxver(0)
     {}
 



More information about the bind10-changes mailing list