Logging replacement

Submitted by snrkiwi on Mon, 2009-09-28 12:55

RTT-dev

From recent ML discussions, and Peter's concluding email, RTT 2.x
will contain an alternative logging functionality. My question is,
what should it do ...? At the every least, it should support the same
functionality that the current RTT::Logger class provides, but several
issues were identified on the ML that people believe that RTT needs to
support.

So please discuss, critique or compliment the following ... they are
approximately in order of priority, in my mind at least.

0) Completely disable all logging
1) Able log variable sized string messages
2) Able log from non-realtime and realtime code
3) Minimize (as reasonably practicable) the effect on runtime
performance (eg minimize CPU cycles consumed)
4) Support different log levels
5) Support different "storage mediums" (ie able to log messages to
file, to socket, to stdout)

** bar 3, and the "realtime" part of 2, the above is the
functionality of the existing RTT::Logger **

6) Support different log levels within a deployed system (ie able to
log debug in one area, and info in another)
7) Support multiple storage mediums simultaneously at runtime
8) Runtime configuration of storage mediums and logging levels
9) Allow the user to extend the possible storage mediums at deployment-
time (ie user can provide new storage class)

Optional IMHO
10) Support nested diagnostic contexts [1] [2] (a more advanced
version of the Logger::In() that RTT's logger currently supports)

Stephen

[1] http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/NDC.html
[2] Patterns for Logging Diagnostic Messages Abstract Introduction

Logging replacement

Submitted by sspr on Thu, 2009-10-01 09:30.

2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
> From recent ML discussions, and Peter's concluding email, RTT 2.x will contain an alternative logging functionality. My question is, what should it do ...? At the every least, it should support the same functionality that the current RTT::Logger class provides, but several issues were identified on the ML that people believe that RTT needs to support.

It's not RTT. It's OCL that needs to support this by means of a
component and component interface. Component interfaces should be as
easy to use as native RTT classes, although we don't support C++
operators, nor overloading (yet) in the component interface. The
stuff you require below is the description of a service (ie interface)
a logging component is offering.

> So please discuss, critique or compliment the following ... they are approximately in order of priority, in my mind at least.
> 0) Completely disable all logging
> 1) Able log variable sized string messages
> 2) Able log from non-realtime and realtime code
> 3) Minimize (as reasonably practicable) the effect on runtime performance (eg minimize CPU cycles consumed)
> 4) Support different log levels
> 5) Support different "storage mediums" (ie able to log messages to file, to socket, to stdout)
> ** bar 3, and the "realtime" part of 2, the above is the functionality of the existing RTT::Logger **
> 6) Support different log levels within a deployed system (ie able to log debug in one area, and info in another)
> 7) Support multiple storage mediums simultaneously at runtime
> 8) Runtime configuration of storage mediums and logging levels
> 9) Allow the user to extend the possible storage mediums at deployment-time (ie user can provide new storage class)
> Optional IMHO
> 10) Support nested diagnostic contexts [1] [2] (a more advanced version of the Logger::In() that RTT's logger currently supports)

I think this is already a fairly complete list of requirements. What
you're missing is to distribute your logging, which is trivial/implied
if logging is a component service.

If you want different loglevels per 'component' you need a means to
attach an id to a message, so it looks like you need to setup a
message (with id and loglevel) and then send that at once to the
logger.

logservice.log( logmessage(Info, this->getName() ) << "my message" );

? Where logmessage() helps us in creating a LogMessage struct to send
over the wire, log is a method or message and logservice is
representing our OCL component.

Peter

Logging replacement

Submitted by snrkiwi on Thu, 2009-10-01 12:50.

On Oct 1, 2009, at 05:24 , Peter Soetens wrote:

> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>> From recent ML discussions, and Peter's concluding email, RTT 2.x
>> will contain an alternative logging functionality. My question is,
>> what should it do ...? At the every least, it should support the
>> same functionality that the current RTT::Logger class provides, but
>> several issues were identified on the ML that people believe that
>> RTT needs to support.
>
> It's not RTT. It's OCL that needs to support this by means of a
> component and component interface. Component interfaces should be as
> easy to use as native RTT classes, although we don't support C++
> operators, nor overloading (yet) in the component interface. The
> stuff you require below is the description of a service (ie interface)
> a logging component is offering.

So you see the back end stuff (the "storage mediums" below, or
appenders in log4j/log4cpp-speak) in OCL. That makes sense. But I
presume that RTT will also make use of this logging system?

>> So please discuss, critique or compliment the following ... they
>> are approximately in order of priority, in my mind at least.
>> 0) Completely disable all logging
>> 1) Able log variable sized string messages
>> 2) Able log from non-realtime and realtime code
>> 3) Minimize (as reasonably practicable) the effect on runtime
>> performance (eg minimize CPU cycles consumed)
>> 4) Support different log levels
>> 5) Support different "storage mediums" (ie able to log messages to
>> file, to socket, to stdout)
>> ** bar 3, and the "realtime" part of 2, the above is the
>> functionality of the existing RTT::Logger **
>> 6) Support different log levels within a deployed system (ie able
>> to log debug in one area, and info in another)
>> 7) Support multiple storage mediums simultaneously at runtime
>> 8) Runtime configuration of storage mediums and logging levels
>> 9) Allow the user to extend the possible storage mediums at
>> deployment-time (ie user can provide new storage class)
>> Optional IMHO
>> 10) Support nested diagnostic contexts [1] [2] (a more advanced
>> version of the Logger::In() that RTT's logger currently supports)
>
> I think this is already a fairly complete list of requirements. What
> you're missing is to distribute your logging, which is trivial/implied
> if logging is a component service.

Agreed. What precisely are you thinking of with "distributed"?

> If you want different loglevels per 'component' you need a means to
> attach an id to a message, so it looks like you need to setup a
> message (with id and loglevel) and then send that at once to the
> logger.
>
> logservice.log( logmessage(Info, this->getName() ) << "my message" );
>
> ? Where logmessage() helps us in creating a LogMessage struct to send
> over the wire, log is a method or message and logservice is
> representing our OCL component.

You could do it a similar but different way, in that when you get the
logservice within a component you specify the ID. Somewhere else has
configured the log level per ID (they're categories in log4j, loggers
in logback). Then the local service code decides whether to log for
this ID, bundles up the data into a LogMessage, and then transfers the
message off to the appropriate backend logging component (realising
that multiple possible backends may be in use).

Looking at OSGi (Herman's suggestion), it appears to be a component-
or service-oriented wrapper around log4j/logback style frameworks. I
think we need the same thing. I will reiterate what I said in a
previous email - I believe that rewriting an entire logging framework
from scratch, rather than wrapping/modifying an existing mature
framework, is perilous and time consuming. Having said that, we better
make a good decision in which framework to use! (and I noticed recent
Xenomai ML traffic, Peter, in talking of not trusting tests when re-
using existing packages. Definitely applies here, particularly to TLSF).

So, assuming we agree on this model, check out http://logback.qos.ch/manual/architecture.html
for a reasonable introduction to existing Java logging frameworks (I
use java ones here, as the good C++ logging frameworks I know of are
all based on the java ones. Java did it "right" first)

A framework consists of loggers (categories in log4j), layouts and
appenders. Lets ignore layouts for now. A component would obtain/
create/use a logger instance for a given ID (say
"org.orocos.ocl.deployment"). The component logs to that logger

RTT::rtstring message;
message << "some stuff here"
myLogger.debug(message)

Internally, the logger decides whether to log (based on its level, or
the level of its parent loggers) and then passes off the log message
to all associated appenders (if this message is to be logged). The
appenders would exist in other components, and do what they do with
the message (eg log to console, write to file, send over socket).

So the "OCL logging service" would consist of

a) a way for components to create/obtain/use loggers
b) appenders that reside in components
c) configuration of the above (ie levels per loggers, attaching
appenders to loggers, and factory creation of appenders - all done at
deployment time)

The actual modifications/extensions would be

1) use RTT::rtstring instead of std::string [RTT addition, logging
framework change]
2) pass log messages from loggers to appenders over RTT's data flow
implementation [logging framework extension]
3) provide default appenders that exist within components (say, a
console appender and a write-to-file appender, for starters) [OCL]
4) provide configuration of the logging service via the deployer (I
don't yet have a firm handle on how to do this, but I don't anticipate
it being complicated). [OCL]
5) make sure the logging framework works in real-time and is multi-
thread safe [logging framework change]. Most of the frameworks I've
seen already support multi-thread, and some provide an abstraction of
the actual threading/mutex environment (eg posix vs xxx)

I think 2 is the hardest part of the above, and 5 is the biggest
uncertainty (and hence potentially the nightmare part).

Note also that loggers/categories exist in a tree hierarchy. Very
handy for turning on/off logging in certain parts of a program. Say
you have loggers in a large app like

org.me.myapp.component1
org.me.myapp.component2
org.me.myapp.component3.a
org.me.myapp.component3.b

You can set an overall log level for all categories simply by
specifying it at the root.

org.me.loglevel = warn

and then turn on/off only certain parts if required

org.me.loglevel = info
org.me.myapp.component3.b.loglevel = debug

Also note that there are several performance optimizations available
to, for example, avoid creating "message" above when myLogger.debug()
won't log anyway, and similar things. I'm concentrating here on
getting the overall system laid out, not the tiny details. We can
discuss those as we proceed.

Cheers
Stephen

Logging replacement

Submitted by sspr on Fri, 2009-10-02 08:50.

On Thu, Oct 1, 2009 at 14:44, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>
>> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>>>
>>> From recent ML discussions, and Peter's concluding email, RTT 2.x will
>>> contain an alternative logging functionality. My question is, what should it
>>> do ...? At the every least, it should support the same functionality that
>>> the current RTT::Logger class provides, but several issues were identified
>>> on the ML that people believe that RTT needs to support.
>>
>> It's not RTT. It's OCL that needs to support this by means of a
>> component and component interface. Component interfaces should be as
>> easy to use as native RTT classes, although we don't support C++
>> operators, nor overloading (yet) in the component interface. The
>> stuff you require below is the description of a service (ie interface)
>> a logging component is offering.
>
> So you see the back end stuff (the "storage mediums" below, or appenders in
> log4j/log4cpp-speak) in OCL. That makes sense. But I presume that RTT will
> also make use of this logging system?

Ideally it would, but I don't have the time budget yet to change RTT
over. There could be a very lightweight appender that replaces the
Logger for the simple/getting started/embedded cases.

