Commit f7f03585 authored by Stephen Morris's avatar Stephen Morris
Browse files

[trac558] Stage 1 of backing out log4cxx support

The introduction of logging caused problems when building BIND10
on a number of systems because up to date log4cxx support was not
available. (It appears that v0.9.8 is the minimum required, and a
number of distributions only have v0.9.7.)  For this reason, the
logging is being altered (for the moment) to withdraw log4cxx and
to write directly to the console.

The best solution seemed to be to split the basic API and the
implementation and to provide implementations for different logging
systems. (This was entered as ticket 529, but is being done now.)
The current commit leaves the logging system still using log4cxx,
but with the implementation split from the API.
parent 90980c50
......@@ -13,6 +13,7 @@ liblog_la_SOURCES += dbglevels.h
liblog_la_SOURCES += dummylog.h dummylog.cc
liblog_la_SOURCES += filename.h filename.cc
liblog_la_SOURCES += logger.cc logger.h
liblog_la_SOURCES += logger_impl.cc logger_impl.h
liblog_la_SOURCES += logger_support.cc logger_support.h
liblog_la_SOURCES += messagedef.cc messagedef.h
liblog_la_SOURCES += message_dictionary.cc message_dictionary.h
......
......@@ -19,229 +19,100 @@
#include <stdarg.h>
#include <stdio.h>
#include <log4cxx/appender.h>
#include <log4cxx/basicconfigurator.h>
#include <log4cxx/patternlayout.h>
#include <log4cxx/consoleappender.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;
namespace isc {
namespace log {
// Static initializations
// Constructor
bool Logger::init_ = false;
Logger::Logger(const std::string& name, bool infunc) :
loggerptr_(new LoggerImpl(name, infunc))
{}
// Destructor. Delete log4cxx stuff if "don't delete" is clear.
// Destructor.
Logger::~Logger() {
if (exit_delete_) {
delete loggerptr_;
}
delete loggerptr_;
}
// Initialize logger - create a logger as a child of the root logger. With
// log4cxx this is assured by naming the logger <parent>.<child>.
// Get Name of Logger
void
Logger::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);
// Set the default logging to INFO
sys_root_logger->setLevel(log4cxx::Level::getInfo());
// All static stuff initialized
init_ = true;
}
// 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_));
}
else {
loggerptr_ = new log4cxx::LoggerPtr(
log4cxx::Logger::getLogger(root_name + "." + name_)
);
}
std::string
Logger::getName() {
return (loggerptr_->getName());
}
// 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.
// Set the severity for logging.
void
Logger::setSeverity(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);
}
Logger::setSeverity(isc::log::Severity severity, int dbglevel) {
loggerptr_->setSeverity(severity, dbglevel);
}
// Convert between numeric log4cxx logging level and BIND-10 logging severity.
Logger::Severity
Logger::convertLevel(int value) const {
// 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);
} else {
return (NONE);
}
}
// Return the severity of the logger.
isc::log::Severity
Logger::getSeverity() {
return (loggerptr_->getSeverity());
}
// Return the logging severity associated with this logger.
// Get Effective Severity Level for Logger
Logger::Severity
Logger::getSeverityCommon(const log4cxx::LoggerPtr& ptrlogger,
bool check_parent) const {
isc::log::Severity
Logger::getEffectiveSeverity() {
return (loggerptr_->getEffectiveSeverity());
}
log4cxx::LevelPtr level = ptrlogger->getLevel();
if (level == log4cxx::LevelPtr()) {
// Debug level (only relevant if messages of severity DEBUG are being logged).
// Null level returned, logging should be that of the parent.
int
Logger::getDebugLevel() {
return (loggerptr_->getDebugLevel());
}
if (check_parent) {
log4cxx::LoggerPtr parent = ptrlogger->getParent();
if (parent == log4cxx::LoggerPtr()) {
// Check on the current severity settings
// No parent, so reached the end of the chain. Return INFO
// severity.
return (INFO);
}
else {
return getSeverityCommon(parent, check_parent);
}
}
else {
return (DEFAULT);
}
} else {
return convertLevel(level->toInt());
}
bool
Logger::isDebugEnabled(int dbglevel) {
return (loggerptr_->isDebugEnabled(dbglevel));
}
bool
Logger::isInfoEnabled() {
return (loggerptr_->isInfoEnabled());
}
// Get the debug level. This returns 0 unless the severity is DEBUG.
bool
Logger::isWarnEnabled() {
return (loggerptr_->isWarnEnabled());
}
int
Logger::getDebugLevel() {
bool
Logger::isErrorEnabled() {
return (loggerptr_->isErrorEnabled());
}
log4cxx::LevelPtr level = getLogger()->getLevel();
if (level == log4cxx::LevelPtr()) {
// Null pointer returned, logging should be that of the parent.
return (0);
} else {
int severity = level->toInt();
if (severity <= log4cxx::Level::DEBUG_INT) {
return (log4cxx::Level::DEBUG_INT - severity);
}
else {
return (0);
}
}
bool
Logger::isFatalEnabled() {
return (loggerptr_->isFatalEnabled());
}
// Log an error message:
// Common code. Owing to the use of variable arguments, this must be inline
// (hence the definition of the macro). Also note that it expects that the
// message buffer "message" is declared in the compilation unit.
// Format a message: looks up the message text in the dictionary and formats
// it, replacing tokens with arguments.
//
// Owing to the use of variable arguments, this must be inline (hence the
// definition of the macro). Also note that it expects that the message buffer
// "message" is declared in the compilation unit.
#define MESSAGE_SIZE (256)
#define MESSAGE_SIZE (512)
#define FORMAT_MESSAGE(message) \
{ \
......@@ -262,7 +133,7 @@ Logger::debug(int dbglevel, isc::log::MessageID ident, ...) {
if (isDebugEnabled(dbglevel)) {
char message[MESSAGE_SIZE];
FORMAT_MESSAGE(message);
LOG4CXX_DEBUG(getLogger(), ident << ", " << message);
loggerptr_->debug(ident, message);
}
}
......@@ -271,7 +142,7 @@ Logger::info(isc::log::MessageID ident, ...) {
if (isInfoEnabled()) {
char message[MESSAGE_SIZE];
FORMAT_MESSAGE(message);
LOG4CXX_INFO(getLogger(), ident << ", " << message);
loggerptr_->info(ident, message);
}
}
......@@ -280,7 +151,7 @@ Logger::warn(isc::log::MessageID ident, ...) {
if (isWarnEnabled()) {
char message[MESSAGE_SIZE];
FORMAT_MESSAGE(message);
LOG4CXX_WARN(getLogger(), ident << ", " << message);
loggerptr_->warn(ident, message);
}
}
......@@ -289,7 +160,7 @@ Logger::error(isc::log::MessageID ident, ...) {
if (isErrorEnabled()) {
char message[MESSAGE_SIZE];
FORMAT_MESSAGE(message);
LOG4CXX_ERROR(getLogger(), ident << ", " << message);
loggerptr_->error(ident, message);
}
}
......@@ -298,10 +169,20 @@ Logger::fatal(isc::log::MessageID ident, ...) {
if (isFatalEnabled()) {
char message[MESSAGE_SIZE];
FORMAT_MESSAGE(message);
LOG4CXX_FATAL(getLogger(), ident << ", " << message);
loggerptr_->fatal(ident, message);
}
}
// Protected methods (used for testing)
bool Logger::operator==(const Logger& other) {
return (*loggerptr_ == *other.loggerptr_);
}
bool Logger::isInitialized() {
return loggerptr_->isInitialized();
}
} // namespace log
} // namespace isc
......@@ -19,29 +19,37 @@
#include <cstdlib>
#include <string>
#include <boost/lexical_cast.hpp>
#include <log4cxx/logger.h>
#include <log/dbglevels.h>
#include <log/logger_levels.h>
#include <log/message_types.h>
namespace isc {
namespace log {
/// \brief Logging API
///
/// This module forms the interface into the logging subsystem. Features of the
/// system and its implementation are:
///
/// # Multiple logging objects can be created, each given a name; those with the
/// same name share characteristics (like destination, level being logged
/// etc.)
/// # Messages can be logged at severity levels of FATAL, ERROR, WARN, INFO or
/// DEBUG. The DEBUG level has further sub-levels numbered 0 (least
/// informative) to 99 (most informative).
/// # Each logger has a severity level set associated with it. When a message
/// is logged, it is output only if it is logged at a level equal to the
/// logger severity level or greater, e.g. if the logger's severity is WARN,
/// only messages logged at WARN, ERROR or FATAL will be output.
/// # Messages are identified by message identifiers, which are keys into a
/// message dictionary.
class LoggerImpl; // Forward declaration of the implementation class
class Logger {
public:
/// \brief Severity Levels
typedef enum {
DEFAULT, // Default to logging level of parent
DEBUG,
INFO,
WARN,
ERROR,
FATAL,
NONE // Disable logging
} Severity;
/// \brief Constructor
///
/// Creates/attaches to a logger of a specific name.
......@@ -50,64 +58,40 @@ public:
/// this creates an instance of the root logger; otherwise it creates a
/// child of the root logger.
///
/// \param exit_delete This argument is present to get round a bug in
/// log4cxx. If a log4cxx logger is declared outside an execution unit, it
/// is not deleted until the program runs down. At that point all such
/// objects - including internal log4cxx objects - are deleted. However,
/// there seems to be a bug in log4cxx where the way that such objects are
/// destroyed causes a MutexException to be thrown (this is described in
/// \param infunc This argument is present to get round a bug in some
/// implementations of the logging system. If the logger is declared in
/// a function (such that it will be deleted when the function exits,
/// before the program ends), set this true. If declared outside a
/// function (such that it gets deleted during program rundown), set false
/// (the default).\n
/// \n
/// The problems encountered was that during program rundown, one logging
/// implementation (log4cxx) threw a MutexException (this is described in
/// https://issues.apache.org/jira/browse/LOGCXX-322). As this only occurs
/// during program rundown, the issue is not serious - it just looks bad to
/// have the program crash instead of shut down cleanly.\n
/// \n
/// The original implementation of the isc::log::Logger had as a member a
/// log4cxx logger (actually a LoggerPtr). If the isc:: Logger was declared
/// statically, when it was destroyed at the end of the program the internal
/// LoggerPtr was destroyed, which triggered the problem. The problem did
/// not occur if the isc::log::Logger was created on the stack. To get
/// round this, the internal LoggerPtr is now created dynamically. The
/// exit_delete argument controls its destruction: if true, it is destroyed
/// in the ISC Logger destructor. If false, it is not.\n
/// If log4cxx is chosen as the implementation, this flag controls the
/// deletion of the underlying log4cxx data structures when the logger is
/// deleted. Setting it false for externally-declared loggers inhibits
/// their deletion; so at program exit the memory is not reclaimed during
/// program rundown, only when the process is delected. Setting it true
/// for loggers that will be deleted in the normal running of the program
/// enables their deletion - which causes no issues as the problem only
/// manifests itself during program rundown.
/// \n
/// When creating an isc::log::Logger on the stack, the argument should be
/// false (the default); when the Logger is destroyed, all the internal
/// log4cxx objects are destroyed. As only the logger (and not the internal
/// log4cxx data structures are being destroyed), all is well. However,
/// when creating the logger statically, the argument should be false. This
/// means that the log4cxx objects are not destroyed at program rundown;
/// instead memory is reclaimed and files are closed when the process is
/// destroyed, something that does not trigger the bug.
Logger(const std::string& name, bool exit_delete = false) :
loggerptr_(), name_(name), exit_delete_(exit_delete)
{}
/// The falg has no effect on non-log4cxx implementations.
Logger(const std::string& name, bool infunc = false);
/// \brief Destructor
virtual ~Logger();
/// \brief Configure Options
///
/// TEMPORARY: Pass in the command-line options to set the logging severity
/// for the root logger. Future versions of the logger will get this
/// information from the configuration database.
///
/// \param severity Severity level to log
/// \param dbglevel If the severity is DEBUG, this is the debug level.
/// This can be in the range 1 to 100 and controls the verbosity. A value
/// outside these limits is silently coerced to the nearest boundary.
/// \param local_file If provided, the name of a message file to read in and
/// supersede one or more of the current messages.
static void runTimeInit(Severity severity = INFO, int dbglevel = 1,
const char* local_file = NULL);
/// \brief Get Name of Logger
///
/// \return The full name of the logger (including the root name)
virtual std::string getName() {
return getLogger()->getName();
}
virtual std::string getName();
/// \brief Set Severity Level for Logger
......@@ -119,25 +103,22 @@ public:
/// \param dbglevel If the severity is DEBUG, this is the debug level.
/// This can be in the range 1 to 100 and controls the verbosity. A value
/// outside these limits is silently coerced to the nearest boundary.
virtual void setSeverity(Severity severity, int dbglevel = 1);
virtual void setSeverity(isc::log::Severity severity, int dbglevel = 1);
/// \brief Get Severity Level for Logger
///
/// \return The current logging level of this logger. In most cases though,
/// the effective logging level is what is required.
virtual Severity getSeverity() {
return getSeverityCommon(getLogger(), false);
}
virtual isc::log::Severity getSeverity();
/// \brief Get Effective Severity Level for Logger
///
/// \return The effective severity level of the logger. This is the same
/// as getSeverity() if the logger has a severity level set, but otherwise
/// is the severity of the parent.
virtual Severity getEffectiveSeverity() {
return getSeverityCommon(getLogger(), true);
}
virtual isc::log::Severity getEffectiveSeverity();
/// \brief Return DEBUG Level
......@@ -152,35 +133,23 @@ public:
/// \param dbglevel Level for which debugging is checked. Debugging is
/// enabled only if the logger has DEBUG enabled and if the dbglevel
/// checked is less than or equal to the debug level set for the logger.
virtual bool
isDebugEnabled(int dbglevel = MIN_DEBUG_LEVEL) {
return (getLogger()->getEffectiveLevel()->toInt() <=
(log4cxx::Level::DEBUG_INT - dbglevel));
}
virtual bool isDebugEnabled(int dbglevel = MIN_DEBUG_LEVEL);
/// \brief Is INFO Enabled?
virtual bool isInfoEnabled() {
return (getLogger()->isInfoEnabled());
}
virtual bool isInfoEnabled();
/// \brief Is WARNING Enabled?
virtual bool isWarnEnabled() {
return (getLogger()->isWarnEnabled());
}
virtual bool isWarnEnabled();
/// \brief Is ERROR Enabled?
virtual bool isErrorEnabled() {
return (getLogger()->isErrorEnabled());
}
virtual bool isErrorEnabled();
/// \brief Is FATAL Enabled?
virtual bool isFatalEnabled() {
return (getLogger()->isFatalEnabled());
}
virtual bool isFatalEnabled();
/// \brief Output Debug Message
......@@ -219,7 +188,6 @@ public:
/// \param ... Optional arguments for the message.
void fatal(MessageID ident, ...);
protected:
/// \brief Equality
......@@ -228,96 +196,19 @@ protected:
/// (This method is principally for testing.)
///
/// \return true if the logger objects are instances of the same logger.
bool operator==(const Logger& other) const {
return (*loggerptr_ == *other.loggerptr_);
}
bool operator==(const Logger& other);
/// \brief Logger Initialized
///
/// Check that the logger has been properly initialized. (This method
/// is principally for testing.)
///
/// \return true if this logger object has been initialized.
bool isInitialized() const {
return (loggerptr_ != NULL);
}
/// \brief Get Severity Level for Logger
///
/// This is common code for getSeverity() and getEffectiveSeverity() -
/// it returns the severity of the logger; if not set (and the check_parent)
/// flag is set, it searches up the parent-child tree until a severity
/// level is found and uses that.
///
/// \param ptrlogger Pointer to the log4cxx logger to check.
/// \param check_parent true to search up the tree, false to return the
/// current level.
///
/// \return The effective severity level of the logger. This is the same
/// as getSeverity() if the logger has a severity level set, but otherwise
/// is the severity of the parent.
Logger::Severity getSeverityCommon(const log4cxx::LoggerPtr& ptrlogger,
bool check_parent) const;
/// \brief Convert Between BIND-10 and log4cxx Logging Levels
///
/// Converts between the numeric value of the log4cxx logging level
/// and the BIND-10 severity level.
///
/// \param value log4cxx numeric logging level
///
/// \return BIND-10 logging severity
Severity convertLevel(int value) const;
/// \brief Initialize log4cxx Logger
///
/// Creates the log4cxx logger used internally. A function is provided for
/// this so that the creation does not take place when this Logger object
/// is created but when it is used. As the latter occurs in executable
/// code but the former can occur during initialization, this order
/// guarantees that anything that is statically initialized has completed
/// its initialization by the time the logger is used.
void initLogger();
/// \brief Return log4cxx Logger
///
/// Returns the log4cxx logger, initializing it if not already initialized.
///
/// \return Loggerptr object
log4cxx::LoggerPtr& getLogger() {
if (loggerptr_ == NULL) {
initLogger();
}
return *loggerptr_;