Commit 0afb9dde authored by Stephen Morris's avatar Stephen Morris
Browse files

[trac558] Seond and final stage of backing out log4cxx support

Introduced an implementation class that writes its output to stdout.
It does implement a logger hierarchy, but will be slower at logging
if setting a logging configuration for anything other than the
root logger.
parent 614ecf7c
......@@ -366,46 +366,44 @@ AC_SUBST(USE_LCOV)
# Configure log4cxx header and library path
#
# If explicitly specified, use it.
AC_ARG_WITH([log4cxx],
AC_HELP_STRING([--with-log4cxx=PATH],
[specify directory where log4cxx is installed]),
[
log4cxx_include_path="${withval}/include";
log4cxx_library_path="${withval}/lib"
])
# If not specified, try some common paths. These default to
# /usr/include and /usr/lib if not found
if test -z "$with_log4cxx"; then
log4cxxdirs="/usr/local /usr/pkg /opt /opt/local"
for d in $log4cxxdirs
do
if test -d $d/include/log4cxx; then
log4cxx_include_path=$d/include
log4cxx_library_path=$d/lib
break
fi
done
fi
CPPFLAGS_SAVES="$CPPFLAGS"
if test "${log4cxx_include_path}" ; then
LOG4CXX_INCLUDES="-I${log4cxx_include_path}"
CPPFLAGS="$CPPFLAGS $LOG4CXX_INCLUDES"
fi
AC_CHECK_HEADER([log4cxx/logger.h],, AC_MSG_ERROR([Missing log4cxx header files.]))
CPPFLAGS="$CPPFLAGS_SAVES"
AC_SUBST(LOG4CXX_INCLUDES)
LOG4CXX_LDFLAGS="-llog4cxx";
if test "${log4cxx_library_path}"; then
LOG4CXX_LDFLAGS="-L${log4cxx_library_path} -llog4cxx"
fi
AC_SUBST(LOG4CXX_LDFLAGS)
#
# AC_ARG_WITH([log4cxx],
# AC_HELP_STRING([--with-log4cxx=PATH],
# [specify directory where log4cxx is installed]),
# [
# log4cxx_include_path="${withval}/include";
# log4cxx_library_path="${withval}/lib"
# ])
#
# # If not specified, try some common paths. These default to
# # /usr/include and /usr/lib if not found
#
# if test -z "$with_log4cxx"; then
# log4cxxdirs="/usr/local /usr/pkg /opt /opt/local"
# for d in $log4cxxdirs
# do
# if test -d $d/include/log4cxx; then
# log4cxx_include_path=$d/include
# log4cxx_library_path=$d/lib
# break
# fi
# done
# fi
#
# CPPFLAGS_SAVES="$CPPFLAGS"
# if test "${log4cxx_include_path}" ; then
# LOG4CXX_INCLUDES="-I${log4cxx_include_path}"
# CPPFLAGS="$CPPFLAGS $LOG4CXX_INCLUDES"
# fi
# AC_CHECK_HEADER([log4cxx/logger.h],, AC_MSG_ERROR([Missing log4cxx header files.]))
# CPPFLAGS="$CPPFLAGS_SAVES"
# AC_SUBST(LOG4CXX_INCLUDES)
#
# LOG4CXX_LDFLAGS="-llog4cxx";
# if test "${log4cxx_library_path}"; then
# LOG4CXX_LDFLAGS="-L${log4cxx_library_path} -llog4cxx"
# fi
# AC_SUBST(LOG4CXX_LDFLAGS)
#
# Configure Boost header path
......@@ -811,8 +809,8 @@ dnl includes too
${PYTHON_LDFLAGS}
${PYTHON_LIB}
Boost: ${BOOST_INCLUDES}
log4cxx: ${LOG4CXX_INCLUDES}
${LOG4CXX_LDFLAGS}
dnl log4cxx: ${LOG4CXX_INCLUDES}
dnl ${LOG4CXX_LDFLAGS}
SQLite: $SQLITE_CFLAGS
$SQLITE_LIBS
......
......@@ -2,7 +2,7 @@ SUBDIRS = . compiler tests
AM_CPPFLAGS = -I$(top_builddir)/src/lib -I$(top_srcdir)/src/lib
AM_CPPFLAGS += $(BOOST_INCLUDES)
AM_CPPFLAGS += $(LOG4CXX_INCLUDES)
# AM_CPPFLAGS += $(LOG4CXX_INCLUDES)
AM_CPPFLAGS += -I$(top_srcdir)/src/lib/log -I$(top_builddir)/src/lib/log
CLEANFILES = *.gcno *.gcda
......@@ -23,9 +23,9 @@ liblog_la_SOURCES += message_reader.cc message_reader.h
liblog_la_SOURCES += message_types.h
liblog_la_SOURCES += root_logger_name.cc root_logger_name.h
liblog_la_SOURCES += strutil.h strutil.cc
liblog_la_SOURCES += xdebuglevel.cc xdebuglevel.h
# liblog_la_SOURCES += xdebuglevel.cc xdebuglevel.h
liblog_la_LDFLAGS = $(LOG4CXX_LDFLAGS)
# liblog_la_LDFLAGS = $(LOG4CXX_LDFLAGS)
# Note: the ordering matters: -Wno-... must follow -Wextra (defined in
# B10_CXXFLAGS)
......
......@@ -216,18 +216,8 @@ To use the current version of the logging:
isc::log::Logger logger("myname", true);
This is due to an apparent bug in the underlying log4cxx, where the deletion
of a statically-declared object at program termination can cause a segment
fault. (The destruction of internal memory structures can sometimes happen
out of order.) By default the Logger class creates the structures in its
constructor but does not delete them in the destruction. The default
behavious works because instead of reclaiming memory at program run-down,
the operating system reclaims it when the process is deleted.
Setting the second argument "true" causes the Logger's destructor to delete
the log4cxx structures. This does not cause a problem if the program is
not terminating. So use the second form when declaring an automatic
instance of isc::log::Logger on the stack.
The argument is ignored for underlying implementations other than log4cxx.
See below for the use of this argument.
3. The main program unit should include a call to isc::log::runTimeInit()
(defined in logger_support.h) to set the logging severity, debug log level,
......@@ -235,12 +225,12 @@ To use the current version of the logging:
a) The logging severity is one of the enum defined in logger.h, i.e.
isc::log::Logger::DEBUG
isc::log::Logger::INFO
isc::log::Logger::WARN
isc::log::Logger::ERROR
isc::log::Logger::FATAL
isc::log::Logger::NONE
isc::log::DEBUG
isc::log::INFO
isc::log::WARN
isc::log::ERROR
isc::log::FATAL
isc::log::NONE
b) The debug log level is only interpreted when the severity is DEBUG and
is an integer raning from 0 to 99. 0 should be used for the highest-level
......@@ -348,16 +338,8 @@ DEBUG is specifically chosen.
b) Record system-related and packet-related messages via different loggers
(e.g. in the example given, sever events could be logged using the logger
"auth" and packet-related events at that level logged using the logger
"pkt-auth".)
As the loggers are independent and the severity levels independent, fine-tuning
of what and what is not recorded can be achieved.
Outstanding Issues
==================
* Ability to configure system according to configuration database.
* Update the build procedure to create .cc and .h files from the .msg file
during the build process. (Requires that the message compiler is built first.)
"pkt-auth".) As the loggers are independent and the severity levels
independent, fine-tuning of what and what is not recorded can be achieved.
Notes
......@@ -369,3 +351,67 @@ the server starts up (or when triggered by a command) to read in a message
file to overwrite the internal dictionary. Writing it in C++ means there
is only one piece of code that does this functionality.
Outstanding Issues
==================
* Ability to configure system according to configuration database.
* Update the build procedure to create .cc and .h files from the .msg file
during the build process. (Requires that the message compiler is built
first.)
log4cxx Issues
==============
Second Argument in Logger Constructor
-------------------------------------
As noted above, when using log4cxx as the underlying implementation, the
argument to the logger's constructor should be set true if declaring the
logger within a method and set false (or omitted) if declaring the logger
external to an execution unit.
This is due to an apparent bug in the underlying log4cxx, where the deletion
of a statically-declared object at program termination can cause a segment
fault. (The destruction of internal memory structures can sometimes happen
out of order.) By default the Logger class creates the structures in
its constructor but does not delete them in the destruction. The default
behavious works because instead of reclaiming memory at program run-down,
the operating system reclaims it when the process is deleted.
Setting the second argument "true" causes the Logger's destructor to delete
the log4cxx structures. This does not cause a problem if the program is
not terminating. So use the second form when declaring an automatic instance
of isc::log::Logger on the stack.
Building with log4cxx
---------------------
Owing to issues with versions of log4cxx on different systems, log4cxx was
temporarily disabled. To use log4cxx on your system:
* Uncomment the log4cxx lines in configure.ac
* In src/lib/log, replace the logger_impl.{cc,h} files with their log4cxx
equivalents, i.e.
cp logger_impl_log4cxx.h logger_impl.h
cp logger_impl_log4cxx.cc logger_impl.cc
* In src/lib/log/Makefile.am, uncomment the lines:
# AM_CPPFLAGS += $(LOG4CXX_INCLUDES)
# liblog_la_SOURCES += xdebuglevel.cc xdebuglevel.h
# liblog_la_LDFLAGS = $(LOG4CXX_LDFLAGS)
* In src/lib/log/test, re-enable testing of the log4cxx implementation
class, i.e.
cp logger_impl_log4cxx_unittest.cc logger_impl_unittest.cc
... and uncomment the following lines in Makefile.am:
# run_unittests_SOURCES += logger_impl_unittest.cc
# run_unittests_SOURCES += xdebuglevel_unittest.cc
Then rebuild the system from scratch.
......@@ -173,16 +173,16 @@ Logger::fatal(isc::log::MessageID ident, ...) {
}
}
// Protected methods (used for testing)
bool Logger::operator==(const Logger& other) {
return (*loggerptr_ == *other.loggerptr_);
}
bool Logger::isInitialized() {
return loggerptr_->isInitialized();
}
// Protected methods (used for testing)
void
Logger::reset() {
LoggerImpl::reset();
}
} // namespace log
} // namespace isc
......@@ -80,7 +80,7 @@ public:
/// enables their deletion - which causes no issues as the problem only
/// manifests itself during program rundown.
/// \n
/// The falg has no effect on non-log4cxx implementations.
/// The flag has no effect on non-log4cxx implementations.
Logger(const std::string& name, bool infunc = false);
......@@ -188,8 +188,6 @@ public:
/// \param ... Optional arguments for the message.
void fatal(MessageID ident, ...);
protected:
/// \brief Equality
///
/// Check if two instances of this logger refer to the same stream.
......@@ -198,14 +196,13 @@ protected:
/// \return true if the logger objects are instances of the same logger.
bool operator==(const Logger& other);
/// \brief Logger Initialized
///
/// Check that the logger has been properly initialized. (This method
/// is principally for testing.)
protected:
/// \brief Reset Global Data
///
/// \return true if this logger object has been initialized.
bool isInitialized();
/// Used for testing, this calls upon the underlying logger implementation
/// to clear any global data.
static void reset();
private:
LoggerImpl* loggerptr_; /// Pointer to the underlying logger
......
......@@ -15,22 +15,19 @@
// $Id$
#include <iostream>
#include <algorithm>
#include <stdarg.h>
#include <stdio.h>
#include <log4cxx/appender.h>
#include <log4cxx/basicconfigurator.h>
#include <log4cxx/patternlayout.h>
#include <log4cxx/consoleappender.h>
#include <log/debug_levels.h>
#include <log/root_logger_name.h>
#include <log/logger.h>
#include <log/logger_impl.h>
#include <log/message_dictionary.h>
#include <log/message_types.h>
#include <log/root_logger_name.h>
#include <log/strutil.h>
#include <log/xdebuglevel.h>
using namespace std;
......@@ -39,205 +36,221 @@ namespace log {
// Static initializations
bool LoggerImpl::init_ = false;
LoggerImpl::LoggerInfoMap LoggerImpl::logger_info_;
LoggerImpl::LoggerInfo LoggerImpl::root_logger_info_(isc::log::INFO, 0);
// Destructor. Delete log4cxx stuff if "don't delete" is clear.
// Destructor. (Here because of virtual declaration.)
LoggerImpl::~LoggerImpl() {
if (exit_delete_) {
delete loggerptr_;
}
// Return the name of the logger (fully-qualified with the root name if
// possible).
string LoggerImpl::getName() {
string root_name = RootLoggerName::getName();
if (root_name.empty() || (name_ == root_name)) {
return (name_);
}
else {
return (root_name + "." + name_);
}
}
// Initialize logger - create a logger as a child of the root logger. With
// log4cxx this is assured by naming the logger <parent>.<child>.
// Set the severity for logging.
void
LoggerImpl::initLogger() {
// Initialize basic logging if not already done. This is a one-off for
// all loggers.
if (!init_) {
// TEMPORARY
// Add a suitable console logger to the log4cxx root logger. (This
// is the logger at the root of the log4cxx tree, not the BIND-10 root
// logger, which is one level down.) The chosen format is:
//
// YYYY-MM-DD hh:mm:ss.sss [logger] SEVERITY: text
//
// As noted, this is a temporary hack: it is done here to ensure that
// a suitable output and output pattern is set. Future versions of the
// software will set this based on configuration data.
log4cxx::LayoutPtr layout(
new log4cxx::PatternLayout(
"%d{yyyy-MM-DD HH:mm:ss.SSS} %-5p [%c] %m\n"));
log4cxx::AppenderPtr console(
new log4cxx::ConsoleAppender(layout));
log4cxx::LoggerPtr sys_root_logger = log4cxx::Logger::getRootLogger();
sys_root_logger->addAppender(console);
LoggerImpl::setSeverity(isc::log::Severity severity, int dbglevel) {
// Silently coerce the debug level into the valid range of 0 to 99
int debug_level = max(MIN_DEBUG_LEVEL, min(MAX_DEBUG_LEVEL, dbglevel));
if (isRootLogger()) {
// Set the default logging to INFO
sys_root_logger->setLevel(log4cxx::Level::getInfo());
// 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);
}
} 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);
}
} else {
// All static stuff initialized
init_ = true;
// Want to set this information
logger_info_[name_] = LoggerInfo(severity, debug_level);
}
}
// Initialize this logger. Name this as to whether the BIND-10 root logger
// name has been set. (If not, this mucks up the hierarchy :-( ).
string root_name = RootLoggerName::getName();
if (root_name.empty() || (name_ == root_name)) {
loggerptr_ = new log4cxx::LoggerPtr(log4cxx::Logger::getLogger(name_));
// Return severity level
isc::log::Severity
LoggerImpl::getSeverity() {
if (isRootLogger()) {
return (root_logger_info_.severity);
}
else {
loggerptr_ = new log4cxx::LoggerPtr(
log4cxx::Logger::getLogger(root_name + "." + name_)
);
LoggerInfoMap::iterator i = logger_info_.find(name_);
if (i != logger_info_.end()) {
return ((i->second).severity);
}
else {
return (isc::log::DEFAULT);
}
}
}
// Get effective severity. Either the current severity or, if not set, the
// severity of the root level.
// Set the severity for logging. There is a 1:1 mapping between the logging
// severity and the log4cxx logging levels, apart from DEBUG.
//
// In log4cxx, each of the logging levels (DEBUG, INFO, WARN etc.) has a numeric
// value. The level is set to one of these and any numeric level equal to or
// above it that is reported. For example INFO has a value of 20000 and ERROR
// a value of 40000. So if a message of WARN severity (= 30000) is logged, it is
// not logged when the logger's severity level is ERROR (as 30000 !>= 40000).
// It is reported if the logger's severity level is set to WARN (as 30000 >=
/// 30000) or INFO (30000 >= 20000).
//
// This gives a simple system for handling different debug levels. The debug
// level is a number between 0 and 99, with 0 being least verbose and 99 the
// most. To implement this seamlessly, when DEBUG is set, the numeric value
// of the logging level is actually set to (DEBUG - debug-level). Similarly
// messages of level "n" are logged at a logging level of (DEBUG - n). Thus if
// the logging level is set to DEBUG and the debug level set to 25, the actual
// level set is 10000 - 25 = 99975.
//
// Attempting to log a debug message of level 26 is an attempt to log a message
// of level 10000 - 26 = 9974. As 9974 !>= 9975, it is not logged. A
// message of level 25 is, because 9975 >= 9975.
//
// The extended set of logging levels is implemented by the XDebugLevel class.
isc::log::Severity
LoggerImpl::getEffectiveSeverity() {
if (! isRootLogger()) {
void
LoggerImpl::setSeverity(isc::log::Severity severity, int dbglevel) {
switch (severity) {
case NONE:
getLogger()->setLevel(log4cxx::Level::getOff());
break;
case FATAL:
getLogger()->setLevel(log4cxx::Level::getFatal());
break;
case ERROR:
getLogger()->setLevel(log4cxx::Level::getError());
break;
case WARN:
getLogger()->setLevel(log4cxx::Level::getWarn());
break;
case INFO:
getLogger()->setLevel(log4cxx::Level::getInfo());
break;
case DEBUG:
getLogger()->setLevel(
log4cxx::XDebugLevel::getExtendedDebug(dbglevel));
break;
// Will get here for DEFAULT or any other value. This disables the
// logger's own severity and it defaults to the severity of the parent
// logger.
default:
getLogger()->setLevel(0);
// Not root logger, look this logger up in the map.
LoggerInfoMap::iterator i = logger_info_.find(name_);
if (i != logger_info_.end()) {
// Found, so return the 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);
}
// Convert between numeric log4cxx logging level and BIND-10 logging severity.
// Get the debug level. This returns 0 unless the severity is DEBUG.
isc::log::Severity
LoggerImpl::convertLevel(int value) {
// The order is optimised. This is only likely to be called when testing
// for writing debug messages, so the check for DEBUG_INT is first.
if (value <= log4cxx::Level::DEBUG_INT) {
return (DEBUG);
} else if (value <= log4cxx::Level::INFO_INT) {
return (INFO);
} else if (value <= log4cxx::Level::WARN_INT) {
return (WARN);
} else if (value <= log4cxx::Level::ERROR_INT) {
return (ERROR);
} else if (value <= log4cxx::Level::FATAL_INT) {
return (FATAL);
int
LoggerImpl::getDebugLevel() {
if (! isRootLogger()) {
// Not root logger, look this logger up in the map.
LoggerInfoMap::iterator i = logger_info_.find(name_);
if (i != logger_info_.end()) {
// Found, so return the debug level.
if ((i->second).severity == isc::log::DEBUG) {
return ((i->second).dbglevel);
} else {
return (0);
}
}
}
// 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);
} else {
return (NONE);
return (0);
}
}
// The code for isXxxEnabled is quite simple and is in the header. The only
// exception is isDebugEnabled() where we have the complication of the debug
// levels.
// Return the logging severity associated with this logger.
bool
LoggerImpl::isDebugEnabled(int dbglevel) {
isc::log::Severity
LoggerImpl::getSeverityCommon(const log4cxx::LoggerPtr& ptrlogger,
bool check_parent) {
if (logger_info_.empty()) {
log4cxx::LevelPtr level = ptrlogger->getLevel();
if (level == log4cxx::LevelPtr()) {
// Nothing set, return information from the root logger.
return ((root_logger_info_.severity <= isc::log::DEBUG) &&
(root_logger_info_.dbglevel >= dbglevel));
}
// Null level returned, logging should be that of the parent.
// Something is in the general logger map, so we need to look up the
// information. We don't use getSeverity() and getDebugLevel() separately
// as each involves a lookup in the map, something that we can optimise
// here.
if (check_parent) {
log4cxx::LoggerPtr parent = ptrlogger->getParent();
if (parent == log4cxx::LoggerPtr()) {
if (! isRootLogger()) {
// No parent, so reached the end of the chain. Return INFO
// severity.
return (INFO);
}
else {
return getSeverityCommon(parent, check_parent);
// Not root logger, look this logger up in the map.
LoggerInfoMap::iterator i = logger_info_.find(name_);
if (i != logger_info_.end()) {
// Found, so return the debug level.
if ((i->second).severity <= isc::log::DEBUG) {
return ((i->second).dbglevel >= dbglevel);
} else {
return (false); // Nothing lower than debug
}
}
else {
return (DEFAULT);
}
}
// 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);
} else {
return convertLevel(level->toInt());
return (false);
}
}