You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@avalon.apache.org by vo...@basf-it-services.com on 2003/06/22 14:27:23 UTC
SitemapSource calls Pipeline twice, Logging issue in Avalon
Hi all,
I post this also to the Avalon list, because while tracking this
SitemapSource issue I found a Avalon Logging issue also.
Ok, what happen:
Calling a Cocoon Source "cocoon://....." the Pipeline inside the Sitemap is
called twice. The reason is the following code inside the
SitemapSourceFactory
public void release( Source source ) {
if ( null != source ) {
if ( this.getLogger().isDebugEnabled() ) {
this.getLogger().debug("Releasing source " + source.getURI());
}
((SitemapSource)source).recycle();
}
}
The problem is the source.getURI() inside the logging statement. Why?
Because the source is already reset after the serialization and a call to
source.getURI initialize the source again and this calles the Sitemap again
:-(
My proposal is, remove the source.getURI from the logging statement or
change the getURI() implementation to not init the Source again. I am not
sure if this URI can change after it is init?
Now to the Avalon Logging issue.
Hm I am wondering why
if ( this.getLogger().isDebugEnabled() )
was true, because I had no log-level configured as DEBUG.
After a long time of debugging :-( I found two things.
1. org.apache.avalon.framework.logger.LogKit2AvalonLoggerAdapter
In the method:
public static org.apache.log.Logger createLogger( final Logger logger )
{
final Hierarchy hierarchy = new Hierarchy();
final org.apache.log.Logger logKitLogger = hierarchy.getLoggerFor( ""
);
final LogKit2AvalonLoggerAdapter target =
new LogKit2AvalonLoggerAdapter( logger );
logKitLogger.setLogTargets( new LogTarget[ ] { target } );
return logKitLogger;
}
a logKitLogger is created with "hierarchy.getLoggerFor( "" )" this defaults
the loglevel to DEBUG. The orig Logger is wrapped inside the LogTarget, so
the result loglevel of the logger is allways DEBUG independant of the orig
Logger setting.
I have add the following code after the creation of the logKitLogger
if (!logger.isDebugEnabled()) {
if (!logger.isWarnEnabled()) {
if (!logger.isErrorEnabled()) {
logKitLogger.setPriority(Priority.FATAL_ERROR);
} else {
logKitLogger.setPriority(Priority.ERROR);
}
} else {
logKitLogger.setPriority(Priority.WARN);
}
}
and vola, now the isDebugEnabled inside the SitemapSourceFactory return
false :-)
But then I wonder why is the Logger inside the SitemapSourceFactory is a
wrapped Logger, because SitemapSourceFactory impl. LogEnabled, so the
wrapping isn't needed. After an additional debugging session I found the
reason.
2. org.apache.avalon.excalibur.component.DefaultComponentFactory
Method newInstance first checks if a Component implements "LogEnabled" and
after this it checks for "Loggable". The problem is, if a Component impl.
AbstractDualLogEnabled like ExcaliburComponentSelector the "setLogger"
method of AbstractDualLogEnabled impl. overwrites the prev. set Logger with
a wrapped LogKitLogger. Hm, I changed the order and put the check for
"LogEnabled" after the "Loggable" and :-) the Logger isn't a wrapped
LogKitLogger anymore.
Switch back to Cocoon:
There are a lot of Components inside the cocoon.xconf which has no logger
configured inside the configuration. Example are "Source Factories" and
most of the Selectors itself.
<input-modules>
<output-modules>
<source-factories>
Should we change this?
Sorry for such a long mail, but I hope this helps improve the performance
of Cocoon ;-) While debugging all this stuff I thought it's time to switch
to a new Container which hasn't all this Adapter/Wrapper classe ;-)
Volker
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Joerg Heinicke <jo...@gmx.de>.
volker.schmitt@basf-it-services.com wrote:
> Ok, what happen:
> Calling a Cocoon Source "cocoon://....." the Pipeline inside the Sitemap is
> called twice. The reason is the following code inside the
> SitemapSourceFactory
>
> public void release( Source source ) {
> if ( null != source ) {
> if ( this.getLogger().isDebugEnabled() ) {
> this.getLogger().debug("Releasing source " + source.getURI());
> }
> ((SitemapSource)source).recycle();
> }
> }
>
> The problem is the source.getURI() inside the logging statement. Why?
> Because the source is already reset after the serialization and a call to
> source.getURI initialize the source again and this calles the Sitemap again
> :-(
>
> My proposal is, remove the source.getURI from the logging statement or
> change the getURI() implementation to not init the Source again. I am not
> sure if this URI can change after it is init?
Is this possibly the same problem as described at
http://marc.theaimsgroup.com/?t=105586313100003&r=1&w=2 ??
Joerg
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Anton Tagunov <at...@mail.cnt.ru>.
vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
I mean, please co avalon-excalibur/component from the cvs :)
- Anton
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re[2]: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Anton Tagunov <at...@mail.cnt.ru>.
Hello Leo!
AT> Have I fixed this? :-)
AT>
AT> - if( component instanceof Loggable )
AT> + else if( component instanceof Loggable )
LS> that's along the line of my expectation of correct behaviour. But it
LS> might break existing code that depends on receiving both?
Oh, now I see more..
Should I revert the change?
- Anton
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
RE: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Carsten Ziegeler <cz...@s-und-n.de>.
I changed the AbstractDualLogEnabled on friday; it now tests when
the "Loggable" Logger is set, if the "LogEnabled" is already set;
and only if that was not set previously, the wrapper is used.
I guess this should fix the problem as well; if not, the change
should not do any harm.
Carsten
> -----Original Message-----
> From: news [mailto:news@main.gmane.org]On Behalf Of Leo Simons
> Sent: Monday, June 30, 2003 10:24 AM
> To: dev@avalon.apache.org
> Subject: Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
>
>
> Anton Tagunov wrote:
> > vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
> > vsbisc> Method newInstance first checks if a Component
> implements "LogEnabled" and
> > vsbisc> after this it checks for "Loggable". The problem is, if
> a Component impl.
> > vsbisc> AbstractDualLogEnabled like ExcaliburComponentSelector
> the "setLogger"
> > vsbisc> method of AbstractDualLogEnabled impl. overwrites the
> prev. set Logger
> >
> > Have I fixed this? :-)
> >
> > - if( component instanceof Loggable )
> > + else if( component instanceof Loggable )
>
> that's along the line of my expectation of correct behaviour. But it
> might break existing code that depends on receiving both?
>
> - Leo
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
> For additional commands, e-mail: dev-help@avalon.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Leo Simons <le...@apache.org>.
Anton Tagunov wrote:
> vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
> vsbisc> Method newInstance first checks if a Component implements "LogEnabled" and
> vsbisc> after this it checks for "Loggable". The problem is, if a Component impl.
> vsbisc> AbstractDualLogEnabled like ExcaliburComponentSelector the "setLogger"
> vsbisc> method of AbstractDualLogEnabled impl. overwrites the prev. set Logger
>
> Have I fixed this? :-)
>
> - if( component instanceof Loggable )
> + else if( component instanceof Loggable )
that's along the line of my expectation of correct behaviour. But it
might break existing code that depends on receiving both?
- Leo
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Anton Tagunov <at...@mail.cnt.ru>.
Hello Volker!
vsbisc> My proposal is, remove the source.getURI from the logging statement or
vsbisc> change the getURI() implementation to not init the Source again.
Is this indeed possible? I personally would prefer this.
If for some reason it is not possible we may want to
scratch our heads again :)
vsbisc> Now to the Avalon Logging issue.
vsbisc> Hm I am wondering why
vsbisc> if ( this.getLogger().isDebugEnabled() )
vsbisc> was true, because I had no log-level configured as DEBUG.
vsbisc> After a long time of debugging :-( I found two things.
vsbisc> 1. org.apache.avalon.framework.logger.LogKit2AvalonLoggerAdapter
vsbisc> In the method:
vsbisc> public static org.apache.log.Logger createLogger( final Logger logger )
Hmmm... looks like LogKit2AvalonLoggerAdapter does only
part of the job: the
.debug()
.error()
etc.
calls are passed onto the wrapped avalon logger correctly, but
the .isDebugEnabled(), etc. are not passed at all. A good point.
I'm no guru here, but I would prefer a complete
LogKit2AvalonLoggerAdapter.createLogger() rewrite.
The best would be the reverse of LogKitLogger.
I only doubt how to name it.
I also doubt that it belongs to avalon framework.
But essentially we need a reverse of LogKitLogger.
vsbisc> I have add the following code after the creation of the logKitLogger
vsbisc> if (!logger.isDebugEnabled()) {
vsbisc> if (!logger.isWarnEnabled()) {
vsbisc> if (!logger.isErrorEnabled()) {
vsbisc> logKitLogger.setPriority(Priority.FATAL_ERROR);
vsbisc> } else {
vsbisc> logKitLogger.setPriority(Priority.ERROR);
vsbisc> }
vsbisc> } else {
vsbisc> logKitLogger.setPriority(Priority.WARN);
vsbisc> }
vsbisc> }
Hmmm... another solution, it's inside the
LogKit2AvalonLoggerAdapter.createLogger()
method, isn't it? The idea is to deduct the log level of the
avalon logger we're wrapping and assign it to our LogKit logger..
A complete rewrite of this method looks better to me..
If there is a need to fix this class at all..
vsbisc> and vola, now the isDebugEnabled inside the SitemapSourceFactory return
vsbisc> false :-)
vsbisc> But then I wonder why is the Logger inside the SitemapSourceFactory is a
vsbisc> wrapped Logger, because SitemapSourceFactory impl. LogEnabled, so the
vsbisc> wrapping isn't needed. After an additional debugging session I found the
vsbisc> reason.
vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
vsbisc> Method newInstance first checks if a Component implements "LogEnabled" and
vsbisc> after this it checks for "Loggable". The problem is, if a Component impl.
vsbisc> AbstractDualLogEnabled like ExcaliburComponentSelector the "setLogger"
vsbisc> method of AbstractDualLogEnabled impl. overwrites the prev. set Logger
Have I fixed this? :-)
- if( component instanceof Loggable )
+ else if( component instanceof Loggable )
- Anton
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Leo Simons <le...@apache.org>.
volker.schmitt@basf-it-services.com wrote:
> Now to the Avalon Logging issue.
> Hm I am wondering why
> if ( this.getLogger().isDebugEnabled() )
> was true, because I had no log-level configured as DEBUG.
> After a long time of debugging :-( I found two things.
>
> 1. org.apache.avalon.framework.logger.LogKit2AvalonLoggerAdapter
> In the method:
>
> public static org.apache.log.Logger createLogger( final Logger logger )
> {
> final Hierarchy hierarchy = new Hierarchy();
> final org.apache.log.Logger logKitLogger = hierarchy.getLoggerFor( ""
> );
> final LogKit2AvalonLoggerAdapter target =
> new LogKit2AvalonLoggerAdapter( logger );
> logKitLogger.setLogTargets( new LogTarget[ ] { target } );
> return logKitLogger;
> }
>
> a logKitLogger is created with "hierarchy.getLoggerFor( "" )" this defaults
> the loglevel to DEBUG. The orig Logger is wrapped inside the LogTarget, so
> the result loglevel of the logger is allways DEBUG independant of the orig
> Logger setting.
that's not really what we want, is it? :D
I guess something like
> if (!logger.isDebugEnabled()) {
> if (!logger.isWarnEnabled()) {
> if (!logger.isErrorEnabled()) {
> logKitLogger.setPriority(Priority.FATAL_ERROR);
> } else {
> logKitLogger.setPriority(Priority.ERROR);
> }
> } else {
> logKitLogger.setPriority(Priority.WARN);
> }
> }
can go into createLogger().
> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
> Method newInstance first checks if a Component implements "LogEnabled" and
> after this it checks for "Loggable". The problem is, if a Component impl.
> AbstractDualLogEnabled like ExcaliburComponentSelector the "setLogger"
> method of AbstractDualLogEnabled impl. overwrites the prev. set Logger with
> a wrapped LogKitLogger. Hm, I changed the order and put the check for
> "LogEnabled" after the "Loggable" and :-) the Logger isn't a wrapped
> LogKitLogger anymore.
Hmm. Why do we have a component that is both LogEnabled and Loggable?
That seems to be, in general, a bad idea. I have always been under the
impression that the two stages should be mutually exclusive.
cheers,
- Leo
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@avalon.apache.org
For additional commands, e-mail: dev-help@avalon.apache.org
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Anton Tagunov <at...@mail.cnt.ru>.
vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
I mean, please co avalon-excalibur/component from the cvs :)
- Anton
Re: SitemapSource calls Pipeline twice, Logging issue in Avalon
Posted by Anton Tagunov <at...@mail.cnt.ru>.
Hello Volker!
vsbisc> My proposal is, remove the source.getURI from the logging statement or
vsbisc> change the getURI() implementation to not init the Source again.
Is this indeed possible? I personally would prefer this.
If for some reason it is not possible we may want to
scratch our heads again :)
vsbisc> Now to the Avalon Logging issue.
vsbisc> Hm I am wondering why
vsbisc> if ( this.getLogger().isDebugEnabled() )
vsbisc> was true, because I had no log-level configured as DEBUG.
vsbisc> After a long time of debugging :-( I found two things.
vsbisc> 1. org.apache.avalon.framework.logger.LogKit2AvalonLoggerAdapter
vsbisc> In the method:
vsbisc> public static org.apache.log.Logger createLogger( final Logger logger )
Hmmm... looks like LogKit2AvalonLoggerAdapter does only
part of the job: the
.debug()
.error()
etc.
calls are passed onto the wrapped avalon logger correctly, but
the .isDebugEnabled(), etc. are not passed at all. A good point.
I'm no guru here, but I would prefer a complete
LogKit2AvalonLoggerAdapter.createLogger() rewrite.
The best would be the reverse of LogKitLogger.
I only doubt how to name it.
I also doubt that it belongs to avalon framework.
But essentially we need a reverse of LogKitLogger.
vsbisc> I have add the following code after the creation of the logKitLogger
vsbisc> if (!logger.isDebugEnabled()) {
vsbisc> if (!logger.isWarnEnabled()) {
vsbisc> if (!logger.isErrorEnabled()) {
vsbisc> logKitLogger.setPriority(Priority.FATAL_ERROR);
vsbisc> } else {
vsbisc> logKitLogger.setPriority(Priority.ERROR);
vsbisc> }
vsbisc> } else {
vsbisc> logKitLogger.setPriority(Priority.WARN);
vsbisc> }
vsbisc> }
Hmmm... another solution, it's inside the
LogKit2AvalonLoggerAdapter.createLogger()
method, isn't it? The idea is to deduct the log level of the
avalon logger we're wrapping and assign it to our LogKit logger..
A complete rewrite of this method looks better to me..
If there is a need to fix this class at all..
vsbisc> and vola, now the isDebugEnabled inside the SitemapSourceFactory return
vsbisc> false :-)
vsbisc> But then I wonder why is the Logger inside the SitemapSourceFactory is a
vsbisc> wrapped Logger, because SitemapSourceFactory impl. LogEnabled, so the
vsbisc> wrapping isn't needed. After an additional debugging session I found the
vsbisc> reason.
vsbisc> 2. org.apache.avalon.excalibur.component.DefaultComponentFactory
vsbisc> Method newInstance first checks if a Component implements "LogEnabled" and
vsbisc> after this it checks for "Loggable". The problem is, if a Component impl.
vsbisc> AbstractDualLogEnabled like ExcaliburComponentSelector the "setLogger"
vsbisc> method of AbstractDualLogEnabled impl. overwrites the prev. set Logger
Have I fixed this? :-)
- if( component instanceof Loggable )
+ else if( component instanceof Loggable )
- Anton