>
>>> So please discuss, critique or compliment the following ... they are
>>> approximately in order of priority, in my mind at least.
>>> 0) Completely disable all logging
>>> 1) Able log variable sized string messages
>>> 2) Able log from non-realtime and realtime code
>>> 3) Minimize (as reasonably practicable) the effect on runtime performance
>>> (eg minimize CPU cycles consumed)
>>> 4) Support different log levels
>>> 5) Support different "storage mediums" (ie able to log messages to file,
>>> to socket, to stdout)
>>> ** bar 3, and the "realtime" part of 2, the above is the functionality
>>> of the existing RTT::Logger **
>>> 6) Support different log levels within a deployed system (ie able to log
>>> debug in one area, and info in another)
>>> 7) Support multiple storage mediums simultaneously at runtime
>>> 8) Runtime configuration of storage mediums and logging levels
>>> 9) Allow the user to extend the possible storage mediums at
>>> deployment-time (ie user can provide new storage class)
>>> Optional IMHO
>>> 10) Support nested diagnostic contexts [1] [2] (a more advanced version
>>> of the Logger::In() that RTT's logger currently supports)
>>
>> I think this is already a fairly complete list of requirements. What
>> you're missing is to distribute your logging, which is trivial/implied
>> if logging is a component service.
>
> Agreed. What precisely are you thinking of with "distributed"?

Nothing extra compared to what RTT can offer already: multiple loggers
gathering logs from multiple components, independent of on which node
which component lives.

>
>> If you want different loglevels per 'component' you need a means to
>> attach an id to a message, so it looks like you need to setup a
>> message (with id and loglevel) and then send that at once to the
>> logger.
>>
>> logservice.log( logmessage(Info, this->getName() ) << "my message" );
>>
>> ? Where logmessage() helps us in creating a LogMessage struct to send
>> over the wire, log is a method or message and logservice is
>> representing our OCL component.
>
> You could do it a similar but different way, in that when you get the
> logservice within a component you specify the ID. Somewhere else has
> configured the log level per ID (they're categories in log4j, loggers in
> logback). Then the local service code decides whether to log for this ID,
> bundles up the data into a LogMessage, and then transfers the message off to
> the appropriate backend logging component (realising that multiple possible
> backends may be in use).

Markus is right that data flow ports already offer this distribution,
multiplexing and buffering capability (once an input can receive
messages from multiple outputs! ) Now that I think of it, data flow
ports would even be required in case you want to log from a real-time
thread to a distributed logging service. The log4j Logger is always
local (to the class even), but it needs to send the message directly
to a (remote) backend. I'm not sure how well log4j will allow to be
adapted to do this over RTT primitives...

>
> Looking at OSGi (Herman's suggestion), it appears to be a component- or
> service-oriented wrapper around log4j/logback style frameworks. I think we
> need the same thing. I will reiterate what I said in a previous email - I
> believe that rewriting an entire logging framework from scratch, rather than
> wrapping/modifying an existing mature framework, is perilous and time
> consuming. Having said that, we better make a good decision in which
> framework to use! (and I noticed recent Xenomai ML traffic, Peter, in
> talking of not trusting tests when re-using existing packages. Definitely
> applies here, particularly to TLSF).

For clarity, the only thing we *should* be doing is thinking up an
Orocos component interface that maps to and delegates all logging
requests to an existing logging framework. In terms of log4j, the
Logger would be always local, the appender local or remote.

>
> So, assuming we agree on this model, check out
> http://logback.qos.ch/manual/architecture.html for a reasonable introduction
> to existing Java logging frameworks (I use java ones here, as the good C++
> logging frameworks I know of are all based on the java ones. Java did it
> "right" first)
>
> A framework consists of loggers (categories in log4j), layouts and
> appenders. Lets ignore layouts for now. A component would obtain/create/use
> a logger instance for a given ID (say "org.orocos.ocl.deployment"). The
> component logs to that logger
>
> RTT::rtstring message;
> message << "some stuff here"

(message would need to be an rt_stringstream)

> myLogger.debug(message)
>
> Internally, the logger decides whether to log (based on its level, or the
> level of its parent loggers) and then passes off the log message to all

Can a parent be remote or is this always a local concept ? Are the
hierarchies spanning multiple systems or are most loggers only for
in-process logging.?

> associated appenders (if this message is to be logged). The appenders would
> exist in other components, and do what they do with the message (eg log to
> console, write to file, send over socket).

ok.

>
> So the "OCL logging service" would consist of
>
> a) a way for components to create/obtain/use loggers
> b) appenders that reside in components
> c) configuration of the above (ie levels per loggers, attaching appenders to
> loggers, and factory creation of appenders - all done at deployment time)

ok.

>
> The actual modifications/extensions would be
>
> 1) use RTT::rtstring instead of std::string [RTT addition, logging framework
> change]
> 2) pass log messages from loggers to appenders over RTT's data flow
> implementation [logging framework extension]

The problem I see is that there might be more going on between loggers
and appenders than just passing messages. It will be very dependent on
the existing logging framework...

> 3) provide default appenders that exist within components (say, a console
> appender and a write-to-file appender, for starters) [OCL]
> 4) provide configuration of the logging service via the deployer (I don't
> yet have a firm handle on how to do this, but I don't anticipate it being
> complicated). [OCL]
> 5) make sure the logging framework works in real-time and is multi-thread
> safe [logging framework change]. Most of the frameworks I've seen already
> support multi-thread, and some provide an abstraction of the actual
> threading/mutex environment (eg posix vs xxx)
>
> I think 2 is the hardest part of the above, and 5 is the biggest uncertainty
> (and hence potentially the nightmare part).

We would like to think otherwise, but experience confirms your fears :-)

I start to get the picture, we'll have to find the balance between
re-use of RTT (data flow, etc) and re-use of a logger framework.

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-02 12:20.

On Oct 2, 2009, at 04:48 , Peter Soetens wrote:

> On Thu, Oct 1, 2009 at 14:44, Stephen Roderick <kiwi [dot] net [..] ...>
> wrote:
>> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>>
>>> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>>>>
>>>> From recent ML discussions, and Peter's concluding email, RTT 2.x
>>>> will
>>>> contain an alternative logging functionality. My question is,
>>>> what should it
>>>> do ...? At the every least, it should support the same
>>>> functionality that
>>>> the current RTT::Logger class provides, but several issues were
>>>> identified
>>>> on the ML that people believe that RTT needs to support.
>>>
>>> It's not RTT. It's OCL that needs to support this by means of a
>>> component and component interface. Component interfaces should be as
>>> easy to use as native RTT classes, although we don't support C++
>>> operators, nor overloading (yet) in the component interface. The
>>> stuff you require below is the description of a service (ie
>>> interface)
>>> a logging component is offering.
>>
>> So you see the back end stuff (the "storage mediums" below, or
>> appenders in
>> log4j/log4cpp-speak) in OCL. That makes sense. But I presume that
>> RTT will
>> also make use of this logging system?
>
> Ideally it would, but I don't have the time budget yet to change RTT
> over. There could be a very lightweight appender that replaces the
> Logger for the simple/getting started/embedded cases.

My thought has been (without any real depth to it yet) to consider
replacing the implementation of RTT::Logger with something that calls
into the new logging system. A pipe dream maybe but ...

<sni

>> myLogger.debug(message)
>>
>> Internally, the logger decides whether to log (based on its level,
>> or the
>> level of its parent loggers) and then passes off the log message to
>> all
>
> Can a parent be remote or is this always a local concept ? Are the
> hierarchies spanning multiple systems or are most loggers only for
> in-process logging.?

I had not considered that. Using a logger hierarchy spread amongst
processes. At first glance that strikes me as really difficult,
but ... ? Do you have a specific use case in mind here?

<sni

>> 3) provide default appenders that exist within components (say, a
>> console
>> appender and a write-to-file appender, for starters) [OCL]
>> 4) provide configuration of the logging service via the deployer (I
>> don't
>> yet have a firm handle on how to do this, but I don't anticipate it
>> being
>> complicated). [OCL]
>> 5) make sure the logging framework works in real-time and is multi-
>> thread
>> safe [logging framework change]. Most of the frameworks I've seen
>> already
>> support multi-thread, and some provide an abstraction of the actual
>> threading/mutex environment (eg posix vs xxx)
>>
>> I think 2 is the hardest part of the above, and 5 is the biggest
>> uncertainty
>> (and hence potentially the nightmare part).
>
> We would like to think otherwise, but experience confirms your
> fears :-)

Once burned, twice shy ... :-)

> I start to get the picture, we'll have to find the balance between
> re-use of RTT (data flow, etc) and re-use of a logger framework.

Agreed. That's part of what I'm trying to hash out with these
discussion ...
Stephen

Logging replacement

Submitted by sspr on Fri, 2009-10-02 12:30.

On Fri, Oct 2, 2009 at 14:16, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
> On Oct 2, 2009, at 04:48 , Peter Soetens wrote:
>
>> On Thu, Oct 1, 2009 at 14:44, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
>>>
>>> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>>>
>>>> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>>>>>
>>>>> From recent ML discussions, and Peter's concluding email, RTT 2.x will
>>>>> contain an alternative logging functionality. My question is, what
>>>>> should it
>>>>> do ...? At the every least, it should support the same functionality
>>>>> that
>>>>> the current RTT::Logger class provides, but several issues were
>>>>> identified
>>>>> on the ML that people believe that RTT needs to support.
>>>>
>>>> It's not RTT. It's OCL that needs to support this by means of a
>>>> component and component interface. Component interfaces should be as
>>>> easy to use as native RTT classes, although we don't support C++
>>>> operators, nor overloading (yet) in the component interface. The
>>>> stuff you require below is the description of a service (ie interface)
>>>> a logging component is offering.
>>>
>>> So you see the back end stuff (the "storage mediums" below, or appenders
>>> in
>>> log4j/log4cpp-speak) in OCL. That makes sense. But I presume that RTT
>>> will
>>> also make use of this logging system?
>>
>> Ideally it would, but I don't have the time budget yet to change RTT
>> over. There could be a very lightweight appender that replaces the
>> Logger for the simple/getting started/embedded cases.
>
> My thought has been (without any real depth to it yet) to consider replacing
> the implementation of RTT::Logger with something that calls into the new
> logging system. A pipe dream maybe but ...
>
> <sni

>
>>> myLogger.debug(message)
>>>
>>> Internally, the logger decides whether to log (based on its level, or the
>>> level of its parent loggers) and then passes off the log message to all
>>
>> Can a parent be remote or is this always a local concept ? Are the
>> hierarchies spanning multiple systems or are most loggers only for
>> in-process logging.?
>
> I had not considered that. Using a logger hierarchy spread amongst
> processes. At first glance that strikes me as really difficult, but ... ? Do
> you have a specific use case in mind here?
>

I probably had a wrong view. I thought you had to assign a single root
logger for the whole system, but this can probably be done per process
as well; will duplicate effort per process, for example:

rtt.level = info
org.me.level = debug

can only be set per process, not system wide ?

Anyway I think it's better to not cross process boundaries for looking
up 'parent' log levels. Pushing from parent to a child is an option,
but can be added later on as well.

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-02 12:40.

On Oct 2, 2009, at 08:24 , Peter Soetens wrote:

> On Fri, Oct 2, 2009 at 14:16, Stephen Roderick <kiwi [dot] net [..] ...>
> wrote:
>> On Oct 2, 2009, at 04:48 , Peter Soetens wrote:
>>
>>> On Thu, Oct 1, 2009 at 14:44, Stephen Roderick <kiwi [dot] net [..] ...>
>>> wrote:
>>>>
>>>> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>>>>
>>>>> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>>>>>>
>>>>>> From recent ML discussions, and Peter's concluding email, RTT
>>>>>> 2.x will
>>>>>> contain an alternative logging functionality. My question is,
>>>>>> what
>>>>>> should it
>>>>>> do ...? At the every least, it should support the same
>>>>>> functionality
>>>>>> that
>>>>>> the current RTT::Logger class provides, but several issues were
>>>>>> identified
>>>>>> on the ML that people believe that RTT needs to support.
>>>>>
>>>>> It's not RTT. It's OCL that needs to support this by means of a
>>>>> component and component interface. Component interfaces should
>>>>> be as
>>>>> easy to use as native RTT classes, although we don't support C++
>>>>> operators, nor overloading (yet) in the component interface. The
>>>>> stuff you require below is the description of a service (ie
>>>>> interface)
>>>>> a logging component is offering.
>>>>
>>>> So you see the back end stuff (the "storage mediums" below, or
>>>> appenders
>>>> in
>>>> log4j/log4cpp-speak) in OCL. That makes sense. But I presume that
>>>> RTT
>>>> will
>>>> also make use of this logging system?
>>>
>>> Ideally it would, but I don't have the time budget yet to change RTT
>>> over. There could be a very lightweight appender that replaces the
>>> Logger for the simple/getting started/embedded cases.
>>
>> My thought has been (without any real depth to it yet) to consider
>> replacing
>> the implementation of RTT::Logger with something that calls into
>> the new
>> logging system. A pipe dream maybe but ...
>>
>> <sni

