Performance
The study presented here compares the performance of Pantheios with
eight other "competitor"1
diagnostic logging libraries, in eight different scenarios.
Competitors
The "competitors"1 include
five established diagnostic logging libraries:
along with three custom written for the performance test:
-
IOStreams - using a custom streambuf.
-
logprintf_post() - a syslog()-like
function that checks the log statement severity level after
preparing the statement for transport.
-
logprintf_pre() - a syslog()-like
function that checks the log statement severity level before
preparing the statement for transport.
(The purpose of these three artificial logging libraries is to inform
the interpretation of the results, by highlight what are (likely to be)
the fundamental costs of the two "de facto" formatting idioms:
IOStream insertion operators
and
printf()-family variadics. It's
worth pointing out that Pantheios uses a new and unique way of
handling string generalisation -
String Access Shims
- that is more generic, more type-safe and more efficient than these
"old" approaches, and is a significant factor in its superior
performance characteristics of all other diagnostic logging libraries, as
demonstrated here.)
Transport
In order to be free of the influence of any distorting effects of
the host environment, the file-system, or any particular transport
mechanisms, the transport selected in all cases is a stub, that
sends the message into the bit bucket, as follows:
| Diagnostic Logging Library |
Stub implementation |
| ACE |
A Null_Log class, derived from
ACE_Log_Msg_Callback, which is
implemented in terms of
null_output()2.
|
| Boost.log |
An appender function write_to_null(),
implemented in terms of
null_output()2.
|
| IOStreams |
A null_streambuf class, derived from
std::basic_streambuf, which is
implemented in terms of
null_output()2.
|
| log4cpp |
A custom-written NullAppender class, derived from
log4cpp::LayoutAppender, which is
implemented in terms of
null_output()2.
|
| log4cplus |
The log4cplus appender log4cplus::NullAppender().
|
| log4cxx |
A custom-written NullAppender class, derived from
log4cxx::AppenderSkeleton, which is
implemented in terms of
null_output()2.
|
| logprintf_post() |
A syslog()-like variadic function
logprintf_post(),
implemented in terms of
null_output()2.
|
| logprintf_pre() |
A syslog()-like variadic function
logprintf_pre(),
implemented in terms of
null_output()2.
|
| Pantheios |
The stock back-end be.null.
|
Scenarios
There are eight scenarios. The first seven consider a particular
specific type of information that may be logged, to illustrate
the different efficiencies of diagnostic logging libraries with respect to
the different kinds of data.
The last represents what we feel is a realistic scenario, involving
several logging statements including elements from the other
scenarios:
-
Scenario 8: A composite scenario
involving elements from Scenarios 1-7.
Each of the eight scenarios are listed in detail below, including
the code that comprises the Pantheios variant. All other variants
are functionally equivalent. Note that because Pantheios does
not require extra-statement severity testing to achieve its high
efficiency when logging is switched off, we do not do so with the
other diagnostic logging libraries. The advantage of Pantheios is that one
gets succinct and discoverable client code without sacrificing
performance; other libraries do not (and cannot) offer this.
Note: the full source code for all the scenarios presented here
is available
here.
Scenario 1 - A single string
This scenario attempts to quantify the relative performances of
the competitors in handling a statement with a single string. This
will not involve any statement formatting, so should offer a
reasonable indication as to the basic cost of each library's
application -> back-end cost.
The Pantheios code (minus namespace qualifications) for this
scenario is:
log(emergency, "statement for Pantheios performance test scenario #1");
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 1.
Scenario 2 - Several string instances
This scenario attempts to quantify the relative performances of
the competitors in handling a statement with instances of several
string types.
The Pantheios code (minus namespace qualifications) for this
scenario is:
static const char arg_0[] = "arg0";
static const std::string arg_1("arg1");
static const std::runtime_error arg_2("arg2");
static const char* arg_3 = "arg3";
static const stlsoft::simple_string arg_4("arg4");
log( emergency
, "This is a string based example, with ", arg_0, ", ", arg_1, ", "
, arg_2, ", ", arg_3, ", and ", arg_4);
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 2.
Scenario 3 - Several numeric type instances
This scenario attempts to quantify the relative performances of
the competitors in handling a statement with instances of several
numeric types.
The Pantheios code (minus namespace qualifications) for this
scenario is:
static const long arg_0 = -1234;
static const double arg_1 = 98.765;
static const unsigned int arg_2 = 0x33110022;
log( emergency
, "This contains a long ("
, integer(arg_0)
, "), a double ("
, real(arg_1)
, ") and an unsigned integer ("
, integer(arg_2, fmt::fullHex | 8)
, ")");
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 3.
Scenario 4 - A pointer, and a blob
In this scenario a pointer and a blob are logged. (In our experience)
logging of blobs is a common activity in application logging, esp. in
network servers.
The Pantheios code (minus namespace qualifications) for this
scenario is:
static const void* arg_0 = reinterpret_cast<void const*>(0x01234567);
static const int arg_1[] =
{
-1, 1, -2, 2, -3, 3, -4, 4
, -5, 5, -6, 6, -7, 7, -8, 8
, -9, 9, -10, 10, -11, 11, -12, 12
, -13, 13, -14, 14, -15, 15, -16, 16
, -17, 17, -18, 18, -19, 19, -20, 20
};
log( emergency
, "This contains a pointer ("
, pointer(arg_0, fmt::hex)
, ") and a blob ("
, blob(arg_1, sizeof(arg_1), 2, " ")
, ")");
(The pantheios::blob inserter class
uses the stlsoft::format_bytes()
function, part of the STLSoft
libraries' Conversion library. For this scenario, the other
diagnostic logging libraries must call this directly. Even though it is a
very efficient formatting function, the implications of having to
call it before the decision to log is made is clear in the
results.)
The results, for 100,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 4.
Scenario 5 - A blob, in Base-64
Like Scenario 4 This scenario converts
a binary region, but does so in Base-64 format, using the
pantheios::b64 inserter class, which
is implemented in terms of
b64, a
separate Open-Source library.
The Pantheios code (minus namespace qualifications) for this
scenario is:
static const int arg_0[] =
{
-1, 1, -2, 2, -3, 3, -4, 4
, -5, 5, -6, 6, -7, 7, -8, 8
, -9, 9, -10, 10, -11, 11, -12, 12
, -13, 13, -14, 14, -15, 15, -16, 16
, -17, 17, -18, 18, -19, 19, -20, 20
};
log( emergency
, "This contains a blob ("
, b64(arg_0, sizeof(arg_0))
, ") expressed in Base-64");
(The pantheios::b64 inserter class
uses the b64::encode()
function, part of the b64
library. For this scenario, the other
diagnostic logging libraries must call this directly. Even though the b64 library
is very efficient, the implications of having to
call it before the decision to log is made is clear in the
results.)
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 5.
Scenario 6 - A GUID, as an example of a non-string type that is implicitly understood by Pantheios
This scenario is an attempt at a simplest-possible example of
where the power of Pantheios truly imposes itself: in the (infinitely
extensible) set of non-string types that, by virtue of
String Access Shims,
are implicitly understood by Pantheios. (It is "simplest-possible" because
the conversion of a GUID is a small, fixed-complexity operation.)
The Pantheios code (minus namespace qualifications) for this
scenario is:
const GUID guid;
log(emergency, "This contains a guid (", guid, ")");
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 6.
Scenario 7 - A custom type: Person
This scenario illustrates the challenge presented to any diagnostic logging
library by the need to log instances of a custom type. The type
here is a Person class:
class Person
{
private:
typedef std::wstring string_type;
public:
Person(wchar_t const* forename, wchar_t const* surname, unsigned age);
public:
string_type const& forename() const;
string_type const& surname() const;
unsigned age() const;
private:
const string_type m_forename;
const string_type m_surname;
const unsigned m_age;
private:
Person &operator =(Person const&);
};
Note the added twist that Person's string types
are based on the wchar_t type, rather than
char. This means that all diagnostic logging libraries
have the additional task of converting the Person's
contents into char-based format prior to logging.
The Pantheios code (minus namespace qualifications) for this
scenario is:
const Person person(L"Dr", L"Proctor", 38);
log(emergency, "This contains a person (", person, ")");
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 7.
Scenario 8 - A composite scenario involving elements from Scenarios 1-7.
This scenario adds all the elements from the other scenarios into
the mix, along with a few other elements, such as time structure and
VARIANT instances. This constitutes a much more
representative comparison between the libraries because, obviously, a real
application that is using logging extensively will be logging lots of
different kinds of things, in different combinations.
The Pantheios code (minus namespace qualifications) for this
scenario is:
static const int packetData[] =
{
-1, 1, -2, 2, -3, 3, -4, 4
, -5, 5, -6, 6, -7, 7, -8, 8
, -9, 9, -10, 10, -11, 11, -12, 12
, -13, 13, -14, 14, -15, 15, -16, 16
, -17, 17, -18, 18, -19, 19, -20, 20
};
log(emergency, "starting ...");
short port = 513;
log(emergency, "Opening socket on port: ", pantheios::integer(port));
char host[] = "localhost";
log( emergency
, "Received packet from host {"
, host
, "}; contents=["
, blob(packetData, sizeof(packetData), 4, " ", 4, "\n")
, "]");
SYSTEMTIME tm;
VARIANT var;
::GetLocalTime(&tm);
::VariantInit(&var);
var.vt = VT_DATE;
var.date = 0;
log( emergency
, "The time now is: "
, tm
, "; the variant's value is: "
, var
, "; and the person responsible is: "
, person);
log(emergency, "exiting ...");
The results, for 1,000,000 iterations of this (and its equivalent
for the other libraries) are shown in Figure 8.
Conclusion
We're not going to draw any conclusion here. The results, which tally with
other studies we've conducted over the last couple of years, show that
Pantheios is 10-100+ times more efficient than any of the leading diagnostic logging
libraries currently in popular use. You can draw your own conclusions from
that.
One thing we will say is that the use of #ifdef DEBUG
conditional code has all but disappeared from our projects since we've
introduced Pantheios, because the virtually negligible cost of logging
(when switched off) means that there's no reason to make decisions at
compile-time that can be made at runtime.
[1] The word competitor is used here in its most benign form.
Pantheios is not intended to be a replacement for established,
feature-rich diagnostic logging libraries such as
ACE
and
log4cxx.
Although Pantheios contains plenty of
transport functionality
for
small/medium projects, it is ideally married with the rich logging
facilities of such established libraries. By using them in concert,
the user gains the best of both worlds: the unmatched performance
characteristics of Pantheios and the richness and flexibility of
the ACE, log4???, etc.
[2] To ensure that the stub implementations are representative of
the function calls that would be made in real diagnostic logging, all custom
implementations are made in terms of a
null_output()
function, defined as follows:
extern "C" void null_output(int severity, char const* entry, size_t cchEntry)
{
((void)severity);
((void)entry);
((void)cchEntry);
}
|
