Proposed qpid logging API

[Alan Conway <ac...@redhat.com>]

I haven't found a logging solution that blows me away, rlog looks like
the easiest for me to integrate. I propose to integrated it under a
single-macro QPID_LOG API the following one-macro logging API which is
type safe (ostream based), and should be efficiently implementable over
any logging infrastructure that is capable of not evaluating the log
message if no log will be generated.

rlog will let us retrieve logs by level, by component (arbirary
collection of source files), by individual source file or combinations
thereof. It has stderr and syslog backends built in and can be extended.
It can be configured to include source file/line, thread ID, function
name in logs. If it lets us down long term, we should be able to replace
easily since only QPID_LOG macros will be widely distributed.

(rlog actually offers hierarchical channels beyond simple log levels,
deliberately ignored to increase portability to future log
infrastructures.)

Comments welcome but I'm implementing right away so speak up!

Cheers,
Alan.

Re: Proposed qpid logging API

[Alan Conway <ac...@redhat.com>]

On Wed, 2007-05-09 at 16:03 +0100, Martin Ritchie wrote:
> Just a shame we can't use the same in the Java Broker, would have been
> good to have shared configuration files so we could get similar
> logging from both brokers with a single configuration.
> 
Agreed and not ruled out. My goal today is to establish an API for log
statements that can easily be re-implemented over other frameworks,
establish one low-impact-if-off implementation and get the code somewhat
instrumented so I can move on with other things. 

I think rlog is the fastest way to get there today but I don't think
it'll be the last or best logging option we'll support. In fact I will
provide a second non-rlog implementation to satisfy Apache's LGPL
phobia, so logging impl will be a real build-time option. I don't expect
alternate logging impls to have the same configuration - only that they
are source-compatible with the QPID_LOG macro so the impact of change is
local.

The amount of code I'm actually writing is *very* small, so I wont cry a
bit if someone wants to replace it with log4c?? or whatever in the
future. I do expect we'll settle on one "best" logging implementation at
some point not too far away but I gave up on this being it.

Cheers,
Alan.

> On 09/05/07, Alan Conway <ac...@redhat.com> wrote:
> > On Wed, 2007-05-09 at 07:53 -0400, Kim van der Riet wrote:
> > > Two silly questions:
> > Quite pertinent actually!
> >
> > > 1. What are the performance constraints on the logging infrastructure?
> > > Clearly, any logging activity that occurs in performance-critical
> > > sections of the code need to be closely looked at... Do we have a
> > > strategy for evaluating this for any proposed solution?
> >
> > My main criteria for now is near-zero overhead for disabled log
> > statements so we can reasonably leave logging in production code. rlog
> > is the best of the bunch in that regard, and probably at the theoretical
> > limit short of actually compiling them out: a single if (ptr!=0) (with
> > extra optimization hints for g++) - ends up about 3 machine instructions
> > on x86 for disabled logs.
> >
> > The other dimension is performance when logging is enabled, which
> > determines how much logging you can usefully turn on before things slow
> > to the point of uselessness. Pantheios is the winner here:
> > http://pantheios.sourceforge.net/performance.html but as the graphs show
> > the differences with logging enabled are not nearly as dramatic as the
> > logging off differences. The proposed QPID API will perform like the
> > IOStream column in those tests. The native rlog printf API would be
> > about the same (like logprintf in the graph).
> >
> > Rationale for the API:
> >  - Macro API is most flexible and easiest to wrap around other APIs.
> >  - Ostream formatting is type safe
> >  - Most "stringable" C++ types have ostream<< operators
> >  - boost::format provides printf formatting compatible with ostream.
> >
> > Rationale for rlog:
> >  - fastest in no-logging case
> >  - small but flexible and covers basics
> >  - I estimate will be quickest for me to implement in Qpid.
> >
> > Rlog is not "the" qpid logging framework, its just the first impl. I'll
> > do a brain-dead homegrown alternative to satisfy Apache licensing. We
> > can replace with another alterantive if/when we feel the need.
> >
> > > 2. Are there any reliability/write guarantees on logging, in other
> > > words, when some of the logging is sent to disk, is there any
> > > requirement that it must arrive there before continuing, or is it not an
> > > issue?
> >
> > Assume there are no guarantees at all. Logging (in this sense of the
> > overloaded word) is for debug/management purposes. It's best effort but
> > it should not take measures to be reliable that would slow the app down.
> >
> > Actual guarantees depend on how back-end is implemented, which I think
> > is regular buffered file writes or syslog calls depending on how you
> > configure.
> >
> > Cheers,
> > Alan.
> >
> >
> 
> 

Re: Proposed qpid logging API

[Martin Ritchie <ri...@apache.org>]

Just a shame we can't use the same in the Java Broker, would have been
good to have shared configuration files so we could get similar
logging from both brokers with a single configuration.