>>
>>>> myLogger.debug(message)
>>>>
>>>> Internally, the logger decides whether to log (based on its
>>>> level, or the
>>>> level of its parent loggers) and then passes off the log message
>>>> to all
>>>
>>> Can a parent be remote or is this always a local concept ? Are the
>>> hierarchies spanning multiple systems or are most loggers only for
>>> in-process logging.?
>>
>> I had not considered that. Using a logger hierarchy spread amongst
>> processes. At first glance that strikes me as really difficult,
>> but ... ? Do
>> you have a specific use case in mind here?
>>
>
> I probably had a wrong view. I thought you had to assign a single root
> logger for the whole system, but this can probably be done per process
> as well; will duplicate effort per process, for example:
>
> rtt.level = info
> org.me.level = debug
>
> can only be set per process, not system wide ?

AFAIK, yes.

Though I can easily see ways using Orocos to create a central "logger
configuration" component, and pull data from that to other deployers
as they start up. Should a user wish to develop such a thing.

> Anyway I think it's better to not cross process boundaries for looking
> up 'parent' log levels. Pushing from parent to a child is an option,
> but can be added later on as well.

Definitely. I would like to keep the implementation "per process" for
now, and we can see if definitive use cases turn up for "cross-
process" requests like pushing options from procss1.parent to
process2.child.
Stephen

Logging replacement

Submitted by snrkiwi on Tue, 2009-10-06 21:45.

I have added a wiki page outlining the design of a possible solution.
Feedback appreciated. I am mostly worried about the deployment side of
things - getting the logging appears to be much easier ...

There is a questions/issues section at the end.

http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging

Cheers
Stephen

Logging replacement

Submitted by sspr on Thu, 2009-10-08 12:15.

On Tue, Oct 6, 2009 at 23:40, S Roderick <kiwi [dot] net [..] ...> wrote:
> I have added a wiki page outlining the design of a possible solution.
> Feedback appreciated. I am mostly worried about the deployment side of
> things - getting the logging appears to be much easier ...
>
> There is a questions/issues section at the end.
>
> http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging

I added a small section about rt_string vs rt_stringstream, the latter
uses the boost::iostreams library.

I've been with a customer this week which also implemented his own
rt-logger, using a local stringstream mechanism and then sending the
data over in fixed c strings over an Orocos buffered data port. The
appender component then wrote it down. It relied on the fact that all
log messages arrived in the same buffer, such that the messages were
correctly ordered. When spreading log messages over categories, this
will not be guaranteed. This may be (Very) annoying.

Another issue: if log4cpp has its own configuration file, why
duplicating this with properties ? Why not just adding
methods/commands that let you configure log4cpp at runtime, and let
the initial configuration be read from its native format ?

Peter

Logging replacement

Submitted by snrkiwi on Thu, 2009-10-08 12:35.

On Oct 8, 2009, at 08:12 , Peter Soetens wrote:

> On Tue, Oct 6, 2009 at 23:40, S Roderick <kiwi [dot] net [..] ...> wrote:
>> I have added a wiki page outlining the design of a possible solution.
>> Feedback appreciated. I am mostly worried about the deployment side
>> of
>> things - getting the logging appears to be much easier ...
>>
>> There is a questions/issues section at the end.
>>
>> http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging
>
> I added a small section about rt_string vs rt_stringstream, the latter
> uses the boost::iostreams library.
>
> I've been with a customer this week which also implemented his own
> rt-logger, using a local stringstream mechanism and then sending the
> data over in fixed c strings over an Orocos buffered data port. The
> appender component then wrote it down. It relied on the fact that all
> log messages arrived in the same buffer, such that the messages were
> correctly ordered. When spreading log messages over categories, this
> will not be guaranteed. This may be (Very) annoying.

We've done exactly the same thing here, though without the string
stream. This continual reinvention definitely shows the need for RT
logging! I don't think I've personally noticed any out-of-order
messages in our system, though I can see how that latent "fault" might
exist in the implementation.

I have never heard mention of a method to combat the out-of-order
message situation, nor seen any code in log4cpp, log4cxx, etc. We
could certainly add some additional code in appender's, to hold a few
messages for some period of time and sort them timewise if necessary.
This would be an easy add-on for a version 1.1 implementation.

> Another issue: if log4cpp has its own configuration file, why
> duplicating this with properties ? Why not just adding
> methods/commands that let you configure log4cpp at runtime, and let
> the initial configuration be read from its native format ?

I did think of this, but chose against it. There are three basic
entities involved ...

1) appenders, which in our case will simply be components and hence
IMHO should be deployed by the deployer

2) layouts, which are associated with appenders and hence I chose to
have our existing configuration system just specify the two layout
configuration items (layout name and format string) by RTT::Property's

3) categories, which need to have a level set for them, and
connections to appenders made (which involves port creation for us)

I can see how using the existing log4cpp configuration makes sense for
3, but IMHO it makes no sense for 1 and only a little bit of sense for
2.

If we used the log4cpp configurator, then it would be creating
appender components alongside those that are created directly from XML
by the deployer. It might get confusing for some people having
components created in two places. Also, log4cpp can't deal with remote
appenders like Orocos already can.

Categories are certainly easier to specify in log4cpp, but we already
have to write some custom code here to create the buffer port for each
and to connect appender components appropriately. So we are either
extending the log4cpp configurator to support our extended category
implementation,or put the same functionality within our existing
configuration system instead. I chose the latter.

What sort of runtime configuration of log4cpp do you have in mind?

Thoughts?
Stephen

Logging replacement

Submitted by sspr on Thu, 2009-10-08 14:00.

On Thu, Oct 8, 2009 at 14:33, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
> On Oct 8, 2009, at 08:12 , Peter Soetens wrote:
>
>> On Tue, Oct 6, 2009 at 23:40, S Roderick <kiwi [dot] net [..] ...> wrote:
>>>
>>> I have added a wiki page outlining the design of a possible solution.
>>> Feedback appreciated. I am mostly worried about the deployment side of
>>> things - getting the logging appears to be much easier ...
>>>
>>> There is a questions/issues section at the end.
>>>
>>> http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging
>>
>> I added a small section about rt_string vs rt_stringstream, the latter
>> uses the boost::iostreams library.
>>
>> I've been with a customer this week which also implemented his own
>> rt-logger, using a local stringstream mechanism and then sending the
>> data over in fixed c strings over an Orocos buffered data port. The
>> appender component then wrote it down. It relied on the fact that all
>> log messages arrived in the same buffer, such that the messages were
>> correctly ordered. When spreading log messages over categories, this
>> will not be guaranteed. This may be (Very) annoying.
>
> We've done exactly the same thing here, though without the string stream.
> This continual reinvention definitely shows the need for RT logging! I don't
> think I've personally noticed any out-of-order messages in our system,
> though I can see how that latent "fault" might exist in the implementation.
>
> I have never heard mention of a method to combat the out-of-order message
> situation, nor seen any code in log4cpp, log4cxx, etc. We could certainly
> add some additional code in appender's, to hold a few messages for some
> period of time and sort them timewise if necessary. This would be an easy
> add-on for a version 1.1 implementation.
>
>> Another issue: if log4cpp has its own configuration file, why
>> duplicating this with properties ? Why not just adding
>> methods/commands that let you configure log4cpp at runtime, and let
>> the initial configuration be read from its native format ?
>
>
> I did think of this, but chose against it. There are three basic entities
> involved ...
>
> 1) appenders, which in our case will simply be components and hence IMHO
> should be deployed by the deployer
>
> 2) layouts, which are associated with appenders and hence I chose to have
> our existing configuration system just specify the two layout configuration
> items (layout name and format string) by RTT::Property's
>
> 3) categories, which need to have a level set for them, and connections to
> appenders made (which involves port creation for us)
>
> I can see how using the existing log4cpp configuration makes sense for 3,
> but IMHO it makes no sense for 1 and only a little bit of sense for 2.

But log4cpp allows to specify all in one file, while you need 2 + 1
for each appender. Hmm, you could propose to formulate the appender
like this:

<struct name="AppenderA" type="ocl::ConsoleAppender">
    <simple name="PropertyFile" ...><value>AppAConfig.cpf</value></simple>
    <struct name="Peers"> <simple>Logger</simple></struct>
    <struct name="Properties">
         <simple name="LayoutClass"
type="string"><value>ocl.PatternLayout</value>
         <simple name="LayoutConversionPattern"
type="string"><value>%-4r [%t] %-5p %c %x - %m%n</value>
    </struct>
</struct>

But I admit it's cheating :-)

>
> If we used the log4cpp configurator, then it would be creating appender
> components alongside those that are created directly from XML by the
> deployer. It might get confusing for some people having components created
> in two places. Also, log4cpp can't deal with remote appenders like Orocos
> already can.
>
> Categories are certainly easier to specify in log4cpp, but we already have
> to write some custom code here to create the buffer port for each and to
> connect appender components appropriately. So we are either extending the
> log4cpp configurator to support our extended category implementation,or put
> the same functionality within our existing configuration system instead. I
> chose the latter.
>
> What sort of runtime configuration of log4cpp do you have in mind?

Changing log levels at runtime, for example, to turn on debug and then
again off.

>
> Thoughts?

I hope the RTT 2.0 automatic connection of interfaces will also lead
to removal of red tape, in which appenders require the 'Logger'
service and can choose/switch if multiple are available. A component
which 'requires' the logger interface, will also need to provide a
'logsource' interface, which exposes the categories being logged to
the logger. As such, when a log source is peer connected to the
logger, the logger can look up what flow ports to create and connect.

We definately need a diagram showing the flow of log messages and the
required configuration at each component.

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-09 08:05.

On Oct 8, 2009, at 09:38 , Peter Soetens wrote:

> On Thu, Oct 8, 2009 at 14:33, Stephen Roderick <kiwi [dot] net [..] ...>
> wrote:
>> On Oct 8, 2009, at 08:12 , Peter Soetens wrote:
>>
>>> On Tue, Oct 6, 2009 at 23:40, S Roderick <kiwi [dot] net [..] ...> wrote:
>>>>
>>>> I have added a wiki page outlining the design of a possible
>>>> solution.
>>>> Feedback appreciated. I am mostly worried about the deployment
>>>> side of
>>>> things - getting the logging appears to be much easier ...
>>>>
>>>> There is a questions/issues section at the end.
>>>>
>>>> http://www.orocos.org/wiki/rtt/rtt-20/real-time-logging
>>>
>>> I added a small section about rt_string vs rt_stringstream, the
>>> latter
>>> uses the boost::iostreams library.
>>>
>>> I've been with a customer this week which also implemented his own
>>> rt-logger, using a local stringstream mechanism and then sending the
>>> data over in fixed c strings over an Orocos buffered data port. The
>>> appender component then wrote it down. It relied on the fact that
>>> all
>>> log messages arrived in the same buffer, such that the messages were
>>> correctly ordered. When spreading log messages over categories, this
>>> will not be guaranteed. This may be (Very) annoying.
>>
>> We've done exactly the same thing here, though without the string
>> stream.
>> This continual reinvention definitely shows the need for RT
>> logging! I don't
>> think I've personally noticed any out-of-order messages in our
>> system,
>> though I can see how that latent "fault" might exist in the
>> implementation.
>>
>> I have never heard mention of a method to combat the out-of-order
>> message
>> situation, nor seen any code in log4cpp, log4cxx, etc. We could
>> certainly
>> add some additional code in appender's, to hold a few messages for
>> some
>> period of time and sort them timewise if necessary. This would be
>> an easy
>> add-on for a version 1.1 implementation.
>>
>>> Another issue: if log4cpp has its own configuration file, why
>>> duplicating this with properties ? Why not just adding
>>> methods/commands that let you configure log4cpp at runtime, and let
>>> the initial configuration be read from its native format ?
>>
>>
>> I did think of this, but chose against it. There are three basic
>> entities
>> involved ...
>>
>> 1) appenders, which in our case will simply be components and hence
>> IMHO
>> should be deployed by the deployer
>>
>> 2) layouts, which are associated with appenders and hence I chose
>> to have
>> our existing configuration system just specify the two layout
>> configuration
>> items (layout name and format string) by RTT::Property's
>>
>> 3) categories, which need to have a level set for them, and
>> connections to
>> appenders made (which involves port creation for us)
>>
>> I can see how using the existing log4cpp configuration makes sense
>> for 3,
>> but IMHO it makes no sense for 1 and only a little bit of sense for
>> 2.
>
> But log4cpp allows to specify all in one file, while you need 2 + 1
> for each appender. Hmm, you could propose to formulate the appender
> like this:
>
>

