2
0
mirror of https://gitlab.isc.org/isc-projects/kea synced 2025-08-30 13:37:55 +00:00

[2445] Address the smaller points in the review

This commit is contained in:
Jelte Jansen 2012-12-05 21:15:19 +01:00
parent dd2d08d8cb
commit f1f6c26aa9
10 changed files with 126 additions and 42 deletions

View File

@ -368,7 +368,9 @@ specification is processed (even an empty one), the buffered log messages will
be flushed according to the specification. Note that if this option is used, be flushed according to the specification. Note that if this option is used,
the program SHOULD call one of the LoggerManager's process() calls. If the the program SHOULD call one of the LoggerManager's process() calls. If the
program exits before this is done, all log messages are dumped in a shortened program exits before this is done, all log messages are dumped in a shortened
format to stdout (so that no messages get lost). format to stdout (so that no messages get lost). If you are using the built-in
logging configuration handling in ModuleCCSession, this is automatically
handled.
Variant #2, Used by Unit Tests Variant #2, Used by Unit Tests
------------------------------ ------------------------------

View File

@ -15,6 +15,7 @@
#include <log/log_buffer.h> #include <log/log_buffer.h>
#include <log4cplus/loglevel.h> #include <log4cplus/loglevel.h>
#include <boost/scoped_ptr.hpp>
namespace isc { namespace isc {
namespace log { namespace log {
@ -26,17 +27,17 @@ LogBuffer& getLogBuffer() {
return (*log_buffer); return (*log_buffer);
} }
LogBuffer::LogBuffer() {
flushed_ = false;
}
LogBuffer::~LogBuffer() { LogBuffer::~LogBuffer() {
// If there is anything left in the buffer, // If there is anything left in the buffer,
// it means no reconfig has been done, and // it means no reconfig has been done, and
// we can assume the logging system was either // we can assume the logging system was either
// never setup, or broke while doing so. // never setup, or broke while doing so.
// So dump all that is left to stdout // So dump all that is left to stdout
flush_stdout(); try {
flushStdout();
} catch (...) {
// Ok if we can't even seem to dump to stdout, never mind.
}
} }
void void
@ -45,11 +46,16 @@ LogBuffer::add(const log4cplus::spi::InternalLoggingEvent& event) {
isc_throw(LogBufferAddAfterFlush, isc_throw(LogBufferAddAfterFlush,
"Internal log buffer has been flushed already"); "Internal log buffer has been flushed already");
} }
stored_.push_back(log4cplus::spi::InternalLoggingEvent(event)); // get a clone, and put the pointer in a shared_pt
std::auto_ptr<log4cplus::spi::InternalLoggingEvent> event_aptr =
event.clone();
boost::shared_ptr<log4cplus::spi::InternalLoggingEvent> event_sptr(
event_aptr.release());
stored_.push_back(event_sptr);
} }
void void
LogBuffer::flush_stdout() { LogBuffer::flushStdout() {
// This does not show a bit of information normal log messages // This does not show a bit of information normal log messages
// do, so perhaps we should try and setup a new logger here // do, so perhaps we should try and setup a new logger here
// However, as this is called from a destructor, it may not // However, as this is called from a destructor, it may not
@ -58,30 +64,35 @@ LogBuffer::flush_stdout() {
// settings were). // settings were).
// So we print a slightly shortened format (it really only excludes // So we print a slightly shortened format (it really only excludes
// the time and the pid) // the time and the pid)
std::vector<log4cplus::spi::InternalLoggingEvent>::const_iterator it; LoggerEventPtrList::const_iterator it;
const log4cplus::LogLevelManager& manager = const log4cplus::LogLevelManager& manager =
log4cplus::getLogLevelManager(); log4cplus::getLogLevelManager();
for (it = stored_.begin(); it != stored_.end(); ++it) { for (it = stored_.begin(); it != stored_.end(); ++it) {
std::cout << manager.toString(it->getLogLevel()) << " " << std::cout << manager.toString((*it)->getLogLevel()) << " " <<
"[" << it->getLoggerName() << "] " << "[" << (*it)->getLoggerName() << "] " <<
it->getMessage() << std::endl; (*it)->getMessage() << std::endl;
} }
stored_.clear(); stored_.clear();
} }
void void
LogBuffer::flush() { LogBuffer::flush() {
for (size_t i = 0; i < stored_.size(); ++i) { LoggerEventPtrList::const_iterator it;
const log4cplus::spi::InternalLoggingEvent event(stored_.at(i)); for (it = stored_.begin(); it != stored_.end(); ++it) {
log4cplus::Logger logger = log4cplus::Logger logger =
log4cplus::Logger::getInstance(event.getLoggerName()); log4cplus::Logger::getInstance((*it)->getLoggerName());
logger.log(event.getLogLevel(), event.getMessage()); logger.log((*it)->getLogLevel(), (*it)->getMessage());
} }
stored_.clear(); stored_.clear();
flushed_ = true; flushed_ = true;
} }
size_t
LogBuffer::getBufferSize() const {
return (stored_.size());
}
void void
BufferAppender::append(const log4cplus::spi::InternalLoggingEvent& event) { BufferAppender::append(const log4cplus::spi::InternalLoggingEvent& event) {
buffer_.add(event); buffer_.add(event);

View File

@ -19,7 +19,7 @@
#include <log4cplus/logger.h> #include <log4cplus/logger.h>
#include <log4cplus/spi/loggingevent.h> #include <log4cplus/spi/loggingevent.h>
#include <boost/scoped_ptr.hpp> #include <boost/shared_ptr.hpp>
namespace isc { namespace isc {
namespace log { namespace log {
@ -37,6 +37,10 @@ public:
{} {}
}; };
/// Convenience typedef for a list of logger events
typedef std::vector<boost::shared_ptr<log4cplus::spi::InternalLoggingEvent> >
LoggerEventPtrList;
/// \brief Buffering class for logging event /// \brief Buffering class for logging event
/// ///
/// This class is used to store logging events; it simply keeps any /// This class is used to store logging events; it simply keeps any
@ -58,13 +62,12 @@ public:
/// If the LogBuffer instance is destroyed before being flushed, it will /// If the LogBuffer instance is destroyed before being flushed, it will
/// dump any event it has left to stdout. /// dump any event it has left to stdout.
class LogBuffer { class LogBuffer {
// For testing purposes, we make this a friend class, so that
// it can inspect the stored_ vector
friend class LogBufferTest;
public: public:
LogBuffer(); LogBuffer() : flushed_(false) {};
~LogBuffer(); ~LogBuffer();
/// \brief add the given event to the list of stored events /// \brief add the given event to the list of stored events
/// ///
/// This is called by the BufferAppender. /// This is called by the BufferAppender.
@ -73,10 +76,27 @@ public:
/// \exception LogBufferAddAfterFlush if this method is called /// \exception LogBufferAddAfterFlush if this method is called
/// when \c flush() has been called previously /// when \c flush() has been called previously
void add(const log4cplus::spi::InternalLoggingEvent& event); void add(const log4cplus::spi::InternalLoggingEvent& event);
/// \brief Flush all stored events to their loggers
///
/// All events are replayed to their loggers (which should have
/// other appenders when this is called.
/// Once this method has been called, no more events can be
/// added trough calls to \c add(); if \c add() is called after flush(),
/// an exception will be raised.
void flush(); void flush();
/// \brief Returns number of stored events
///
/// Mostly for testing purposes
size_t getBufferSize() const;
private: private:
void flush_stdout(); /// \brief Simplified flush() to stdout
std::vector<log4cplus::spi::InternalLoggingEvent> stored_; ///
/// Used in the desctructor; all remainging stored events are
/// printed to stdout, in case flush() was never called.
void flushStdout();
LoggerEventPtrList stored_;
bool flushed_; bool flushed_;
}; };
@ -97,6 +117,7 @@ public:
/// that can be reached using \c getLogBuffer() /// that can be reached using \c getLogBuffer()
BufferAppender(LogBuffer& buffer) : buffer_(buffer) {} BufferAppender(LogBuffer& buffer) : buffer_(buffer) {}
virtual void close() {} virtual void close() {}
protected:
virtual void append(const log4cplus::spi::InternalLoggingEvent& event); virtual void append(const log4cplus::spi::InternalLoggingEvent& event);
private: private:
LogBuffer& buffer_; LogBuffer& buffer_;

View File

@ -32,8 +32,6 @@
#include <log/logger_specification.h> #include <log/logger_specification.h>
#include <log/log_buffer.h> #include <log/log_buffer.h>
#include <boost/scoped_ptr.hpp>
using namespace std; using namespace std;
namespace isc { namespace isc {

View File

@ -142,7 +142,6 @@ private:
/// flushed (which is done at the end of \c ProcessSpecification(). /// flushed (which is done at the end of \c ProcessSpecification().
/// ///
/// \param logger Log4cplus logger to which the appender must be attached. /// \param logger Log4cplus logger to which the appender must be attached.
/// \param opt Output options for this appender.
static void createBufferAppender(log4cplus::Logger& logger); static void createBufferAppender(log4cplus::Logger& logger);
/// \brief Set default layout and severity for root logger /// \brief Set default layout and severity for root logger

View File

@ -20,9 +20,11 @@
using namespace isc::log; using namespace isc::log;
namespace {
void usage() { void usage() {
std::cout << "Usage: buffer_logger_test [-n]" << std::endl; std::cout << "Usage: buffer_logger_test [-n]" << std::endl;
} }
} // end unnamed namespace
/// \brief Test InitLogger /// \brief Test InitLogger
/// ///

View File

@ -23,6 +23,7 @@
#include <log4cplus/loggingmacros.h> #include <log4cplus/loggingmacros.h>
#include <log4cplus/logger.h> #include <log4cplus/logger.h>
#include <log4cplus/nullappender.h> #include <log4cplus/nullappender.h>
#include <log4cplus/spi/loggingevent.h>
using namespace isc::log; using namespace isc::log;
@ -41,6 +42,10 @@ protected:
~LogBufferTest() { ~LogBufferTest() {
// If any log messages are left, we don't care, get rid of them, // If any log messages are left, we don't care, get rid of them,
// by flushing them to a null appender // by flushing them to a null appender
// Given the 'messages should not get lost' approach of the logging
// system, not flushing them to a null appender would cause them
// to be dumped to stdout as the test is destroyed, making
// unnecessarily messy test output.
log4cplus::SharedAppenderPtr null_appender( log4cplus::SharedAppenderPtr null_appender(
new log4cplus::NullAppender()); new log4cplus::NullAppender());
logger.removeAllAppenders(); logger.removeAllAppenders();
@ -49,10 +54,6 @@ protected:
buffer2.flush(); buffer2.flush();
} }
void checkBufferedSize(const LogBuffer& buffer, size_t expected) const {
ASSERT_EQ(expected, buffer.stored_.size());
}
LogBuffer buffer1; LogBuffer buffer1;
LogBuffer buffer2; LogBuffer buffer2;
log4cplus::SharedAppenderPtr appender1; log4cplus::SharedAppenderPtr appender1;
@ -63,28 +64,28 @@ protected:
// Test that log events are indeed stored, and that they are // Test that log events are indeed stored, and that they are
// flushed to the new appenders of their logger // flushed to the new appenders of their logger
TEST_F(LogBufferTest, flush) { TEST_F(LogBufferTest, flush) {
checkBufferedSize(buffer1, 0); ASSERT_EQ(0, buffer1.getBufferSize());
checkBufferedSize(buffer2, 0); ASSERT_EQ(0, buffer2.getBufferSize());
// Create a Logger, log a few messages with the first appender // Create a Logger, log a few messages with the first appender
logger.addAppender(appender1); logger.addAppender(appender1);
LOG4CPLUS_INFO(logger, "Foo"); LOG4CPLUS_INFO(logger, "Foo");
checkBufferedSize(buffer1, 1); ASSERT_EQ(1, buffer1.getBufferSize());
LOG4CPLUS_INFO(logger, "Foo"); LOG4CPLUS_INFO(logger, "Foo");
checkBufferedSize(buffer1, 2); ASSERT_EQ(2, buffer1.getBufferSize());
LOG4CPLUS_INFO(logger, "Foo"); LOG4CPLUS_INFO(logger, "Foo");
checkBufferedSize(buffer1, 3); ASSERT_EQ(3, buffer1.getBufferSize());
// Second buffer should still be empty // Second buffer should still be empty
checkBufferedSize(buffer2, 0); ASSERT_EQ(0, buffer2.getBufferSize());
// Replace the appender by the second one, and call flush; // Replace the appender by the second one, and call flush;
// this should cause all events to be moved to the second buffer // this should cause all events to be moved to the second buffer
logger.removeAllAppenders(); logger.removeAllAppenders();
logger.addAppender(appender2); logger.addAppender(appender2);
buffer1.flush(); buffer1.flush();
checkBufferedSize(buffer1, 0); ASSERT_EQ(0, buffer1.getBufferSize());
checkBufferedSize(buffer2, 3); ASSERT_EQ(3, buffer2.getBufferSize());
} }
// Once flushed, logging new messages with the same buffer should fail // Once flushed, logging new messages with the same buffer should fail
@ -93,13 +94,38 @@ TEST_F(LogBufferTest, addAfterFlush) {
buffer1.flush(); buffer1.flush();
EXPECT_THROW(LOG4CPLUS_INFO(logger, "Foo"), LogBufferAddAfterFlush); EXPECT_THROW(LOG4CPLUS_INFO(logger, "Foo"), LogBufferAddAfterFlush);
// It should not have been added // It should not have been added
checkBufferedSize(buffer1, 0); ASSERT_EQ(0, buffer1.getBufferSize());
// But logging should work again as long as a different buffer is used // But logging should work again as long as a different buffer is used
logger.removeAllAppenders(); logger.removeAllAppenders();
logger.addAppender(appender2); logger.addAppender(appender2);
LOG4CPLUS_INFO(logger, "Foo"); LOG4CPLUS_INFO(logger, "Foo");
checkBufferedSize(buffer2, 1); ASSERT_EQ(1, buffer2.getBufferSize());
}
TEST_F(LogBufferTest, addDirectly) {
// A few direct calls
log4cplus::spi::InternalLoggingEvent event("buffer",
log4cplus::INFO_LOG_LEVEL,
"Bar", "file", 123);
buffer1.add(event);
ASSERT_EQ(1, buffer1.getBufferSize());
// Do one from a smaller scope to make sure destruction doesn't harm
{
log4cplus::spi::InternalLoggingEvent event2("buffer",
log4cplus::INFO_LOG_LEVEL,
"Bar", "file", 123);
buffer1.add(event2);
}
ASSERT_EQ(2, buffer1.getBufferSize());
// And flush them to the next
logger.removeAllAppenders();
logger.addAppender(appender2);
buffer1.flush();
ASSERT_EQ(0, buffer1.getBufferSize());
ASSERT_EQ(2, buffer2.getBufferSize());
} }
} }

View File

@ -224,9 +224,12 @@ class ConfigManager:
def check_logging_config(self, config): def check_logging_config(self, config):
if self.log_module_name in config: if self.log_module_name in config:
# If there is logging config, apply it.
ccsession.default_logconfig_handler(config[self.log_module_name], ccsession.default_logconfig_handler(config[self.log_module_name],
self.log_config_data) self.log_config_data)
else: else:
# If there is no logging config, we still need to trigger the
# handler, so make it use defaults (and flush any buffered logs)
ccsession.default_logconfig_handler({}, self.log_config_data) ccsession.default_logconfig_handler({}, self.log_config_data)
def notify_boss(self): def notify_boss(self):

View File

@ -278,13 +278,13 @@ PyMethodDef methods[] = {
"Arguments:\n" "Arguments:\n"
"name: root logger name\n" "name: root logger name\n"
"severity (optional): one of 'DEBUG', 'INFO', 'WARN', 'ERROR' or " "severity (optional): one of 'DEBUG', 'INFO', 'WARN', 'ERROR' or "
"'FATAL')\n" "'FATAL'\n"
"debuglevel (optional): a debug level (integer in the range 0-99) " "debuglevel (optional): a debug level (integer in the range 0-99) "
"file (optional): a file name of a dictionary with message text " "file (optional): a file name of a dictionary with message text "
"translations\n" "translations\n"
"buffer (optional), boolean, when True, causes all log messages " "buffer (optional), boolean, when True, causes all log messages "
"to be stored internally until log_config_update is called, at " "to be stored internally until log_config_update is called, at "
"which pointed they shall be logged."}, "which point they shall be logged."},
{"resetUnitTestRootLogger", resetUnitTestRootLogger, METH_VARARGS, {"resetUnitTestRootLogger", resetUnitTestRootLogger, METH_VARARGS,
"Resets the configuration of the root logger to that set by the " "Resets the configuration of the root logger to that set by the "
"B10_XXX environment variables. It is aimed at unit tests, where " "B10_XXX environment variables. It is aimed at unit tests, where "

View File

@ -56,6 +56,28 @@ class Manager(unittest.TestCase):
# ignore errors like missing file? # ignore errors like missing file?
isc.log.init("root", "INFO", 0, "/no/such/file"); isc.log.init("root", "INFO", 0, "/no/such/file");
def test_init_keywords(self):
isc.log.init(name="root", severity="DEBUG", debuglevel=50, file=None,
buffer=True)
# unknown keyword
self.assertRaises(TypeError, isc.log.init, name="root", foo="bar")
# Replace the values for each keyword by a wrong type, one by one
self.assertRaises(TypeError, isc.log.init, name=1,
severity="DEBUG", debuglevel=50, file=None,
buffer=True)
self.assertRaises(TypeError, isc.log.init, name="root",
severity=2, debuglevel=50, file=None,
buffer=True)
self.assertRaises(TypeError, isc.log.init, name="root",
severity="DEBUG", debuglevel="50", file=None,
buffer=True)
self.assertRaises(TypeError, isc.log.init, name="root",
severity="DEBUG", debuglevel=50, file=1,
buffer=True)
self.assertRaises(TypeError, isc.log.init, name="root",
severity="DEBUG", debuglevel=50, file=None,
buffer=None)
def test_log_config_update(self): def test_log_config_update(self):
log_spec = json.dumps(isc.config.module_spec_from_file(path_search('logging.spec', bind10_config.PLUGIN_PATHS)).get_full_spec()) log_spec = json.dumps(isc.config.module_spec_from_file(path_search('logging.spec', bind10_config.PLUGIN_PATHS)).get_full_spec())