[trac1008] Throw exception if logging before initialization has been done

src/lib/log/logger.cc

@@ -18,6 +18,7 @@
 #include <log/logger.h>
 #include <log/logger_impl.h>
 #include <log/logger_name.h>
+#include <log/logger_support.h>
 #include <log/message_dictionary.h>
 #include <log/message_types.h>
 
@@ -28,9 +29,14 @@ using namespace std;
 namespace isc {
 namespace log {
 
-// Initialize Logger.
+// Initialize underlying logger, but only if logging has been initialized.
 void Logger::initLoggerImpl() {
-    loggerptr_ = new LoggerImpl(name_);
+    if (isLoggingInitialized()) {
+        loggerptr_ = new LoggerImpl(name_);
+    } else {
+        isc_throw(LoggingNotInitialized, "attempt to access logging function "
+                  "before logging has been initialized");
+    }
 }
 
 // Destructor.

src/lib/log/logger.h

@@ -18,6 +18,7 @@
 #include <cstdlib>
 #include <string>
 
+#include <exceptions/exceptions.h>
 #include <log/logger_level.h>
 #include <log/message_types.h>
 #include <log/log_formatter.h>
@@ -73,6 +74,17 @@ namespace log {
 
 class LoggerImpl;   // Forward declaration of the implementation class
 
+/// \brief Logging Not Initialized
+///
+/// Exception thrown if an attempt is made to access a logging function
+/// if the logging system has not been initialized.
+class LoggingNotInitialized : public isc::Exception {
+public:
+    LoggingNotInitialized(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:
@@ -224,15 +236,14 @@ private:
 
     /// \brief Initialize Implementation
     ///
-    /// Returns the logger pointer.  If not yet set, the underlying
-    /// implementation class is initialized.\n
-    /// \n
-    /// The reason for this indirection is to avoid the "static initialization
-    /// fiacso", whereby we cannot rely on the order of static initializations.
-    /// The main problem is the root logger name - declared statically - which
-    /// is referenced by various loggers.  By deferring a reference to it until
-    /// after the program starts executing - by which time the root name object
-    /// will be initialized - we avoid this problem.
+    /// Returns the logger pointer.  If not yet set, the implementation class is
+    /// initialized.
+    ///
+    /// The main reason for this is to allow loggers to be declared statically
+    /// before the underlying logging system is initialized.  However, any
+    /// attempt to access a logging method on any logger before initialization -
+    /// regardless of whether is is statically or automatically declared -  will
+    /// cause an exception to be thrown.
     ///
     /// \return Returns pointer to implementation
     LoggerImpl* getLoggerPtr() {

src/lib/log/logger_manager.cc

@@ -15,10 +15,11 @@
 #include <algorithm>
 #include <vector>
 
-#include <log/logger.h>
+#include <log/logger_level.h>
 #include <log/logger_manager_impl.h>
 #include <log/logger_manager.h>
 #include <log/logger_name.h>
+#include <log/logger_support.h>
 #include <log/messagedef.h>
 #include <log/message_dictionary.h>
 #include <log/message_exception.h>
@@ -110,6 +111,7 @@ LoggerManager::init(const std::string& root, isc::log::Severity severity,
     // Initialize the implementation logging.  After this point, some basic
     // logging has been set up and messages can be logged.
     LoggerManagerImpl::init(severity, dbglevel);
+    setLoggingInitialized();
 
     // Check if there were any duplicate message IDs in the default dictionary
     // and if so, log them.  Log using the logging facility logger.

src/lib/log/logger_support.cc

@@ -29,28 +29,51 @@
 #include <iostream>
 #include <string>
 
-#include <log/logger.h>
+#include <log/logger_level.h>
 #include <log/logger_manager.h>
 #include <log/logger_support.h>
 
+using namespace std;
+
+namespace {
+
+// Flag to hold logging initialization state.  This is held inside a function
+// to ensure that it is correctly initialized even when referenced during
+// program initialization (thus avoiding the "static initialization fiasco").
+bool&
+loggingInitializationFlag() {
+    static bool init_flag = false;
+    return (init_flag);
+}
+
+} // Anonymous namespace
+
 namespace isc {
 namespace log {
 
-using namespace std;
-
-// Declare a logger for the logging subsystem.  This is a sub-logger of the
-// root logger and is used in all functions in this file.
-Logger logger("log");
+// Return initialization state.
+bool
+isLoggingInitialized() {
+    return (loggingInitializationFlag());
+}
 
-/// Logger Run-Time Initialization
+// Set initialization state.  (Note: as logging can be initialized via a direct
+// call to LoggerManager::init(), this function is called from there, not from
+// the initialization functions in this file.
+void
+setLoggingInitialized(bool state) {
+    loggingInitializationFlag() = state;
+}
 
+// Logger Run-Time Initialization.  This function is present for historical
+// reasons.
 void
 initLogger(const string& root, isc::log::Severity severity, int dbglevel,
     const char* file) {
     LoggerManager::init(root, severity, dbglevel, file);
 }
 
-/// Logger Run-Time Initialization via Environment Variables
+// Logger Run-Time Initialization via Environment Variables
 void initLogger(isc::log::Severity severity, int dbglevel) {
 
     // Root logger name is defined by the environment variable B10_LOGGER_ROOT.
@@ -79,20 +102,20 @@ void initLogger(isc::log::Severity severity, int dbglevel) {
             try {
                 level = boost::lexical_cast<int>(dbg_char);
                 if (level < MIN_DEBUG_LEVEL) {
-                    std::cerr << "**ERROR** debug level of " << level
-                              << " is invalid - a value of " << MIN_DEBUG_LEVEL
-                              << " will be used\n";
+                    cerr << "**ERROR** debug level of " << level
+                         << " is invalid - a value of " << MIN_DEBUG_LEVEL
+                         << " will be used\n";
                     level = MIN_DEBUG_LEVEL;
                 } else if (level > MAX_DEBUG_LEVEL) {
-                    std::cerr << "**ERROR** debug level of " << level
-                              << " is invalid - a value of " << MAX_DEBUG_LEVEL
-                              << " will be used\n";
+                    cerr << "**ERROR** debug level of " << level
+                         << " is invalid - a value of " << MAX_DEBUG_LEVEL
+                         << " will be used\n";
                     level = MAX_DEBUG_LEVEL;
                 }
             } catch (...) {
                 // Error, but not fatal to the test
-                std::cerr << "**ERROR** Unable to translate "
-                             "B10_LOGGER_DBGLEVEL - a value of 0 will be used\n";
+                cerr << "**ERROR** Unable to translate "
+                        "B10_LOGGER_DBGLEVEL - a value of 0 will be used\n";
             }
             dbglevel = level;
         }

src/lib/log/logger_support.h

@@ -23,6 +23,26 @@
 namespace isc {
 namespace log {
 
+/// \brief Is logging initialized?
+///
+/// As some underlying logging implementations can behave unpredictably if they
+/// have not been initialized when a logging function is called, their
+/// initialization state is tracked.  The logger functions will check this flag
+/// and throw an exception if logging is not initialized at that point.
+///
+/// \return true if logging has been initialized, false if not
+bool isLoggingInitialized();
+
+/// \brief Set "logging initialized" flag
+///
+/// Sets the state of the "logging initialized" flag.
+///
+/// \param state State to set the flag to. (This is expected to be "true" - the
+///        default - for all code apart from specific unit tests.)
+void setLoggingInitialized(bool state = true);
+
+
+
 /// \brief Run-Time Initialization
 ///
 /// Performs run-time initialization of the logger in particular supplying:
@@ -70,7 +90,9 @@ void initLogger(const std::string& root,
 ///
 /// Any errors in the settings cause messages to be output to stderr.
 ///
-/// This function is most likely to be called from unit test programs.
+/// This function is aimed at test programs, allowing the default settings to
+/// be overridden by the tester.  It is not intended for use in production
+/// code.
 
 void initLogger(isc::log::Severity severity = isc::log::INFO,
                 int dbglevel = 0);

src/lib/log/tests/Makefile.am

@@ -19,6 +19,7 @@ run_unittests_SOURCES += logger_level_impl_unittest.cc
 run_unittests_SOURCES += logger_level_unittest.cc
 run_unittests_SOURCES += logger_manager_unittest.cc
 run_unittests_SOURCES += logger_name_unittest.cc
+run_unittests_SOURCES += logger_support_unittest.cc
 run_unittests_SOURCES += logger_unittest.cc
 run_unittests_SOURCES += logger_specification_unittest.cc
 run_unittests_SOURCES += message_dictionary_unittest.cc

src/lib/log/tests/logger_support_unittest.cc

@@ -0,0 +1,72 @@
+// 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 <gtest/gtest.h>
+#include <log/logger_support.h>
+#include <log/messagedef.h>
+
+using namespace isc::log;
+
+// Check that the initialized flag can be manipulated.  This is a bit chicken-
+// -and-egg: we want to reset to the flag to the original value at the end
+// of the test, so use the functions to do that.  But we are trying to check
+// that these functions in fact work.
+
+TEST(LoggerSupportTest, InitializedFlag) {
+    bool current_flag = isLoggingInitialized();
+
+    // check we can flip the flag.
+    setLoggingInitialized(!current_flag);
+    EXPECT_NE(current_flag, isLoggingInitialized());
+    setLoggingInitialized(!isLoggingInitialized());
+    EXPECT_EQ(current_flag, isLoggingInitialized());
+
+    // Check we can set it to explicit values (tests that a call to the "set"
+    // function does not just flip the flag).
+    setLoggingInitialized(false);
+    EXPECT_FALSE(isLoggingInitialized());
+    setLoggingInitialized(false);
+    EXPECT_FALSE(isLoggingInitialized());
+
+    setLoggingInitialized(true);
+    EXPECT_TRUE(isLoggingInitialized());
+    setLoggingInitialized(true);
+    EXPECT_TRUE(isLoggingInitialized());
+
+    // Reset to original value
+    setLoggingInitialized(current_flag);
+}
+
+// Check that a logger will throw an exception if logging has not been
+// initialized.
+
+TEST(LoggerSupportTest, LoggingInitializationCheck) {
+
+    // Assert that logging has been initialized (it should be in main()).
+    bool current_flag = isLoggingInitialized();
+    EXPECT_TRUE(current_flag);
+
+    // Flag that it has not been initialized and declare a logger. Any logging
+    // operation should then throw.
+    setLoggingInitialized(false);
+    isc::log::Logger test_logger("test");
+
+    EXPECT_THROW(test_logger.isDebugEnabled(), LoggingNotInitialized);
+    EXPECT_THROW(test_logger.info(MSG_OPENIN), LoggingNotInitialized);
+
+    // ... and check that they work when logging is initialized.
+    setLoggingInitialized(true);
+    EXPECT_NO_THROW(test_logger.isDebugEnabled());
+    EXPECT_NO_THROW(test_logger.info(MSG_OPENIN));
+}