> <struct name="AppenderA" type="ocl::ConsoleAppender">
>    <simple name="PropertyFile" ...><value>AppAConfig.cpf</value></ 
> simple>
>    <struct name="Peers"> <simple>Logger</simple></struct>
>    <struct name="Properties">
>         <simple name="LayoutClass"
> type="string"><value>ocl.PatternLayout</value>
>         <simple name="LayoutConversionPattern"
> type="string"><value>%-4r [%t] %-5p %c %x - %m%n</value>
>    </struct>
> </struct>
>

>
> But I admit it's cheating :-)

Agreed!!! I did think of something like this, as the current approach
doesn't scale well in the logger situation. You end up distributing
what should be one basic configuration file (ala log4cpp configurator)
into several XML files. I'm open to cheating if other's thing the
compromise is worth it? Could we modify the deployer to optionally
take properties directly in the component definition, without having
to use a property file?

>> If we used the log4cpp configurator, then it would be creating
>> appender
>> components alongside those that are created directly from XML by the
>> deployer. It might get confusing for some people having components
>> created
>> in two places. Also, log4cpp can't deal with remote appenders like
>> Orocos
>> already can.
>>
>> Categories are certainly easier to specify in log4cpp, but we
>> already have
>> to write some custom code here to create the buffer port for each
>> and to
>> connect appender components appropriately. So we are either
>> extending the
>> log4cpp configurator to support our extended category
>> implementation,or put
>> the same functionality within our existing configuration system
>> instead. I
>> chose the latter.
>>
>> What sort of runtime configuration of log4cpp do you have in mind?
>
> Changing log levels at runtime, for example, to turn on debug and then
> again off.

No problem in C++

getCategory("org.me.myapp")->setLevel(DEBUG)

Now using an Orocos interface, my only question is within which
component do we wrap each category? One thought was with the "Logger"
component (or perhaps it is better named, LoggerConfiguration or
LoggerManager?), that we provide Properties/Methods to do similar
things? I'm not yet sure about this, but I honestly don't think it
will be a big deal no matter what we decide. The basic things we want
to interact with are already centralized, so we just need to provide
access in an "Orocos manner".

>> Thoughts?
>
> I hope the RTT 2.0 automatic connection of interfaces will also lead
> to removal of red tape, in which appenders require the 'Logger'
> service and can choose/switch if multiple are available. A component
> which 'requires' the logger interface, will also need to provide a
> 'logsource' interface, which exposes the categories being logged to
> the logger. As such, when a log source is peer connected to the
> logger, the logger can look up what flow ports to create and connect.

I don't yet have my head wrapped around what this new feature set will
look like, so I can't comment on it.

> We definately need a diagram showing the flow of log messages and the
> required configuration at each component.

Not sure that the attached makes things any clearer .... green are
new, blue are modifications.
S

Logging replacement

Submitted by Butch Slayer on Mon, 2009-10-12 07:00.

>
> required configuration at each component.
>>
> We definately need a diagram showing the flow of log messages and the
>
> Not sure that the attached makes things any clearer .... green are new,
> blue are modifications.
> S
>
> This seems like a lot of code. I'm not sure this will still fit in my
small embedded controller :-s

Butch.

Logging replacement

Submitted by snrkiwi on Mon, 2009-10-12 12:30.

On Oct 12, 2009, at 02:54 , Butch Slayer wrote:

> required configuration at each component.
> We definately need a diagram showing the flow of log messages and the
>
> Not sure that the attached makes things any clearer .... green are
> new, blue are modifications.
> S
>
> This seems like a lot of code. I'm not sure this will still fit in
> my small embedded controller :-s
>
> Butch.

A lot of code ... really? ;-)

sloccount data from the preliminary, and working, implementation. SLOC
= source lines of code, for those who don't know. Non-blank, non-
comment lines.

SLOC Directory SLOC-by-Language (Sorted)
496 top_dir cpp=496
54 tests cpp=54
0 tmp (none)

Totals grouped by language (dominant language first):
cpp: 550 (100.00%)

The rtalloc wrapper I am working around TLSF, is less than 100
additional SLOC.

Admittedly, on really tightly constrained systems this might push you
over the edge ... but for most of us I suspect that isn't the case.
S

Logging replacement

Submitted by sspr on Fri, 2009-10-09 09:15.

On Fri, Oct 9, 2009 at 02:52, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
> On Oct 8, 2009, at 09:38 , Peter Soetens wrote:
>
>> But log4cpp allows to specify all in one file, while you need 2 + 1
>> for each appender. Hmm, you could propose to formulate the appender
>> like this:
>>
>>

>> <struct name="AppenderA" type="ocl::ConsoleAppender">
>>   <simple name="PropertyFile" ...><value>AppAConfig.cpf</value></simple>
>>   <struct name="Peers"> <simple>Logger</simple></struct>
>>   <struct name="Properties">
>>        <simple name="LayoutClass"
>> type="string"><value>ocl.PatternLayout</value>
>>        <simple name="LayoutConversionPattern"
>> type="string"><value>%-4r [%t] %-5p %c %x - %m%n</value>
>>   </struct>
>> </struct>
>>

>>
>> But I admit it's cheating :-)
>
> Agreed!!! I did think of something like this, as the current approach
> doesn't scale well in the logger situation. You end up distributing what
> should be one basic configuration file (ala log4cpp configurator) into
> several XML files. I'm open to cheating if other's thing the compromise is
> worth it? Could we modify the deployer to optionally take properties
> directly in the component definition, without having to use a property file?

Why doesn't anybody read my release notes !?
http://www.orocos.org/stable/documentation/rtt/v1.8.x/doc-xml/orocos-rtt...

In the section Improvements, second bullet.

OR
http://www.orocos.org/stable/documentation/ocl/v1.8.x/doc-xml/orocos-dep...
Look for the <struct name="Properties"> tag.

Would a wiki have helped better?

>
>>> If we used the log4cpp configurator, then it would be creating appender
>>> components alongside those that are created directly from XML by the
>>> deployer. It might get confusing for some people having components
>>> created
>>> in two places. Also, log4cpp can't deal with remote appenders like Orocos
>>> already can.
>>>
>>> Categories are certainly easier to specify in log4cpp, but we already
>>> have
>>> to write some custom code here to create the buffer port for each and to
>>> connect appender components appropriately. So we are either extending the
>>> log4cpp configurator to support our extended category implementation,or
>>> put
>>> the same functionality within our existing configuration system instead.
>>> I
>>> chose the latter.
>>>
>>> What sort of runtime configuration of log4cpp do you have in mind?
>>
>> Changing log levels at runtime, for example, to turn on debug and then
>> again off.
>
> No problem in C++
>
> getCategory("org.me.myapp")->setLevel(DEBUG)
>
> Now using an Orocos interface, my only question is within which component do
> we wrap each category? One thought was with the "Logger" component (or
> perhaps it is better named, LoggerConfiguration or LoggerManager?), that we
> provide Properties/Methods to do similar things? I'm not yet sure about
> this, but I honestly don't think it will be a big deal no matter what we
> decide. The basic things we want to interact with are already centralized,
> so we just need to provide access in an "Orocos manner".

I wouldn't call it Logger either. LoggingService or similar seams
better suited, and that's also the place where I'd expect such
configuration. We don't specify the log level depending on the
appender ?

>
>>> Thoughts?
>>
>> I hope the RTT 2.0 automatic connection of interfaces will also lead
>> to removal of red tape, in which appenders require the 'Logger'
>> service and can choose/switch if multiple are available. A component
>> which 'requires' the logger interface, will also need to provide a
>> 'logsource' interface, which exposes the categories being logged to
>> the logger. As such, when a log source is peer connected to the
>> logger, the logger can look up what flow ports to create and connect.
>
> I don't yet have my head wrapped around what this new feature set will look
> like, so I can't comment on it.

I know. No one has (except Markus ?).

>
>> We definately need a diagram showing the flow of log messages and the
>> required configuration at each component.
>
> Not sure that the attached makes things any clearer .... green are new, blue
> are modifications.

It doesn't if the resolution is only 640x388 !?

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-09 11:40.

On Oct 9, 2009, at 05:12 , Peter Soetens wrote:

> On Fri, Oct 9, 2009 at 02:52, Stephen Roderick <kiwi [dot] net [..] ...>
> wrote:
>> On Oct 8, 2009, at 09:38 , Peter Soetens wrote:
>>
>>> But log4cpp allows to specify all in one file, while you need 2 + 1
>>> for each appender. Hmm, you could propose to formulate the appender
>>> like this:
>>>
>>>

>>> <struct name="AppenderA" type="ocl::ConsoleAppender">
>>>   <simple name="PropertyFile" ...><value>AppAConfig.cpf</value></ 
>>> simple>
>>>   <struct name="Peers"> <simple>Logger</simple></struct>
>>>   <struct name="Properties">
>>>        <simple name="LayoutClass"
>>> type="string"><value>ocl.PatternLayout</value>
>>>        <simple name="LayoutConversionPattern"
>>> type="string"><value>%-4r [%t] %-5p %c %x - %m%n</value>
>>>   </struct>
>>> </struct>
>>>

>>>
>>> But I admit it's cheating :-)
>>
>> Agreed!!! I did think of something like this, as the current approach
>> doesn't scale well in the logger situation. You end up distributing
>> what
>> should be one basic configuration file (ala log4cpp configurator)
>> into
>> several XML files. I'm open to cheating if other's thing the
>> compromise is
>> worth it? Could we modify the deployer to optionally take properties
>> directly in the component definition, without having to use a
>> property file?
>
> Why doesn't anybody read my release notes !?
> http://www.orocos.org/stable/documentation/rtt/v1.8.x/doc-xml/orocos-rtt...

Holy s#*t!! That's awesome ...

> In the section Improvements, second bullet.
>
> OR
> http://www.orocos.org/stable/documentation/ocl/v1.8.x/doc-xml/orocos-dep...
> Look for the <struct name="Properties"> tag.
>
> Would a wiki have helped better?

No, completely my fault. Sorry. I don't think a wiki would help,
unfortunately. I remember seeing the new loadProperties, etc, but
missed "Properties". Yes, your approach outlined above is _much_
better ... and no longer looks like cheating!

>>>> If we used the log4cpp configurator, then it would be creating
>>>> appender
>>>> components alongside those that are created directly from XML by
>>>> the
>>>> deployer. It might get confusing for some people having components
>>>> created
>>>> in two places. Also, log4cpp can't deal with remote appenders
>>>> like Orocos
>>>> already can.
>>>>
>>>> Categories are certainly easier to specify in log4cpp, but we
>>>> already
>>>> have
>>>> to write some custom code here to create the buffer port for each
>>>> and to
>>>> connect appender components appropriately. So we are either
>>>> extending the
>>>> log4cpp configurator to support our extended category
>>>> implementation,or
>>>> put
>>>> the same functionality within our existing configuration system
>>>> instead.
>>>> I
>>>> chose the latter.
>>>>
>>>> What sort of runtime configuration of log4cpp do you have in mind?
>>>
>>> Changing log levels at runtime, for example, to turn on debug and
>>> then
>>> again off.
>>
>> No problem in C++
>>
>> getCategory("org.me.myapp")->setLevel(DEBUG)
>>
>> Now using an Orocos interface, my only question is within which
>> component do
>> we wrap each category? One thought was with the "Logger" component
>> (or
>> perhaps it is better named, LoggerConfiguration or LoggerManager?),
>> that we
>> provide Properties/Methods to do similar things? I'm not yet sure
>> about
>> this, but I honestly don't think it will be a big deal no matter
>> what we
>> decide. The basic things we want to interact with are already
>> centralized,
>> so we just need to provide access in an "Orocos manner".
>
> I wouldn't call it Logger either. LoggingService or similar seams
> better suited, and that's also the place where I'd expect such
> configuration. We don't specify the log level depending on the
> appender ?

