logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Aron Bock" <aronb...@hotmail.com>
Subject Re: Multiple Projects Using Same Logger
Date Sun, 22 May 2005 22:27:28 GMT
Jacob,

As I mentioned in a prior post I'm getting the behavior I want, and have 
since found that 'static'-ness of logger variables are not contributing 
factors to the contrary.  My findings are below and, since they only 
supplement the prior statement, may be skipped.

Thank you for your help.  I believe I now have a slightly better 
understanding of log4j.

Regards,

--A

> >However, from my reading of the "short" version of the online manual, 
>which
> >states that "Under certain well-defined circumstances however, the static
> >inializer of the Logger class will attempt to automatically configure
> >log4j", but which subsequently severally exemplifies explicitly 
>indicating
> >the log4j configuration file, I came away with the idea that explicitly
> >indicating the configuration file is preferable.

Heh!  I didn't mean to be that dense--but I was too lazy to split the 
sentence after I'd started it, and from the tone of the prior response 
assumed I'd have to resolve this issue myself anyway :-)  Still, all I meant 
was that the online manual talked about 'auto configuration' in "certain 
well defined circumstances", but then immediately showed several samples of 
explicit configuration ... so I assumed explicit was better.

>are you saying that autoconfiguration works, but your explicit 
>configuration doesn't?   In that case, I'd be a bit wary that you are 
>actually configuring things properly in explicit configuration.

Yes, auto config works, but I'm not saying that explicit config does not.  
What I *can* say is that auto- or explicit-, I *am* passing in a valid log4j 
configuration file.

>You do realize that autoconfiguration is probably happening anyway.  This 
>is because the static initializer will come into play before you config 
>servlet does.  And the fact that you have log4j.properties in the classpath 
>(WEB-INF/classes) means that autoconfiguration will find the file.

I made sure this was not the case--when I tried explicit configuration I 
removed the props file from classes/, and placed it in a new folder, 
WEB-INF/conf/

>However, this also presents a dilemma, because there may exist a Log4j 
>config file somewhere in a higher classloader.

This is not the case in my test app as described.

>To shortcircuit that, I recommend putting a minimal log4j.xml file in 
>WEB-INF/classes that sets the root logger to OFF or something like that.  
>Then, if there is any logging happening, you can attribute it purely to the 
>explicit configuration.

Good suggestion.  During explicit configuration tests, when the static 
initializer kicked in (before the Servlet) I used to get "log4j:WARN Please 
initialize the log4j system properly."  Then the Servlet would kick in and 
configure ... and subsequently I get log4j output as expected.  Now I've 
placed a single-line file

log4j.rootLogger=OFF

under classes/, and that initial warning message is suppressed.

>Ok, here's the thing.  I hinted at it before, but did not spell it out.  I 
>told that "you are probably making bad assumptions on
>behavior which is why you only ever see the System.out message".

As noted before, I get logger output from Foo, but "sysout" output from Bar. 
  The difference, again, is that Foo is a class in the "main" app, and Bar 
is in a referenced "library" app.

