Logging issues

Andreas Hartmann wrote:

>
> Hi Michi,
>
> thanks for your commits - but I have some comments:
>
>> +import org.apache.log4j.Category;
>
>
> please don't introduce a custom logging concept for
single classes.
> DefaultDocument is already LogEnabled.


I know, but the current logging concept really sucks if I
might say so.
If you are able to show how one can configure it in a better
way, then I 
am fine,
but the logging information as it is just doesn't help at
all.

>
>>
>> +
>> +        if (languages.length > 0) {
>> +                log.warn("Document ("
+ this + ") exists in at least 
>> one language: " + languages.length);
>
>
> This warning message is not appropriate. Please use
debug instead.


agreed

> Too many warning logs will affect performance.
>
>
>> +                String[] allLanguages = 
>> getPublication().getLanguages();
>> +                if (languages.length ==
allLanguages.length) 
>> log.warn("Document (" + this + ")
exists even in all languages of 
>> this publication");
>> +                return true;
>> +            } else {
>> +                log.warn("Document ("
+ this + ") does NOT exist in 
>> any language");
>
>
> Same here. A warning is not appropriate here, because
it is normal
> behaviour.


Even if it's normal behaviour I think a WARNING makes
perfect sense, 
because no language exists
and I think it makes a lot of sense to tell where it is
being determined 
to figure out what might
be the reason for this

Michi

>
>
> -- Andreas
>
>
>> +                return false;
>> +            }
>> +
>> +// NOTE: This seems to be unecessary because
getLanguage() already 
>> creates these documents
>> +/*
>>          try {
>>              String[] languages = getLanguages();
>>              for (int i = 0; i <
languages.length; i++) {
>>  -274,6 +299,7 
>>              throw new DocumentException(e);
>>          }
>>          return exists;
>> +*/
>>      }
>>  
>>      protected DocumentIdentifier getIdentifier() {
>>  -341,16 +367,22 
>>       * see 
>>
org.apache.lenya.cms.metadata.MetaDataOwner#getMetaDataManag
er()
>>       */
>>      public MetaDataManager getMetaDataManager() {
>> +        log.debug("getSourceURI(): " +

>> getPublication().getSourceURI());
>>          if (this.metaDataManager == null) {
>>              SourceResolver resolver = null;
>>              RepositorySource source = null;
>>              try {
>>                  resolver = (SourceResolver) 
>> this.manager.lookup(SourceResolver.ROLE);
>> +
>> +                // TODO: This needs to be improved
...
>>                  String sourceUri =
getPublication().getSourceURI() + 
>> "/content/" + getArea()
>>                          + getId() +
"/index_" + getLanguage() + ".xml";
>> +
>> +                log.debug("Source URI:
" + sourceUri);
>>                  source = (RepositorySource) 
>> resolver.resolveURI(sourceUri);
>>                  this.metaDataManager = 
>> source.getNode().getMetaDataManager();
>>              } catch (Exception e) {
>> +                log.warn(e.getMessage());
>>                  throw new RuntimeException(e);
>>              } finally {
>>                  if (resolver != null) {
>
>
>


-- 
Michael Wechner
Wyona      -   Open Source Content Management   -    Apache
Lenya
http://www.wyona.com     
                http://lenya.apache.org
michael.wechnerwyona.com                        michiapache.org


------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
For additional commands, e-mail: dev-helplenya.apache.org

On Mon, 2006-03-13 at 19:46 +0100, Michael Wechner wrote:
> Andreas Hartmann wrote:
> 
> >
> > Hi Michi,
> >
> > thanks for your commits - but I have some
comments:
> >
> >> +import org.apache.log4j.Category;
> >
> >
> > please don't introduce a custom logging concept
for single classes.
> > DefaultDocument is already LogEnabled.
> 
> 
> I know, but the current logging concept really sucks if
I might say so.
> If you are able to show how one can configure it in a
better way, then I 
> am fine,
> but the logging information as it is just doesn't help
at all.

What I don't understand about the current logging is the
logger names.
For example, the output of PublicationImpl belongs to the
logger
"core.manager", and the output of
DefaultDocument belongs to
"lenya.publication" (at least that's what I see
in log4j.log).

It seems the names are associated to the avalon components,
but it makes
it kinda difficult to filter the log output of a certain
java class.

> 
> >
> >>
> >> +
> >> +        if (languages.length > 0) {
> >> +                log.warn("Document
(" + this + ") exists in at least 
> >> one language: " + languages.length);
> >
> >
> > This warning message is not appropriate. Please
use debug instead.
> 
> 
> agreed
> 
> > Too many warning logs will affect performance.
> >
> >
> >> +                String[] allLanguages = 
> >> getPublication().getLanguages();
> >> +                if (languages.length ==
allLanguages.length) 
> >> log.warn("Document (" + this +
") exists even in all languages of 
> >> this publication");
> >> +                return true;
> >> +            } else {
> >> +                log.warn("Document
(" + this + ") does NOT exist in 
> >> any language");
> >
> >
> > Same here. A warning is not appropriate here,
because it is normal
> > behaviour.
> 
> 
> Even if it's normal behaviour I think a WARNING makes
perfect sense, 
> because no language exists
> and I think it makes a lot of sense to tell where it is
being determined 
> to figure out what might
> be the reason for this

FYI, these are the descriptions of the log levels from the
log4j docu,
see [1]:

OFF
        The OFF has the highest possible rank and is
intended to turn
        off logging.

____________________________________________________________
____________
FATAL
        The FATAL level designates very severe error events
that will
        presumably lead the application to abort.

____________________________________________________________
____________
ERROR
        The ERROR level designates error events that might
still allow
        the application to continue running.

____________________________________________________________
____________
WARN
        The WARN level designates potentially harmful
situations.

____________________________________________________________
____________
INFO
        The INFO level designates informational messages
that highlight
        the progress of the application at coarse-grained
level.

____________________________________________________________
____________
DEBUG
        The DEBUG Level designates fine-grained
informational events
        that are most useful to debug an application.

____________________________________________________________
____________
TRACE
        The TRACE Level designates finer-grained
informational events
        than the DEBUG

____________________________________________________________
____________
ALL
        The ALL has the lowest possible rank and is intended
to turn on
        all logging.
        
        
Do you think it's a "potentially harmful
situation" if the method
existsInAnyLanguage() returns false? 
IMHO, only the caller of this method can determine whether
the result
(true or false) is harmful for the application. For the
method itself,
either result is fine.

Josias

[1] http://logging.apache.org/log4j/docs/api/org
/apache/log4j/Level.html


> 
> Michi
> 
> >
> >
> > -- Andreas
> >
> >
> >> +                return false;
> >> +            }
> >> +
> >> +// NOTE: This seems to be unecessary because
getLanguage() already 
> >> creates these documents
> >> +/*
> >>          try {
> >>              String[] languages =
getLanguages();
> >>              for (int i = 0; i <
languages.length; i++) {
> >>  -274,6 +299,7 
> >>              throw new DocumentException(e);
> >>          }
> >>          return exists;
> >> +*/
> >>      }
> >>  
> >>      protected DocumentIdentifier
getIdentifier() {
> >>  -341,16 +367,22 
> >>       * see 
> >>
org.apache.lenya.cms.metadata.MetaDataOwner#getMetaDataManag
er()
> >>       */
> >>      public MetaDataManager
getMetaDataManager() {
> >> +        log.debug("getSourceURI():
" + 
> >> getPublication().getSourceURI());
> >>          if (this.metaDataManager == null) {
> >>              SourceResolver resolver = null;
> >>              RepositorySource source = null;
> >>              try {
> >>                  resolver = (SourceResolver) 
> >> this.manager.lookup(SourceResolver.ROLE);
> >> +
> >> +                // TODO: This needs to be
improved ...
> >>                  String sourceUri =
getPublication().getSourceURI() + 
> >> "/content/" + getArea()
> >>                          + getId() +
"/index_" + getLanguage() + ".xml";
> >> +
> >> +                log.debug("Source URI:
" + sourceUri);
> >>                  source = (RepositorySource) 
> >> resolver.resolveURI(sourceUri);
> >>                  this.metaDataManager = 
> >> source.getNode().getMetaDataManager();
> >>              } catch (Exception e) {
> >> +                log.warn(e.getMessage());
> >>                  throw new
RuntimeException(e);
> >>              } finally {
> >>                  if (resolver != null) {
> >
> >
> >
> 
> 


------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
For additional commands, e-mail: dev-helplenya.apache.org

Josias Thöny wrote:

>On Mon, 2006-03-13 at 19:46 +0100, Michael Wechner
wrote:
>  
>
>>Andreas Hartmann wrote:
>>
>>    
>>
>>>Hi Michi,
>>>
>>>thanks for your commits - but I have some
comments:
>>>
>>>      
>>>
>>>>+import org.apache.log4j.Category;
>>>>        
>>>>
>>>please don't introduce a custom logging concept
for single classes.
>>>DefaultDocument is already LogEnabled.
>>>      
>>>
>>I know, but the current logging concept really sucks
if I might say so.
>>If you are able to show how one can configure it in
a better way, then I 
>>am fine,
>>but the logging information as it is just doesn't
help at all.
>>    
>>
>
>What I don't understand about the current logging is
the logger names.
>For example, the output of PublicationImpl belongs to
the logger
>"core.manager", and the output of
DefaultDocument belongs to
>"lenya.publication" (at least that's what I
see in log4j.log).
>
>It seems the names are associated to the avalon
components, but it makes
>it kinda difficult to filter the log output of a certain
java class.
>  
>

I think so too. If one uses log4j directly and uses the
following 
pattern within log4j.xconf

<param name="ConversionPattern"
value="%-4r %d [%t] %-5p %c.%M():%L %x - 
%m%n"/>

then debugging will become very easy, because one will know
exactly what 
class, method and line ...

>        
>        
>Do you think it's a "potentially harmful
situation" if the method
>existsInAnyLanguage() returns false? 
>  
>

false, there is no language version and I think this should
be indicated 
by at  least a WARNING

>IMHO, only the caller of this method can determine
whether the result
>(true or false) is harmful for the application. For the
method itself,
>either result is fine.
>  
>

the problem I see is that the DefaultDocument is an
implementation and 
if the implementation
itself does not throw a WARNING or an ERROR, but only higher
up, then 
it's very hard to debug
where the actually problem is located. If one would throw a
stacktrace 
then it should be alright,
but so far we don't log stacktraces for WARNINGS.

Michi

>Josias
>
>[1] http://logging.apache.org/log4j/docs/api/org
/apache/log4j/Level.html
>
>
>  
>
>>Michi
>>
>>    
>>
>>>-- Andreas
>>>
>>>
>>>      
>>>
>>>>+                return false;
>>>>+            }
>>>>+
>>>>+// NOTE: This seems to be unecessary
because getLanguage() already 
>>>>creates these documents
>>>>+/*
>>>>         try {
>>>>             String[] languages =
getLanguages();
>>>>             for (int i = 0; i <
languages.length; i++) {
>>>> -274,6 +299,7 
>>>>             throw new DocumentException(e);
>>>>         }
>>>>         return exists;
>>>>+*/
>>>>     }
>>>> 
>>>>     protected DocumentIdentifier
getIdentifier() {
>>>> -341,16 +367,22 
>>>>      * see 
>>>>org.apache.lenya.cms.metadata.MetaDataOwner#
getMetaDataManager()
>>>>      */
>>>>     public MetaDataManager
getMetaDataManager() {
>>>>+        log.debug("getSourceURI():
" + 
>>>>getPublication().getSourceURI());
>>>>         if (this.metaDataManager == null) {
>>>>             SourceResolver resolver = null;
>>>>             RepositorySource source = null;
>>>>             try {
>>>>                 resolver = (SourceResolver)

>>>>this.manager.lookup(SourceResolver.ROLE);
>>>>+
>>>>+                // TODO: This needs to be
improved ...
>>>>                 String sourceUri =
getPublication().getSourceURI() + 
>>>>"/content/" + getArea()
>>>>                         + getId() +
"/index_" + getLanguage() + ".xml";
>>>>+
>>>>+                log.debug("Source
URI: " + sourceUri);
>>>>                 source = (RepositorySource)

>>>>resolver.resolveURI(sourceUri);
>>>>                 this.metaDataManager = 
>>>>source.getNode().getMetaDataManager();
>>>>             } catch (Exception e) {
>>>>+                log.warn(e.getMessage());
>>>>                 throw new
RuntimeException(e);
>>>>             } finally {
>>>>                 if (resolver != null) {
>>>>        
>>>>
>>>
>>>      
>>>
>>    
>>
>
>
>--------------------------------------------------------
-------------
>To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
>For additional commands, e-mail: dev-helplenya.apache.org
>
>
>  
>


-- 
Michael Wechner
Wyona      -   Open Source Content Management   -    Apache
Lenya
http://www.wyona.com     
                http://lenya.apache.org
michael.wechnerwyona.com                        michiapache.org


------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
For additional commands, e-mail: dev-helplenya.apache.org

Michael Wechner wrote:

[...]

>>               Do you think it's a
"potentially harmful situation" if 
>> the method
>> existsInAnyLanguage() returns false?  
>>
> 
> false, there is no language version and I think this
should be indicated 
> by at  least a WARNING

No, that's not the case. The check for the existing
language version
implicates that the caller is aware of the case that the
language
version does not exist. This method could be called, for
instance, to
enable / disable the "Create language version"
menu item.


>> IMHO, only the caller of this method can determine
whether the result
>> (true or false) is harmful for the application. For
the method itself,
>> either result is fine.

I totally agree to Josias.


> the problem I see is that the DefaultDocument is an
implementation and 
> if the implementation
> itself does not throw a WARNING or an ERROR, but only
higher up, then 
> it's very hard to debug
> where the actually problem is located.

I don't understand this implication. You throw an exception
when a
problem occurs. Why should you log a warning if the caller
might
interpret the result of this method as a problem? Then you
could
log warnings in virtually every line of the code.


> If one would throw a stacktrace 
> then it should be alright,
> but so far we don't log stacktraces for WARNINGS.

If an exception is thrown, a stack trace is logged.

-- Andreas


-- 
Andreas Hartmann
Wyona Inc.  -   Open Source Content Management   -   Apache
Lenya
http://www.wyona.com     
                http://lenya.apache.org
andreas.hartmannwyona.com                     andreasapache.org


------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
For additional commands, e-mail: dev-helplenya.apache.org

Josias Thöny wrote:
> On Mon, 2006-03-13 at 19:46 +0100, Michael Wechner
wrote:
>> Andreas Hartmann wrote:
>>
>>> Hi Michi,
>>>
>>> thanks for your commits - but I have some
comments:
>>>
>>>> +import org.apache.log4j.Category;
>>>
>>> please don't introduce a custom logging
concept for single classes.
>>> DefaultDocument is already LogEnabled.
>>
>> I know, but the current logging concept really
sucks if I might say so.
>> If you are able to show how one can configure it in
a better way, then I 
>> am fine,
>> but the logging information as it is just doesn't
help at all.
> 
> What I don't understand about the current logging is
the logger names.
> For example, the output of PublicationImpl belongs to
the logger
> "core.manager",

That's because the PublicationManager component isn't
configured
in cocoon.xconf. You could add for instance

<component
class="org.apache.lenya.cms.publication.PublicationMan
agerImpl"
           
role="org.apache.lenya.cms.publication.PublicationMana
ger"
            logger="lenya.publication"/>

Then the logger "lenya.publication" is used.

> and the output of DefaultDocument belongs to
> "lenya.publication" (at least that's what
I see in log4j.log).

The DefaultDocumentBuilder has the lenya.publication logger:

     <document-builders>
       <component-instance 
class="org.apache.lenya.cms.publication.DefaultDocumen
tBuilder" 
logger="lenya.publication"
name="default"/>
     </document-builders>



> It seems the names are associated to the avalon
components, but it makes
> it kinda difficult to filter the log output of a
certain java class.

If we need finer logging granularity, we could replace

   ContainerUtil.enableLogging(publication, getLogger());

with

   ContainerUtil.enableLogging(publication,
getLogger().getChildLogger(...));

IMO component-level granularity is sufficient in most cases,
but
it's fine with me to change it.


-- Andreas


-- 
Andreas Hartmann
Wyona Inc.  -   Open Source Content Management   -   Apache
Lenya
http://www.wyona.com     
                http://lenya.apache.org
andreas.hartmannwyona.com                     andreasapache.org


------------------------------------------------------------
---------
To unsubscribe, e-mail: dev-unsubscribelenya.apache.org
For additional commands, e-mail: dev-helplenya.apache.org