Commit 3666c6d7 authored by Stephen Morris's avatar Stephen Morris

Initial version of logging module.

First cut at the logging module.  Still lacking configuration and
basic appenders.
parent ebb344c1
......@@ -334,10 +334,13 @@ AC_SUBST(USE_LCOV)
AC_ARG_WITH([log4cxx],
AC_HELP_STRING([--with-log4cxx=PATH],
[specify directory where log4cxx is installed]),
[log4cxx_include_path="${withval}/include"])
[
log4cxx_include_path="${withval}/include";
log4cxx_lib_path="${$withval}/lib"
])
# If not specified, try some common paths. These default to
# /usr/include if not found
# /usr/include and /usr/lib if not found
if test -z "$with_log4cxx"; then
log4cxxdirs="/usr/local /usr/pkg /opt /opt/local"
......@@ -345,6 +348,7 @@ if test -z "$with_log4cxx"; then
do
if test -d $d/include/log4cxx; then
log4cxx_include_path=$d/include
log4cxx_library_path=$d/lib
break
fi
done
......@@ -359,6 +363,13 @@ 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
......@@ -645,6 +656,7 @@ AC_CONFIG_FILES([Makefile
src/lib/datasrc/tests/Makefile
src/lib/xfr/Makefile
src/lib/log/Makefile
src/lib/log/compiler/Makefile
src/lib/log/tests/Makefile
src/lib/testutils/Makefile
src/lib/testutils/testdata/Makefile
......@@ -756,6 +768,7 @@ dnl includes too
${PYTHON_LIB}
Boost: ${BOOST_INCLUDES}
log4cxx: ${LOG4CXX_INCLUDES}
${LOG4CXX_LDFLAGS}
SQLite: $SQLITE_CFLAGS
$SQLITE_LIBS
......
......@@ -21,7 +21,7 @@ run_unittests_SOURCES += asiolink_unittest.cc
run_unittests_SOURCES += udpdns_unittest.cc
run_unittests_SOURCES += run_unittests.cc
run_unittests_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES)
run_unittests_LDFLAGS = $(AM_LDFLAGS) $(GTEST_LDFLAGS)
run_unittests_LDFLAGS = $(AM_LDFLAGS) $(GTEST_LDFLAGS) $(LOG4CXX_LDFLAGS)
run_unittests_LDADD = $(GTEST_LDADD)
run_unittests_LDADD += $(SQLITE_LIBS)
run_unittests_LDADD += $(top_builddir)/src/lib/dns/libdns++.la
......
SUBDIRS = . tests
SUBDIRS = . compiler tests
AM_CPPFLAGS = -I$(top_builddir)/src/lib -I$(top_srcdir)/src/lib
AM_CPPFLAGS += $(BOOST_INCLUDES)
......@@ -7,12 +7,20 @@ AM_CPPFLAGS += -I$(top_srcdir)/src/lib/log -I$(top_builddir)/src/lib/log
CLEANFILES = *.gcno *.gcda
lib_LTLIBRARIES = liblog.la
liblog_la_SOURCES = root_logger_name.cc root_logger_name.h
liblog_la_SOURCES += xdebuglevel.cc xdebuglevel.h
liblog_la_SOURCES =
liblog_la_SOURCES += dbglevels.h
liblog_la_SOURCES += dummylog.h dummylog.cc Message.h
liblog_la_SOURCES += filename.h filename.cc
liblog_la_SOURCES += logger.cc logger.h
liblog_la_SOURCES += messagedef.cc messagedef.h
liblog_la_SOURCES += message_dictionary.cc message_dictionary.h
liblog_la_SOURCES += message_exception.h message_exception.cc
liblog_la_SOURCES += message_initializer.cc message_initializer.h
liblog_la_SOURCES += message_reader.cc message_reader.h
liblog_la_SOURCES += filename.h filename.cc
liblog_la_SOURCES += stringutil.h stringutil.cc
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
# Note: the ordering matters: -Wno-... must follow -Wextra (defined in
# B10_CXXFLAGS)
......
Logging Messages
This directory holds the first release of the logging system.
The steps in using the system are:
1. Create a message file. Ideally it should have a file type of ".msg".
2. Run it through the message compiler to produce the .h and .cc files.
3. Include the .h file in your source code to define message symbols. Also
include the file logger.h to create loggers and to log error messages.
The ".cc" file needs to be linked into the program - static initialization
will add the symbols to the global dictionary.
Outstanding
===========
* Ability to configure system according to configuration database.
* Writing of suitable appenders and formatters.
* Ability to override message via a run-time file.
* 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.)
Message Storage
===============
......@@ -10,14 +29,17 @@ The message identifier (along with parameters) is passed through the logging
system to an appender, which uses the identifier to look up the message in
the dictionary. The message is then formatted and written out.
Message File
============
Message Files
=============
1) File Contents and Format
A message file is a file containing message definitions. Typically there will
be one message file for each component that declares message symbols.
A example file could
be:
A example file could be:
-- BEGIN --
# Example message file
# $ID:$
......@@ -29,43 +51,54 @@ TEST1 message %s is much too large
UNKNOWN unknown message
+ Issued when the message is unknown.
-- END --
Point to note:
* Leading and trailing space are trimmed from the line.
* Blank lines are ignored
* Lines starting with "#" are comments are are ignored.
* Lines starting $ are directives. At present, the only directive recognised
is $PREFIX, which has one argument: the string used to prefix symbols. If
there is no facility directive, there is no prefix to the symbols.
there is no facility directive, there is no prefix to the symbols. (Prefixes
are explained below.)
* Lines starting + indicate an explanation for the preceding message. These
are processed by a separate program and used to generate an error messages
manual. However they are treated like comments here.
* Message lines. These comprise a symbol name and a message (which includes
C-style substitution strings).
* Message lines. These comprise a symbol name and a message, which may
include one or more instances of the "%s" the C-style substitution string.
(The logging system only recognises the "%s" string.)
Message Compiler
================
The message compiler produces two files:
2) Message Compiler
The message compiler is a program built in the src/log/compiler directory. It
processes the message file to produce two files:
1) A C++ header file (called <message-file-name>.h) that holds lines of the
form:
namespace {
const char* PREFIX_IDENTIFIER = "identifier";
isc::log::MessageID PREFIX_IDENTIFIER = "IDENTIFIER";
:
}
These are just convenience symbols to avoid the need to type in the string in
quotes. PREFIX_ is the string in the $PREFIX directive and is used to avoid
potential clashes with system-defined symbols.
The symbols define the keys in the global message dictionary. At present
they are defined as std::strings, but a future implementation could redefine
them as numeric values.
The "PREFIX_" part of the symbol name is the string defined in the $PREFIX
the argument to the directive. So "$PREFIX MSG_" would prefix the identifer
ABC with "MSG_" to give the symbol MSG_ABC. Similarly "$PREFIX E" would
prefix it with "E" to give the symbol EABC.
2) A C++ source file (called <message-file-name>.cpp) that holds the code
to insert the symbols and messages into the map.
2) A C++ source file (called <message-file-name>.cpp) that holds the code to
insert the symbols and messages into the map.
This file declares an array of identifiers/messages in the form:
namespace {
const char* messages = {
const char* values[] = {
identifier1, text1,
identifier2, text2,
:
......@@ -79,41 +112,42 @@ it is not needed.)
It then declares an object that will add information to the global dictionary:
DictionaryAppender <message-file-name>_<prefix>_<time>(messages);
MessageInitializer <message-file-name>_<time>(values);
(Declaring the object as "static" or in the anonymous namespace runs the risk
of it being optimised away when the module is compiled with optimisation. But
giving it a standard name would cause a clash when multiple files are used,
hence an attempt at disambiguation.)
The constructor of the DictionaryAppender object retrieves the singleton
global Dictionary object (created using standard methods to avoid the "static
initialization fiasco") and adds each identifier and text to the member
std::map. A check is made as each is added; if the identifier already exists,
it is added to "overflow" vector; the vector is printed to the main logging
output when logging is finally enabled (to indicate a programming error).
User Message Files
==================
During logging initialization, a search is made for a user message file in a
specific location. (The specification of the location has yet to be decided -
it will probably be a command-line option.) These messages are read into a
local Dictionary object (which performs the same checks as the global
Dictionary for duplicate messages).
The local Dictionary is then merged with the global Dictionary. In this case
though, warnings are issued where a message does not replace one in the global
Dictionary.
An additional check that could be done is to compare the user message string
with the main message string and to check that they have the same number of
"%s" components. This will avoid potential problems in message formatting. (As
noted in another design document, the intention within logging is to convert
all parameters to strings at the point at which the logging call is made.)
Message Compiler Implementation
===============================
The fact that user files are read in at run-time implies that the code that
reads the files should be C++. An implication of this is that the message
compiler should be written in C++ (instead of Python, which is probably
better for the task) to avoid two sets of code where message files are parsed.
The constructor of the MessageInitializer object retrieves the singleton
global Dictionary object (created using standard methods to avoid the
"static initialization fiasco") and adds each identifier and text to it.
A check is made as each is added; if the identifier already exists, it is
added to "overflow" vector; the vector is printed to the main logging output
when logging is finally enabled (to indicate a programming error).
Using the Logging
=================
To use the current version of the logging:
1. Build message header file and source file as describe above.
2. In the code that needs to do logging, declare a logger with a given name,
e.g.
#include <log/logger.h>
:
isc::log::Logger logger("myname"); // "myname" can be anything
3. Issue logging calls using methods on logger, e.g.
logger.error(DPS_NSTIMEOUT, "isc.org");
(where, in the example above we might have defined the symbol in the message
file with something along the lines of:
$PREFIX DPS_
:
NSTIMEOUT queries to all nameservers for %s have timed out
As noted above, presently the only logging is to the console using the default
log4cxx format (which is somewhat awkward to read).
SUBDIRS = .
AM_CPPFLAGS = -I$(top_srcdir)/src/lib -I$(top_builddir)/src/lib
AM_CPPFLAGS += -I$(top_srcdir)/src/lib/log -I$(top_builddir)/src/lib/log
AM_CPPFLAGS += $(BOOST_INCLUDES)
AM_CXXFLAGS = $(B10_CXXFLAGS)
if USE_STATIC_LINK
AM_LDFLAGS = -static
endif
pkglibexecdir = $(libexecdir)/@PACKAGE@
CLEANFILES = *.gcno *.gcda
pkglibexec_PROGRAMS = message
message_SOURCES = message.cc
message_LDADD = $(top_builddir)/src/lib/log/liblog.la
message_LDADD += $(LOG4CXX_LDFLAGS)
......@@ -14,11 +14,29 @@
// $Id$
#include <cctype>
#include <fstream>
#include <iostream>
#include <unistd.h>
#include <string>
#include <vector>
#include <errno.h>
#include <getopt.h>
#include <string.h>
#include <time.h>
#include <unistd.h>
#include <log/filename.h>
#include <log/message_dictionary.h>
#include <log/message_exception.h>
#include <log/message_reader.h>
#include <log/messagedef.h>
#include <log/strutil.h>
#include <log/logger.h>
using namespace std;
using namespace isc::log;
static const char* VERSION = "1.0-0";
......@@ -66,12 +84,292 @@ static void usage() {
"-h Print this message and exit\n" <<
"-p Output a Python module holding the message definitions.\n" <<
" By default a C++ header file and implementation file are\n" <<
" written.\n" <<
"-v Print the program version and exit\n" <<
"\n" <<
"<message-file> is the name of the input message file.\n";
}
/// \brief Create Time
///
/// Returns the current time as a suitably-formatted string.
///
/// \return Current time
static string currentTime() {
// Get the current time.
time_t curtime;
time(&curtime);
// Format it
char buffer[32];
ctime_r(&curtime, buffer);
// Convert to string and strip out the trailing newline
string current_time = buffer;
return isc::strutil::trim(current_time);
}
/// \brief Create Header Sentinel
///
/// Given the name of a file, create an #ifdef sentinel name. The name is
/// __<name>_<ext>, where <name> is the name of the file, and <ext> is the
/// extension less the leading period. The sentinel will be upper-case.
///
/// \param file Filename object representing the file.
///
/// \return Sentinel name
static string sentinel(Filename& file) {
string name = file.name();
string ext = file.extension();
string sentinel_text = "__" + name + "_" + ext.substr(1);
isc::strutil::uppercase(sentinel_text);
return sentinel_text;
}
/// \brief Quote String
///
/// Inserts an escape character (a backslash) prior to any double quote
/// characters. This is used to handle the fact that the input file does not
/// contain quotes, yet the string will be included in a C++ literal string.
string quoteString(const string& instring) {
// Create the output string and reserve the space needed to hold the input
// string. (Most input strings will not contain quotes, so this single
// reservation should be all that is needed.)
string outstring;
outstring.reserve(instring.size());
// Iterate through the input string, preceding quotes with a slash.
for (size_t i = 0; i < instring.size(); ++i) {
if (instring[i] == '"') {
outstring += '\\';
}
outstring += instring[i];
}
return outstring;
}
/// \brief Sorted Identifiers
///
/// Given a dictionary, return a vector holding the message IDs in sorted
/// order.
///
/// \param dictionary Dictionary to examine
///
/// \return Sorted list of message IDs
vector<MessageID> sortedIdentifiers(MessageDictionary* dictionary) {
vector<MessageID> ident;
for (MessageDictionary::const_iterator i = dictionary->begin();
i != dictionary->end(); ++i) {
ident.push_back(i->first);
}
sort(ident.begin(), ident.end());
return ident;
}
/// \brief Write Header File
///
/// Writes the C++ header file containing the symbol definitions.
///
/// \param file Name of the message file. The header file is written to a
/// file of the same name but with a .h suffix.
/// \param prefix Prefix string to use in symbols
/// \param dictionary Dictionary holding the message definitions.
void writeHeaderFile(const string& file, const string& prefix,
MessageDictionary* dictionary)
{
Filename message_file(file);
Filename header_file(message_file.useAsDefault(".h"));
// Text to use as the sentinels.
string sentinel_text = sentinel(header_file);
// Open the output file for writing
ofstream hfile(header_file.fullName().c_str());
try {
if (hfile.fail()) {
throw MessageException(MSG_OPENOUT, header_file.fullName(),
strerror(errno));
}
// Write the header preamble. If there is an error, we'll pick it up
// after the last write.
hfile <<
"// File created from " << message_file.fullName() << " on " <<
currentTime() << "\n" <<
"\n" <<
"#ifndef " << sentinel_text << "\n" <<
"#define " << sentinel_text << "\n" <<
"\n" <<
"#include <log/message_types.h>\n" <<
"\n" <<
"namespace {\n" <<
"\n";
vector<MessageID> idents = sortedIdentifiers(dictionary);
for (vector<MessageID>::const_iterator j = idents.begin();
j != idents.end(); ++j) {
hfile << "isc::log::MessageID " << prefix << *j <<
" = \"" << *j << "\";\n";
}
// ... and finally the postamble
hfile <<
"\n" <<
"} // Anonymous namespace\n" <<
"\n" <<
"#endif // " << sentinel_text;
// Report errors (if any) and exit
if (hfile.fail()) {
throw MessageException(MSG_WRITERR, header_file.fullName(),
strerror(errno));
}
hfile.close();
}
catch (MessageException&) {
hfile.close();
throw;
}
}
/// \brief Convert Non Alpha-Numeric Characters to Underscores
///
/// Simple function for use in a call to transform
char replaceNonAlphaNum(char c) {
return (isalnum(c) ? c : '_');
}
/// \brief Write Program File
///
/// Writes the C++ source code file. This defines an external objects whose
/// constructor is run at initialization time. The constructor adds the message
/// definitions to the main global dictionary.
void writeProgramFile(const string& file, MessageDictionary* dictionary)
{
Filename message_file(file);
Filename program_file(message_file.useAsDefault(".cc"));
// Open the output file for writing
ofstream ccfile(program_file.fullName().c_str());
try {
if (ccfile.fail()) {
throw MessageException(MSG_OPENOUT, program_file.fullName(),
strerror(errno));
}
// Write the preamble. If there is an error, we'll pick it up after
// the last write.
ccfile <<
"// File created from " << message_file.fullName() << " on " <<
currentTime() << "\n" <<
"\n" <<
"#include <cstddef>\n" <<
"#include <log/message_initializer.h>\n" <<
"\n" <<
"using namespace isc::log;\n" <<
"\n" <<
"namespace {\n" <<
"\n" <<
"const char* values[] = {\n";
// Output the identifiers and the associated text.
vector<MessageID> idents = sortedIdentifiers(dictionary);
for (vector<MessageID>::const_iterator i = idents.begin();
i != idents.end(); ++i) {
ccfile << " \"" << *i << "\", \"" <<
quoteString(dictionary->getText(*i)) << "\",\n";
}
// ... and the postamble
ccfile <<
" NULL\n" <<
"};\n" <<
"\n" <<
"} // Anonymous namespace\n" <<
"\n";
// Now construct a unique name. We don't put the message initializer as
// a static variable or in an anonymous namespace lest the C++
// compiler's optimizer decides it can optimise it away.
string unique_name = program_file.name() + program_file.extension() +
"_" + currentTime();
transform(unique_name.begin(), unique_name.end(), unique_name.begin(),
replaceNonAlphaNum);
// ... and write the initialization code
ccfile <<
"MessageInitializer " << unique_name << "(values);\n";
// Report errors (if any) and exit
if (ccfile.fail()) {
throw MessageException(MSG_WRITERR, program_file.fullName(),
strerror(errno));
}
ccfile.close();
}
catch (MessageException&) {
ccfile.close();
throw;
}
}
/// \brief Warn of Duplicate Entries
///
/// If the input file contained duplicate message IDs, only the first will be
/// processed. However, we should warn about it.
///
/// \param dictionary Dictionary containing the message IDs and text.
static void warnDuplicates(MessageDictionary* dictionary) {
// Get the duplicates (the overflow) and, if present, sort them into some
// order and remove those which occur more than once (which mean that they
// occur more than twice in the input file).
vector<MessageID> duplicates = dictionary->getOverflow();
if (duplicates.size() > 0) {
cout << "Warning: the following duplicate IDs were found:\n";
sort(duplicates.begin(), duplicates.end());
vector<MessageID>::iterator new_end =
unique(duplicates.begin(), duplicates.end());
for (vector<MessageID>::iterator i = duplicates.begin();
i != new_end; ++i) {
cout << " " << *i << "\n";
}
}
}
/// \brief Main Program
///
/// Parses the options then dispatches to the appropriate function. See the
......@@ -113,18 +411,46 @@ int main(int argc, char** argv) {
// Do we have the message file?
if (optind < (argc - 1)) {
std::cout << "Error: excess arguments in command line\n";
cout << "Error: excess arguments in command line\n";
usage();
return 1;
}
else if (optind >= argc) {
std::cout << "Error: missing message file\n";
} else if (optind >= argc) {
cout << "Error: missing message file\n";
usage();
return 1;
}
string message_file = argv[optind];
try {
// Have identified the file, so process it. First create a local
// dictionary into which the data will be put.
MessageDictionary dictionary;
// Read the data into it.
MessageReader reader(&dictionary);
reader.readFile(message_file);
// Now write the header file.
writeHeaderFile(message_file, reader.getPrefix(), &dictionary);