> >if ( logger != null && logger.getAllAppenders().hasMoreElements()
>
>1.  You define the logger above.  It won't be null.  The check is 
>unnecessary, but causes no harm.  So far so good

Yeah, I didn't know Logger.get<logger> semantics.  I originally assumed if 
things weren't "configured" I'd get back null.

>2.  You attempt to get the appenders on the current logger and assume that 
>hasMoreElements() will tell you if there is an appender defined for that 
>logger.  However, I believe this assumption is incorrect.  Inherited 
>appenders won't show themselves here.

Yes, this was my assumption: the online manual talked about how appenders 
were inherited, and 'additive'.  Thus it seemed logical that if I didn't 
explicitly set an appender for a non-root logger, yet could expect to get 
output from it, I could also expect to enumerate its [implicitly-set, 
inherited] appenders.  Furthermore, even if I don't explicitly set an 
appender for a non-root logger, I can still set its output level (DEBUG, 
INFO, etc); to me this corroborated my mental modal that inherited appenders 
would show up in an enumeration.  Obviously my mental model was wrong.

>You added an appender to the root logger.  I would hasten to bet that 
>getRootLogger.getAllAppenders.hasMoreElements() would return true.  
>However, as no appenders were explicitly added to the current logger, 
>hasMoreElements() will return false on the current logger (someone please 
>correct me if I'm wrong here).

This is correct, as I subsequently discovered and posted.

>I just re-read your original message and saw noticed when you said "Now, I 
>want to use this already-initialized logger".  Are you under the impression 
>that loggers are initialized individually?   When you perform 
>configuration, you are configuring the behavior of a "logger repository".

I hadn't as yet come across the term "logger repository" ... but I meant 
something along the lines of 'now I want to use existing initialization 
settings', keeping in mind that I'd seen mention of loggers being 
singletons.

> >The reason I first call logMessage() is so that it is the one "gateway" 
>to
> >logging (I would, of course, arrange for calls to it not to use the
> >log4j-specific "Level" parameter).  Also, remember that Bar is a separate
> >"library", and I don't want its logs going to log4j when not used in a
> >webapp.  Hence the check for configuredness, etc.
>
>It is difficult to check for Log4j configuredness, at least under 
>Log4j-1.2.x.  However, there is some code out there that can help...
>
>See the isConfigured() method at
>http://wiki.apache.org/logging-log4j/UsefulCode

Thanx for the link.  I came across it after I discovered the 
test-root-appenders approach myself.  IMO the example is unnecessarily 
wordy--NullEnumeration extends Enumeration, so we may as well call 
hasMoreElements without all that instanceof business.  I didn't know about 
LogManager.  I did read elsewhere that isConfigured is/will be a 1.3 method.

>If the only difference between the "working" version of your setup and the 
>non-working version is the use of autoconfiguration or not with absolutely 
>everything else exactly the same, then I would tend to suspect your 
>explicit configuration.

The explicit configuration is correct.

> >private void logMessage(String msg, Level lvl) {
> >        Logger logger = Logger.getLogger(this.getClass().getName());
> >        if ( logger.isDebugEnabled()
> >                &&
> >Logger.getRootLogger().getAllAppenders().hasMoreElements() )
> >...
>
>Ok, well, first of all, you changed your code from before.  Now you are 
>getting appenders attached to the root logger, instead of the current local 
>logger.  Change one thing at a time.

I do change one thing at a time.  I prefer not to post each change 
individually ;-)

>  I bet this code would work in your previous case from your first email.  
>I think you are confused.

It does work (again, as I discovered and posted) -- the "right" code has a 
disconcerting habit of doing so.  That I was/am confused is stating the 
obvious :-)

>The change of the logger  from static to a non-static local variable makes 
>no difference unless you are extending this class, in which case this 
>getClass().getName() could return different names.  It wouldn't have to be 
>a local variable, though.  An instance variable would work fine in that 
>case.

I'm not extending classes--my test setup has 2 classes: Foo and Bar.  I've 
since found that the sole issue was that of assuming that inherited 
appenders would show up in getAllAppenders().

>As such, the check makes little to no sense unless you are sometimes using 
>this library in cases where you do not configure Log4j at all.  But then 
>why use Log4j in the first place?  The whole point is to remove usage of 
>System.out for logging.  Well, I guess you have your own requirements, so I 
>won't second guess that this may simply be something you have to support.  
>Looks messy to me, IMHO.

Yes, sometimes I want to use the "library" in a different environment, and 
don't want log4j output.  The System.out was simply for testing 
configuredness.  It could be replaced by an adapter for a JMS queue for all 
I care.  What's more I may use a framework such as Spring to "inject" a 
concrete logging mechanism at runtime, if the need arises.  So, in sum, yes, 
let's just say that sometimes I want to use log4j, and some other times I 
don't (and don't want to see warning messages).

Anyway, the behavior I've isolated follows.  First, my setup, again:

