BIND 10 trac1704, updated. 5395aa1b8dfa638523a4e547dde574c91b90a4ed [1704] Add unit test to check that a file lock is acquired when a message is logged
BIND 10 source code commits
bind10-changes at lists.isc.org
Tue May 22 03:39:33 UTC 2012
The branch, trac1704 has been updated
via 5395aa1b8dfa638523a4e547dde574c91b90a4ed (commit)
from 5f89e03f687942a5dc77f1f4684b55a208213094 (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 5395aa1b8dfa638523a4e547dde574c91b90a4ed
Author: Mukund Sivaraman <muks at isc.org>
Date: Tue May 22 09:00:31 2012 +0530
[1704] Add unit test to check that a file lock is acquired when a message is logged
-----------------------------------------------------------------------
Summary of changes:
src/lib/log/log_messages.cc | 4 +-
src/lib/log/log_messages.h | 3 +-
src/lib/log/log_messages.mes | 3 +
src/lib/log/logger.h | 38 ++++++------
src/lib/log/logger_impl.cc | 36 ++++++------
src/lib/log/logger_impl.h | 62 ++++++++++++++++++--
src/lib/log/tests/Makefile.am | 1 +
src/lib/log/tests/logger_unittest.cc | 102 ++++++++++++++++++++++++++++++++++
src/lib/util/file_lock.cc | 27 +++++++++
src/lib/util/file_lock.h | 1 +
10 files changed, 232 insertions(+), 45 deletions(-)
-----------------------------------------------------------------------
diff --git a/src/lib/log/log_messages.cc b/src/lib/log/log_messages.cc
index f60898c..762d061 100644
--- a/src/lib/log/log_messages.cc
+++ b/src/lib/log/log_messages.cc
@@ -1,4 +1,4 @@
-// File created from log_messages.mes on Thu Jul 7 15:32:06 2011
+// File created from log_messages.mes on Tue May 22 08:17:08 2012
#include <cstddef>
#include <log/message_types.h>
@@ -14,6 +14,7 @@ extern const isc::log::MessageID LOG_DUPLICATE_MESSAGE_ID = "LOG_DUPLICATE_MESSA
extern const isc::log::MessageID LOG_DUPLICATE_NAMESPACE = "LOG_DUPLICATE_NAMESPACE";
extern const isc::log::MessageID LOG_INPUT_OPEN_FAIL = "LOG_INPUT_OPEN_FAIL";
extern const isc::log::MessageID LOG_INVALID_MESSAGE_ID = "LOG_INVALID_MESSAGE_ID";
+extern const isc::log::MessageID LOG_LOCK_TEST_MESSAGE = "LOG_LOCK_TEST_MESSAGE";
extern const isc::log::MessageID LOG_NAMESPACE_EXTRA_ARGS = "LOG_NAMESPACE_EXTRA_ARGS";
extern const isc::log::MessageID LOG_NAMESPACE_INVALID_ARG = "LOG_NAMESPACE_INVALID_ARG";
extern const isc::log::MessageID LOG_NAMESPACE_NO_ARGS = "LOG_NAMESPACE_NO_ARGS";
@@ -41,6 +42,7 @@ const char* values[] = {
"LOG_DUPLICATE_NAMESPACE", "line %1: duplicate $NAMESPACE directive found",
"LOG_INPUT_OPEN_FAIL", "unable to open message file %1 for input: %2",
"LOG_INVALID_MESSAGE_ID", "line %1: invalid message identification '%2'",
+ "LOG_LOCK_TEST_MESSAGE", "this is a test message.",
"LOG_NAMESPACE_EXTRA_ARGS", "line %1: $NAMESPACE directive has too many arguments",
"LOG_NAMESPACE_INVALID_ARG", "line %1: $NAMESPACE directive has an invalid argument ('%2')",
"LOG_NAMESPACE_NO_ARGS", "line %1: no arguments were given to the $NAMESPACE directive",
diff --git a/src/lib/log/log_messages.h b/src/lib/log/log_messages.h
index 10e1501..5a717eb 100644
--- a/src/lib/log/log_messages.h
+++ b/src/lib/log/log_messages.h
@@ -1,4 +1,4 @@
-// File created from log_messages.mes on Thu Jul 7 15:32:06 2011
+// File created from log_messages.mes on Tue May 22 08:17:08 2012
#ifndef __LOG_MESSAGES_H
#define __LOG_MESSAGES_H
@@ -15,6 +15,7 @@ extern const isc::log::MessageID LOG_DUPLICATE_MESSAGE_ID;
extern const isc::log::MessageID LOG_DUPLICATE_NAMESPACE;
extern const isc::log::MessageID LOG_INPUT_OPEN_FAIL;
extern const isc::log::MessageID LOG_INVALID_MESSAGE_ID;
+extern const isc::log::MessageID LOG_LOCK_TEST_MESSAGE;
extern const isc::log::MessageID LOG_NAMESPACE_EXTRA_ARGS;
extern const isc::log::MessageID LOG_NAMESPACE_INVALID_ARG;
extern const isc::log::MessageID LOG_NAMESPACE_NO_ARGS;
diff --git a/src/lib/log/log_messages.mes b/src/lib/log/log_messages.mes
index f150f39..aa415da 100644
--- a/src/lib/log/log_messages.mes
+++ b/src/lib/log/log_messages.mes
@@ -144,3 +144,6 @@ Within a message file, a line starting with a dollar symbol was found
% LOG_WRITE_ERROR error writing to %1: %2
The specified error was encountered by the message compiler when writing
to the named output file.
+
+% LOG_LOCK_TEST_MESSAGE this is a test message.
+This is a test message for the lock test.
diff --git a/src/lib/log/logger.h b/src/lib/log/logger.h
index 5715bc4..6ddd6f8 100644
--- a/src/lib/log/logger.h
+++ b/src/lib/log/logger.h
@@ -244,6 +244,25 @@ public:
/// \return true if the logger objects are instances of the same logger.
bool operator==(Logger& other);
+ /// \brief Initialize Implementation
+ ///
+ /// 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 a "LoggingNotInitialized" exception to be thrown.
+ ///
+ /// \return Returns pointer to implementation
+ LoggerImpl* getLoggerPtr() {
+ if (!loggerptr_) {
+ initLoggerImpl();
+ }
+ return (loggerptr_);
+ }
+
private:
friend class isc::log::Formatter<Logger>;
@@ -267,25 +286,6 @@ private:
/// just create another one of the same name.
Logger& operator=(const Logger&);
- /// \brief Initialize Implementation
- ///
- /// 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 a "LoggingNotInitialized" exception to be thrown.
- ///
- /// \return Returns pointer to implementation
- LoggerImpl* getLoggerPtr() {
- if (!loggerptr_) {
- initLoggerImpl();
- }
- return (loggerptr_);
- }
-
/// \brief Initialize Underlying Implementation and Set loggerptr_
void initLoggerImpl();
diff --git a/src/lib/log/logger_impl.cc b/src/lib/log/logger_impl.cc
index c0a4adc..940df35 100644
--- a/src/lib/log/logger_impl.cc
+++ b/src/lib/log/logger_impl.cc
@@ -51,9 +51,10 @@ 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_ = new LoggerWrapper(name_);
+
lockfile_path_ = LOCKFILE_DIR;
const char* const env = getenv("B10_FROM_SOURCE");
@@ -75,8 +76,7 @@ LoggerImpl::LoggerImpl(const string& name) : name_(expandLoggerName(name)),
umask(mode);
if (lock_fd_ == -1) {
- LOG4CPLUS_ERROR(logger_, "Unable to use logger lockfile: " +
- lockfile_path_);
+ logger_->error("Unable to use logger lockfile: " + lockfile_path_);
}
}
@@ -87,26 +87,28 @@ LoggerImpl::~LoggerImpl() {
close(lock_fd_);
}
// The lockfile will continue to exist, as we mustn't delete it.
+
+ delete logger_;
}
// Set the severity for logging.
void
LoggerImpl::setSeverity(isc::log::Severity severity, int dbglevel) {
Level level(severity, dbglevel);
- logger_.setLogLevel(LoggerLevelImpl::convertFromBindLevel(level));
+ logger_->setLogLevel(LoggerLevelImpl::convertFromBindLevel(level));
}
// Return severity level
isc::log::Severity
LoggerImpl::getSeverity() {
- Level level = LoggerLevelImpl::convertToBindLevel(logger_.getLogLevel());
+ Level level = LoggerLevelImpl::convertToBindLevel(logger_->getLogLevel());
return level.severity;
}
// Return current debug level (only valid if current severity level is DEBUG).
int
LoggerImpl::getDebugLevel() {
- Level level = LoggerLevelImpl::convertToBindLevel(logger_.getLogLevel());
+ Level level = LoggerLevelImpl::convertToBindLevel(logger_->getLogLevel());
return level.dbglevel;
}
@@ -114,7 +116,7 @@ LoggerImpl::getDebugLevel() {
// severity of the root level.
isc::log::Severity
LoggerImpl::getEffectiveSeverity() {
- Level level = LoggerLevelImpl::convertToBindLevel(logger_.getChainedLogLevel());
+ Level level = LoggerLevelImpl::convertToBindLevel(logger_->getChainedLogLevel());
return level.severity;
}
@@ -122,7 +124,7 @@ LoggerImpl::getEffectiveSeverity() {
// is DEBUG).
int
LoggerImpl::getEffectiveDebugLevel() {
- Level level = LoggerLevelImpl::convertToBindLevel(logger_.getChainedLogLevel());
+ Level level = LoggerLevelImpl::convertToBindLevel(logger_->getChainedLogLevel());
return level.dbglevel;
}
@@ -143,37 +145,35 @@ LoggerImpl::outputRaw(const Severity& severity, const string& message) {
if (lock_fd_ != -1) {
if (!l.lock()) {
- LOG4CPLUS_ERROR(logger_, "Unable to lock logger lockfile: " +
- lockfile_path_);
+ logger_->error("Unable to lock logger lockfile: " + lockfile_path_);
}
}
// Log the message
switch (severity) {
case DEBUG:
- LOG4CPLUS_DEBUG(logger_, message);
+ logger_->debug(message);
break;
case INFO:
- LOG4CPLUS_INFO(logger_, message);
+ logger_->info(message);
break;
case WARN:
- LOG4CPLUS_WARN(logger_, message);
+ logger_->warn(message);
break;
case ERROR:
- LOG4CPLUS_ERROR(logger_, message);
+ logger_->error(message);
break;
case FATAL:
- LOG4CPLUS_FATAL(logger_, message);
+ logger_->fatal(message);
}
if (lock_fd_ != -1) {
if (!l.unlock()) {
- LOG4CPLUS_ERROR(logger_, "Unable to unlock logger lockfile: " +
- lockfile_path_);
+ logger_->error("Unable to unlock logger lockfile: " + lockfile_path_);
}
}
}
diff --git a/src/lib/log/logger_impl.h b/src/lib/log/logger_impl.h
index 164bf94..d92f1cb 100644
--- a/src/lib/log/logger_impl.h
+++ b/src/lib/log/logger_impl.h
@@ -35,6 +35,51 @@
namespace isc {
namespace log {
+class LoggerWrapper {
+public:
+ LoggerWrapper(const std::string& name) : logger_(log4cplus::Logger::getInstance(name)) {
+ }
+
+ virtual bool isEnabledFor(log4cplus::LogLevel level) {
+ return (logger_.isEnabledFor(level));
+ }
+
+ virtual void setLogLevel(log4cplus::LogLevel level) {
+ logger_.setLogLevel(level);
+ }
+
+ virtual log4cplus::LogLevel getLogLevel() {
+ return (logger_.getLogLevel());
+ }
+
+ virtual log4cplus::LogLevel getChainedLogLevel() {
+ return (logger_.getChainedLogLevel());
+ }
+
+ virtual void debug(std::string msg) {
+ LOG4CPLUS_DEBUG(logger_, msg);
+ }
+
+ virtual void info(std::string msg) {
+ LOG4CPLUS_INFO(logger_, msg);
+ }
+
+ virtual void warn(std::string msg) {
+ LOG4CPLUS_WARN(logger_, msg);
+ }
+
+ virtual void error(std::string msg) {
+ LOG4CPLUS_ERROR(logger_, msg);
+ }
+
+ virtual void fatal(std::string msg) {
+ LOG4CPLUS_FATAL(logger_, msg);
+ }
+
+private:
+ log4cplus::Logger logger_; ///< Underlying log4cplus logger
+};
+
/// \brief Console Logger Implementation
///
/// The logger uses a "pimpl" idiom for implementation, where the base logger
@@ -129,27 +174,27 @@ public:
/// checked is less than or equal to the debug level set for the logger.
virtual bool isDebugEnabled(int dbglevel = MIN_DEBUG_LEVEL) {
Level level(DEBUG, dbglevel);
- return logger_.isEnabledFor(LoggerLevelImpl::convertFromBindLevel(level));
+ return logger_->isEnabledFor(LoggerLevelImpl::convertFromBindLevel(level));
}
/// \brief Is INFO Enabled?
virtual bool isInfoEnabled() {
- return (logger_.isEnabledFor(log4cplus::INFO_LOG_LEVEL));
+ return (logger_->isEnabledFor(log4cplus::INFO_LOG_LEVEL));
}
/// \brief Is WARNING Enabled?
virtual bool isWarnEnabled() {
- return (logger_.isEnabledFor(log4cplus::WARN_LOG_LEVEL));
+ return (logger_->isEnabledFor(log4cplus::WARN_LOG_LEVEL));
}
/// \brief Is ERROR Enabled?
virtual bool isErrorEnabled() {
- return (logger_.isEnabledFor(log4cplus::ERROR_LOG_LEVEL));
+ return (logger_->isEnabledFor(log4cplus::ERROR_LOG_LEVEL));
}
/// \brief Is FATAL Enabled?
virtual bool isFatalEnabled() {
- return (logger_.isEnabledFor(log4cplus::FATAL_LOG_LEVEL));
+ return (logger_->isEnabledFor(log4cplus::FATAL_LOG_LEVEL));
}
/// \brief Raw output
@@ -177,9 +222,14 @@ public:
return (name_ == other.name_);
}
+ void setLoggerWrapper(LoggerWrapper *wrapper) {
+ delete logger_;
+ logger_ = wrapper;
+ }
+
private:
std::string name_; ///< Full name of this logger
- log4cplus::Logger logger_; ///< Underlying log4cplus logger
+ LoggerWrapper *logger_; ///< Underlying log4cplus wrapper
std::string lockfile_path_;
int lock_fd_;
};
diff --git a/src/lib/log/tests/Makefile.am b/src/lib/log/tests/Makefile.am
index dd3c08c..5689e32 100644
--- a/src/lib/log/tests/Makefile.am
+++ b/src/lib/log/tests/Makefile.am
@@ -2,6 +2,7 @@ SUBDIRS = .
AM_CPPFLAGS = -I$(top_builddir)/src/lib -I$(top_srcdir)/src/lib
AM_CPPFLAGS += $(BOOST_INCLUDES)
+AM_CPPFLAGS += -DLOCKFILE_DIR=\"${localstatedir}/${PACKAGE_NAME}\"
AM_CPPFLAGS += -DTOP_SRCDIR=\"${abs_top_srcdir}\"
AM_CXXFLAGS = $(B10_CXXFLAGS)
AM_LDADD =
diff --git a/src/lib/log/tests/logger_unittest.cc b/src/lib/log/tests/logger_unittest.cc
index 069205e..8e8e746 100644
--- a/src/lib/log/tests/logger_unittest.cc
+++ b/src/lib/log/tests/logger_unittest.cc
@@ -20,10 +20,15 @@
#include <util/unittests/resource.h>
#include <log/logger.h>
+#include <log/logger_impl.h>
#include <log/logger_manager.h>
#include <log/logger_name.h>
#include <log/log_messages.h>
+#include <util/file_lock.h>
+#include <unistd.h>
+#include <fcntl.h>
+
using namespace isc;
using namespace isc::log;
using namespace std;
@@ -379,3 +384,100 @@ TEST_F(LoggerTest, LoggerNameLength) {
}, ".*");
#endif
}
+
+// Checks that the logger logs exclusively and other BIND 10 components
+// are locked out.
+
+class MockWrapper : public LoggerWrapper {
+public:
+ MockWrapper(const std::string& name) : LoggerWrapper(name), was_locked_(false) {
+ }
+
+ virtual void fatal(std::string msg) {
+ int fds[2];
+
+ msg = msg; // shut up compiler
+
+ // Here, we check that a lock has been taken by forking and
+ // checking from the child that a lock exists. This has to be
+ // done from a separate process as we test by trying to lock the
+ // range again on the lock file. The lock attempt would pass if
+ // done from the same process for the granted range. The lock
+ // attempt must fail to pass our check.
+
+ pipe(fds);
+
+ if (fork() == 0) {
+ unsigned char locked = 0;
+ // Child writes to pipe
+ close(fds[0]);
+
+ // Check if the lock file was indeed locked.
+ string lockfile_path = LOCKFILE_DIR;
+
+ const char* const env = getenv("B10_FROM_SOURCE");
+ if (env != NULL) {
+ lockfile_path = env;
+ }
+
+ const char* const env2 = getenv("B10_FROM_SOURCE_LOCALSTATEDIR");
+ if (env2 != NULL) {
+ lockfile_path = env2;
+ }
+
+ lockfile_path += "/logger_lockfile";
+
+ int lock_fd = open(lockfile_path.c_str(), O_RDWR);
+ if (lock_fd != -1) {
+ isc::util::file_lock l(lock_fd);
+
+ if (!l.tryLock()) {
+ locked = 1;
+ }
+ close(lock_fd);
+ }
+
+ write(fds[1], &locked, sizeof locked);
+ close(fds[1]);
+ exit(0);
+ } else {
+ unsigned char locked;
+ // Parent reads from pipe
+ close(fds[1]);
+
+ // Read status and set flag
+ read(fds[0], &locked, sizeof locked);
+ if (locked == 0) {
+ was_locked_ = false;
+ } else {
+ was_locked_ = true;
+ }
+
+ close(fds[0]);
+ }
+ }
+
+ bool wasLocked() {
+ return was_locked_;
+ }
+
+private:
+ bool was_locked_;
+};
+
+TEST_F(LoggerTest, Lock) {
+ // Create a logger
+ Logger logger("alpha");
+
+ // Setup our own mock wrapper so that we can intercept the logging
+ // call and check if a file lock has been taken.
+ LoggerImpl *i = logger.getLoggerPtr();
+ MockWrapper *my_wrapper = new MockWrapper("alpha");
+ i->setLoggerWrapper(my_wrapper);
+
+ // Log a message and put things into play.
+ logger.setSeverity(isc::log::FATAL, 100);
+ logger.fatal(LOG_LOCK_TEST_MESSAGE);
+
+ EXPECT_TRUE(my_wrapper->wasLocked());
+}
diff --git a/src/lib/util/file_lock.cc b/src/lib/util/file_lock.cc
index 8759636..4e504c9 100644
--- a/src/lib/util/file_lock.cc
+++ b/src/lib/util/file_lock.cc
@@ -54,6 +54,33 @@ file_lock::lock() {
}
bool
+file_lock::tryLock() {
+ if (is_locked_) {
+ return true;
+ }
+
+ if (fd_ != -1) {
+ struct flock lock;
+ int status;
+
+ // Acquire the exclusive lock
+ memset(&lock, 0, sizeof lock);
+ lock.l_type = F_WRLCK;
+ lock.l_whence = SEEK_SET;
+ lock.l_start = 0;
+ lock.l_len = 1;
+
+ status = fcntl(fd_, F_SETLK, &lock);
+ if (status == 0) {
+ is_locked_ = true;
+ return true;
+ }
+ }
+
+ return false;
+}
+
+bool
file_lock::unlock() {
if (!is_locked_) {
return true;
diff --git a/src/lib/util/file_lock.h b/src/lib/util/file_lock.h
index eb0cd8f..d11b432 100644
--- a/src/lib/util/file_lock.h
+++ b/src/lib/util/file_lock.h
@@ -30,6 +30,7 @@ public:
virtual ~file_lock();
bool lock();
+ bool tryLock();
bool unlock();
private:
int fd_;
More information about the bind10-changes
mailing list