On 09/05/07, Alan Conway <ac...@redhat.com> wrote:
> On Wed, 2007-05-09 at 07:53 -0400, Kim van der Riet wrote:
> > Two silly questions:
> Quite pertinent actually!
>
> > 1. What are the performance constraints on the logging infrastructure?
> > Clearly, any logging activity that occurs in performance-critical
> > sections of the code need to be closely looked at... Do we have a
> > strategy for evaluating this for any proposed solution?
>
> My main criteria for now is near-zero overhead for disabled log
> statements so we can reasonably leave logging in production code. rlog
> is the best of the bunch in that regard, and probably at the theoretical
> limit short of actually compiling them out: a single if (ptr!=0) (with
> extra optimization hints for g++) - ends up about 3 machine instructions
> on x86 for disabled logs.
>
> The other dimension is performance when logging is enabled, which
> determines how much logging you can usefully turn on before things slow
> to the point of uselessness. Pantheios is the winner here:
> http://pantheios.sourceforge.net/performance.html but as the graphs show
> the differences with logging enabled are not nearly as dramatic as the
> logging off differences. The proposed QPID API will perform like the
> IOStream column in those tests. The native rlog printf API would be
> about the same (like logprintf in the graph).
>
> Rationale for the API:
>  - Macro API is most flexible and easiest to wrap around other APIs.
>  - Ostream formatting is type safe
>  - Most "stringable" C++ types have ostream<< operators
>  - boost::format provides printf formatting compatible with ostream.
>
> Rationale for rlog:
>  - fastest in no-logging case
>  - small but flexible and covers basics
>  - I estimate will be quickest for me to implement in Qpid.
>
> Rlog is not "the" qpid logging framework, its just the first impl. I'll
> do a brain-dead homegrown alternative to satisfy Apache licensing. We
> can replace with another alterantive if/when we feel the need.
>
> > 2. Are there any reliability/write guarantees on logging, in other
> > words, when some of the logging is sent to disk, is there any
> > requirement that it must arrive there before continuing, or is it not an
> > issue?
>
> Assume there are no guarantees at all. Logging (in this sense of the
> overloaded word) is for debug/management purposes. It's best effort but
> it should not take measures to be reliable that would slow the app down.
>
> Actual guarantees depend on how back-end is implemented, which I think
> is regular buffered file writes or syslog calls depending on how you
> configure.
>
> Cheers,
> Alan.
>
>


-- 
Martin Ritchie

Re: Proposed qpid logging API

[Alan Conway <ac...@redhat.com>]

On Wed, 2007-05-09 at 07:53 -0400, Kim van der Riet wrote:
> Two silly questions:
Quite pertinent actually!

> 1. What are the performance constraints on the logging infrastructure?
> Clearly, any logging activity that occurs in performance-critical
> sections of the code need to be closely looked at... Do we have a
> strategy for evaluating this for any proposed solution? 

My main criteria for now is near-zero overhead for disabled log
statements so we can reasonably leave logging in production code. rlog
is the best of the bunch in that regard, and probably at the theoretical
limit short of actually compiling them out: a single if (ptr!=0) (with
extra optimization hints for g++) - ends up about 3 machine instructions
on x86 for disabled logs.

The other dimension is performance when logging is enabled, which
determines how much logging you can usefully turn on before things slow
to the point of uselessness. Pantheios is the winner here:
http://pantheios.sourceforge.net/performance.html but as the graphs show
the differences with logging enabled are not nearly as dramatic as the
logging off differences. The proposed QPID API will perform like the
IOStream column in those tests. The native rlog printf API would be
about the same (like logprintf in the graph).

Rationale for the API:
 - Macro API is most flexible and easiest to wrap around other APIs.
 - Ostream formatting is type safe
 - Most "stringable" C++ types have ostream<< operators
 - boost::format provides printf formatting compatible with ostream.

Rationale for rlog:
 - fastest in no-logging case
 - small but flexible and covers basics
 - I estimate will be quickest for me to implement in Qpid.

Rlog is not "the" qpid logging framework, its just the first impl. I'll
do a brain-dead homegrown alternative to satisfy Apache licensing. We
can replace with another alterantive if/when we feel the need.

> 2. Are there any reliability/write guarantees on logging, in other
> words, when some of the logging is sent to disk, is there any
> requirement that it must arrive there before continuing, or is it not an
> issue?

Assume there are no guarantees at all. Logging (in this sense of the
overloaded word) is for debug/management purposes. It's best effort but
it should not take measures to be reliable that would slow the app down.

Actual guarantees depend on how back-end is implemented, which I think
is regular buffered file writes or syslog calls depending on how you
configure.

Cheers,
Alan.

Re: Proposed qpid logging API

[Kim van der Riet <ki...@redhat.com>]

Two silly questions:

1. What are the performance constraints on the logging infrastructure?
Clearly, any logging activity that occurs in performance-critical
sections of the code need to be closely looked at... Do we have a
strategy for evaluating this for any proposed solution?

2. Are there any reliability/write guarantees on logging, in other
words, when some of the logging is sent to disk, is there any
requirement that it must arrive there before continuing, or is it not an
issue?

Kim

On Tue, 2007-05-08 at 18:19 -0400, Alan Conway wrote:
> I haven't found a logging solution that blows me away, rlog looks like
> the easiest for me to integrate. I propose to integrated it under a
> single-macro QPID_LOG API the following one-macro logging API which is
> type safe (ostream based), and should be efficiently implementable over
> any logging infrastructure that is capable of not evaluating the log
> message if no log will be generated.
> 
> rlog will let us retrieve logs by level, by component (arbirary
> collection of source files), by individual source file or combinations
> thereof. It has stderr and syslog backends built in and can be extended.
> It can be configured to include source file/line, thread ID, function
> name in logs. If it lets us down long term, we should be able to replace
> easily since only QPID_LOG macros will be widely distributed.
> 
> (rlog actually offers hierarchical channels beyond simple log levels,
> deliberately ignored to increase portability to future log
> infrastructures.)
> 
> Comments welcome but I'm implementing right away so speak up!
> 
> Cheers,
> Alan.
> 
>