On 8/29/07, Raymond Feng <[EMAIL PROTECTED]> wrote:
>
> I just created https://issues.apache.org/jira/browse/TUSCANY-1635 to track
> the aspectj-based tracing.
>
> Thanks,
> Raymond
>
> ----- Original Message -----
> From: "Jean-Sebastien Delfino" <[EMAIL PROTECTED]>
> To: <tuscany-dev@ws.apache.org>
> Sent: Wednesday, August 29, 2007 11:06 AM
> Subject: Re: Monitoring, logging and exceptions (again)
>
>
> > Simon Laws wrote:
> >> On 8/20/07, Simon Laws <[EMAIL PROTECTED]> wrote:
> >>
> >>>
> >>> On 8/20/07, Simon Nash <[EMAIL PROTECTED] > wrote:
> >>>
> >>>> See inline.
> >>>>
> >>>> Simon
> >>>>
> >>>> Raymond Feng wrote:
> >>>>
> >>>>
> >>>>> Comments inline.
> >>>>>
> >>>>> Thanks,
> >>>>> Raymond
> >>>>>
> >>>>> ----- Original Message ----- From: "Jean-Sebastien Delfino"
> >>>>> < [EMAIL PROTECTED]>
> >>>>> To: < tuscany-dev@ws.apache.org>
> >>>>> Sent: Friday, August 17, 2007 9:27 AM
> >>>>> Subject: Re: Monitoring, logging and exceptions (again)
> >>>>>
> >>>>>
> >>>>>
> >>>>>> [snip]
> >>>>>> ant elder wrote:
> >>>>>>
> >>>>>>
> >>>>>>> And also my 2p inline...
> >>>>>>>
> >>>>>>> ...ant
> >>>>>>>
> >>>>>>> On 8/16/07, Simon Laws < [EMAIL PROTECTED]> wrote:
> >>>>>>>
> >>>>>>>
> >>>>>>>> A number of different requirements have been discussed and
> >>>>>>>>
> >>>> solutions
> >>>>
> >>>>>>>> proposed. My 2p (I'm using Raymond's definitions b.t.w)
> >>>>>>>>
> >>>>>>>> Tracing: Dump out input/output/exception for method calls for the
> >>>>>>>> purpose
> >>>>>>>> of
> >>>>>>>> debugging/troubleshooting. (Target for developers/technical
> >>>>>>>>
> >>>> support)
> >>>>
> >>>>>>>> I feel that tracing of execution paths through the Tuscany
> codebase
> >>>>>>>> would
> >>>>>>>> be
> >>>>>>>> useful but agree that " it's a lot of work and will be difficult
> to
> >>>>>>>> maintain
> >>>>>>>> and keep consistent" if we did it manually. I'm happy that this
> is
> >>>>>>>>
> >>>> the
> >>>>
> >>>>>>>> responsibility of whoever wants to trace through the code and not
> a
> >>>>>>>> core
> >>>>>>>> part of the codebase. For the Tuscany developer community AspectJ
> >>>>>>>>
> >>>> have
> >>>>
> >>>>>>>> been
> >>>>>>>> proposed a couple of times and support has been prototyped. We
> >>>>>>>>
> >>>> could
> >>>>
> >>>>>>>> choose
> >>>>>>>> SLF4J as the interface through which messages are output.
> >>>>>>>>
> >>>>>>>>
> >>>>>>> I'm not sure we need to use SLF4J if we go the AspectJ route.
> SLF4J
> >>>>>>>
> >>>> is a
> >>>>
> >>>>>>> facade for logging APIs, so you can code to the SLF4J API and
> then
> >>>>>>> plug in
> >>>>>>> whatever logging impl you like, but if the only logging calls we
> >>>>>>>
> >>>> have
> >>>>
> >>>>>>> are
> >>>>>>> confined to a single tracing aspect we might as well just code
> that
> >>>>>>> aspect
> >>>>>>> to a specific logging API like JDK logging. That avoids the extra
> >>>>>>> dependency
> >>>>>>> on SLF4J and anyone can add additional aspects if they really want
> >>>>>>>
> >>>> to
> >>>>
> >>>>>>> use a
> >>>>>>> different logger. The main other benefit of SLF4J is its
> >>>>>>>
> >>>> parameterized
> >>>>
> >>>>>>> message logging (avoids all the "if(logger.isDebugEnabled())" )
> but
> >>>>>>> again if
> >>>>>>> all the logging calls are in a single aspect thats not so useful.
> >>>>>>>
> >>>>>>>
> >>>>>> Makes sense to me. If we go the aspectj route for tracing method
> >>>>>> entry/exit, I agree that using the JDK logger directly is simpler.
> >>>>>>
> >>>>>>
> >>>>> Since the aspect is on the side, we're flexible. JDK logger can be
> >>>>> default and it can be replaced easily if the embedders or users
> choose
> >>>>> to do so.
> >>>>>
> >>>>>
> >>>>>> A few more questions on this: What dependencies will aspectj add to
> >>>>>> our distribution? aspectjweaver is more than 1Mb, do we need it?
> >>>>>>
> >>>>> I'll try to spend some time to explore both the compile-time and
> >>>>> load-time weaving.
> >>>>>
> >>>>>
> >>>>>>> What about mid-method logging of specific interesting events, for
> >>>>>>> example
> >>>>>>> the contents of requests as the enter and leave bindings and
> >>>>>>> implementation
> >>>>>>> types and things like that? That sort of logging is often all a
> lot
> >>>>>>> of users
> >>>>>>> want to see not the detail tracing of every method entry/exit.
> Could
> >>>>>>> we add
> >>>>>>> things like this in specific places?
> >>>>>>>
> >>>>>>>
> >>>> +1 for the ability to produce this level of information. This is my
> >>>> preferred approach for debugging or understanding how some part of
> the
> >>>> code works. Having every method entry and exit produce a trace line
> >>>> often creates a huge amount of output that obscures the essential
> >>>> details
> >>>> of what is happening.
> >>>>
> >>>>
> >>>>>> Can this mid-method logging be split in two categories?
> >>>>>>
> >>>>>> a) Debug tracing
> >>>>>> A simple solution is to split the method in two, and then leverage
> >>>>>>
> >>>> the
> >>>>
> >>>>>> entry/exit method tracing as discussed above.
> >>>>>>
> >>>> In many cases this would lead to a convoluted code structure with
> local
> >>>> variables needing to be passed as parameters between the two methods,
> >>>> or
> >>>> methods that contain a single line of code (if a trace line needs to
> be
> >>>> produced from within a loop).
> >>>>
> >>>>
> >>>>> We can use JDK logger to add statements in the middle of a method.
> >>>>>
> >>>> Then
> >>>>
> >>>>> we can use an aspect to capture such calls to dump out the
> >>>>>
> >>>> information.
> >>>>
> >>>>> For example, if we have the following statement in a method:
> >>>>> logger.debug(...);
> >>>>> The apsect can trap it by a point cut like "call *
> >>>>> java.util.logger.Logger.debug(..).
> >>>>>
> >>>>>
> >>>> If the logger call is already there, why is an aspect needed to trap
> >>>> it?
> >>>> Why not just let it execute?
> >>>>
> >>>>
> >>>>>> b) End-user readable information (info that a binding is
> >>>>>> sending/receiving a message for example)
> >>>>>> This falls into the second category discussed in this thread,
> >>>>>> reporting significant events to a management console.
> >>>>>>
> >>>>> The above suggestion should help too. The key here is to have some
> >>>>>
> >>>> calls
> >>>>
> >>>>> to indicate such requirements and they can be then trapped to
> provide
> >>>>> the concrete logic.
> >>>>>
> >>>>>
> >>>>>> I think we're starting to see concrete solutions for (a) with
> >>>>>>
> >>>> aspectj.
> >>>>
> >>>>>> I have not seen any real concrete proposal for (b) yet.
> >>>>>>
> >>>>>> --
> >>>>>> Jean-Sebastien
> >>>>>>
> >>>>>>
> >>>>>>
> >>>>
> >>>> ---------------------------------------------------------------------
> >>>> To unsubscribe, e-mail: [EMAIL PROTECTED]
> >>>> For additional commands, e-mail: [EMAIL PROTECTED]
> >>>>
> >>> I agree that entry and exit tracing can be overwhelming in a lot of
> >>> situations. I think this is an advantage of taking the AspectJ
> approach.
> >>> If
> >>> people want to add this kind of tracing then we can make that possible
> >>> with
> >>> no direct impact on the tuscany code base.
> >>>
> >>> A concrete proposal for other messages...
> >>>
> >>> I've been poking around to see what others do and, on closer
> inspection,
> >>> CXF have a rather nice, IMHO, approach which is a combination of a
> home
> >>> grown logging util class and the JDK logger that.
> >>>
> >>> uses parameters to reduce the formatting load for inactive log
> >>> statements
> >>> uses message property files for message lookup
> >>> encompasses basic internationalization support using ICU and the
> >>> message
> >>> files behind the scenes
> >>> handles exceptions and strings (although it doesn't localize
> exception
> >>> strings)
> >>>
> >>> SLF4J does very similar things to this but we didn't seem to get much
> >>> traction with that before on this thread. It seems that we all have
> >>> different requirements for reducing dependencies vs providing logging
> >>> function. If we can reach a satisfactory level of function while
> relying
> >>> on
> >>> the built in JDK logging features then that seems to be a good
> >>> compromise.
> >>> Also with some home grown utilities we can at least make life a little
> >>> easier for ourselves in terms of recording user oriented messages
> >>> related to
> >>> model elements.
> >>>
> >>> Looking at the CXF code this is what you build.
> >>>
> >>> MyModule
> >>> src
> >>> main
> >>> java
> >>> somepath
> >>> SomeTuscanyClassA
> >>> Messages.properties
> >>> resources
> >>> logging.properties
> >>>
> >>> Nothing too surprising there. They have a LogUtil class (see
> >>> cxf-common-utilities) which provides an interface for getting JDK
> >>> loggers
> >>> and for logging with them. I'm assuming they created it but we should
> >>> check.
> >>> Here is an example of how to use it.
> >>>
> >>> import java.util.logging.Level;
> >>> import java.util.logging.Logger;
> >>>
> >>> import org.apache.cxf.common.logging.LogUtils;
> >>>
> >>> public class SomeTuscanyClassA {
> >>>
> >>> private static final Logger Log1 = LogUtils.getL7dLogger (
> >>> SomeTuscanyClassA.class);
> >>>
> >>> public SomeTuscanyClassA() {
> >>> Integer params[] = {8, 9, 4};
> >>>
> >>> LogUtils.log(Log1,
> >>> Level.INFO,
> >>> "TEST_MESSAGE",
> >>> null,
> >>> (Object[])params);
> >>>
> >>> Exception ex = new IllegalStateException("some exception
> >>> string");
> >>>
> >>> LogUtils.log(Log1,
> >>> Level.INFO ,
> >>> "TEST_MESSAGE",
> >>> ex,
> >>> (Object[])params);
> >>>
> >>>
> >>> }
> >>>
> >>> We could then extend this to allow for common Tuscany situations. For
> >>> example, by allowing a model element to be passed in,
> >>>
> >>> LogUtils.log(Log1,
> >>> Level.INFO,
> >>> composite, // or some other specialization
> of
> >>> Base where the component name, uri can be read from
> >>> "TEST_MESSAGE",
> >>> null,
> >>> (Object[])params);
> >>>
> >>> We could then chose to use
> >>>
> >>> SEVERE
> >>> WARNING
> >>> INFO
> >>> CONFIG
> >>>
> >>> To record our end user readable information. This proposal assumes
> >>> people
> >>> are comfortable with committing to JDK logging. If people are
> >>> comfortable
> >>> with this then I don't see why we can't use.
> >>>
> >>> FINE
> >>> FINER
> >>> FINEST
> >>>
> >>> for mid method tracing.
> >>>
> >>> So is this going in the right direction? Or do people have completely
> >>> different approaches in mind?
> >>>
> >>> Regards
> >>>
> >>> Simon
> >>>
> >>>
> >>>
> >>>
> >>>
> >>>
> >>>
> >>>
> >>>
> >>> I have noticed JDK logger statements appearing in various places in
> the
> >>>
> >> code. Did we reached a conclusion on this?
> >>
> >> Simon
> >>
> >>
> >
> > Looks like System.out.println calls have been replaced by JDK logger
> calls
> > in revision r568417:
> > http://svn.apache.org/viewvc?view=rev&revision=568417
> >
> > I'm happy with that change, JDK logger is probably not perfect... but
> > which logger library is? Sorry for bringing that up :)
> >
> > I don't think we've reached any clear conclusion on tracing. Here's my
> > opinion:
> >
> > I'm +1 on using JDK logger;
> >
> > would prefer to avoid a home-grown logger layer on top of it (as we have
> > better things to do than grow yet another not perfect logger API);
> >
> > and I'm happy with using aspectj to generate entry/exit trace calls
> > externally without polluting the runtime source code, but I think we
> > should just provide a sample + documentation showing how to do it on the
> > side instead of embedding aspectj in our runtime.
> >
> > I don't have a firm opinion on monitoring - which is a different subject
> > IMO - yet.
> >
> > --
> > Jean-Sebastien
> >
> >
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: [EMAIL PROTECTED]
> > For additional commands, e-mail: [EMAIL PROTECTED]
> >
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: [EMAIL PROTECTED]
> For additional commands, e-mail: [EMAIL PROTECTED]
>
> Ok, so we know there is no generally acceptable logging interface. Has
been proved time and time again. All we can hope to do is use something that
suits us and doesn't mess up anyone who wants to embed our code.
I'm perfectly happy to +1 JDK logging. However without some wrappers to do
it for us we need to define the ground rules for how we use it.
So, in line with what I believe is common practice, how about these...
End user readable information is expected to be recorded against the
following levels
SEVERE
WARNING
INFO
CONFIG
The following levels are tracing levels and are assumed to be developer
readable only
FINE
FINER
FINEST
Loggers will be initialized against the class name to which they relate, and
a resource bundle for the package/or module.
private static final Logger Log = Logger.getLogger(
SomeTuscanyClassB.class.getName(), "tuscany-?-messages");
We can define some global o.a.t.s loggers if we don't want to have to make
bundles for all of the non-extension modules, e.g.
private static final Logger Log = Logger.getLogger("org.apache.tuscany.sca,
"tuscany-messages");
Log statements for user readable messages will take the following form, for
example,
Log.log(Level.INFO,
"MESSAGE1");
String componentName = "Some component";
Log.log(Level.INFO,
"MESSAGE2", // message id
componentName); // parameter
Integer params[] = {8, 9, 4};
Log.log(Level.INFO,
"MESSAGE3", // message id
params); // parameter
Exception ex = new IllegalStateException("TEST_MESSAGE");
Log.log(Level.INFO,
"MESSAGE4", // message id
ex); // parameter
These messages will be localized against a message bundle from the classpath
based on the configuration of the Logger (or the Logger's parent), for
example, tuscany-messages.properties, tuscany-messages_en.properties etc.
MESSAGE1 = This is a test message with no params
MESSAGE2 = This is a test message with a string param {0}
MESSAGE3 = This is a test message with numbers {0}, {1}, {2}
MESSAGE4 = This is a test message with exception
Which can of course be provided on an extension by extension basis if
required and if specified when the logger is created.
Developer readable messages are assumed not to be localized and so can be
output using the Logger convenience methods.
We won't use log.entering and log exiting. This level of tracing will be
provided via AspectJ injection.
I'm assuming we don't want our logging properties to have to live in
jdk/lib/logging properties so we need an extensible/replaceable way to
initialize logging. e.g.
InputStream logConfigStream = Thread.currentThread
().getContextClassLoader().getResourceAsStream("tuscany-logging.properties
");
LogManager.getLogManager().readConfiguration(logConfigStream);
+ any other logging configuration that we need
Anyone have a good idea where to put this. It should go close to the start
of our domain/node implementation but would be good if it's replaceable. So
we could do with a new logging extension type that is one of the first
things that gets loaded.
Simon
