Merge branch 'master' into trac815

ChangeLog

@@ -1,3 +1,18 @@
+232.	[func]      stephen
+	To facilitate the writing of extended descriptions in message files,
+	altered the message file format.  The message is now flagged with a "%"
+	as the first non-blank character in the line and the lines in the
+	extended description are no longer preceded by a "+".
+	(Trac #900, git b395258c708b49a5da8d0cffcb48d83294354ba3)
+
+231.	[func]*
+	The logging interface changed slightly. We use
+	logger.foo(MESSAGE_ID).arg(bar); instead of logger.foo(MESSAGE_ID, bar);
+	internally. The message definitions use '%1,%2,...' instead of '%s,%d',
+	which allows us to cope better with mismatched placeholders and allows
+	reordering of them in case of translation.
+	(Trac901, git 4903410e45670b30d7283f5d69dc28c2069237d6)
+
 230.	[bug]		naokikambe
 	Removed too repeated verbose messages in two cases of:
 	 - when auth sends statistics data to stats

src/lib/asiodns/Makefile.am

@@ -8,12 +8,17 @@ AM_CPPFLAGS += -I$(top_srcdir)/src/lib/util -I$(top_builddir)/src/lib/util
 
 AM_CXXFLAGS = $(B10_CXXFLAGS)
 
-CLEANFILES = *.gcno *.gcda
+CLEANFILES = *.gcno *.gcda asiodef.h asiodef.cc
+
+# Define rule to build logging source files from message file
+asiodef.h asiodef.cc: asiodef.mes
+	$(top_builddir)/src/lib/log/compiler/message $(top_srcdir)/src/lib/asiodns/asiodef.mes
+
+BUILT_SOURCES = asiodef.h asiodef.cc
 
 lib_LTLIBRARIES = libasiodns.la
 libasiodns_la_SOURCES = dns_answer.h
 libasiodns_la_SOURCES += asiodns.h
-libasiodns_la_SOURCES += asiodef.cc asiodef.h
 libasiodns_la_SOURCES += dns_lookup.h
 libasiodns_la_SOURCES += dns_server.h
 libasiodns_la_SOURCES += dns_service.cc dns_service.h
@@ -21,7 +26,9 @@ libasiodns_la_SOURCES += tcp_server.cc tcp_server.h
 libasiodns_la_SOURCES += udp_server.cc udp_server.h
 libasiodns_la_SOURCES += io_fetch.cc io_fetch.h
 
-EXTRA_DIST = asiodef.msg
+nodist_libasiodns_la_SOURCES = asiodef.cc asiodef.h
+
+EXTRA_DIST = asiodef.mes
 
 # Note: the ordering matters: -Wno-... must follow -Wextra (defined in
 # B10_CXXFLAGS)

src/lib/asiodns/asiodef.cc

@@ -1,39 +0,0 @@
-// File created from asiodef.msg on Mon Feb 28 17:15:30 2011
-
-#include <cstddef>
-#include <log/message_types.h>
-#include <log/message_initializer.h>
-
-namespace isc {
-namespace asiodns {
-
-extern const isc::log::MessageID ASIODNS_FETCHCOMP = "FETCHCOMP";
-extern const isc::log::MessageID ASIODNS_FETCHSTOP = "FETCHSTOP";
-extern const isc::log::MessageID ASIODNS_OPENSOCK = "OPENSOCK";
-extern const isc::log::MessageID ASIODNS_RECVSOCK = "RECVSOCK";
-extern const isc::log::MessageID ASIODNS_RECVTMO = "RECVTMO";
-extern const isc::log::MessageID ASIODNS_SENDSOCK = "SENDSOCK";
-extern const isc::log::MessageID ASIODNS_UNKORIGIN = "UNKORIGIN";
-extern const isc::log::MessageID ASIODNS_UNKRESULT = "UNKRESULT";
-
-} // namespace asiodns
-} // namespace isc
-
-namespace {
-
-const char* values[] = {
-    "FETCHCOMP", "upstream fetch to %s(%d) has now completed",
-    "FETCHSTOP", "upstream fetch to %s(%d) has been stopped",
-    "OPENSOCK", "error %d opening %s socket to %s(%d)",
-    "RECVSOCK", "error %d reading %s data from %s(%d)",
-    "RECVTMO", "receive timeout while waiting for data from %s(%d)",
-    "SENDSOCK", "error %d sending data using %s to %s(%d)",
-    "UNKORIGIN", "unknown origin for ASIO error code %d (protocol: %s, address %s)",
-    "UNKRESULT", "unknown result (%d) when IOFetch::stop() was executed for I/O to %s(%d)",
-    NULL
-};
-
-const isc::log::MessageInitializer initializer(values);
-
-} // Anonymous namespace
-

src/lib/asiodns/asiodef.h

@@ -1,23 +0,0 @@
-// File created from asiodef.msg on Mon Feb 28 17:15:30 2011
-
-#ifndef __ASIODEF_H
-#define __ASIODEF_H
-
-#include <log/message_types.h>
-
-namespace isc {
-namespace asiodns {
-
-extern const isc::log::MessageID ASIODNS_FETCHCOMP;
-extern const isc::log::MessageID ASIODNS_FETCHSTOP;
-extern const isc::log::MessageID ASIODNS_OPENSOCK;
-extern const isc::log::MessageID ASIODNS_RECVSOCK;
-extern const isc::log::MessageID ASIODNS_RECVTMO;
-extern const isc::log::MessageID ASIODNS_SENDSOCK;
-extern const isc::log::MessageID ASIODNS_UNKORIGIN;
-extern const isc::log::MessageID ASIODNS_UNKRESULT;
-
-} // namespace asiodns
-} // namespace isc
-
-#endif // __ASIODEF_H

src/lib/asiodns/asiodef.mes

@@ -0,0 +1,56 @@
+# Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+#
+# Permission to use, copy, modify, and/or distribute this software for any
+# purpose with or without fee is hereby granted, provided that the above
+# copyright notice and this permission notice appear in all copies.
+#
+# THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+# REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+# AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+# LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+# OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+# PERFORMANCE OF THIS SOFTWARE.
+
+$PREFIX ASIODNS_
+$NAMESPACE isc::asiodns
+
+% FETCHCOMP   upstream fetch to %1(%2) has now completed
+A debug message, this records the the upstream fetch (a query made by the
+resolver on behalf of its client) to the specified address has completed.
+
+% FETCHSTOP   upstream fetch to %1(%2) has been stopped
+An external component has requested the halting of an upstream fetch.  This
+is an allowed operation, and the message should only appear if debug is
+enabled.
+
+% OPENSOCK    error %1 opening %2 socket to %3(%4)
+The asynchronous I/O code encountered an error when trying to open a socket
+of the specified protocol in order to send a message to the target address.
+The the number of the system error that cause the problem is given in the
+message.
+
+% RECVSOCK    error %1 reading %2 data from %3(%4)
+The asynchronous I/O code encountered an error when trying read data from
+the specified address on the given protocol.  The the number of the system
+error that cause the problem is given in the message.
+
+% SENDSOCK    error %1 sending data using %2 to %3(%4)
+The asynchronous I/O code encountered an error when trying send data to
+the specified address on the given protocol.  The the number of the system
+error that cause the problem is given in the message.
+
+% RECVTMO     receive timeout while waiting for data from %1(%2)
+An upstream fetch from the specified address timed out.  This may happen for
+any number of reasons and is most probably a problem at the remote server
+or a problem on the network.  The message will only appear if debug is
+enabled.
+
+% UNKORIGIN  unknown origin for ASIO error code %1 (protocol: %2, address %3)
+This message should not appear and indicates an internal error if it does.
+Please enter a bug report.
+
+% UNKRESULT  unknown result (%1) when IOFetch::stop() was executed for I/O to %2(%3)
+The termination method of the resolver's upstream fetch class was called with
+an unknown result code (which is given in the message).  This message should
+not appear and may indicate an internal error.  Please enter a bug report.

src/lib/asiodns/asiodef.msg

@@ -1,56 +0,0 @@
-# Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
-#
-# Permission to use, copy, modify, and/or distribute this software for any
-# purpose with or without fee is hereby granted, provided that the above
-# copyright notice and this permission notice appear in all copies.
-#
-# THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
-# REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
-# AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
-# INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
-# LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
-# OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
-# PERFORMANCE OF THIS SOFTWARE.
-
-$PREFIX ASIODNS_
-$NAMESPACE isc::asiodns
-
-FETCHCOMP   upstream fetch to %s(%d) has now completed
-+ A debug message, this records the the upstream fetch (a query made by the
-+ resolver on behalf of its client) to the specified address has completed.
-
-FETCHSTOP   upstream fetch to %s(%d) has been stopped
-+ An external component has requested the halting of an upstream fetch.  This
-+ is an allowed operation, and the message should only appear if debug is
-+ enabled.
-
-OPENSOCK    error %d opening %s socket to %s(%d)
-+ The asynchronous I/O code encountered an error when trying to open a socket
-+ of the specified protocol in order to send a message to the target address.
-+ The the number of the system error that cause the problem is given in the
-+ message.
-
-RECVSOCK    error %d reading %s data from %s(%d)
-+ The asynchronous I/O code encountered an error when trying read data from
-+ the specified address on the given protocol.  The the number of the system
-+ error that cause the problem is given in the message.
-
-SENDSOCK    error %d sending data using %s to %s(%d)
-+ The asynchronous I/O code encountered an error when trying send data to
-+ the specified address on the given protocol.  The the number of the system
-+ error that cause the problem is given in the message.
-
-RECVTMO     receive timeout while waiting for data from %s(%d)
-+ An upstream fetch from the specified address timed out.  This may happen for
-+ any number of reasons and is most probably a problem at the remote server
-+ or a problem on the network.  The message will only appear if debug is
-+ enabled.
-
-UNKORIGIN  unknown origin for ASIO error code %d (protocol: %s, address %s)
-+ This message should not appear and indicates an internal error if it does.
-+ Please enter a bug report.
-
-UNKRESULT  unknown result (%d) when IOFetch::stop() was executed for I/O to %s(%d)
-+ The termination method of the resolver's upstream fetch class was called with
-+ an unknown result code (which is given in the message).  This message should
-+ not appear and may indicate an internal error.  Please enter a bug report.

src/lib/asiodns/io_fetch.cc

@@ -40,6 +40,7 @@
 #include <dns/opcode.h>
 #include <dns/rcode.h>
 #include <log/logger.h>
+#include <log/macros.h>
 
 #include <asiodns/asiodef.h>
 #include <asiodns/io_fetch.h>
@@ -61,7 +62,17 @@ namespace asiodns {
 
 /// Use the ASIO logger
 
+namespace {
+
 isc::log::Logger logger("asiolink");
+// Log debug verbosity
+enum {
+    DBG_IMPORTANT = 1,
+    DBG_COMMON = 20,
+    DBG_ALL = 50
+};
+
+}
 
 /// \brief IOFetch Data
 ///
@@ -331,42 +342,34 @@ IOFetch::stop(Result result) {
         // numbers indicating the most important information.  The relative
         // values are somewhat arbitrary.
         //
-        // Although Logger::debug checks the debug flag internally, doing it
-        // below before calling Logger::debug avoids the overhead of a string
-        // conversion in the common case when debug is not enabled.
-        //
         // TODO: Update testing of stopped_ if threads are used.
         data_->stopped = true;
         switch (result) {
             case TIME_OUT:
-                if (logger.isDebugEnabled(1)) {
-                    logger.debug(20, ASIODNS_RECVTMO,
-                                 data_->remote_snd->getAddress().toText().c_str(),
-                                 static_cast<int>(data_->remote_snd->getPort()));
-                }
+                LOG_DEBUG(logger, DBG_COMMON, ASIODNS_RECVTMO).
+                    arg(data_->remote_snd->getAddress().toText()).
+                    arg(data_->remote_snd->getPort());
                 break;
 
             case SUCCESS:
-                if (logger.isDebugEnabled(50)) {
-                    logger.debug(30, ASIODNS_FETCHCOMP,
-                                 data_->remote_rcv->getAddress().toText().c_str(),
-                                 static_cast<int>(data_->remote_rcv->getPort()));
-                }
+                LOG_DEBUG(logger, DBG_ALL, ASIODNS_FETCHCOMP).
+                    arg(data_->remote_rcv->getAddress().toText()).
+                    arg(data_->remote_rcv->getPort());
                 break;
 
             case STOPPED:
                 // Fetch has been stopped for some other reason.  This is
                 // allowed but as it is unusual it is logged, but with a lower
                 // debug level than a timeout (which is totally normal).
-                logger.debug(1, ASIODNS_FETCHSTOP,
-                             data_->remote_snd->getAddress().toText().c_str(),
-                             static_cast<int>(data_->remote_snd->getPort()));
+                LOG_DEBUG(logger, DBG_IMPORTANT, ASIODNS_FETCHSTOP).
+                    arg(data_->remote_snd->getAddress().toText()).
+                    arg(data_->remote_snd->getPort());
                 break;
 
             default:
-                logger.error(ASIODNS_UNKRESULT, static_cast<int>(result),
-                             data_->remote_snd->getAddress().toText().c_str(),
-                             static_cast<int>(data_->remote_snd->getPort()));
+                LOG_ERROR(logger, ASIODNS_UNKRESULT).
+                    arg(data_->remote_snd->getAddress().toText()).
+                    arg(data_->remote_snd->getPort());
         }
 
         // Stop requested, cancel and I/O's on the socket and shut it down,
@@ -394,12 +397,11 @@ void IOFetch::logIOFailure(asio::error_code ec) {
            (data_->origin == ASIODNS_UNKORIGIN));
 
     static const char* PROTOCOL[2] = {"TCP", "UDP"};
-    logger.error(data_->origin,
-                 ec.value(),
-                 ((data_->remote_snd->getProtocol() == IPPROTO_TCP) ?
-                     PROTOCOL[0] : PROTOCOL[1]),
-                 data_->remote_snd->getAddress().toText().c_str(),
-                 static_cast<int>(data_->remote_snd->getPort()));
+    LOG_ERROR(logger, data_->origin).arg(ec.value()).
+        arg((data_->remote_snd->getProtocol() == IPPROTO_TCP) ?
+                     PROTOCOL[0] : PROTOCOL[1]).
+        arg(data_->remote_snd->getAddress().toText()).
+        arg(data_->remote_snd->getPort());
 }
 
 } // namespace asiodns

src/lib/dns/tests/message_unittest.cc

@@ -683,11 +683,12 @@ TEST_F(MessageTest, toWireWithoutRcode) {
 TEST_F(MessageTest, toText) {
     // Check toText() output for a typical DNS response with records in
     // all sections
-    ifstream ifs;
-    unittests::openTestData("message_toText1.txt", ifs);
+    
     factoryFromFile(message_parse, "message_toText1.wire");
     {
         SCOPED_TRACE("Message toText test (basic case)");
+        ifstream ifs;
+        unittests::openTestData("message_toText1.txt", ifs);
         unittests::matchTextData(ifs, message_parse.toText());
     }
 
@@ -695,12 +696,12 @@ TEST_F(MessageTest, toText) {
     // from the dig output (other than replacing tabs with a space): adding
     // a newline after the "OPT PSEUDOSECTION".  This is an intentional change
     // in our version for better readability.
-    ifs.close();
     message_parse.clear(Message::PARSE);
-    unittests::openTestData("message_toText2.txt", ifs);
     factoryFromFile(message_parse, "message_toText2.wire");
     {
         SCOPED_TRACE("Message toText test with EDNS");
+        ifstream ifs;
+        unittests::openTestData("message_toText2.txt", ifs);
         unittests::matchTextData(ifs, message_parse.toText());
     }
 
@@ -708,12 +709,12 @@ TEST_F(MessageTest, toText) {
     // from the dig output (other than replacing tabs with a space): removing
     // a redundant white space at the end of TSIG RDATA.  We'd rather consider
     // it a dig's defect than a feature.
-    ifs.close();
     message_parse.clear(Message::PARSE);
-    unittests::openTestData("message_toText3.txt", ifs);
     factoryFromFile(message_parse, "message_toText3.wire");
     {
         SCOPED_TRACE("Message toText test with TSIG");
+        ifstream ifs;
+        unittests::openTestData("message_toText3.txt", ifs);
         unittests::matchTextData(ifs, message_parse.toText());
     }
 }

src/lib/log/Makefile.am

@@ -16,11 +16,13 @@ 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
-liblog_la_SOURCES += message_exception.h message_exception.cc
+liblog_la_SOURCES += message_exception.h
 liblog_la_SOURCES += message_initializer.cc message_initializer.h
 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 += log_formatter.h log_formatter.cc
+liblog_la_SOURCES += macros.h
 
 EXTRA_DIST  = README
 EXTRA_DIST += messagedef.mes

src/lib/log/README

@@ -44,7 +44,7 @@ stored definitions; this updated text is logged.  However, to aid support,
 the message identifier so in the example above, the message finally logged
 would be something like:
 
-    OPENIN, unable to open a.txt for input
+    FAC_OPENIN, unable to open a.txt for input
 
 
 Using The System
@@ -55,17 +55,15 @@ The steps in using the system are:
    mnemonic for the message, typically 6-12 characters long - and a message.
    The file is described in more detail below.
 
-   Ideally the file should have a file type of ".msg".
+   Ideally the file should have a file type of ".mes".
 
-2. Run it through the message compiler to produce the .h and .cc files.  It
-   is intended that this step be included in the build process.  However,
-   for now run the compiler (found in the "compiler" subdirectory) manually.
-   The only argument is the name of the message file: it will produce as
-   output two files, having the same name as the input file but with file
-   types of ".h" and ".cc".
-
-   The compiler is built in the "compiler" subdirectory of the "src/lib/log"
-   directory.
+2. Run it through the message compiler to produce the .h and .cc files.  This
+   step should be included in the build process. (For an example of how to
+   do this, see src/lib/nsas/Makefile.am.) During development though, the
+   message compiler (found in the "src/lib/log/compiler" directory) will need
+   to be run manually.  The only argument is the name of the message file: it
+   will produce as output two files in the default directory, having the same
+   name as the input file but with file types of ".h" and ".cc".
 
 3. Include the .h file in your source code to define message symbols, and
    make sure that the .cc file is compiled and linked into your program -
@@ -96,11 +94,12 @@ An example file could be:
 
 $PREFIX TEST_
 $NAMESPACE isc::log
-TEST1       message %s is much too large
-+ This message is a test for the general message code
 
-UNKNOWN     unknown message
-+ Issued when the message is unknown.
+% TEST1       message %1 is much too large
+This message is a test for the general message code
+
+% UNKNOWN     unknown message
+Issued when the message is unknown.
 
 -- END --
 
@@ -117,23 +116,31 @@ Points to note:
 
 * Lines starting $ are directives.  At present, two directives are recognised:
 
-  * $PREFIX, which has one argument: the string used to prefix symbols.  If
-    absent, there is no prefix to the symbols. (Prefixes are explained below.)
+  * $PREFIX, which has one optional argument: the string used to prefix symbols.
+    If absent, there is no prefix to the symbols. (Prefixes are explained below.)
+
   * $NAMESPACE, which has one argument: the namespace in which the symbols are
-    created.  In the absence of a $NAMESPACE directive, symbols will be put
-    in the global namespace.
+    created.  In the absence of a $NAMESPACE directive, symbols will be put in
+    the anonymous namespace.
 
-* Lines starting + indicate an explanation for the preceding message.  These
-  are intended to be processed by a separate program and used to generate
-  an error messages manual.  However they are treated like comments by the
-  message compiler.  As with comments, these must be on a line by themselves;
-  if inline, the text (including the leading "+") will be interpreted as
-  part of the line.
+* Message lines.  These start with a "%" and are followed by the message
+  identification and the message text, the latter including zero or more
+  replacement tokens, e.g.
 
-* Message lines.  These comprise a symbol name and a message, which may
-  include zero or more printf-style tokens.  Symbol names will be upper-cased
-  by the compiler.
+     % TEST  message %1 is larger than the permitted length of %2
 
+  * There may be zero or more spaces between the leading "%" and the message
+    identification (which, in the example above, is the word "TEST").
+
+  * The replacement tokens are the strings "%1", "%2" etc.  When a message
+    is logged, these are replaced with the arguments passed to the logging
+    call: %1 refers to the first argument, %2 to the second etc.  Within the
+    message text, the placeholders can appear in any order, and placeholders
+    can be repeated.
+     
+* Remaining lines indicate an explanation for the preceding message.  These
+  are intended to be processed by a separate program and used to generate
+  an error messages manual.  They are ignored by the message compiler.
 
 Message Compiler
 ----------------
@@ -153,9 +160,8 @@ the form:
       :
    }
 
-The symbols define the keys in the global message dictionary.
-
-The namespace enclosing the symbols is set by the $NAMESPACE directive.
+The symbols define the keys in the global message dictionary, with the
+namespace enclosing the symbols set by the $NAMESPACE directive.
 
 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 identifier
@@ -163,12 +169,20 @@ ABC with "MSG_" to give the symbol MSG_ABC.  Similarly "$PREFIX E" would
 prefix it with "E" to give the symbol EABC.  If no $PREFIX is given, no
 prefix appears (so the symbol in this example would be ABC).
 
+The prefix is "syntactic sugar".  Generally all symbols in a given message file
+will be prefixed with the same set of letters.  By extracting these into
+a separate prefix, it becomes easier to disambiguate the different symbols.
+
+There may be multiple $PREFIX directives in a file.  A $PREFIX directive applies
+to all message definitions between it an the next $PREFIX directive.  A $PREFIX
+directive with no arguments clears the current prefix.
+
 2) A C++ source file (called <message-file-name>.cc) that holds the definitions
 of the global symbols and code to insert the symbols and messages into the map.
 
 Symbols are defined to be equal to strings holding the identifier, e.g.
 
-   extern const isc::log::MessageID MSG_DUPLNS = "DUPLNS";
+   extern const isc::log::MessageID MSG_DUPLNS = "MSG_DUPLNS";
 
 (The implementation allows symbols to be compared.  However, use of strings
 should not be assumed - a future implementation may change this.)
@@ -243,27 +257,49 @@ To use the current version of the logging:
       highest-level debug messages and 99 for the lowest-level (and typically
       more verbose) messages.
 
-   c) Name of an external message file.  This is the same as a standard message
-      file, although it should not include any directives. (A single directive
-      of a particular type will be ignored; multiple directives will cause the
-      read of the file to fail with an error.)  If a message is replaced, the
-      message should include the same printf-format directives in the same order
-      as the original message.
+   c) The external message file.  If present, this is the same as a standard
+      message file, although it should not include any directives. (A single
+      directive of a particular type will be ignored; multiple directives will
+      cause the read of the file to fail with an error.)
 
 4. Issue logging calls using methods on logger, e.g.
 