That does sound better. I should get time this afternoon to take a
first whack at doing this, though the initial version will be non-
realtime. I'm more worried about how to get it all started up and
configured, than I am about getting the real-time shoe-horned in.
Funny that ...

>>>> Thoughts?
>>>
>>> I hope the RTT 2.0 automatic connection of interfaces will also lead
>>> to removal of red tape, in which appenders require the 'Logger'
>>> service and can choose/switch if multiple are available. A component
>>> which 'requires' the logger interface, will also need to provide a
>>> 'logsource' interface, which exposes the categories being logged to
>>> the logger. As such, when a log source is peer connected to the
>>> logger, the logger can look up what flow ports to create and
>>> connect.
>>
>> I don't yet have my head wrapped around what this new feature set
>> will look
>> like, so I can't comment on it.
>
> I know. No one has (except Markus ?).
>
>>
>>> We definately need a diagram showing the flow of log messages and
>>> the
>>> required configuration at each component.
>>
>> Not sure that the attached makes things any clearer .... green are
>> new, blue
>> are modifications.
>
> It doesn't if the resolution is only 640x388 !?

Get off the phone and back onto the laptop ... ;-)
S

Logging replacement

Submitted by markus.klotzbuecher on Thu, 2009-10-01 13:40.

On Thu, Oct 01, 2009 at 02:44:19PM +0200, Stephen Roderick wrote:
> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>
> > 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
> >> From recent ML discussions, and Peter's concluding email, RTT 2.x
> >> will contain an alternative logging functionality. My question is,
> >> what should it do ...? At the every least, it should support the
> >> same functionality that the current RTT::Logger class provides, but
> >> several issues were identified on the ML that people believe that
> >> RTT needs to support.
> >
> > It's not RTT. It's OCL that needs to support this by means of a
> > component and component interface. Component interfaces should be as
> > easy to use as native RTT classes, although we don't support C++
> > operators, nor overloading (yet) in the component interface. The
> > stuff you require below is the description of a service (ie interface)
> > a logging component is offering.
>
> So you see the back end stuff (the "storage mediums" below, or
> appenders in log4j/log4cpp-speak) in OCL. That makes sense. But I
> presume that RTT will also make use of this logging system?
>
> >> So please discuss, critique or compliment the following ... they
> >> are approximately in order of priority, in my mind at least.
> >> 0) Completely disable all logging
> >> 1) Able log variable sized string messages
> >> 2) Able log from non-realtime and realtime code
> >> 3) Minimize (as reasonably practicable) the effect on runtime
> >> performance (eg minimize CPU cycles consumed)
> >> 4) Support different log levels
> >> 5) Support different "storage mediums" (ie able to log messages to
> >> file, to socket, to stdout)
> >> ** bar 3, and the "realtime" part of 2, the above is the
> >> functionality of the existing RTT::Logger **
> >> 6) Support different log levels within a deployed system (ie able
> >> to log debug in one area, and info in another)
> >> 7) Support multiple storage mediums simultaneously at runtime
> >> 8) Runtime configuration of storage mediums and logging levels
> >> 9) Allow the user to extend the possible storage mediums at
> >> deployment-time (ie user can provide new storage class)
> >> Optional IMHO
> >> 10) Support nested diagnostic contexts [1] [2] (a more advanced
> >> version of the Logger::In() that RTT's logger currently supports)
> >
> > I think this is already a fairly complete list of requirements. What
> > you're missing is to distribute your logging, which is trivial/implied
> > if logging is a component service.
>
> Agreed. What precisely are you thinking of with "distributed"?
>
> > If you want different loglevels per 'component' you need a means to
> > attach an id to a message, so it looks like you need to setup a
> > message (with id and loglevel) and then send that at once to the
> > logger.
> >
> > logservice.log( logmessage(Info, this->getName() ) << "my message" );
> >
> > ? Where logmessage() helps us in creating a LogMessage struct to send
> > over the wire, log is a method or message and logservice is
> > representing our OCL component.
>
> You could do it a similar but different way, in that when you get the
> logservice within a component you specify the ID. Somewhere else has
> configured the log level per ID (they're categories in log4j, loggers
> in logback). Then the local service code decides whether to log for
> this ID, bundles up the data into a LogMessage, and then transfers the
> message off to the appropriate backend logging component (realising
> that multiple possible backends may be in use).
>
> Looking at OSGi (Herman's suggestion), it appears to be a component-
> or service-oriented wrapper around log4j/logback style frameworks. I
> think we need the same thing. I will reiterate what I said in a
> previous email - I believe that rewriting an entire logging framework
> from scratch, rather than wrapping/modifying an existing mature
> framework, is perilous and time consuming. Having said that, we better
> make a good decision in which framework to use! (and I noticed recent
> Xenomai ML traffic, Peter, in talking of not trusting tests when re-
> using existing packages. Definitely applies here, particularly to TLSF).
>
> So, assuming we agree on this model, check out http://logback.qos.ch/manual/architecture.html
> for a reasonable introduction to existing Java logging frameworks (I
> use java ones here, as the good C++ logging frameworks I know of are
> all based on the java ones. Java did it "right" first)
>
> A framework consists of loggers (categories in log4j), layouts and
> appenders. Lets ignore layouts for now. A component would obtain/
> create/use a logger instance for a given ID (say
> "org.orocos.ocl.deployment"). The component logs to that logger
>
> RTT::rtstring message;
> message << "some stuff here"
> myLogger.debug(message)
>
> Internally, the logger decides whether to log (based on its level, or
> the level of its parent loggers) and then passes off the log message
> to all associated appenders (if this message is to be logged). The
> appenders would exist in other components, and do what they do with
> the message (eg log to console, write to file, send over socket).
>
> So the "OCL logging service" would consist of
>
> a) a way for components to create/obtain/use loggers
> b) appenders that reside in components
> c) configuration of the above (ie levels per loggers, attaching
> appenders to loggers, and factory creation of appenders - all done at
> deployment time)
>
> The actual modifications/extensions would be
>
> 1) use RTT::rtstring instead of std::string [RTT addition, logging
> framework change]
> 2) pass log messages from loggers to appenders over RTT's data flow
> implementation [logging framework extension]
> 3) provide default appenders that exist within components (say, a
> console appender and a write-to-file appender, for starters) [OCL]
> 4) provide configuration of the logging service via the deployer (I
> don't yet have a firm handle on how to do this, but I don't anticipate
> it being complicated). [OCL]
> 5) make sure the logging framework works in real-time and is multi-
> thread safe [logging framework change]. Most of the frameworks I've
> seen already support multi-thread, and some provide an abstraction of
> the actual threading/mutex environment (eg posix vs xxx)

Call me ignorant but I don't quite see why logging can't simply be
realized by defining the best practice that each component has a "log"
port to which it writes its logging messages and a logger component
which reads and processes all these messages and allows to
disable/enable/filter/dispatch messages appropriately (your points 2)
3) and 4). Why duplicate real-time and thread-safe queuing and
buffering (point 5) in a logging framework if we already have these
mechanisms in the more generic dataflow?

WRT 1) I would be concerned with having a RTT:rtstring because it
seems like a free ride in real-time allocation while it will require
careful coordination of memory resources.

> I think 2 is the hardest part of the above, and 5 is the biggest
> uncertainty (and hence potentially the nightmare part).
>
> Note also that loggers/categories exist in a tree hierarchy. Very
> handy for turning on/off logging in certain parts of a program. Say
> you have loggers in a large app like
>
> org.me.myapp.component1
> org.me.myapp.component2
> org.me.myapp.component3.a
> org.me.myapp.component3.b
>
> You can set an overall log level for all categories simply by
> specifying it at the root.
>
> org.me.loglevel = warn
>
> and then turn on/off only certain parts if required
>
> org.me.loglevel = info
> org.me.myapp.component3.b.loglevel = debug

Fine if these are RTT::properties or RTT::method calls...

> Also note that there are several performance optimizations available
> to, for example, avoid creating "message" above when myLogger.debug()
> won't log anyway, and similar things. I'm concentrating here on
> getting the overall system laid out, not the tiny details. We can
> discuss those as we proceed.

Markus

Logging replacement

Submitted by snrkiwi on Thu, 2009-10-01 15:30.

On Oct 1, 2009, at 09:39 , Markus Klotzbuecher wrote:

> On Thu, Oct 01, 2009 at 02:44:19PM +0200, Stephen Roderick wrote:
>> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
>>
>>> 2009/9/28 Stephen Roderick <kiwi [dot] net [..] ...>:
>>>> From recent ML discussions, and Peter's concluding email, RTT 2.x
>>>> will contain an alternative logging functionality. My question is,
>>>> what should it do ...? At the every least, it should support the
>>>> same functionality that the current RTT::Logger class provides, but
>>>> several issues were identified on the ML that people believe that
>>>> RTT needs to support.
>>>
>>> It's not RTT. It's OCL that needs to support this by means of a
>>> component and component interface. Component interfaces should be as
>>> easy to use as native RTT classes, although we don't support C++
>>> operators, nor overloading (yet) in the component interface. The
>>> stuff you require below is the description of a service (ie
>>> interface)
>>> a logging component is offering.
>>
>> So you see the back end stuff (the "storage mediums" below, or
>> appenders in log4j/log4cpp-speak) in OCL. That makes sense. But I
>> presume that RTT will also make use of this logging system?
>>
>>>> So please discuss, critique or compliment the following ... they
>>>> are approximately in order of priority, in my mind at least.
>>>> 0) Completely disable all logging
>>>> 1) Able log variable sized string messages
>>>> 2) Able log from non-realtime and realtime code
>>>> 3) Minimize (as reasonably practicable) the effect on runtime
>>>> performance (eg minimize CPU cycles consumed)
>>>> 4) Support different log levels
>>>> 5) Support different "storage mediums" (ie able to log messages to
>>>> file, to socket, to stdout)
>>>> ** bar 3, and the "realtime" part of 2, the above is the
>>>> functionality of the existing RTT::Logger **
>>>> 6) Support different log levels within a deployed system (ie able
>>>> to log debug in one area, and info in another)
>>>> 7) Support multiple storage mediums simultaneously at runtime
>>>> 8) Runtime configuration of storage mediums and logging levels
>>>> 9) Allow the user to extend the possible storage mediums at
>>>> deployment-time (ie user can provide new storage class)
>>>> Optional IMHO
>>>> 10) Support nested diagnostic contexts [1] [2] (a more advanced
>>>> version of the Logger::In() that RTT's logger currently supports)
>>>
>>> I think this is already a fairly complete list of requirements. What
>>> you're missing is to distribute your logging, which is trivial/
>>> implied
>>> if logging is a component service.
>>
>> Agreed. What precisely are you thinking of with "distributed"?
>>
>>> If you want different loglevels per 'component' you need a means to
>>> attach an id to a message, so it looks like you need to setup a
>>> message (with id and loglevel) and then send that at once to the
>>> logger.
>>>
>>> logservice.log( logmessage(Info, this->getName() ) << "my
>>> message" );
>>>
>>> ? Where logmessage() helps us in creating a LogMessage struct to
>>> send
>>> over the wire, log is a method or message and logservice is
>>> representing our OCL component.
>>
>> You could do it a similar but different way, in that when you get the
>> logservice within a component you specify the ID. Somewhere else has
>> configured the log level per ID (they're categories in log4j, loggers
>> in logback). Then the local service code decides whether to log for
>> this ID, bundles up the data into a LogMessage, and then transfers
>> the
>> message off to the appropriate backend logging component (realising
>> that multiple possible backends may be in use).
>>
>> Looking at OSGi (Herman's suggestion), it appears to be a component-
>> or service-oriented wrapper around log4j/logback style frameworks. I
>> think we need the same thing. I will reiterate what I said in a
>> previous email - I believe that rewriting an entire logging framework
>> from scratch, rather than wrapping/modifying an existing mature
>> framework, is perilous and time consuming. Having said that, we
>> better
>> make a good decision in which framework to use! (and I noticed recent
>> Xenomai ML traffic, Peter, in talking of not trusting tests when re-
>> using existing packages. Definitely applies here, particularly to
>> TLSF).
>>
>> So, assuming we agree on this model, check out http://logback.qos.ch/manual/architecture.html
>> for a reasonable introduction to existing Java logging frameworks (I
>> use java ones here, as the good C++ logging frameworks I know of are
>> all based on the java ones. Java did it "right" first)
>>
>> A framework consists of loggers (categories in log4j), layouts and
>> appenders. Lets ignore layouts for now. A component would obtain/
>> create/use a logger instance for a given ID (say
>> "org.orocos.ocl.deployment"). The component logs to that logger
>>
>> RTT::rtstring message;
>> message << "some stuff here"
>> myLogger.debug(message)
>>
>> Internally, the logger decides whether to log (based on its level, or
>> the level of its parent loggers) and then passes off the log message
>> to all associated appenders (if this message is to be logged). The
>> appenders would exist in other components, and do what they do with
>> the message (eg log to console, write to file, send over socket).
>>
>> So the "OCL logging service" would consist of
>>
>> a) a way for components to create/obtain/use loggers
>> b) appenders that reside in components
>> c) configuration of the above (ie levels per loggers, attaching
>> appenders to loggers, and factory creation of appenders - all done at
>> deployment time)
>>
>> The actual modifications/extensions would be
>>
>> 1) use RTT::rtstring instead of std::string [RTT addition, logging
>> framework change]
>> 2) pass log messages from loggers to appenders over RTT's data flow
>> implementation [logging framework extension]
>> 3) provide default appenders that exist within components (say, a
>> console appender and a write-to-file appender, for starters) [OCL]
>> 4) provide configuration of the logging service via the deployer (I
>> don't yet have a firm handle on how to do this, but I don't
>> anticipate
>> it being complicated). [OCL]
>> 5) make sure the logging framework works in real-time and is multi-
>> thread safe [logging framework change]. Most of the frameworks I've
>> seen already support multi-thread, and some provide an abstraction of
>> the actual threading/mutex environment (eg posix vs xxx)
>
> Call me ignorant but I don't quite see why logging can't simply be
> realized by defining the best practice that each component has a "log"
> port to which it writes its logging messages and a logger component
> which reads and processes all these messages and allows to
> disable/enable/filter/dispatch messages appropriately (your points 2)
> 3) and 4). Why duplicate real-time and thread-safe queuing and
> buffering (point 5) in a logging framework if we already have these
> mechanisms in the more generic dataflow?

Ok, so sitting here thinking ... "am I overly complicating this" ...
leads me to ...

Writing from scratch:

1) write a logger that can be instantiated in a component, which
selectively logs based on a level, and which passes log messages off
through the data flow implementation. Simple, no big deal

I'm not quite sure how to configure these via the deployer yet, but
we'll get to that.

2) write logging components that accept log messages from data flow,
and do something with them. For starters, create one component that
logs to the console, and a second one that logs to file. No big deal.

The deployer can easily create and manage these components with the
existing RTT deployment implementation.

Voila, Orocos' real-time custom logging framework v1.0!

3) Someone wants to format log messages differently. We now have to
write a modified component(s) (through specialization or otherwise) to
format messages differently. Or you add in a general formatting
capability.

You've just written the log4j "layout" capability.

We have an immediate need for this. In one project, the standard RTT
"seconds since startup" timing is fine, but in another we need full
date and time down to the microsecond.

4) Some clown (guess who!) with a large enough system wants to be able
to specify one logging for all loggers, and then specify differing
level for just one or two components. Or set the overall default, but
also set differing levels for one or two components and a differing
level for another whole subsystem of components. Rather than manually
specify each level, they would prefer to configure with something like:

org.me.myapp.level = warn // set default
for all components
org.me.myapp.component1.1.level = info // set for component 1.1
org.me.myapp.component1.5.level = trace // set for component 1.5
org.me.myapp.component2.level = debug // setting components 2.x

Another use case here is to have a need for a default logging
component (say send over the network), but a different logging
component for a subsystem (say to file). In the example above, I might
want to write to local file all messages from the
org.me.myapp.component2.x components.

You've just written a "hierarchy" of loggers/categories, though it
could be implemented differently I'm sure.

5) The same clown wants to remotely deploy a logging component.
Bypasses having to create a write-to-socket logging component - just
send it via data flow thru CORBA and log to file at other end. Either
the custom or existing-framework supports this. Nothing new needed
here. Love Orocos!! :-)

6) Refactor the existing OCL Reporting to use the logging components.
Fundamentally a reporter now becomes just a sampling front end that
logs to a specific category. This decoupling allows the front-end
reporter to run real-time (potentially), while the logging components
do the non-real-time heavy lifting work (thus getting around the
current non-realtime reporting limitation). Either the custom or
existing-framework supports this, as the custom formatting has to
appear in the reporter side, not in the logging side.

Summary:

If you stick with just 1) and 2) then writing from scratch makes
sense. But as soon as you head down the path of 3) or 4), I'm
concerned about simply rewriting something that already exists.
Alternately, rephrase the last half of that sentence to "how can we
refactor the requirements to do more with less code, than the smart
programmers already did with log4j, etc?".

Hoping for more discussion here ... try to come to some community
consensus of what people do require.
Stephen

Logging replacement

Submitted by sspr on Fri, 2009-10-02 09:10.

On Thu, Oct 1, 2009 at 17:23, Stephen Roderick <kiwi [dot] net [..] ...> wrote:
> On Oct 1, 2009, at 09:39 , Markus Klotzbuecher wrote:
>> Call me ignorant but I don't quite see why logging can't simply be
>> realized by defining the best practice that each component has a "log"
>> port to which it writes its logging messages and a logger component
>> which reads and processes all these messages and allows to
>> disable/enable/filter/dispatch messages appropriately (your points 2)
>> 3) and 4). Why duplicate real-time and thread-safe queuing and
>> buffering (point 5) in a logging framework if we already have these
>> mechanisms in the more generic dataflow?
>
> Ok, so sitting here thinking ... "am I overly complicating this" ... leads
> me to ...
>
> Writing from scratch:
>
> 1) write a logger that can be instantiated in a component, which selectively
> logs based on a level, and which passes log messages off through the data
> flow implementation. Simple, no big deal

For people getting confused, read
http://logging.apache.org/log4j/1.2/manual.html for a short
introduction of what a Logger is in log4j.

>
> I'm not quite sure how to configure these via the deployer yet, but we'll
> get to that.
>
> 2) write logging components that accept log messages from data flow, and do
> something with them. For starters, create one component that logs to the
> console, and a second one that logs to file. No big deal.
>
> The deployer can easily create and manage these components with the existing
> RTT deployment implementation.
>
> Voila, Orocos' real-time custom logging framework v1.0!

It is indeed remarkably simple :-) I'm also leaning towards a custom
front-end (ie Logger) but reuse of backends (ie appenders/layouts).

>
> 3) Someone wants to format log messages differently. We now have to write a
> modified component(s) (through specialization or otherwise) to format
> messages differently. Or you add in a general formatting capability.
>
> You've just written the log4j "layout" capability.

Or 'just used the log4j layout cap' ?

>
> We have an immediate need for this. In one project, the standard RTT
> "seconds since startup" timing is fine, but in another we need full date and
> time down to the microsecond.
>
> 4) Some clown (guess who!) with a large enough system wants to be able to
> specify one logging for all loggers, and then specify differing level for
> just one or two components. Or set the overall default, but also set
> differing levels for one or two components and a differing level for another
> whole subsystem of components. Rather than manually specify each level, they
> would prefer to configure with something like:
>
> org.me.myapp.level = warn // set default for
> all components
> org.me.myapp.component1.1.level = info // set for component 1.1
> org.me.myapp.component1.5.level = trace // set for component 1.5
> org.me.myapp.component2.level = debug // setting components 2.x
>
> Another use case here is to have a need for a default logging component (say
> send over the network), but a different logging component for a subsystem
> (say to file). In the example above, I might want to write to local file all
> messages from the org.me.myapp.component2.x components.
>
> You've just written a "hierarchy" of loggers/categories, though it could be
> implemented differently I'm sure.

What I fear is that each 'default' logger will need to ask his parent
what the log level is, and that the parent may be remote. Since the
parent can change log level at any time, it needs to be queried each
time.

>
> 5) The same clown wants to remotely deploy a logging component. Bypasses
> having to create a write-to-socket logging component - just send it via data
> flow thru CORBA and log to file at other end. Either the custom or
> existing-framework supports this. Nothing new needed here. Love Orocos!! :-)
>
> 6) Refactor the existing OCL Reporting to use the logging components.
> Fundamentally a reporter now becomes just a sampling front end that logs to
> a specific category. This decoupling allows the front-end reporter to run
> real-time (potentially), while the logging components do the non-real-time
> heavy lifting work (thus getting around the current non-realtime reporting
> limitation). Either the custom or existing-framework supports this, as the
> custom formatting has to appear in the reporter side, not in the logging
> side.

I'm not convinced about the reporting case, but it can wait.

>
> Summary:
>
> If you stick with just 1) and 2) then writing from scratch makes sense. But
> as soon as you head down the path of 3) or 4), I'm concerned about simply
> rewriting something that already exists. Alternately, rephrase the last half
> of that sentence to "how can we refactor the requirements to do more with
> less code, than the smart programmers already did with log4j, etc?".
>
> Hoping for more discussion here ... try to come to some community consensus
> of what people do require.

My dream combination remains new to write RTT logger as front-end
(allows real-time, distribution etc) and log4j (allows re-use,
configuration etc) as backend.

Anyway, it really sounds cool already.

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-02 12:25.

On Oct 2, 2009, at 05:08 , Peter Soetens wrote:

> On Thu, Oct 1, 2009 at 17:23, Stephen Roderick <kiwi [dot] net [..] ...>
> wrote:
>> On Oct 1, 2009, at 09:39 , Markus Klotzbuecher wrote:
>>> Call me ignorant but I don't quite see why logging can't simply be
>>> realized by defining the best practice that each component has a
>>> "log"
>>> port to which it writes its logging messages and a logger component
>>> which reads and processes all these messages and allows to
>>> disable/enable/filter/dispatch messages appropriately (your points
>>> 2)
>>> 3) and 4). Why duplicate real-time and thread-safe queuing and
>>> buffering (point 5) in a logging framework if we already have these
>>> mechanisms in the more generic dataflow?
>>
>> Ok, so sitting here thinking ... "am I overly complicating
>> this" ... leads
>> me to ...
>>
>> Writing from scratch:
>>
>> 1) write a logger that can be instantiated in a component, which
>> selectively
>> logs based on a level, and which passes log messages off through
>> the data
>> flow implementation. Simple, no big deal
>
> For people getting confused, read
> http://logging.apache.org/log4j/1.2/manual.html for a short
> introduction of what a Logger is in log4j.
>
>>
>> I'm not quite sure how to configure these via the deployer yet, but
>> we'll
>> get to that.
>>
>> 2) write logging components that accept log messages from data
>> flow, and do
>> something with them. For starters, create one component that logs
>> to the
>> console, and a second one that logs to file. No big deal.
>>
>> The deployer can easily create and manage these components with the
>> existing
>> RTT deployment implementation.
>>
>> Voila, Orocos' real-time custom logging framework v1.0!
>
> It is indeed remarkably simple :-) I'm also leaning towards a custom
> front-end (ie Logger) but reuse of backends (ie appenders/layouts).
>
>>
>> 3) Someone wants to format log messages differently. We now have to
>> write a
>> modified component(s) (through specialization or otherwise) to format
>> messages differently. Or you add in a general formatting capability.
>>
>> You've just written the log4j "layout" capability.
>
> Or 'just used the log4j layout cap' ?
>
>>
>> We have an immediate need for this. In one project, the standard RTT
>> "seconds since startup" timing is fine, but in another we need full
>> date and
>> time down to the microsecond.
>>
>> 4) Some clown (guess who!) with a large enough system wants to be
>> able to
>> specify one logging for all loggers, and then specify differing
>> level for
>> just one or two components. Or set the overall default, but also set
>> differing levels for one or two components and a differing level
>> for another
>> whole subsystem of components. Rather than manually specify each
>> level, they
>> would prefer to configure with something like:
>>
>> org.me.myapp.level = warn // set
>> default for
>> all components
>> org.me.myapp.component1.1.level = info // set for component 1.1
>> org.me.myapp.component1.5.level = trace // set for component 1.5
>> org.me.myapp.component2.level = debug // setting components 2.x
>>
>> Another use case here is to have a need for a default logging
>> component (say
>> send over the network), but a different logging component for a
>> subsystem
>> (say to file). In the example above, I might want to write to local
>> file all
>> messages from the org.me.myapp.component2.x components.
>>
>> You've just written a "hierarchy" of loggers/categories, though it
>> could be
>> implemented differently I'm sure.
>
> What I fear is that each 'default' logger will need to ask his parent
> what the log level is, and that the parent may be remote. Since the
> parent can change log level at any time, it needs to be queried each
> time.

Yes, and in log4j that is a tree walk. However, in logback (log4j's
successor, which I have not used) it caches the values it claims. So I
guess that the tree walk occurs when you change log levels, where a
parent informs all its children. Admittedly, in most scenarios that
would happen far less frequently than the act of logging itself so it
sounds like a good optimization. I have not found any C++ ports of
logback yet ... they all seem to be log4j ports.

I'm still tossing over your idea of distribution of categories
throughout a system ...

>> 5) The same clown wants to remotely deploy a logging component.
>> Bypasses
>> having to create a write-to-socket logging component - just send it
>> via data
>> flow thru CORBA and log to file at other end. Either the custom or
>> existing-framework supports this. Nothing new needed here. Love
>> Orocos!! :-)
>>
>> 6) Refactor the existing OCL Reporting to use the logging components.
>> Fundamentally a reporter now becomes just a sampling front end that
>> logs to
>> a specific category. This decoupling allows the front-end reporter
>> to run
>> real-time (potentially), while the logging components do the non-
>> real-time
>> heavy lifting work (thus getting around the current non-realtime
>> reporting
>> limitation). Either the custom or existing-framework supports this,
>> as the
>> custom formatting has to appear in the reporter side, not in the
>> logging
>> side.
>
> I'm not convinced about the reporting case, but it can wait.

Neither am I ...

>> Summary:
>>
>> If you stick with just 1) and 2) then writing from scratch makes
>> sense. But
>> as soon as you head down the path of 3) or 4), I'm concerned about
>> simply
>> rewriting something that already exists. Alternately, rephrase the
>> last half
>> of that sentence to "how can we refactor the requirements to do
>> more with
>> less code, than the smart programmers already did with log4j, etc?".
>>
>> Hoping for more discussion here ... try to come to some community
>> consensus
>> of what people do require.
>
> My dream combination remains new to write RTT logger as front-end
> (allows real-time, distribution etc) and log4j (allows re-use,
> configuration etc) as backend.
>
> Anyway, it really sounds cool already.

Agreed, but I will take "useful and easy to implement" any day ... :-)
Stephen

Logging replacement

Submitted by snrkiwi on Thu, 2009-10-01 14:10.

On Oct 1, 2009, at 09:39 , Markus Klotzbuecher wrote:

This _is_ a logger/category as it currently exists. But it also
provides the hierarchy of loggers (useful in large systems) and
appenders.

> 3) and 4). Why duplicate real-time and thread-safe queuing and
> buffering (point 5) in a logging framework if we already have these
> mechanisms in the more generic dataflow?

I was trying to communicate that some of the existing frameworks
already have multi-thread safety, and use an abstraction of a thread/
mutex model to achieve that. So I think we can just wrap RTT::Mutex,
etc, within the logging framework.

The real change that we have to do is to separate the existing
framework's direct connection from loggers to appenders, and drop the
RTT data flow in there. That is the big change.

I don't think we are duplicating anything.

> WRT 1) I would be concerned with having a RTT:rtstring because it
> seems like a free ride in real-time allocation while it will require
> careful coordination of memory resources.

Hang on, weren't you the one asking for real-time memory allocation
for scripting ...?! :-)

It's either this, or fixed-length message strings. Personally, I'm not
prepared to live with that restriction in comparison to dropping in
TLSF (which Peter already intends to integrate, regardless of this
discussion).

>> I think 2 is the hardest part of the above, and 5 is the biggest
>> uncertainty (and hence potentially the nightmare part).
>>
>> Note also that loggers/categories exist in a tree hierarchy. Very
>> handy for turning on/off logging in certain parts of a program. Say
>> you have loggers in a large app like
>>
>> org.me.myapp.component1
>> org.me.myapp.component2
>> org.me.myapp.component3.a
>> org.me.myapp.component3.b
>>
>> You can set an overall log level for all categories simply by
>> specifying it at the root.
>>
>> org.me.loglevel = warn
>>
>> and then turn on/off only certain parts if required
>>
>> org.me.loglevel = info
>> org.me.myapp.component3.b.loglevel = debug
>
> Fine if these are RTT::properties or RTT::method calls...

This is the part of 4) that I haven't yet gotten a good idea of. My
working concept is for the deployer to get the configuration from XML
file. You might want to provide RTT::Methods to change configuration
later, I don't know yet ...

Stephen

Logging replacement

Submitted by markus.klotzbuecher on Fri, 2009-10-02 07:00.

Hi Stephen,

On Thu, Oct 01, 2009 at 04:00:58PM +0200, Stephen Roderick wrote:
> On Oct 1, 2009, at 09:39 , Markus Klotzbuecher wrote:
>
> > On Thu, Oct 01, 2009 at 02:44:19PM +0200, Stephen Roderick wrote:
> >> On Oct 1, 2009, at 05:24 , Peter Soetens wrote:
<sni

> >> The actual modifications/extensions would be
> >>
> >> 1) use RTT::rtstring instead of std::string [RTT addition, logging
> >> framework change]
> >> 2) pass log messages from loggers to appenders over RTT's data flow
> >> implementation [logging framework extension]
> >> 3) provide default appenders that exist within components (say, a
> >> console appender and a write-to-file appender, for starters) [OCL]
> >> 4) provide configuration of the logging service via the deployer (I
> >> don't yet have a firm handle on how to do this, but I don't
> >> anticipate
> >> it being complicated). [OCL]
> >> 5) make sure the logging framework works in real-time and is multi-
> >> thread safe [logging framework change]. Most of the frameworks I've
> >> seen already support multi-thread, and some provide an abstraction of
> >> the actual threading/mutex environment (eg posix vs xxx)
> >
> > Call me ignorant but I don't quite see why logging can't simply be
> > realized by defining the best practice that each component has a "log"
> > port to which it writes its logging messages and a logger component
> > which reads and processes all these messages and allows to
> > disable/enable/filter/dispatch messages appropriately (your points 2)
>
> This _is_ a logger/category as it currently exists. But it also
> provides the hierarchy of loggers (useful in large systems) and
> appenders.

Yes, exactly!

> > 3) and 4). Why duplicate real-time and thread-safe queuing and
> > buffering (point 5) in a logging framework if we already have these
> > mechanisms in the more generic dataflow?
>
> I was trying to communicate that some of the existing frameworks
> already have multi-thread safety, and use an abstraction of a thread/
> mutex model to achieve that. So I think we can just wrap RTT::Mutex,
> etc, within the logging framework.
>
> The real change that we have to do is to separate the existing
> framework's direct connection from loggers to appenders, and drop the
> RTT data flow in there. That is the big change.
>
> I don't think we are duplicating anything.

Ok, I see (I told you to call me ignorant :-) )

> > WRT 1) I would be concerned with having a RTT:rtstring because it
> > seems like a free ride in real-time allocation while it will require
> > careful coordination of memory resources.
>
> Hang on, weren't you the one asking for real-time memory allocation
> for scripting ...?! :-)

Yes :-) But I don't think I would want to export it outside of lua
scripting and it will be required to explicitely set the preallocated
amount of memory. Because that's actually what a rt allocator does:
it's still preallocation of a fixed size, you only gain the freedom to
break it into chunks of your choice.

How would you deal with this parameter for rtstrings?

> It's either this, or fixed-length message strings. Personally, I'm not
> prepared to live with that restriction in comparison to dropping in
> TLSF (which Peter already intends to integrate, regardless of this
> discussion).

But just dropping in TLSF is not enough.... s.o. Can you give an
example of where you really need to log strings, and can't e.g. log a
number which get's translated into a string by a non-rt component? Or
would this be to inconveniant?

> >> I think 2 is the hardest part of the above, and 5 is the biggest
> >> uncertainty (and hence potentially the nightmare part).
> >>
> >> Note also that loggers/categories exist in a tree hierarchy. Very
> >> handy for turning on/off logging in certain parts of a program. Say
> >> you have loggers in a large app like
> >>
> >> org.me.myapp.component1
> >> org.me.myapp.component2
> >> org.me.myapp.component3.a
> >> org.me.myapp.component3.b
> >>
> >> You can set an overall log level for all categories simply by
> >> specifying it at the root.
> >>
> >> org.me.loglevel = warn
> >>
> >> and then turn on/off only certain parts if required
> >>
> >> org.me.loglevel = info
> >> org.me.myapp.component3.b.loglevel = debug
> >
> > Fine if these are RTT::properties or RTT::method calls...
>
> This is the part of 4) that I haven't yet gotten a good idea of. My
> working concept is for the deployer to get the configuration from XML
> file. You might want to provide RTT::Methods to change configuration
> later, I don't know yet ...

Ok!

Markus

Logging replacement

Submitted by sspr on Fri, 2009-10-02 09:00.

On Fri, Oct 2, 2009 at 08:58, Markus Klotzbuecher
<markus [dot] klotzbuecher [..] ...> wrote:
>> Hang on, weren't you the one asking for real-time memory allocation
>> for scripting ...?! :-)
>
> Yes :-) But I don't think I would want to export it outside of lua
> scripting and it will be required to explicitely set the preallocated
> amount of memory. Because that's actually what a rt allocator does:
> it's still preallocation of a fixed size, you only gain the freedom to
> break it into chunks of your choice.
>
> How would you deal with this parameter for rtstrings?

rt_string would throw std::bad_alloc in case of exhaustion and the log
message would be dropped. We'd probably need serveral TLSF instances
to create a fence between different subsystems with different
reliability needs.