j2ee web app
=======
    webroot/
        WEB-INF/
            classes/
                log4jInitServlet (uses log4j props file)
                log4j.properties
                com.foo/ (contains Foo.java, which uses logger)
            lib/
                bar.jar (contains com.bar.Bar.java)

The log4j props file is as below:

log4j.properties
=======

log4j.rootLogger=ERROR, A1

log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%d [%t] %-5p %c - %m%n

# Set logging levels
log4j.logger.com.foo=INFO
log4j.logger.com.bar=DEBUG

The relevant portions of Bar.java is as follows:
=======

class Bar {
    static Logger logger = Logger.getLogger(Bar.class.getName());

    public void getBar() {
        logMessage( "called getBar", Level.DEBUG);
        logMessage( "called getBar", Level.INFO);
    }

    private void logMessage(String msg, Level lvl) {
       //...
    }
}

case1:
=======

    private void logMessage(String msg, Level lvl) {
       logger.log(lvl,  msg);
    }

Here, I get expected behavior when bar.jar is used in a log4j-webapp.  (That 
it's a webapp has little bearing, really, but since that is what I've 
described thus far, let's keep with it.)  However, when used as a library in 
a non log4j-environment, I get warnings that log4j is not configured.  No 
surprises here.

case2:
=======

    private void logMessage(String msg, Level lvl) {
        if ( logger.isDebugEnabled()
                &&  logger.getAllAppenders().hasMoreElements() )
            logger.log(lvl, msg);
        else
            System.out.println("sysout:" + msg);
    }

Here, when used in a non-log4j environment, I get "sysout"; this is 
expected.  When used in the webapp above I get logger output from Foo, but 
"sysout" output from Bar.  This is explained by appenders set on the root 
logger not being visible in a non-root logger's getAllAppenders result.

case3:
=======

    private void logMessage(String msg, Level lvl) {
        if ( logger.isDebugEnabled()
                &&  
Logger.getRootLogger().getAllAppenders().hasMoreElements() )
            logger.log(lvl, msg);
        else
            System.out.println("sysout:" + msg);
    }

Here, when used in a non-log4j environment, I get "sysout"; this is 
expected.  When used in the webapp above I get logger output from Foo *and* 
Bar.  This is the wanted result.

case4:
=======

    // remove static logger variable

    private void logMessage(String msg, Level lvl) {
        Logger logger = Logger.getLogger( this.getClass().getName() );

        if ( logger.isDebugEnabled()
                &&  
Logger.getRootLogger().getAllAppenders().hasMoreElements() )
            logger.log(lvl, msg);
        else
            System.out.println("sysout:" + msg);
    }

Here, when used in a non-log4j environment, I get "sysout"; this is 
expected.  When used in the webapp above I get logger output from Foo *and* 
Bar.  This shows, as you pointed out, that the "static"-ness of the logger 
variable has no effect.

case5:
=======

    // remove static logger variable

    private void logMessage(String msg, Level lvl) {
        Logger logger = Logger.getLogger( this.getClass().getName() );

        if ( logger.isDebugEnabled()
                &&  logger.getAllAppenders().hasMoreElements() )
            logger.log(lvl, msg);
        else
            System.out.println("sysout:" + msg);
    }

Here, when used in a non-log4j environment, I get "sysout"; this is 
expected.  When used in the webapp above I get logger output from Foo, but 
"sysout" output from Bar.  It supports that root appenders don't show up in 
a non-root logger's getAllAppenders()

Anyhoo, Jacob, thank you very much for your time.

Now I have an unrelated question: I run the webapp under Tomcat 5.x.  When 
the output level of the root logger is set to DEBUG, and I have log4j props 
under WEB-INF/classes, I get a *ton* of Tomcat-output to logs.  Is this 
because Tomacat itself uses log4j, and is reacting to the setting?

I've seen the same behavior from JSF, running under Sun Web Server.

Regards,

--A

_________________________________________________________________
FREE pop-up blocking with the new MSN Toolbar  get it now! 
http://toolbar.msn.click-url.com/go/onm00200415ave/direct/01/


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org


Mime
View raw message