-       logger.error(DPS_NSTIMEOUT, "isc.org");
+       logger.error(DPS_NSTIMEOUT).arg("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
+       NSTIMEOUT  queries to all nameservers for %1 have timed out
 
    At present, the only logging is to the console.
 
 
+Efficiency Considerations
+-------------------------
+A common pattern in logging is a debug call of the form:
+
+   logger.debug(dbglevel, MSGID).arg(expensive_call()).arg(...
+
+... where "expensive_call()" is a function call to obtain logging information
+that may be computationally intensive.  Although the cost may be justified
+when debugging is enabled, the cost is still incurred even if debugging is
+disabled and the debug() method returns without outputting anything.  (The
+same may be true of other logging levels, although there are likely to be
+fewer calls to logger.info(), logger.error() etc. throughout the code and
+they are less likely to be disabled.)
+
+For this reason, a set of macros is provided and are called using the
+construct:
+
+   LOG_DEBUG(logger, dbglevel, MSGID).arg(expensive_call()).arg(...
+   LOG_INFO(logger, MSGID).arg(expensive_call()...)
+
+If these are used, the arguments passed to the arg() method are not evaluated
+if the relevant logging level is disabled.
+
+
 Severity Guidelines
 ===================
 When using logging, the question arises, what severity should a message be
@@ -361,9 +397,6 @@ 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

src/lib/log/compiler/message.cc

@@ -50,17 +50,13 @@ static const char* VERSION = "1.0-0";
 /// \li A .cc file containing code that adds the messages to the program's
 /// message dictionary at start-up time.
 ///
-/// Alternatively, the program can produce a .py file that contains the
-/// message definitions.
-///
-
 /// \b Invocation<BR>
 /// The program is invoked with the command:
 ///
 /// <tt>message [-v | -h | \<message-file\>]</tt>
 ///
-/// It reads the message file and writes out two files of the same name but with
-/// extensions of .h and .cc.
+/// It reads the message file and writes out two files of the same name in the
+/// default directory but with extensions of .h and .cc.
 ///
 /// \-v causes it to print the version number and exit. \-h prints a help
 /// message (and exits).
@@ -251,17 +247,16 @@ writeClosingNamespace(ostream& output, const vector<string>& ns) {
 ///
 /// \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 ns Namespace in which the definitions are to be placed.  An empty
 /// string indicates no namespace.
 /// \param dictionary Dictionary holding the message definitions.
 
 void
-writeHeaderFile(const string& file, const string& prefix,
-        const vector<string>& ns_components, MessageDictionary& dictionary)
+writeHeaderFile(const string& file, const vector<string>& ns_components,
+                MessageDictionary& dictionary)
 {
     Filename message_file(file);
-    Filename header_file(message_file.useAsDefault(".h"));
+    Filename header_file(Filename(message_file.name()).useAsDefault(".h"));
 
     // Text to use as the sentinels.
     string sentinel_text = sentinel(header_file);
@@ -271,7 +266,7 @@ writeHeaderFile(const string& file, const string& prefix,
 
     try {
         if (hfile.fail()) {
-            throw MessageException(MSG_OPNMSGOUT, header_file.fullName(),
+            throw MessageException(MSG_OPENOUT, header_file.fullName(),
                 strerror(errno));
         }
 
@@ -294,7 +289,7 @@ writeHeaderFile(const string& file, const string& prefix,
         vector<string> idents = sortedIdentifiers(dictionary);
         for (vector<string>::const_iterator j = idents.begin();
             j != idents.end(); ++j) {
-            hfile << "extern const isc::log::MessageID " << prefix << *j << ";\n";
+            hfile << "extern const isc::log::MessageID " << *j << ";\n";
         }
         hfile << "\n";
 
@@ -305,7 +300,7 @@ writeHeaderFile(const string& file, const string& prefix,
 
         // Report errors (if any) and exit
         if (hfile.fail()) {
-            throw MessageException(MSG_MSGWRTERR, header_file.fullName(),
+            throw MessageException(MSG_WRITERR, header_file.fullName(),
                 strerror(errno));
         }
 
@@ -354,17 +349,17 @@ replaceNonAlphaNum(char c) {
 /// to it.  But until BIND-10 is ported to Windows, we won't know.
 
 void
-writeProgramFile(const string& file, const string& prefix,
-    const vector<string>& ns_components, MessageDictionary& dictionary)
+writeProgramFile(const string& file, const vector<string>& ns_components,
+                 MessageDictionary& dictionary)
 {
     Filename message_file(file);
-    Filename program_file(message_file.useAsDefault(".cc"));
+    Filename program_file(Filename(message_file.name()).useAsDefault(".cc"));
 
     // Open the output file for writing
     ofstream ccfile(program_file.fullName().c_str());
     try {
         if (ccfile.fail()) {
-            throw MessageException(MSG_OPNMSGOUT, program_file.fullName(),
+            throw MessageException(MSG_OPENOUT, program_file.fullName(),
                 strerror(errno));
         }
 
@@ -387,7 +382,7 @@ writeProgramFile(const string& file, const string& prefix,
         vector<string> idents = sortedIdentifiers(dictionary);
         for (vector<string>::const_iterator j = idents.begin();
             j != idents.end(); ++j) {
-            ccfile << "extern const isc::log::MessageID " << prefix << *j <<
+            ccfile << "extern const isc::log::MessageID " << *j <<
                 " = \"" << *j << "\";\n";
         }
         ccfile << "\n";
@@ -422,7 +417,7 @@ writeProgramFile(const string& file, const string& prefix,
 
         // Report errors (if any) and exit
         if (ccfile.fail()) {
-            throw MessageException(MSG_MSGWRTERR, program_file.fullName(),
+            throw MessageException(MSG_WRITERR, program_file.fullName(),
                 strerror(errno));
         }
 
@@ -518,13 +513,10 @@ main(int argc, char* argv[]) {
         vector<string> ns_components = splitNamespace(reader.getNamespace());
 
         // Write the header file.
-        writeHeaderFile(message_file, reader.getPrefix(), ns_components,
-            dictionary);
+        writeHeaderFile(message_file, ns_components, dictionary);
 
         // Write the file that defines the message symbols and text
-        writeProgramFile(message_file, reader.getPrefix(), ns_components,
-            dictionary);
-
+        writeProgramFile(message_file, ns_components, dictionary);
 
         // Finally, warn of any duplicates encountered.
         warnDuplicates(reader);
@@ -535,9 +527,12 @@ main(int argc, char* argv[]) {
         string text = e.id();
         text += ", ";
         text += global.getText(e.id());
-
         // Format with arguments
-        text = isc::util::str::format(text, e.arguments());
+        vector<string> args(e.arguments());
+        for (size_t i(0); i < args.size(); ++ i) {
+            replacePlaceholder(&text, args[i], i + 1);
+        }
+
         cerr << text << "\n";
 
         return 1;

src/lib/log/message_exception.cc

@@ -12,15 +12,31 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
-/// \brief Body of Virtual Destructor
+#include <log/log_formatter.h>
 
-#include <log/message_exception.h>
+using namespace std;
+using namespace boost;
 
 namespace isc {
 namespace log {
 
-MessageException::~MessageException() throw() {
+void
+replacePlaceholder(string* message, const string& arg,
+                   const unsigned placeholder)
+{
+    string mark("%" + lexical_cast<string>(placeholder));
+    size_t pos(message->find(mark));
+    if (pos != string::npos) {
+        do {
+            message->replace(pos, mark.size(), arg);
+            pos = message->find(mark, pos + arg.size());
+        } while (pos != string::npos);
+    } else {
+        // We're missing the placeholder, so add some complain
+        message->append(" @@Missing placeholder " + mark + " for '" + arg +
+                        "'@@");
+    }
 }
 
-} // namespace log
-} // namespace isc
+}
+}

src/lib/log/log_formatter.h

@@ -0,0 +1,146 @@
+// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#ifndef __LOG_FORMATTER_H
+#define __LOG_FORMMATER_H
+
+#include <string>
+#include <boost/lexical_cast.hpp>
+
+namespace isc {
+namespace log {
+
+/// \brief The internal replacement routine
+///
+/// This is used internally by the Formatter. Replaces a placeholder
+/// in the message by replacement. If the placeholder is not found,
+/// it adds a complain at the end.
+void
+replacePlaceholder(std::string* message, const std::string& replacement,
+                   const unsigned placeholder);
+
+///
+/// \brief The log message formatter
+///
+/// This class allows us to format logging messages conveniently. We
+/// call something like logger.warn(WARN_MSG).arg(15).arg(dnsMsg). This
+/// outputs some text with placeholders replaced by the arguments, if
+/// the logging verbosity is at WARN level or more.
+///
+/// To make this work, we use the Formatter. The warn (or whatever logging
+/// function) returns a Formatter object. That one holds the string to be
+/// output with the placeholders. It also remembers if there should be any
+/// output at all (eg. if the logging is enabled for this level). When there's
+/// no .arg call on the object, it is destroyed right away and we use the
+/// destructor to output the text (but only in case we should output anything).
+///
+/// If there's an .arg call, we return reference to the same object, so another
+/// .arg can be called on it. After the last .arg call is done, the object is
+/// destroyed and, again, we can produce the output.
+///
+/// Of course, if the logging is turned off, we don't bother with any replacing
+/// and just return.
+///
+/// User of logging code should not really care much about this class, only
+/// call the .arg method to generate the correct output.
+///
+/// The class is a template to allow easy testing. Also, we want everything
+/// here in the header anyway and it doesn't depend on the details of what
+/// Logger really is, so it doesn't hurt anything.
+///
+/// Also, if you are interested in the internals, you might find the copy
+/// constructor a bit strange. It deactivates the original formatter. We don't
+/// really want to support copying of the Formatter by user, but C++ needs a
+/// copy constructor when returning from the logging functions, so we need one.
+/// And if we did not deactivate the original Formatter, that one would get
+/// destroyed before any call to .arg, producing an output, and then the one
+/// the .arg calls are called on would get destroyed as well, producing output
+/// again. So, think of this behaviour as soul moving from one to another.
+template<class Logger> class Formatter {
+private:
+    /// \brief The logger we will use to output the final message.
+    ///
+    /// If NULL, we are not active and should not produce anything.
+    mutable Logger* logger_;
+    /// \brief Prefix (eg. "ERROR", "DEBUG" or like that)
+    const char* prefix_;
+    /// \brief The messages with %1, %2... placeholders
+    std::string* message_;
+    /// \brief Which will be the next placeholder to replace
+    unsigned nextPlaceholder_;
+    Formatter& operator =(const Formatter& other);
+public:
+    /// \brief Constructor of "active" formatter
+    ///
+    /// This will create a formatter. If the arguments are set, it
+    /// will be active (will produce output). If you leave them all as NULL,
+    /// it will create an inactive Formatter -- one that'll produce no output.
+    ///
+    /// It is not expected to be called by user of logging system directly.
+    ///
+    /// \param prefix The severity prefix, like "ERROR" or "DEBUG"
+    /// \param message The message with placeholders. We take ownership of
+    ///     it and we will modify the string. Must not be NULL unless
+    ///     logger is also NULL, but it's not checked.
+    /// \param logger The logger where the final output will go, or NULL
+    ///     if no output is wanted.
+    Formatter(const char* prefix = NULL, std::string* message = NULL,
+              Logger* logger = NULL) :
+        logger_(logger), prefix_(prefix), message_(message),
+        nextPlaceholder_(1)
+    {
+    }
+
+    Formatter(const Formatter& other) :
+        logger_(other.logger_), prefix_(other.prefix_),
+        message_(other.message_), nextPlaceholder_(other.nextPlaceholder_)
+    {
+        other.logger_ = false;
+    }
+    /// \brief Destructor.
+    //
+    /// This is the place where output happens if the formatter is active.
+    ~ Formatter() {
+        if (logger_) {
+            logger_->output(prefix_, *message_);
+            delete message_;
+        }
+    }
+    /// \brief Replaces another placeholder
+    ///
+    /// Replaces another placeholder and returns a new formatter with it.
+    /// Deactivates the current formatter. In case the formatter is not active,
+    /// only produces another inactive formatter.
+    ///
+    /// \param arg The argument to place into the placeholder.
+    template<class Arg> Formatter& arg(const Arg& value) {
+        return (arg(boost::lexical_cast<std::string>(value)));
+    }
+    /// \brief String version of arg.
+    Formatter& arg(const std::string& arg) {
+        if (logger_) {
+            // FIXME: This logic has a problem. If we had a message like
+            // "%1 %2" and called .arg("%2").arg(42), we would get "42 %2".
+            // But we consider this to be rare enough not to complicate
+            // matters.
+            replacePlaceholder(message_, arg, nextPlaceholder_ ++);
+        }
+        return (*this);
+    }
+};
+
+}
+}
+
+#endif

src/lib/log/logger.cc

@@ -112,52 +112,57 @@ Logger::isFatalEnabled() {
 // Output methods
 
 void
-Logger::debug(int dbglevel, const isc::log::MessageID& ident, ...) {
+Logger::output(const char* sevText, const string& message) {
+    getLoggerPtr()->outputRaw(sevText, message);
+}
+
+Logger::Formatter
+Logger::debug(int dbglevel, const isc::log::MessageID& ident) {
     if (isDebugEnabled(dbglevel)) {
-        va_list ap;
-        va_start(ap, ident);
-        getLoggerPtr()->debug(ident, ap);
-        va_end(ap);
+        return (Formatter("DEBUG", getLoggerPtr()->lookupMessage(ident),
+                          this));
+    } else {
+        return (Formatter());
     }
 }
 
-void
-Logger::info(const isc::log::MessageID& ident, ...) {
+Logger::Formatter
+Logger::info(const isc::log::MessageID& ident) {
     if (isInfoEnabled()) {
-        va_list ap;
-        va_start(ap, ident);
-        getLoggerPtr()->info(ident, ap);
-        va_end(ap);
+        return (Formatter("INFO ", getLoggerPtr()->lookupMessage(ident),
+                          this));
+    } else {
+        return (Formatter());
     }
 }
 
-void
-Logger::warn(const isc::log::MessageID& ident, ...) {
+Logger::Formatter
+Logger::warn(const isc::log::MessageID& ident) {
     if (isWarnEnabled()) {
-        va_list ap;
-        va_start(ap, ident);
-        getLoggerPtr()->warn(ident, ap);
-        va_end(ap);
+        return (Formatter("WARN ", getLoggerPtr()->lookupMessage(ident),
+                          this));
+    } else {
+        return (Formatter());
     }
 }
 
-void
-Logger::error(const isc::log::MessageID& ident, ...) {
+Logger::Formatter
+Logger::error(const isc::log::MessageID& ident) {
     if (isErrorEnabled()) {
-        va_list ap;
-        va_start(ap, ident);
-        getLoggerPtr()->error(ident, ap);
-        va_end(ap);
+        return (Formatter("ERROR", getLoggerPtr()->lookupMessage(ident),
+                          this));
+    } else {
+        return (Formatter());
     }
 }
 
-void
-Logger::fatal(const isc::log::MessageID& ident, ...) {
+Logger::Formatter
+Logger::fatal(const isc::log::MessageID& ident) {
     if (isFatalEnabled()) {
-        va_list ap;
-        va_start(ap, ident);
-        getLoggerPtr()->fatal(ident, ap);
-        va_end(ap);
+        return (Formatter("FATAL", getLoggerPtr()->lookupMessage(ident),
+                          this));
+    } else {
+        return (Formatter());
     }
 }
 

src/lib/log/logger.h

@@ -21,6 +21,7 @@
 #include <log/debug_levels.h>
 #include <log/logger_levels.h>
 #include <log/message_types.h>
+#include <log/log_formatter.h>
 
 namespace isc {
 namespace log {
@@ -83,10 +84,11 @@ public:
         loggerptr_(NULL), name_(name), infunc_(infunc)
     {}
 
-
     /// \brief Destructor
     virtual ~Logger();
 
+    /// \brief The formatter used to replace placeholders
+    typedef isc::log::Formatter<Logger> Formatter;
 
     /// \brief Get Name of Logger
     ///
@@ -157,36 +159,31 @@ public:
     /// \param dbglevel Debug level, ranging between 0 and 99.  Higher numbers
     /// are used for more verbose output.
     /// \param ident Message identification.
-    /// \param ... Optional arguments for the message.
-    void debug(int dbglevel, const MessageID& ident, ...);
+    Formatter debug(int dbglevel, const MessageID& ident);
 
 
     /// \brief Output Informational Message
     ///
     /// \param ident Message identification.
-    /// \param ... Optional arguments for the message.
-    void info(const MessageID& ident, ...);
+    Formatter info(const MessageID& ident);
 
 
     /// \brief Output Warning Message
     ///
     /// \param ident Message identification.
-    /// \param ... Optional arguments for the message.
-    void warn(const MessageID& ident, ...);
+    Formatter warn(const MessageID& ident);
 
 
     /// \brief Output Error Message
     ///
     /// \param ident Message identification.
-    /// \param ... Optional arguments for the message.
-    void error(const MessageID& ident, ...);
+    Formatter error(const MessageID& ident);
 
 
     /// \brief Output Fatal Message
     ///
     /// \param ident Message identification.
-    /// \param ... Optional arguments for the message.
-    void fatal(const MessageID& ident, ...);
+    Formatter fatal(const MessageID& ident);
 
     /// \brief Equality
     ///
@@ -205,6 +202,12 @@ protected:
     static void reset();
 
 private:
+    friend class isc::log::Formatter<Logger>;
+    /// \brief Raw output function
+    ///
+    /// This is used by the formatter to output formatted output.
+    void output(const char* sevText, const std::string& message);
+
     /// \brief Copy Constructor
     ///
     /// Disabled (marked private) as it makes no sense to copy the logger -

src/lib/log/logger_impl.cc

@@ -13,6 +13,7 @@
 // PERFORMANCE OF THIS SOFTWARE
 
 #include <iostream>
+#include <iomanip>
 #include <algorithm>
 
 #include <stdarg.h>
@@ -194,17 +195,14 @@ LoggerImpl::isDebugEnabled(int dbglevel) {
 }
 
 // Output a general message
+string*
+LoggerImpl::lookupMessage(const MessageID& ident) {
+    return (new string(string(ident) + ", " +
+                       MessageDictionary::globalDictionary().getText(ident)));
+}
 
 void
-LoggerImpl::output(const char* sev_text, const MessageID& ident,
-    va_list ap)
-{
-    char message[512];      // Should be large enough for any message
-
-    // Obtain text of the message and substitute arguments.
-    const string format = MessageDictionary::globalDictionary().getText(ident);
-    vsnprintf(message, sizeof(message), format.c_str(), ap);
-
+LoggerImpl::outputRaw(const char* sevText, const string& message) {
     // Get the time in a struct tm format, and convert to text
     time_t t_time;
     time(&t_time);
@@ -214,8 +212,8 @@ LoggerImpl::output(const char* sev_text, const MessageID& ident,
     (void) strftime(chr_time, sizeof(chr_time), "%Y-%m-%d %H:%M:%S", tm_time);
 
     // Now output.
-    std::cout << chr_time << " " << sev_text << " [" << getName() << "] " <<
-        ident << ", " << message << "\n";
+    cout << chr_time << " " << sevText << " [" << getName() << "] " <<
+        message << endl;
 }
 
 } // namespace log

src/lib/log/logger_impl.h

@@ -167,64 +167,16 @@ public:
         }
     }
 
-
-    /// \brief Output General Message
-    ///
-    /// The message is formatted to include the date and time, the severity
-    /// and the logger generating the message.
+    /// \brief Raw output
     ///
-    /// \param sev_text Severity level as a text string
-    /// \param ident Message identification
-    /// \param ap Variable argument list holding message arguments
-    void output(const char* sev_text, const MessageID& ident,
-        va_list ap);
-
+    /// Writes the message with time into the log. Used by the Formatter
+    /// to produce output.
+    void outputRaw(const char* sev_text, const std::string& message);
 
-    /// \brief Output Debug Message
+    /// \brief Look up message text in dictionary
     ///
-    /// \param ident Message identification.
-    /// \param text Text to log
-    /// \param ap Variable argument list holding message arguments
-    void debug(const MessageID& ident, va_list ap) {
-        output("DEBUG", ident, ap);
-    }
-
-
-    /// \brief Output Informational Message
-    ///
-    /// \param ident Message identification.
-    /// \param text Text to log
-    /// \param ap Variable argument list holding message arguments
-    void info(const MessageID& ident, va_list ap) {
-        output("INFO ", ident, ap);
-    }
-
-    /// \brief Output Warning Message
-    ///
-    /// \param ident Message identification.
-    /// \param text Text to log
-    /// \param ap Variable argument list holding message arguments
-    void warn(const MessageID& ident, va_list ap) {
-        output("WARN ", ident, ap);
-    }
-
-    /// \brief Output Error Message
-    ///
-    /// \param ident Message identification.
-    /// \param text Text to log
-    /// \param ap Variable argument list holding message arguments
-    void error(const MessageID& ident, va_list ap) {
-        output("ERROR", ident, ap);
-    }
-
-    /// \brief Output Fatal Message
-    ///
-    /// \param ident Message identification.
-    /// \param text Text to log
-    /// \param ap Variable argument list holding message arguments
-    void fatal(const MessageID& ident, va_list ap) {
-        output("FATAL", ident, ap);
-    }
+    /// This gets you the unformatted text of message for given ID.
+    std::string* lookupMessage(const MessageID& id);
 
     /// \brief Equality
     ///

src/lib/log/logger_support.cc

@@ -24,6 +24,7 @@
 /// These functions will be replaced once the code has been written to obtain
 /// the logging parameters from the configuration database.
 
+#include <iostream>
 #include <algorithm>
 #include <string>
 #include <vector>
@@ -62,7 +63,7 @@ readLocalMessageFile(const char* file) {
     MessageDictionary& dictionary = MessageDictionary::globalDictionary();
     MessageReader reader(&dictionary);
     try {
-        logger.info(MSG_RDLOCMES, file);
+        logger.info(MSG_RDLOCMES).arg(file);
         reader.readFile(file, MessageReader::REPLACE);
 
         // File successfully read, list the duplicates
@@ -70,7 +71,7 @@ readLocalMessageFile(const char* file) {
         for (MessageReader::MessageIDCollection::const_iterator
             i = unknown.begin(); i != unknown.end(); ++i) {
             string message_id = boost::lexical_cast<string>(*i);
-                logger.warn(MSG_IDNOTFND, message_id.c_str());
+                logger.warn(MSG_IDNOTFND).arg(message_id);
         }
     }
     catch (MessageException& e) {
@@ -82,11 +83,15 @@ readLocalMessageFile(const char* file) {
             break;
 
         case 1:
-            logger.error(ident, args[0].c_str());
+            logger.error(ident).arg(args[0]);
             break;
 
-        default:    // 2 or more (2 should be the maximum)
-            logger.error(ident, args[0].c_str(), args[1].c_str());
+        case 2:
+            logger.error(ident).arg(args[0]).arg(args[1]);
+            break;
+
+        default:    // 3 or more (3 should be the maximum)
+            logger.error(ident).arg(args[0]).arg(args[1]).arg(args[2]);
         }
     }
 }
@@ -117,7 +122,7 @@ initLogger(const string& root, isc::log::Severity severity, int dbglevel,
         vector<string>::iterator new_end =
             unique(duplicates.begin(), duplicates.end());
         for (vector<string>::iterator i = duplicates.begin(); i != new_end; ++i) {
-            logger.warn(MSG_DUPMSGID, i->c_str());
+            logger.warn(MSG_DUPMSGID).arg(*i);
         }
 
     }

src/lib/log/macros.h

@@ -0,0 +1,50 @@
+// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#ifndef __LOG_MACROS_H
+#define __LOG_MACROS_H
+
+#include <log/logger.h>
+
+/// \brief Macro to conveniently test debug output and log it
+#define LOG_DEBUG(LOGGER, LEVEL, MESSAGE) \
+    if (!(LOGGER).isDebugEnabled((LEVEL))) { \
+    } else \
+        (LOGGER).debug((LEVEL), (MESSAGE))
+
+/// \brief Macro to conveniently test info output and log it
+#define LOG_INFO(LOGGER, MESSAGE) \
+    if (!(LOGGER).isInfoEnabled()) { \
+    } else \
+        (LOGGER).info((MESSAGE))
+
+/// \brief Macro to conveniently test warn output and log it
+#define LOG_WARN(LOGGER, MESSAGE) \
+    if (!(LOGGER).isWarnEnabled()) { \
+    } else \
+        (LOGGER).warn((MESSAGE))
+
+/// \brief Macro to conveniently test error output and log it
+#define LOG_ERROR(LOGGER, MESSAGE) \
+    if (!(LOGGER).isErrorEnabled()) { \
+    } else \
+        (LOGGER).error((MESSAGE))
+
+/// \brief Macro to conveniently test fatal output and log it
+#define LOG_FATAL(LOGGER, MESSAGE) \
+    if (!(LOGGER).isFatalEnabled()) { \
+    } else \
+        (LOGGER).fatal((MESSAGE))
+
+#endif

src/lib/log/message_exception.h

@@ -19,6 +19,7 @@
 #include <string>
 #include <vector>
 
+#include <boost/lexical_cast.hpp>
 #include <log/message_types.h>
 
 namespace isc {
@@ -35,33 +36,47 @@ public:
 
     /// \brief Constructor
     ///
-    /// \param id Message identification
-    MessageException(MessageID id) : id_(id)
-    {}
+    /// \param id Message identification.
+    /// \param lineno Line number on which error occurred (if > 0).
+    MessageException(MessageID id, int lineno = 0) : id_(id)
+    {
+        if (lineno > 0) {
+            args_.push_back(boost::lexical_cast<std::string>(lineno));
+        }
+    }
 
     /// \brief Constructor
     ///
-    /// \param id Message identification
-    /// \param arg1 First message argument
-    MessageException(MessageID id, const std::string& arg1) : id_(id)
+    /// \param id Message identification.
+    /// \param arg1 First message argument.
+    /// \param lineno Line number on which error occurred (if > 0).
+    MessageException(MessageID id, const std::string& arg1, int lineno = 0)
+        : id_(id)
     {
+        if (lineno > 0) {
+            args_.push_back(boost::lexical_cast<std::string>(lineno));
+        }
         args_.push_back(arg1);
     }
 
     /// \brief Constructor
     ///
-    /// \param id Message identification
-    /// \param arg1 First message argument
-    /// \param arg2 Second message argument
+    /// \param id Message identification.
+    /// \param arg1 First message argument.
+    /// \param arg2 Second message argument.
+    /// \param lineno Line number on which error occurred (if > 0).
     MessageException(MessageID id, const std::string& arg1,
-        const std::string& arg2) : id_(id)
+        const std::string& arg2, int lineno = 0) : id_(id)
     {
+        if (lineno > 0) {
+            args_.push_back(boost::lexical_cast<std::string>(lineno));
+        }
         args_.push_back(arg1);
         args_.push_back(arg2);
     }
 
     /// \brief Destructor
-    virtual ~MessageException() throw();
+    ~MessageException() throw() {}
 
     /// \brief Return Message ID
     ///

src/lib/log/message_reader.cc

@@ -12,8 +12,10 @@
 // OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 // PERFORMANCE OF THIS SOFTWARE.
 
+#include <cassert>
 #include <errno.h>
 #include <string.h>
+#include <iostream>
 
 #include <iostream>
 #include <fstream>
@@ -25,45 +27,50 @@
 
 using namespace std;
 
-namespace isc {
-namespace log {
-
-// Virtual destructor.
-MessageReader::~MessageReader() {
+namespace {
+const char DIRECTIVE_FLAG = '$';    // Starts each directive
+const char MESSAGE_FLAG = '%';      // Starts each message
 }
 
 
+namespace isc {
+namespace log {
+
 // Read the file.
 
 void
 MessageReader::readFile(const string& file, MessageReader::Mode mode) {
 
-    // Ensure the non-added collection is empty: this object might be
-    // being reused.
+    // Ensure the non-added collection is empty: we could be re-using this
+    // object.
     not_added_.clear();
 
-    // Open the file
+    // Open the file.
     ifstream infile(file.c_str());
     if (infile.fail()) {
-        throw MessageException(MSG_OPNMSGIN, file, strerror(errno));
+        throw MessageException(MSG_OPENIN, file, strerror(errno));
     }
 
-    // Loop round reading it.
+    // Loop round reading it.  As we process the file one line at a time,
+    // keep a track of line number of aid diagnosis of problems.
     string line;
     getline(infile, line);
+    lineno_ = 0;
+
     while (infile.good()) {
+        ++lineno_;
         processLine(line, mode);
         getline(infile, line);
     }
 
     // Why did the loop terminate?
     if (!infile.eof()) {
-        throw MessageException(MSG_MSGRDERR, file, strerror(errno));
+        throw MessageException(MSG_READERR, file, strerror(errno));
     }
     infile.close();
 }
 
-// Parse a line of the file
+// Parse a line of the file.
 
 void
 MessageReader::processLine(const string& line, MessageReader::Mode mode) {
@@ -74,15 +81,16 @@ MessageReader::processLine(const string& line, MessageReader::Mode mode) {
     if (text.empty()) {
         ;                           // Ignore blank lines
 
-    } else if ((text[0] == '#') || (text[0] == '+')) {
-        ;                           // Ignore comments or descriptions
-
-    } else if (text[0] == '$') {
+    } else if (text[0] == DIRECTIVE_FLAG) {
         parseDirective(text);       // Process directives
 
-    } else {
-        parseMessage(text, mode);   // Process other lines
 
+    } else if (text[0] == MESSAGE_FLAG) {
+        parseMessage(text, mode);   // Process message definition line
+
+    } else {
+        ;                           // Other lines are extended message
+                                    // description so are ignored
     }
 }
 
@@ -99,130 +107,162 @@ MessageReader::parseDirective(const std::string& text) {
     isc::util::str::uppercase(tokens[0]);
     if (tokens[0] == string("$PREFIX")) {
         parsePrefix(tokens);
+
     } else if (tokens[0] == string("$NAMESPACE")) {
         parseNamespace(tokens);
+
     } else {
-        throw MessageException(MSG_UNRECDIR, tokens[0]);
+
+        // Unrecognised directive
+        throw MessageException(MSG_UNRECDIR, tokens[0], lineno_);
     }
 }
 
 // Process $PREFIX
-
 void
 MessageReader::parsePrefix(const vector<string>& tokens) {
 
-    // Check argument count
-
-    static string valid = "ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789_";
-    if (tokens.size() < 2) {
-        throw MessageException(MSG_PRFNOARG);
-    } else if (tokens.size() > 2) {
-        throw MessageException(MSG_PRFEXTRARG);
-
-    }
+    // Should not get here unless there is something in the tokens array.
+    assert(tokens.size() > 0);
 
-    // As a style, we are going to have the symbols in uppercase
-    string prefix = tokens[1];
-    isc::util::str::uppercase(prefix);
+    // Process $PREFIX.  With no arguments, the prefix is set to the empty
+    // string.  One argument sets the prefix to the to its value and more than
+    // one argument is invalid.
+    if (tokens.size() == 1) {
+        prefix_ = "";
 
-    // Token is potentially valid providing it only contains alphabetic
-    // and numeric characters (and underscores) and does not start with a
-    // digit.
-    if ((prefix.find_first_not_of(valid) != string::npos) ||
-        (std::isdigit(prefix[0]))) {
+    } else if (tokens.size() == 2) {
+        prefix_ = tokens[1];
 
-        // Invalid character in string or it starts with a digit.
-        throw MessageException(MSG_PRFINVARG, tokens[1]);
-    }
+        // Token is potentially valid providing it only contains alphabetic
+        // and numeric characters (and underscores) and does not start with a
+        // digit.
+        if (invalidSymbol(prefix_)) {
+            throw MessageException(MSG_PRFINVARG, prefix_, lineno_);
+        }
 
-    // All OK - unless the prefix has already been set.
+    } else {
 
-    if (prefix_.size() != 0) {
-        throw MessageException(MSG_DUPLPRFX);
+        // Too many arguments
+        throw MessageException(MSG_PRFEXTRARG, lineno_);
     }
+}
 
-    // Prefix has not been set, so set it and return success.
-
-    prefix_ = prefix;
+// Check if string is an invalid C++ symbol.  It is valid if comprises only
+// alphanumeric characters and underscores, and does not start with a digit.
+// (Owing to the logic of the rest of the code, we check for its invalidity,
+// not its validity.)
+bool
+MessageReader::invalidSymbol(const string& symbol) {
+    static const string valid_chars = "ABCDEFGHIJKLMNOPQRSTUVWXYZ"
+                                      "abcdefghijklmnopqrstuvwxyz"
+                                      "0123456789_";
+    return ( symbol.empty() ||
+            (symbol.find_first_not_of(valid_chars) != string::npos) ||
+            (std::isdigit(symbol[0])));
 }
 
 // Process $NAMESPACE.  A lot of the processing is similar to that of $PREFIX,
 // except that only limited checks will be done on the namespace (to avoid a
-// lot of parsing and separating out of the namespace components.)
+// lot of parsing and separating out of the namespace components.)  Also, unlike
+// $PREFIX, there can only be one $NAMESPACE in a file.
 
 void
 MessageReader::parseNamespace(const vector<string>& tokens) {
 
     // Check argument count
-
-    static string valid = "ABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789_:"
-        "abcdefghijklmnopqrstuvwxyz";
-
     if (tokens.size() < 2) {
-        throw MessageException(MSG_NSNOARG);
+        throw MessageException(MSG_NSNOARG, lineno_);
 
     } else if (tokens.size() > 2) {
-        throw MessageException(MSG_NSEXTRARG);
+        throw MessageException(MSG_NSEXTRARG, lineno_);
 
     }
 
     // Token is potentially valid providing it only contains alphabetic
-    // and numeric characters (and underscores and colons).
-    if (tokens[1].find_first_not_of(valid) != string::npos) {
-
-        // Invalid character in string or it starts with a digit.
-        throw MessageException(MSG_NSINVARG, tokens[1]);
+    // and numeric characters (and underscores and colons).  As noted above,
+    // we won't be exhaustive - after all, and code containing the resultant
+    // namespace will have to be compiled, and the compiler will catch errors.
+    static const string valid_chars = "ABCDEFGHIJKLMNOPQRSTUVWXYZ"
+                                      "abcdefghijklmnopqrstuvwxyz"
+                                      "0123456789_:";
+    if (tokens[1].find_first_not_of(valid_chars) != string::npos) {
+        throw MessageException(MSG_NSINVARG, tokens[1], lineno_);
     }
 
     // All OK - unless the namespace has already been set.
     if (ns_.size() != 0) {
-        throw MessageException(MSG_DUPLNS);
+        throw MessageException(MSG_DUPLNS, lineno_);
     }
 
     // Prefix has not been set, so set it and return success.
-
     ns_ = tokens[1];
 }
 
 // Process message.  By the time this method is called, the line has been
-// stripped of leading and trailing spaces, and we believe that it is a line
-// defining a message.  The first token on the line is converted to uppercase
-// and becomes the message ID; the rest of the line is the message text.
+// stripped of leading and trailing spaces.  The first character of the string
+// is the message introducer, so we can get rid of that.  The remainder is
+// a line defining a message.
+//
+// The first token on the line, when concatenated to the prefix and converted to
+// upper-case, is the message ID.  The first of the line from the next token
+// on is the message text.
 
 void
 MessageReader::parseMessage(const std::string& text, MessageReader::Mode mode) {
 
     static string delimiters("\t\n ");   // Delimiters
 
+    // The line passed should be at least one character long and start with the
+    // message introducer (else we should not have got here).
+    assert((text.size() >= 1) && (text[0] == MESSAGE_FLAG));
+
+    // A line comprising just the message introducer is not valid.
+    if (text.size() == 1) {
+        throw MessageException(MSG_NOMSGID, text, lineno_);
+    }
+
+    // Strip off the introducer and any leading space after that.
+    string message_line = isc::util::str::trim(text.substr(1));
+
     // Look for the first delimiter.
-    size_t first_delim = text.find_first_of(delimiters);
+    size_t first_delim = message_line.find_first_of(delimiters);
     if (first_delim == string::npos) {
 
         // Just a single token in the line - this is not valid
-        throw MessageException(MSG_NOMSGTXT, text);
+        throw MessageException(MSG_NOMSGTXT, message_line, lineno_);
     }
 
-    // Extract the first token into the message ID
-    string ident = text.substr(0, first_delim);
+    // Extract the first token into the message ID, preceding it with the
+    // current prefix, then convert to upper-case.  If the prefix is not set,
+    // perform the valid character check now - the string will become a C++
+    // symbol so we may as well identify problems early.
+    string ident = prefix_ + message_line.substr(0, first_delim);
+    if (prefix_.empty()) {
+        if (invalidSymbol(ident)) {
+            throw MessageException(MSG_INVMSGID, ident, lineno_);
+        }
+    }
+    isc::util::str::uppercase(ident);
 
     // Locate the start of the message text
-    size_t first_text = text.find_first_not_of(delimiters, first_delim);
+    size_t first_text = message_line.find_first_not_of(delimiters, first_delim);
     if (first_text == string::npos) {
 
         // ?? This happens if there are trailing delimiters, which should not
         // occur as we have stripped trailing spaces off the line.  Just treat
         // this as a single-token error for simplicity's sake.
-        throw MessageException(MSG_NOMSGTXT, text);
+        throw MessageException(MSG_NOMSGTXT, message_line, lineno_);
     }
 
     // Add the result to the dictionary and to the non-added list if the add to
     // the dictionary fails.
     bool added;
     if (mode == ADD) {
-        added = dictionary_->add(ident, text.substr(first_text));
+        added = dictionary_->add(ident, message_line.substr(first_text));
     }
     else {
-        added = dictionary_->replace(ident, text.substr(first_text));
+        added = dictionary_->replace(ident, message_line.substr(first_text));
     }
     if (!added) {
         not_added_.push_back(ident);

src/lib/log/message_reader.h

@@ -65,10 +65,6 @@ public:
     {}
 
 
-    /// \brief Virtual Destructor
-    virtual ~MessageReader();
-
-
     /// \brief Get Dictionary
     ///
     /// Returns the pointer to the dictionary object.  Note that ownership is
@@ -188,10 +184,24 @@ private:
     /// \param tokens $NAMESPACE line split into tokens
     void parseNamespace(const std::vector<std::string>& tokens);
 
+    /// \brief Check for invalid C++ symbol name
+    ///
+    /// The message ID (or concatenation of prefix and message ID) will be used
+    /// as the name of a symbol in C++ code.  This function checks if the name
+    /// is invalid (contains anything other than alphanumeric characters or
+    /// underscores, or starts with a digit).
+    ///
+    /// \param symbol name to check to see if it is an invalid C++ symbol.
+    ///
+    /// \return true if the name is invalid, false if it is valid.
+    bool invalidSymbol(const std::string& symbol);
+
+
 
     /// Attributes
     MessageDictionary*  dictionary_;    ///< Dictionary to add messages to
     MessageIDCollection not_added_;     ///< List of IDs not added
+    int                 lineno_;        ///< Number of last line read
     std::string         prefix_;        ///< Argument of $PREFIX statement
     std::string         ns_;            ///< Argument of $NAMESPACE statement
 };

src/lib/log/messagedef.cc

@@ -1,4 +1,4 @@
-// File created from messagedef.mes on Mon Feb 14 11:07:45 2011
+// File created from messagedef.mes on Mon May  9 13:52:54 2011
 
 #include <cstddef>
 #include <log/message_types.h>
@@ -7,23 +7,23 @@
 namespace isc {
 namespace log {
 
-extern const isc::log::MessageID MSG_DUPLNS = "DUPLNS";
-extern const isc::log::MessageID MSG_DUPLPRFX = "DUPLPRFX";
-extern const isc::log::MessageID MSG_DUPMSGID = "DUPMSGID";
-extern const isc::log::MessageID MSG_IDNOTFND = "IDNOTFND";
-extern const isc::log::MessageID MSG_MSGRDERR = "MSGRDERR";
-extern const isc::log::MessageID MSG_MSGWRTERR = "MSGWRTERR";
-extern const isc::log::MessageID MSG_NOMSGTXT = "NOMSGTXT";
-extern const isc::log::MessageID MSG_NSEXTRARG = "NSEXTRARG";
-extern const isc::log::MessageID MSG_NSINVARG = "NSINVARG";
-extern const isc::log::MessageID MSG_NSNOARG = "NSNOARG";
-extern const isc::log::MessageID MSG_OPNMSGIN = "OPNMSGIN";
-extern const isc::log::MessageID MSG_OPNMSGOUT = "OPNMSGOUT";
-extern const isc::log::MessageID MSG_PRFEXTRARG = "PRFEXTRARG";
-extern const isc::log::MessageID MSG_PRFINVARG = "PRFINVARG";
-extern const isc::log::MessageID MSG_PRFNOARG = "PRFNOARG";
-extern const isc::log::MessageID MSG_RDLOCMES = "RDLOCMES";
-extern const isc::log::MessageID MSG_UNRECDIR = "UNRECDIR";
+extern const isc::log::MessageID MSG_DUPLNS = "MSG_DUPLNS";
+extern const isc::log::MessageID MSG_DUPMSGID = "MSG_DUPMSGID";
+extern const isc::log::MessageID MSG_IDNOTFND = "MSG_IDNOTFND";
+extern const isc::log::MessageID MSG_INVMSGID = "MSG_INVMSGID";
+extern const isc::log::MessageID MSG_NOMSGID = "MSG_NOMSGID";
+extern const isc::log::MessageID MSG_NOMSGTXT = "MSG_NOMSGTXT";
+extern const isc::log::MessageID MSG_NSEXTRARG = "MSG_NSEXTRARG";
+extern const isc::log::MessageID MSG_NSINVARG = "MSG_NSINVARG";
+extern const isc::log::MessageID MSG_NSNOARG = "MSG_NSNOARG";
+extern const isc::log::MessageID MSG_OPENIN = "MSG_OPENIN";
+extern const isc::log::MessageID MSG_OPENOUT = "MSG_OPENOUT";
+extern const isc::log::MessageID MSG_PRFEXTRARG = "MSG_PRFEXTRARG";
+extern const isc::log::MessageID MSG_PRFINVARG = "MSG_PRFINVARG";
+extern const isc::log::MessageID MSG_RDLOCMES = "MSG_RDLOCMES";
+extern const isc::log::MessageID MSG_READERR = "MSG_READERR";
+extern const isc::log::MessageID MSG_UNRECDIR = "MSG_UNRECDIR";
+extern const isc::log::MessageID MSG_WRITERR = "MSG_WRITERR";
 
 } // namespace log
 } // namespace isc
@@ -31,23 +31,23 @@ extern const isc::log::MessageID MSG_UNRECDIR = "UNRECDIR";
 namespace {
 
 const char* values[] = {
-    "DUPLNS", "duplicate $NAMESPACE directive found",
-    "DUPLPRFX", "duplicate $PREFIX directive found",
-    "DUPMSGID", "duplicate message ID (%s) in compiled code",
-    "IDNOTFND", "could not replace message for '%s': no such message identification",
-    "MSGRDERR", "error reading from message file %s: %s",
-    "MSGWRTERR", "error writing to %s: %s",
-    "NOMSGTXT", "a line containing a message ID ('%s') and nothing else was found",
-    "NSEXTRARG", "$NAMESPACE directive has too many arguments",
-    "NSINVARG", "$NAMESPACE directive has an invalid argument ('%s')",
-    "NSNOARG", "no arguments were given to the $NAMESPACE directive",
-    "OPNMSGIN", "unable to open message file %s for input: %s",
-    "OPNMSGOUT", "unable to open %s for output: %s",
-    "PRFEXTRARG", "$PREFIX directive has too many arguments",
-    "PRFINVARG", "$PREFIX directive has an invalid argument ('%s')",
-    "PRFNOARG", "no arguments were given to the $PREFIX directive",
-    "RDLOCMES", "reading local message file %s",
-    "UNRECDIR", "unrecognised directive '%s'",
+    "MSG_DUPLNS", "line %1: duplicate $NAMESPACE directive found",
+    "MSG_DUPMSGID", "duplicate message ID (%1) in compiled code",
+    "MSG_IDNOTFND", "could not replace message text for '%1': no such message",
+    "MSG_INVMSGID", "line %1: invalid message identification '%2'",
+    "MSG_NOMSGID", "line %1: message definition line found without a message ID",
+    "MSG_NOMSGTXT", "line %1: line found containing a message ID ('%2') and no text",
+    "MSG_NSEXTRARG", "line %1: $NAMESPACE directive has too many arguments",
+    "MSG_NSINVARG", "line %1: $NAMESPACE directive has an invalid argument ('%2')",
+    "MSG_NSNOARG", "line %1: no arguments were given to the $NAMESPACE directive",
+    "MSG_OPENIN", "unable to open message file %1 for input: %2",
+    "MSG_OPENOUT", "unable to open %1 for output: %2",
+    "MSG_PRFEXTRARG", "line %1: $PREFIX directive has too many arguments",
+    "MSG_PRFINVARG", "line %1: $PREFIX directive has an invalid argument ('%2')",
+    "MSG_RDLOCMES", "reading local message file %1",
+    "MSG_READERR", "error reading from message file %1: %2",
+    "MSG_UNRECDIR", "line %1: unrecognised directive '%2'",
+    "MSG_WRITERR", "error writing to %1: %2",
     NULL
 };
 

src/lib/log/messagedef.h

@@ -1,4 +1,4 @@
-// File created from messagedef.mes on Mon Feb 14 11:07:45 2011
+// File created from messagedef.mes on Mon May  9 13:52:54 2011
 
 #ifndef __MESSAGEDEF_H
 #define __MESSAGEDEF_H
@@ -9,22 +9,22 @@ namespace isc {
 namespace log {
 
 extern const isc::log::MessageID MSG_DUPLNS;
-extern const isc::log::MessageID MSG_DUPLPRFX;
 extern const isc::log::MessageID MSG_DUPMSGID;
 extern const isc::log::MessageID MSG_IDNOTFND;
-extern const isc::log::MessageID MSG_MSGRDERR;
-extern const isc::log::MessageID MSG_MSGWRTERR;
+extern const isc::log::MessageID MSG_INVMSGID;
+extern const isc::log::MessageID MSG_NOMSGID;
 extern const isc::log::MessageID MSG_NOMSGTXT;
 extern const isc::log::MessageID MSG_NSEXTRARG;
 extern const isc::log::MessageID MSG_NSINVARG;
 extern const isc::log::MessageID MSG_NSNOARG;
-extern const isc::log::MessageID MSG_OPNMSGIN;
-extern const isc::log::MessageID MSG_OPNMSGOUT;
+extern const isc::log::MessageID MSG_OPENIN;
+extern const isc::log::MessageID MSG_OPENOUT;
 extern const isc::log::MessageID MSG_PRFEXTRARG;
 extern const isc::log::MessageID MSG_PRFINVARG;
-extern const isc::log::MessageID MSG_PRFNOARG;
 extern const isc::log::MessageID MSG_RDLOCMES;
+extern const isc::log::MessageID MSG_READERR;
 extern const isc::log::MessageID MSG_UNRECDIR;
+extern const isc::log::MessageID MSG_WRITERR;
 
 } // namespace log
 } // namespace isc

src/lib/log/messagedef.mes

@@ -12,108 +12,108 @@
 # OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
 # PERFORMANCE OF THIS SOFTWARE.
 
-$PREFIX MSG_
-$NAMESPACE isc::log
-
 # \brief Message Utility Message File
 #
-# This is the source of the set of messages generated by the message and logging
-# components.  The associated .h and .cc files are created by hand from this
-# file though and are not built during the build process; this is to avoid the
-# chicken-and-egg situation where we need the files to build the message
+# This is the source of the set of messages generated by the message and
+# logging components.  The associated .h and .cc files are created by hand from
+# this file though and are not built during the build process; this is to avoid
+# the chicken-and-egg situation where we need the files to build the message
 # compiler, yet we need the compiler to build the files.
 
-DUPMSGID  duplicate message ID (%s) in compiled code
-+ Indicative of a programming error, when it started up, BIND10 detected that
-+ the given message ID had been registered by one or more modules.  (All message
-+ IDs should be unique throughout BIND10.)  This has no impact on the operation
-+ of the server other that erroneous messages may be logged.  (When BIND10 loads
-+ the message IDs (and their associated text), if a duplicate ID is found it is
-+ discarded.  However, when the module that supplied the duplicate ID logs that
-+ particular message, the text supplied by the module that added the original
-+ ID will be output - something that may bear no relation to the condition being
-+ logged.
-
-DUPLNS    duplicate $NAMESPACE directive found
-+ When reading a message file, more than one $NAMESPACE directive was found.  In
-+ this version of the code, such a condition is regarded as an error and the
-+ read will be abandoned.
-
-DUPLPRFX    duplicate $PREFIX directive found
-+ When reading a message file, more than one $PREFIX directive was found.  In
-+ this version of the code, such a condition is regarded as an error and the
-+ read will be abandoned.
-
-IDNOTFND    could not replace message for '%s': no such message identification
-+ During start-up a local message file was read.  A line with the listed
-+ message identification was found in the file, but the identification is not
-+ one contained in the compiled-in message dictionary.  Either the message
-+ identification has been mis-spelled in the file, or the local file was used
-+ for an earlier version of the software and the message with that
-+ identification has been removed.
-+
-+ This message may appear a number of times in the file, once for every such
-+ unknown message identification.
-
-MSGRDERR    error reading from message file %s: %s
-+ The specified error was encountered reading from the named message file.
-
-MSGWRTERR   error writing to %s: %s
-+ The specified error was encountered by the message compiler when writing to
-+ the named output file.
-
-NSEXTRARG  $NAMESPACE directive has too many arguments
-+ The $NAMESPACE directive takes a single argument, a namespace in which all the
-+ generated symbol names are placed.  This error is generated when the
-+ compiler finds a $NAMESPACE directive with more than one argument.
-
-NSINVARG    $NAMESPACE directive has an invalid argument ('%s')
-+ The $NAMESPACE argument should be a valid C++ namespace.  The reader does a
-+ cursory check on its validity, checking that the characters in the namespace
-+ are correct.  The error is generated when the reader finds an invalid
-+ character. (Valid are alphanumeric characters, underscores and colons.)
-
-NOMSGTXT    a line containing a message ID ('%s') and nothing else was found
-+ Message definitions comprise lines starting with a message identification (a
-+ symbolic name for the message) and followed by the text of the message.  This
-+ error is generated when a line is found in the message file that contains just
-+ the message identification and no text.
-
-NSNOARG     no arguments were given to the $NAMESPACE directive
-+ The $NAMESPACE directive takes a single argument, a namespace in which all the
-+ generated symbol names are placed.  This error is generated when the
-+ compiler finds a $NAMESPACE directive with no arguments.
-
-OPNMSGIN     unable to open message file %s for input: %s
-+ The program was not able to open the specified input message file for the
-+ reason given.
-
-OPNMSGOUT   unable to open %s for output: %s
-+ The program was not able to open the specified output file for the reason
-+ given.
-
-PRFEXTRARG  $PREFIX directive has too many arguments
-+ The $PREFIX directive takes a single argument, a prefix to be added to the
-+ symbol names when a C++ .h file is created.  This error is generated when the
-+ compiler finds a $PREFIX directive with more than one argument.
-
-PRFINVARG   $PREFIX directive has an invalid argument ('%s')
-+ The $PREFIX argument is used in a symbol name in a C++ header file.  As such,
-+ it must adhere to restrictions on C++ symbol names (e.g. may only contain
-+ alphanumeric characters or underscores, and may nor start with a digit).  A
-+ $PREFIX directive was found with an argument (given in the message) that
-+ violates those restictions.
-
-PRFNOARG    no arguments were given to the $PREFIX directive
-+ The $PREFIX directive takes a single argument, a prefix to be added to the
-+ symbol names when a C++ .h file is created.  This error is generated when the
-+ compiler finds a $PREFIX directive with no arguments.
-
-RDLOCMES    reading local message file %s
-+ This is an informational message output by BIND10 when it starts to read a
-+ local message file.  (A local message file may replace the text of one of more
-+ messages; the ID of the message will not be changed though.)
-
-UNRECDIR    unrecognised directive '%s'
-+ A line starting with a dollar symbol was found, but the first word on the line
-+ (shown in the message) was not a recognised message compiler directive.
+$PREFIX MSG_
+$NAMESPACE isc::log
+
+% DUPMSGID      duplicate message ID (%1) in compiled code
+Indicative of a programming error, when it started up, BIND10 detected that
+the given message ID had been registered by one or more modules.  (All message
+IDs should be unique throughout BIND10.)  This has no impact on the operation
+of the server other that erroneous messages may be logged.  (When BIND10 loads
+the message IDs (and their associated text), if a duplicate ID is found it is
+discarded.  However, when the module that supplied the duplicate ID logs that
+particular message, the text supplied by the module that added the original
+ID will be output - something that may bear no relation to the condition being
+logged.
+
+% DUPLNS        line %1: duplicate $NAMESPACE directive found
+When reading a message file, more than one $NAMESPACE directive was found.  In
+this version of the code, such a condition is regarded as an error and the
+read will be abandoned.
+
+% IDNOTFND      could not replace message text for '%1': no such message
+During start-up a local message file was read.  A line with the listed
+message identification was found in the file, but the identification is not
+one contained in the compiled-in message dictionary.  Either the message
+identification has been mis-spelled in the file, or the local file was used
+for an earlier version of the software and the message with that
+identification has been removed.
+
+This message may appear a number of times in the file, once for every such
+unknown message identification.
+
+% INVMSGID      line %1: invalid message identification '%2'
+The concatenation of the prefix and the message identification is used as
+a symbol in the C++ module; as such it may only contain 
+
+% NOMSGID       line %1: message definition line found without a message ID
+Message definition lines are lines starting with a "%".  The rest of the line
+should comprise the message ID and text describing the message.  This error
+indicates the message compiler found a line in the message file comprising
+just the "%" and nothing else.
+
+% NOMSGTXT      line %1: line found containing a message ID ('%2') and no text
+Message definition lines are lines starting with a "%".  The rest of the line
+should comprise the message ID and text describing the message.  This error
+is generated when a line is found in the message file that contains the
+leading "%" and the message identification but no text.
+
+% NSEXTRARG     line %1: $NAMESPACE directive has too many arguments
+The $NAMESPACE directive takes a single argument, a namespace in which all the
+generated symbol names are placed.  This error is generated when the
+compiler finds a $NAMESPACE directive with more than one argument.
+
+% NSINVARG      line %1: $NAMESPACE directive has an invalid argument ('%2')
+The $NAMESPACE argument should be a valid C++ namespace.  The reader does a
+cursory check on its validity, checking that the characters in the namespace
+are correct.  The error is generated when the reader finds an invalid
+character. (Valid are alphanumeric characters, underscores and colons.)
+
+% NSNOARG       line %1: no arguments were given to the $NAMESPACE directive
+The $NAMESPACE directive takes a single argument, a namespace in which all the
+generated symbol names are placed.  This error is generated when the
+compiler finds a $NAMESPACE directive with no arguments.
+
+% OPENIN        unable to open message file %1 for input: %2
+The program was not able to open the specified input message file for the
+reason given.
+
+% OPENOUT       unable to open %1 for output: %2
+The program was not able to open the specified output file for the reason
+given.
+
+% PRFEXTRARG    line %1: $PREFIX directive has too many arguments
+The $PREFIX directive takes a single argument, a prefix to be added to the
+symbol names when a C++ .h file is created.  This error is generated when the
+compiler finds a $PREFIX directive with more than one argument.
+
+% PRFINVARG     line %1: $PREFIX directive has an invalid argument ('%2')
+The $PREFIX argument is used in a symbol name in a C++ header file.  As such,
+it must adhere to restrictions on C++ symbol names (e.g. may only contain
+alphanumeric characters or underscores, and may nor start with a digit).
+A $PREFIX directive was found with an argument (given in the message) that
+violates those restictions.
+
+% RDLOCMES      reading local message file %1
+This is an informational message output by BIND10 when it starts to read a
+local message file.  (A local message file may replace the text of one of more
+messages; the ID of the message will not be changed though.)
+
+% READERR       error reading from message file %1: %2
+The specified error was encountered reading from the named message file.
+
+% WRITERR       error writing to %1: %2
+The specified error was encountered by the message compiler when writing to
+the named output file.
+
+% UNRECDIR      line %1: unrecognised directive '%2'
+A line starting with a dollar symbol was found, but the first word on the line
+(shown in the message) was not a recognised message compiler directive.

src/lib/log/tests/Makefile.am

@@ -22,6 +22,7 @@ run_unittests_SOURCES += message_reader_unittest.cc
 run_unittests_SOURCES += message_initializer_unittest.cc
 run_unittests_SOURCES += message_initializer_unittest_2.cc
 run_unittests_SOURCES += run_unittests.cc
+run_unittests_SOURCES += log_formatter_unittest.cc
 
 run_unittests_CPPFLAGS = $(AM_CPPFLAGS) $(GTEST_INCLUDES)
 run_unittests_LDFLAGS = $(AM_LDFLAGS) $(GTEST_LDFLAGS)

src/lib/log/tests/log_formatter_unittest.cc

@@ -0,0 +1,125 @@
+// Copyright (C) 2011  Internet Systems Consortium, Inc. ("ISC")
+//
+// Permission to use, copy, modify, and/or distribute this software for any
+// purpose with or without fee is hereby granted, provided that the above
+// copyright notice and this permission notice appear in all copies.
+//
+// THE SOFTWARE IS PROVIDED "AS IS" AND ISC DISCLAIMS ALL WARRANTIES WITH
+// REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
+// AND FITNESS.  IN NO EVENT SHALL ISC BE LIABLE FOR ANY SPECIAL, DIRECT,
+// INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES WHATSOEVER RESULTING FROM
+// LOSS OF USE, DATA OR PROFITS, WHETHER IN AN ACTION OF CONTRACT, NEGLIGENCE
+// OR OTHER TORTIOUS ACTION, ARISING OUT OF OR IN CONNECTION WITH THE USE OR
+// PERFORMANCE OF THIS SOFTWARE.
+
+#include <gtest/gtest.h>
+#include <log/log_formatter.h>
+
+#include <vector>
+#include <string>
+
+using namespace std;
+
+namespace {
+
+class FormatterTest : public ::testing::Test {
+protected:
+    typedef pair<const char*, string> Output;
+    typedef isc::log::Formatter<FormatterTest> Formatter;
+    vector<Output> outputs;
+public:
+    void output(const char* prefix, const string& message) {
+        outputs.push_back(Output(prefix, message));
+    }
+    // Just shortcut for new string
+    string* s(const char* text) {
+        return (new string(text));
+    }
+};
+
+// Create an inactive formatter and check it doesn't produce any output
+TEST_F(FormatterTest, inactive) {
+    Formatter();
+    EXPECT_EQ(0, outputs.size());
+}
+
+// Create an active formatter and check it produces output. Does no arg
+// substitution yet
+TEST_F(FormatterTest, active) {
+    Formatter("TEST", s("Text of message"), this);
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("Text of message", outputs[0].second);
+}
+
+// No output even when we have an arg on the inactive formatter
+TEST_F(FormatterTest, inactiveArg) {
+    Formatter().arg("Hello");
+    EXPECT_EQ(0, outputs.size());
+}
+
+// Create an active formatter and replace a placeholder with string
+TEST_F(FormatterTest, stringArg) {
+    {
+        SCOPED_TRACE("C++ string");
+        Formatter("TEST", s("Hello %1"), this).arg(string("World"));
+        ASSERT_EQ(1, outputs.size());
+        EXPECT_STREQ("TEST", outputs[0].first);
+        EXPECT_EQ("Hello World", outputs[0].second);
+    }
+    {
+        SCOPED_TRACE("C++ string");
+        Formatter("TEST", s("Hello %1"), this).arg(string("Internet"));
+        ASSERT_EQ(2, outputs.size());
+        EXPECT_STREQ("TEST", outputs[1].first);
+        EXPECT_EQ("Hello Internet", outputs[1].second);
+    }
+}
+
+// Can convert to string
+TEST_F(FormatterTest, intArg) {
+    Formatter("TEST", s("The answer is %1"), this).arg(42);
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("The answer is 42", outputs[0].second);
+}
+
+// Can use multiple arguments at different places
+TEST_F(FormatterTest, multiArg) {
+    Formatter("TEST", s("The %2 are %1"), this).arg("switched").
+        arg("arguments");
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("The arguments are switched", outputs[0].second);
+}
+
+// Can survive and complains if placeholder is missing
+TEST_F(FormatterTest, missingPlace) {
+    EXPECT_NO_THROW(Formatter("TEST", s("Missing the first %2"), this).
+                    arg("missing").arg("argument"));
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("Missing the first argument "
+              "@@Missing placeholder %1 for 'missing'@@", outputs[0].second);
+}
+
+// Can replace multiple placeholders
+TEST_F(FormatterTest, multiPlaceholder) {
+    Formatter("TEST", s("The %1 is the %1"), this).
+        arg("first rule of tautology club");
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("The first rule of tautology club is "
+              "the first rule of tautology club", outputs[0].second);
+}
+
+// Test we can cope with replacement containing the placeholder
+TEST_F(FormatterTest, noRecurse) {
+    // If we recurse, this will probably eat all the memory and crash
+    Formatter("TEST", s("%1"), this).arg("%1 %1");
+    ASSERT_EQ(1, outputs.size());
+    EXPECT_STREQ("TEST", outputs[0].first);
+    EXPECT_EQ("%1 %1", outputs[0].second);
+}
+
+}

src/lib/log/tests/logger_support_test.cc

@@ -23,6 +23,7 @@
 #include <iostream>
 
 #include <log/logger.h>
+#include <log/macros.h>
 #include <log/logger_support.h>
 #include <log/root_logger_name.h>
 
@@ -92,13 +93,14 @@ int main(int argc, char** argv) {
     initLogger("alpha", severity, dbglevel, localfile);
 
     // Log a few messages
-    logger_ex.fatal(MSG_MSGWRTERR, "test1", "42");
-    logger_ex.error(MSG_UNRECDIR, "false");
-    logger_dlm.warn(MSG_MSGRDERR, "a.txt", "dummy test");
-    logger_dlm.info(MSG_OPNMSGIN, "example.msg", "dummy test");
-    logger_ex.debug(0, MSG_UNRECDIR, "[abc]");
-    logger_ex.debug(24, MSG_UNRECDIR, "[24]");
-    logger_ex.debug(25, MSG_UNRECDIR, "[25]");
-    logger_ex.debug(26, MSG_UNRECDIR, "[26]");
+    LOG_FATAL(logger_ex, MSG_WRITERR).arg("test1").arg("42");
+    LOG_ERROR(logger_ex, MSG_RDLOCMES).arg("dummy/file");
+    LOG_WARN(logger_dlm, MSG_READERR).arg("a.txt").arg("dummy reason");
+    LOG_INFO(logger_dlm, MSG_OPENIN).arg("example.msg").arg("dummy reason");
+    LOG_DEBUG(logger_ex, 0, MSG_RDLOCMES).arg("dummy/0");
+    LOG_DEBUG(logger_ex, 24, MSG_RDLOCMES).arg("dummy/24");
+    LOG_DEBUG(logger_ex, 25, MSG_RDLOCMES).arg("dummy/25");
+    LOG_DEBUG(logger_ex, 26, MSG_RDLOCMES).arg("dummy/26");
+
     return (0);
 }

src/lib/log/tests/message_dictionary_unittest.cc

@@ -29,7 +29,7 @@ using namespace std;
 // and the latter should be present.
 
 static const char* values[] = {
-    "DUPLNS", "duplicate $NAMESPACE directive found",
+    "MSG_DUPLNS", "duplicate $NAMESPACE directive found",
     "NEWSYM", "new symbol added",
     NULL
 };
@@ -190,7 +190,7 @@ TEST_F(MessageDictionaryTest, GlobalTest) {
 TEST_F(MessageDictionaryTest, GlobalLoadTest) {
     vector<string>& duplicates = MessageInitializer::getDuplicates();
     ASSERT_EQ(1, duplicates.size());
-    EXPECT_EQ(string("DUPLNS"), duplicates[0]);
+    EXPECT_EQ(string("MSG_DUPLNS"), duplicates[0]);
 
     string text = MessageDictionary::globalDictionary().getText("NEWSYM");
     EXPECT_EQ(string("new symbol added"), text);

src/lib/log/tests/message_reader_unittest.cc

@@ -68,8 +68,8 @@ TEST_F(MessageReaderTest, BlanksAndComments) {
     EXPECT_NO_THROW(reader_.processLine(" \n "));
     EXPECT_NO_THROW(reader_.processLine("# This is a comment"));
     EXPECT_NO_THROW(reader_.processLine("\t\t # Another comment"));
-    EXPECT_NO_THROW(reader_.processLine("  + A description line"));
-    EXPECT_NO_THROW(reader_.processLine("#+ A comment"));
+    EXPECT_NO_THROW(reader_.processLine("  A description line"));
+    EXPECT_NO_THROW(reader_.processLine("# A comment"));
     EXPECT_NO_THROW(reader_.processLine("  +# A description line"));
 
     // ... and (b) nothing gets added to either the map or the not-added section.
@@ -97,6 +97,15 @@ processLineException(MessageReader& reader, const char* what,
     }
 }
 
+// Check that it recognises invalid directives
+
+TEST_F(MessageReaderTest, InvalidDirectives) {
+
+    // Check that a "$" with nothing else generates an error
+    processLineException(reader_, "$", MSG_UNRECDIR);
+    processLineException(reader_, "$xyz", MSG_UNRECDIR);
+}
+
 // Check that it can parse a prefix
 
 TEST_F(MessageReaderTest, Prefix) {
@@ -104,8 +113,8 @@ TEST_F(MessageReaderTest, Prefix) {
     // Check that no $PREFIX is present
     EXPECT_EQ(string(""), reader_.getPrefix());
 
-    // Check that a $PREFIX directive with no argument generates an error.
-    processLineException(reader_, "$PREFIX", MSG_PRFNOARG);
+    // Check that a $PREFIX directive with no argument is OK
+    EXPECT_NO_THROW(reader_.processLine("$PREFIX"));
 
     // Check a $PREFIX with multiple arguments is invalid
     processLineException(reader_, "$prefix A B", MSG_PRFEXTRARG);
@@ -118,17 +127,19 @@ TEST_F(MessageReaderTest, Prefix) {
 
     // A valid prefix should be accepted
     EXPECT_NO_THROW(reader_.processLine("$PREFIX   dlm__"));
-    EXPECT_EQ(string("DLM__"), reader_.getPrefix());
+    EXPECT_EQ(string("dlm__"), reader_.getPrefix());
 
     // And check that the parser fails on invalid prefixes...
     processLineException(reader_, "$prefix 1ABC", MSG_PRFINVARG);
 
-    // ... and rejects another valid one
-    processLineException(reader_, "$PREFIX ABC", MSG_DUPLPRFX);
-
     // Check that we can clear the prefix as well
     reader_.clearPrefix();
     EXPECT_EQ(string(""), reader_.getPrefix());
+
+    EXPECT_NO_THROW(reader_.processLine("$PREFIX   dlm__"));
+    EXPECT_EQ(string("dlm__"), reader_.getPrefix());
+    EXPECT_NO_THROW(reader_.processLine("$PREFIX"));
+    EXPECT_EQ(string(""), reader_.getPrefix());
 }
 
 // Check that it can parse a namespace
@@ -173,8 +184,8 @@ TEST_F(MessageReaderTest, Namespace) {
 TEST_F(MessageReaderTest, ValidMessageAddDefault) {
 
     // Add a couple of valid messages
-    reader_.processLine("GLOBAL1\t\tthis is message global one\n");
-    reader_.processLine("GLOBAL2 this is message global two");
+    reader_.processLine("% GLOBAL1\t\tthis is message global one\n");
+    reader_.processLine("%GLOBAL2 this is message global two");
 
     // ... and check them
     EXPECT_EQ(string("this is message global one"),
@@ -191,9 +202,9 @@ TEST_F(MessageReaderTest, ValidMessageAddDefault) {
 TEST_F(MessageReaderTest, ValidMessageAdd) {
 
     // Add a couple of valid messages
-    reader_.processLine("GLOBAL1\t\tthis is message global one\n",
+    reader_.processLine("%GLOBAL1\t\tthis is message global one\n",
         MessageReader::ADD);
-    reader_.processLine("GLOBAL2 this is message global two",
+    reader_.processLine("% GLOBAL2 this is message global two",
         MessageReader::ADD);
 
     // ... and check them
@@ -214,9 +225,9 @@ TEST_F(MessageReaderTest, ValidMessageReplace) {
     dictionary_->add("GLOBAL2", "original global2 message");
 
     // Replace a couple of valid messages
-    reader_.processLine("GLOBAL1\t\tthis is message global one\n",
+    reader_.processLine("% GLOBAL1\t\tthis is message global one\n",
         MessageReader::REPLACE);
-    reader_.processLine("GLOBAL2 this is message global two",
+    reader_.processLine("% GLOBAL2 this is message global two",
         MessageReader::REPLACE);
 
     // ... and check them
@@ -237,14 +248,14 @@ TEST_F(MessageReaderTest, ValidMessageReplace) {
 TEST_F(MessageReaderTest, Overflows) {
 
     // Add a couple of valid messages
-    reader_.processLine("GLOBAL1\t\tthis is message global one\n");
-    reader_.processLine("GLOBAL2 this is message global two");
+    reader_.processLine("% GLOBAL1\t\tthis is message global one\n");
+    reader_.processLine("% GLOBAL2 this is message global two");
 
     // Add a duplicate in ADD mode.
-    reader_.processLine("GLOBAL1\t\tthis is a replacement for global one");
+    reader_.processLine("% GLOBAL1\t\tthis is a replacement for global one");
 
     // Replace a non-existent one in REPLACE mode
-    reader_.processLine("LOCAL\t\tthis is a new message",
+    reader_.processLine("% LOCAL\t\tthis is a new message",
         MessageReader::REPLACE);
 
     // Check what is in the dictionary.

src/lib/log/tests/run_time_init_test.sh.in

@@ -29,48 +29,49 @@ passfail() {
 # Create the local message file for testing
 
 cat > $localmes << .
-NOTHERE     this message is not in the global dictionary
-MSGRDERR    replacement read error, parameters: '%s' and '%s'
-UNRECDIR    replacement unrecognised directive message, parameter is '%s'
+\$PREFIX MSG_
+% NOTHERE     this message is not in the global dictionary
+% READERR     replacement read error, parameters: '%1' and '%2'
+% RDLOCMES    replacement read local message file, parameter is '%1'
 .
 
 echo -n "1. runInitTest default parameters: "
 cat > $tempfile << .
-FATAL [alpha.example] MSGWRTERR, error writing to test1: 42
-ERROR [alpha.example] UNRECDIR, unrecognised directive 'false'
-WARN  [alpha.dlm] MSGRDERR, error reading from message file a.txt: dummy test
-INFO  [alpha.dlm] OPNMSGIN, unable to open message file example.msg for input: dummy test
+FATAL [alpha.example] MSG_WRITERR, error writing to test1: 42
+ERROR [alpha.example] MSG_RDLOCMES, reading local message file dummy/file
+WARN  [alpha.dlm] MSG_READERR, error reading from message file a.txt: dummy reason
+INFO  [alpha.dlm] MSG_OPENIN, unable to open message file example.msg for input: dummy reason
 .
 ./logger_support_test | cut -d' ' -f3- | diff $tempfile -
 passfail $?
 
 echo -n "2. Severity filter: "
 cat > $tempfile << .
-FATAL [alpha.example] MSGWRTERR, error writing to test1: 42
-ERROR [alpha.example] UNRECDIR, unrecognised directive 'false'
+FATAL [alpha.example] MSG_WRITERR, error writing to test1: 42
+ERROR [alpha.example] MSG_RDLOCMES, reading local message file dummy/file
 .
 ./logger_support_test -s error | cut -d' ' -f3- | diff $tempfile -
 passfail $?
 
 echo -n "3. Debug level: "
 cat > $tempfile << .
-FATAL [alpha.example] MSGWRTERR, error writing to test1: 42
-ERROR [alpha.example] UNRECDIR, unrecognised directive 'false'
-WARN  [alpha.dlm] MSGRDERR, error reading from message file a.txt: dummy test
-INFO  [alpha.dlm] OPNMSGIN, unable to open message file example.msg for input: dummy test
-DEBUG [alpha.example] UNRECDIR, unrecognised directive '[abc]'
-DEBUG [alpha.example] UNRECDIR, unrecognised directive '[24]'
-DEBUG [alpha.example] UNRECDIR, unrecognised directive '[25]'
+FATAL [alpha.example] MSG_WRITERR, error writing to test1: 42
+ERROR [alpha.example] MSG_RDLOCMES, reading local message file dummy/file
+WARN  [alpha.dlm] MSG_READERR, error reading from message file a.txt: dummy reason
+INFO  [alpha.dlm] MSG_OPENIN, unable to open message file example.msg for input: dummy reason
+DEBUG [alpha.example] MSG_RDLOCMES, reading local message file dummy/0
+DEBUG [alpha.example] MSG_RDLOCMES, reading local message file dummy/24
+DEBUG [alpha.example] MSG_RDLOCMES, reading local message file dummy/25
 .
 ./logger_support_test -s debug -d 25 | cut -d' ' -f3- | diff $tempfile -
 passfail $?
 
 echo -n "4. Local message replacement: "
 cat > $tempfile << .
-WARN  [alpha.log] IDNOTFND, could not replace message for 'NOTHERE': no such message identification
-FATAL [alpha.example] MSGWRTERR, error writing to test1: 42
-ERROR [alpha.example] UNRECDIR, replacement unrecognised directive message, parameter is 'false'
-WARN  [alpha.dlm] MSGRDERR, replacement read error, parameters: 'a.txt' and 'dummy test'
+WARN  [alpha.log] MSG_IDNOTFND, could not replace message text for 'MSG_NOTHERE': no such message
+FATAL [alpha.example] MSG_WRITERR, error writing to test1: 42
+ERROR [alpha.example] MSG_RDLOCMES, replacement read local message file, parameter is 'dummy/file'
+WARN  [alpha.dlm] MSG_READERR, replacement read error, parameters: 'a.txt' and 'dummy reason'
 .
 ./logger_support_test -s warn $localmes | cut -d' ' -f3- | diff $tempfile -
 passfail $?

src/lib/util/unittests/testdata.h

@@ -34,6 +34,14 @@ void addTestDataPath(const std::string& path);
 /// addTestDataPath().  On success, ifs will be ready for reading the data
 /// stored in 'datafile'.  If the data file cannot be open with any of the
 /// registered paths, a runtime_error exception will be thrown.
+///
+/// \note Care should be taken if you want to reuse the same single \c ifs
+/// for multiple input data.  Some standard C++ library implementations retain
+/// the failure bit if the first stream reaches the end of the first file,
+/// and make the second call to \c ifstream::open() fail.  The safest way
+/// is to use a different \c ifstream object for a new call to this function;
+/// alternatively make sure you explicitly clear the error bit by calling
+/// \c ifstream::clear() on \c ifs.
 void openTestData(const char* const datafile, std::ifstream& ifs);
 }
 }