>
>> It's either this, or fixed-length message strings. Personally, I'm not
>> prepared to live with that restriction in comparison to dropping in
>> TLSF (which Peter already intends to integrate, regardless of this
>> discussion).
>
> But just dropping in TLSF is not enough.... s.o. Can you give an
> example of where you really need to log strings, and can't e.g. log a
> number which get's translated into a string by a non-rt component? Or
> would this be to inconveniant?

The irony is that the conversion itself from int to string is
real-time, and only the (de)allocation of the char* buffer isn't. The
purpose of logging is to mix text with data for human inspection and
debugging. There is no way around it than to convert everything in
strings and you don't know the exact length of each string (number can
be big or small) and you don't want to pre-allocate every possible
string.

Peter

Logging replacement

Submitted by markus.klotzbuecher on Fri, 2009-10-02 12:05.

On Fri, Oct 02, 2009 at 10:58:10AM +0200, Peter Soetens wrote:
> On Fri, Oct 2, 2009 at 08:58, Markus Klotzbuecher
> <markus [dot] klotzbuecher [..] ...> wrote:
> >> Hang on, weren't you the one asking for real-time memory allocation
> >> for scripting ...?! :-)
> >
> > Yes :-) But I don't think I would want to export it outside of lua
> > scripting and it will be required to explicitely set the preallocated
> > amount of memory. Because that's actually what a rt allocator does:
> > it's still preallocation of a fixed size, you only gain the freedom to
> > break it into chunks of your choice.
> >
> > How would you deal with this parameter for rtstrings?
>
> rt_string would throw std::bad_alloc in case of exhaustion and the log
> message would be dropped. We'd probably need serveral TLSF instances
> to create a fence between different subsystems with different
> reliability needs.

... and that per process!

And for all theses instances you'll have to define the amount of
memory which they preallocate. How would that be done? At compile
time?

Rt memory will have to be freed to the same pool as it was allocated
from, but I guess you could hide that in the rt-string implementation?

And will people really catch that exception?

> >> It's either this, or fixed-length message strings. Personally, I'm not
> >> prepared to live with that restriction in comparison to dropping in
> >> TLSF (which Peter already intends to integrate, regardless of this
> >> discussion).
> >
> > But just dropping in TLSF is not enough.... s.o. Can you give an
> > example of where you really need to log strings, and can't e.g. log a
> > number which get's translated into a string by a non-rt component? Or
> > would this be to inconveniant?
>
> The irony is that the conversion itself from int to string is
> real-time, and only the (de)allocation of the char* buffer isn't. The
> purpose of logging is to mix text with data for human inspection and
> debugging. There is no way around it than to convert everything in
> strings and you don't know the exact length of each string (number can
> be big or small) and you don't want to pre-allocate every possible
> string.

Markus

Logging replacement

Submitted by sspr on Fri, 2009-10-02 12:20.

On Fri, Oct 2, 2009 at 14:00, Markus Klotzbuecher
<markus [dot] klotzbuecher [..] ...> wrote:
> On Fri, Oct 02, 2009 at 10:58:10AM +0200, Peter Soetens wrote:
>> On Fri, Oct 2, 2009 at 08:58, Markus Klotzbuecher
>> <markus [dot] klotzbuecher [..] ...> wrote:
>> >> Hang on, weren't you the one asking for real-time memory allocation
>> >> for scripting ...?! :-)
>> >
>> > Yes :-) But I don't think I would want to export it outside of lua
>> > scripting and it will be required to explicitely set the preallocated
>> > amount of memory. Because that's actually what a rt allocator does:
>> > it's still preallocation of a fixed size, you only gain the freedom to
>> > break it into chunks of your choice.
>> >
>> > How would you deal with this parameter for rtstrings?
>>
>> rt_string would throw std::bad_alloc in case of exhaustion and the log
>> message would be dropped. We'd probably need serveral TLSF instances
>> to create a fence between different subsystems with different
>> reliability needs.
>
> ... and that per process!
>
> And for all theses instances you'll have to define the amount of
> memory which they preallocate. How would that be done? At compile
> time?

Before you get frantic about all this, the logger only needs one
message and a few rt_string objects at a time/thread (times message
buffer size in data flow buffer ).
So the same piece of heap will be recycled each time. I don't see the
need for more than a few kb per process which will be vastly more than
enough.

>
> Rt memory will have to be freed to the same pool as it was allocated
> from, but I guess you could hide that in the rt-string implementation?
>
> And will people really catch that exception?

They won't need to. No way they'll be using rt_string directly, I
don't want 'some stupid logging code' to throw in their real-time
face. This will/must be encapsulated. Failure to allocate only
degrades the logging (lost message), not the real-time aspects of our
system.

Peter

Logging replacement

Submitted by snrkiwi on Fri, 2009-10-02 12:25.

On Oct 2, 2009, at 08:18 , Peter Soetens wrote:

> On Fri, Oct 2, 2009 at 14:00, Markus Klotzbuecher
> <markus [dot] klotzbuecher [..] ...> wrote:
>> On Fri, Oct 02, 2009 at 10:58:10AM +0200, Peter Soetens wrote:
>>> On Fri, Oct 2, 2009 at 08:58, Markus Klotzbuecher
>>> <markus [dot] klotzbuecher [..] ...> wrote:
>>>>> Hang on, weren't you the one asking for real-time memory
>>>>> allocation
>>>>> for scripting ...?! :-)
>>>>
>>>> Yes :-) But I don't think I would want to export it outside of lua
>>>> scripting and it will be required to explicitely set the
>>>> preallocated
>>>> amount of memory. Because that's actually what a rt allocator does:
>>>> it's still preallocation of a fixed size, you only gain the
>>>> freedom to
>>>> break it into chunks of your choice.
>>>>
>>>> How would you deal with this parameter for rtstrings?
>>>
>>> rt_string would throw std::bad_alloc in case of exhaustion and the
>>> log
>>> message would be dropped. We'd probably need serveral TLSF instances
>>> to create a fence between different subsystems with different
>>> reliability needs.
>>
>> ... and that per process!
>>
>> And for all theses instances you'll have to define the amount of
>> memory which they preallocate. How would that be done? At compile
>> time?
>
> Before you get frantic about all this, the logger only needs one
> message and a few rt_string objects at a time/thread (times message
> buffer size in data flow buffer ).
> So the same piece of heap will be recycled each time. I don't see the
> need for more than a few kb per process which will be vastly more than
> enough.

Agreed. And one of my first questions with integrating TLSF is how do
we configure this size. Compiled in default? Command line option to
deployer? XML option to deployer? (we actually want all of these IMHO)

>> Rt memory will have to be freed to the same pool as it was allocated
>> from, but I guess you could hide that in the rt-string
>> implementation?
>>
>> And will people really catch that exception?
>
> They won't need to. No way they'll be using rt_string directly, I
> don't want 'some stupid logging code' to throw in their real-time
> face. This will/must be encapsulated. Failure to allocate only
> degrades the logging (lost message), not the real-time aspects of our
> system.

Agreed. But, as a user I may want to make use of rt_string or the
dynamic memory allocator in my own code. If we put this capability in,
we must allow the user to make use of it.
Stephen

Logging replacement

Submitted by bruyninc on Mon, 2009-09-28 13:25.

On Mon, 28 Sep 2009, Stephen Roderick wrote:

> From recent ML discussions, and Peter's concluding email, RTT 2.x will contain an alternative logging
> functionality. My question is, what should it do ...? At the every least, it should support the same
> functionality that the current RTT::Logger class provides, but several issues were identified on the ML that
> people believe that RTT needs to support.
> So please discuss, critique or compliment the following ... they are approximately in order of priority, in my
> mind at least.
> 0) Completely disable all logging
> 1) Able log variable sized string messages
> 2) Able log from non-realtime and realtime code
> 3) Minimize (as reasonably practicable) the effect on runtime performance (eg minimize CPU cycles consumed)
> 4) Support different log levels
> 5) Support different "storage mediums" (ie able to log messages to file, to socket, to stdout)
>
> ** bar 3, and the "realtime" part of 2, the above is the functionality of the existing RTT::Logger **
>
> 6) Support different log levels within a deployed system (ie able to log debug in one area, and info in
> another)
> 7) Support multiple storage mediums simultaneously at runtime
> 8) Runtime configuration of storage mediums and logging levels
> 9) Allow the user to extend the possible storage mediums at deployment-time (ie user can provide new storage
> class)
>
> Optional IMHO
> 10) Support nested diagnostic contexts [1] [2] (a more advanced version of the Logger::In() that RTT's logger
> currently supports)
>
> Stephen
>
> [1] http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/NDC.html
> [2] Patterns for Logging Diagnostic Messages Abstract Introduction
>

I have little to add to your excellent summary! Maybe the following: I
think RTT should evolve towards adding a unique identifier to each (version
of a) component, which (among other useful applications) allows to _interpret_ the
logging data better. (I think this is very similar to your "diagnostic
contexts"...) Just giving a name is not enough. The OSGi approach might be
a "best practice" in this respect.

Herman

Logging replacement

Submitted by snrkiwi on Mon, 2009-09-28 14:25.

On Sep 28, 2009, at 09:22 , Herman Bruyninckx wrote:

> On Mon, 28 Sep 2009, Stephen Roderick wrote:
>
>> From recent ML discussions, and Peter's concluding email, RTT 2.x
>> will contain an alternative logging
>> functionality. My question is, what should it do ...? At the every
>> least, it should support the same
>> functionality that the current RTT::Logger class provides, but
>> several issues were identified on the ML that
>> people believe that RTT needs to support.
>> So please discuss, critique or compliment the following ... they
>> are approximately in order of priority, in my
>> mind at least.
>> 0) Completely disable all logging
>> 1) Able log variable sized string messages
>> 2) Able log from non-realtime and realtime code
>> 3) Minimize (as reasonably practicable) the effect on runtime
>> performance (eg minimize CPU cycles consumed)
>> 4) Support different log levels
>> 5) Support different "storage mediums" (ie able to log messages to
>> file, to socket, to stdout)
>> ** bar 3, and the "realtime" part of 2, the above is the
>> functionality of the existing RTT::Logger **
>> 6) Support different log levels within a deployed system (ie able
>> to log debug in one area, and info in
>> another)
>> 7) Support multiple storage mediums simultaneously at runtime
>> 8) Runtime configuration of storage mediums and logging levels
>> 9) Allow the user to extend the possible storage mediums at
>> deployment-time (ie user can provide new storage
>> class)
>> Optional IMHO
>> 10) Support nested diagnostic contexts [1] [2] (a more advanced
>> version of the Logger::In() that RTT's logger
>> currently supports)
>> Stephen
>> [1] http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/NDC.html
>> [2] Patterns for Logging Diagnostic Messages Abstract Introduction
>>
>
> I have little to add to your excellent summary! Maybe the following: I
> think RTT should evolve towards adding a unique identifier to each
> (version
> of a) component, which (among other useful applications) allows to
> _interpret_ the
> logging data better. (I think this is very similar to your "diagnostic
> contexts"...) Just giving a name is not enough. The OSGi approach
> might be
> a "best practice" in this respect.

If using a log4j-related implementation, the categories are often
labelled in (annotated) reverse DNS style ie

org.orocos.rtt.types
org.orocos.rtt.plugins
org.orocos.kdl
org.orocos.ocl.deployment

This might help, bar the version. None of our projects would need
version data, but it would be supported by these existing
implementations.

The NDCs are similar to what you are talking about, but I've typically
seen them used to annotate different areas within categories. So,
within a given component (say the component had one related category),
the NDCs would be used to realise where messages had come from
_within_ the component, or any code called by the component. Output
for the "org.orocos.kdl" category might look like

<date> org.orocos.kdl [context1] Some message
<date> org.orocos.kdl [context1] [context2] start something
...
<date> org.orocos.kdl [context1] [context2] end something
<date> org.orocos.kdl [context1] other message

HTH
Stephen