Merge branch 'work/logpos'

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.msg
+	$(top_builddir)/src/lib/log/compiler/message $(top_srcdir)/src/lib/asiodns/asiodef.msg
+
+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,6 +26,8 @@ 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
 
+nodist_libasiodns_la_SOURCES = asiodef.cc asiodef.h
+
 EXTRA_DIST = asiodef.msg
 
 # Note: the ordering matters: -Wno-... must follow -Wextra (defined in

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.msg

@@ -15,42 +15,42 @@
 $PREFIX ASIODNS_
 $NAMESPACE isc::asiodns
 
-FETCHCOMP   upstream fetch to %s(%d) has now completed
+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 %s(%d) has been stopped
+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 %d opening %s socket to %s(%d)
+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 %d reading %s data from %s(%d)
+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 %d sending data using %s to %s(%d)
+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 %s(%d)
+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 %d (protocol: %s, address %s)
+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 (%d) when IOFetch::stop() was executed for I/O to %s(%d)
+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/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/log/Makefile.am

@@ -21,6 +21,8 @@ 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

@@ -96,7 +96,7 @@ An example file could be:
 
 $PREFIX TEST_
 $NAMESPACE isc::log
-TEST1       message %s is much too large
+TEST1       message %1 is much too large
 + This message is a test for the general message code
 
 UNKNOWN     unknown message
@@ -131,8 +131,8 @@ Points to note:
   part of the line.
 
 * 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.
+  include zero or more %1, %2...  placeholder tokens.  Symbol names will be
+  upper-cased by the compiler.
 
 
 Message Compiler
@@ -252,14 +252,14 @@ To use the current version of the logging:
 
 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.
 

src/lib/log/compiler/message.cc

@@ -261,7 +261,7 @@ writeHeaderFile(const string& file, const string& prefix,
         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);
@@ -358,7 +358,7 @@ writeProgramFile(const string& file, const string& prefix,
     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());
@@ -535,9 +535,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/log_formatter.cc

@@ -0,0 +1,42 @@
+// 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 <log/log_formatter.h>
+
+using namespace std;
+using namespace boost;
+
+namespace isc {
+namespace log {
+
+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 +
+                        "'@@");
+    }
+}
+
+}
+}

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

@@ -62,7 +62,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 +70,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 +82,11 @@ 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());
+            logger.error(ident).arg(args[0]).arg(args[1]);
         }
     }
 }
@@ -117,7 +117,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/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 Thu May  5 16:57:11 2011
 
 #include <cstddef>
 #include <log/message_types.h>
@@ -33,21 +33,21 @@ 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",
+    "DUPMSGID", "duplicate message ID (%1) in compiled code",
+    "IDNOTFND", "could not replace message for '%1': no such message identification",
+    "MSGRDERR", "error reading from message file %1: %2",
+    "MSGWRTERR", "error writing to %1: %2",
+    "NOMSGTXT", "a line containing a message ID ('%1') and nothing else was found",
     "NSEXTRARG", "$NAMESPACE directive has too many arguments",
-    "NSINVARG", "$NAMESPACE directive has an invalid argument ('%s')",
+    "NSINVARG", "$NAMESPACE directive has an invalid argument ('%1')",
     "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",
+    "OPNMSGIN", "unable to open message file %1 for input: %2",
+    "OPNMSGOUT", "unable to open %1 for output: %2",
     "PRFEXTRARG", "$PREFIX directive has too many arguments",
-    "PRFINVARG", "$PREFIX directive has an invalid argument ('%s')",
+    "PRFINVARG", "$PREFIX directive has an invalid argument ('%1')",
     "PRFNOARG", "no arguments were given to the $PREFIX directive",
-    "RDLOCMES", "reading local message file %s",
-    "UNRECDIR", "unrecognised directive '%s'",
+    "RDLOCMES", "reading local message file %1",
+    "UNRECDIR", "unrecognised directive '%1'",
     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 Thu May  5 16:57:11 2011
 
 #ifndef __MESSAGEDEF_H
 #define __MESSAGEDEF_H

src/lib/log/messagedef.mes

@@ -23,7 +23,7 @@ $NAMESPACE isc::log
 # 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
+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
@@ -44,7 +44,7 @@ DUPLPRFX    duplicate $PREFIX directive found
 + 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
+IDNOTFND    could not replace message for '%1': 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
@@ -55,10 +55,10 @@ IDNOTFND    could not replace message for '%s': no such message identification
 + 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
+MSGRDERR    error reading from message file %1: %2
 + The specified error was encountered reading from the named message file.
 
-MSGWRTERR   error writing to %s: %s
+MSGWRTERR   error writing to %1: %2
 + The specified error was encountered by the message compiler when writing to
 + the named output file.
 
@@ -67,13 +67,13 @@ NSEXTRARG  $NAMESPACE directive has too many arguments
 + 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')
+NSINVARG    $NAMESPACE directive has an invalid argument ('%1')
 + 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
+NOMSGTXT    a line containing a message ID ('%1') 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
@@ -84,11 +84,11 @@ NSNOARG     no arguments were given to the $NAMESPACE directive
 + 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
+OPNMSGIN     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.
 
-OPNMSGOUT   unable to open %s for output: %s
+OPNMSGOUT   unable to open %1 for output: %2
 + The program was not able to open the specified output file for the reason
 + given.
 
@@ -97,7 +97,7 @@ PRFEXTRARG  $PREFIX directive has too many arguments
 + 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')
+PRFINVARG   $PREFIX directive has an invalid argument ('%1')
 + 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
@@ -109,11 +109,11 @@ PRFNOARG    no arguments were given to the $PREFIX directive
 + 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
+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.)
 
-UNRECDIR    unrecognised directive '%s'
+UNRECDIR    unrecognised directive '%1'
 + 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,13 @@ 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_MSGWRTERR).arg("test1").arg("42");
+    LOG_ERROR(logger_ex, MSG_UNRECDIR).arg("false");
+    LOG_WARN(logger_dlm, MSG_MSGRDERR).arg("a.txt").arg("dummy test");
+    LOG_INFO(logger_dlm, MSG_OPNMSGIN).arg("example.msg").arg("dummy test");
+    LOG_DEBUG(logger_ex, 0, MSG_UNRECDIR).arg("[abc]");
+    LOG_DEBUG(logger_ex, 24, MSG_UNRECDIR).arg("[24]");
+    LOG_DEBUG(logger_ex, 25, MSG_UNRECDIR).arg("[25]");
+    LOG_DEBUG(logger_ex, 26, MSG_UNRECDIR).arg("[26]");
     return (0);
 }

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

@@ -30,8 +30,8 @@ passfail() {
 
 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'
+MSGRDERR    replacement read error, parameters: '%1' and '%2'
+UNRECDIR    replacement unrecognised directive message, parameter is '%1'
 .
 
 echo -n "1. runInitTest default parameters: "