You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@myfaces.apache.org by Simon Kitching <sk...@apache.org> on 2006/02/20 03:50:52 UTC

logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:

> Simon,
> 
> Could you do me a favor and publicize this in the Struts community as
> well?  The framework code there is littered with static log instances
> to. 

Will do.

>  You might also want to add some notes related to using Log instances
> in Serializable classes (see below). 

Will do that also.

> 
> MyFaces folks,
> 
> There *is* a JSF-specific consideration to think about, if you have
> classes that implement StateHolder (like a UIComponent
> implementation).  Log instances will generally *not* be serializable,
> so you will need to deal specially with them in saveState() and
> restoreState() methods.  The simplest thing is to just not save them,
> and do a "new" operation again in restoreState(). 

Sorry but I don't understand. Why won't the normal approach work?

  public class SomeComponent .... {
    private Log log = LogFactory.getLog(SomeComponent.class);
    ...
  }

AIUI, the log object won't be saved in the saveState method, but it will
be recreated nicely during the RestoreView phase when a new instance is
created for the state to be restored into.

> 
> Along the same lines, if your class implements Serializable, you will
> need to mark the instance variable transient.  I've started using the
> following pattern in my Serializable classes, which would work inside
> a StateHolder as well: 
> 
>     private transient Log log = null;
> 
>     private Log log() {
>         if (log == null) {
>             log = LogFactory.getLog(...);
>         }
>         return log;
>     }
> 
> and a typical call looks like: 
> 
>     if (log().isDebugEnabled()) {
>        log().debug("...");
>     }

Ok, transient is needed here. But apart from that why won't the standard
approach work?

  public class SomeThing implements Serializable {
    private transient Log log = LogFactory.getLog(SomeThing.class);
    ...
    if (log.isDebugEnabled()) {
      log.debug("...");
    }
  }

Doesn't the log object get recreated when the deserialization occurs?

The log() method is quite a lot of boilerplate, and also imposes an
additional method call for every isDebugEnabled() call. [The extra call
inside the guard is not really relevant as output *is* going to occur at
this point which greatly outweighs the price of the method call].

Cheers,

Simon


Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Martin Marinschek <ma...@gmail.com>.
Hmm... didn't we settle on JDK 1.4 a while ago?

Simon has some other arguments on not using JDK logging, see above.

regards,

Martin

On 2/20/06, Craig McClanahan <cr...@apache.org> wrote:
>
>
> On 2/19/06, Martin Marinschek <ma...@gmail.com> wrote:
> > Indeed.
> >
> > this really means I'd be willing to switch to JDK logging. What was
> > the reason again we couldn't do that?
>
> If we are willing to live with a "JDK 1.4 or later" restriction, no reason
> at all.  That, however, would seem to be an issue for some current users.
>
> > regards,
> >
> > Martin
>
> Craig
>
> > On 2/20/06, Adam Winer <aw...@gmail.com> wrote:
> > > Weeellll....  if you implement StateHolder, this isn't an issue.
> > > The public no-arg constructor will be used, variable initializer
> > > expressions will run, etc.
> > >
> > > If you implement Serializable instead, then Craig's totally right -
> > > transient variables will not be re-initialized.   You can deal with
> > > this by adding the log() method, or by providing an implementation
> > > of:
> > >
> > >  private void readObject(ObjectInputStream in)
> > >
> > > ... which can re-initialize any transient values.
> > >
> > > I am *so* thankful that java.util.logging doesn't force any of
> > > this pain on its users.
> > >
> > > -- Adam
> > >
> > >
> > >
> > > On 2/19/06, Craig McClanahan <cr...@apache.org> wrote:
> > > >
> > > >
> > > >
> > > > On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
> > > > > On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:
> > > > >
> > > > > > Simon,
> > > > > >
> > > > > > Could you do me a favor and publicize this in the Struts community
> as
> > > > > > well?  The framework code there is littered with static log
> instances
> > > > > > to.
> > > > >
> > > > > Will do.
> > > > >
> > > > > >  You might also want to add some notes related to using Log
> instances
> > > > > > in Serializable classes (see below).
> > > > >
> > > > > Will do that also.
> > > > >
> > > > > >
> > > > > > MyFaces folks,
> > > > > >
> > > > > > There *is* a JSF-specific consideration to think about, if you
> have
> > > > > > classes that implement StateHolder (like a UIComponent
> > > > > > implementation).  Log instances will generally *not* be
> serializable,
> > > > > > so you will need to deal specially with them in saveState() and
> > > > > > restoreState() methods.  The simplest thing is to just not save
> them,
> > > > > > and do a "new" operation again in restoreState().
> > > > >
> > > > > Sorry but I don't understand. Why won't the normal approach work?
> > > > >
> > > > >   public class SomeComponent .... {
> > > > >     private Log log = LogFactory.getLog(SomeComponent.class);
> > > > >     ...
> > > > >   }
> > > > >
> > > > > AIUI, the log object won't be saved in the saveState method, but it
> will
> > > > > be recreated nicely during the RestoreView phase when a new instance
> is
> > > > > created for the state to be restored into.
> > > > >
> > > > > >
> > > > > > Along the same lines, if your class implements Serializable, you
> will
> > > > > > need to mark the instance variable transient.  I've started using
> the
> > > > > > following pattern in my Serializable classes, which would work
> inside
> > > > > > a StateHolder as well:
> > > > > >
> > > > > >     private transient Log log = null;
> > > > > >
> > > > > >     private Log log() {
> > > > > >         if (log == null) {
> > > > > >             log = LogFactory.getLog(...);
> > > > > >         }
> > > > > >         return log;
> > > > > >     }
> > > > > >
> > > > > > and a typical call looks like:
> > > > > >
> > > > > >     if (log().isDebugEnabled()) {
> > > > > >        log().debug("...");
> > > > > >     }
> > > > >
> > > > > Ok, transient is needed here. But apart from that why won't the
> standard
> > > > > approach work?
> > > > >
> > > > >   public class SomeThing implements Serializable {
> > > > >     private transient Log log = LogFactory.getLog (SomeThing.class);
> > > > >     ...
> > > > >     if ( log.isDebugEnabled()) {
> > > > >       log.debug("...");
> > > > >     }
> > > > >   }
> > > > >
> > > > > Doesn't the log object get recreated when the deserialization
> occurs?
> > > >
> > > > No, AIUI.  When an object is deserialized, it does *not* execute the
> > > > variable initializer expressions.  Since it was declared transient,
> there's
> > > > no state for that object to be restored.
> > > >
> > > > > The log() method is quite a lot of boilerplate, and also imposes an
> > > > > additional method call for every isDebugEnabled() call. [The extra
> call
> > > > > inside the guard is not really relevant as output *is* going to
> occur at
> > > > > this point which greatly outweighs the price of the method call].
> > > >
> > > > You can reduce that by one call by protecting only the conditional
> > > > expression, because if you get inside you know there's an object ...
> but
> > > > that means you are relying on the implicit contract between the log
> instance
> > > > variable and the log() method.
> > > >
> > > > > Cheers,
> > > > >
> > > > > Simon
> > > > >
> > > > >
> > > > Craig
> > > >
> > > >
> > >
> >
> >
> > --
> >
> > http://www.irian.at
> >
> > Your JSF powerhouse -
> > JSF Consulting, Development and
> > Courses in English and German
> >
> > Professional Support for Apache MyFaces
> >
>
>


--

http://www.irian.at

Your JSF powerhouse -
JSF Consulting, Development and
Courses in English and German

Professional Support for Apache MyFaces

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Craig McClanahan <cr...@apache.org>.
On 2/19/06, Martin Marinschek <ma...@gmail.com> wrote:
>
> Indeed.
>
> this really means I'd be willing to switch to JDK logging. What was
> the reason again we couldn't do that?


If we are willing to live with a "JDK 1.4 or later" restriction, no reason
at all.  That, however, would seem to be an issue for some current users.

regards,
>
> Martin


Craig

On 2/20/06, Adam Winer <aw...@gmail.com> wrote:
> > Weeellll....  if you implement StateHolder, this isn't an issue.
> > The public no-arg constructor will be used, variable initializer
> > expressions will run, etc.
> >
> > If you implement Serializable instead, then Craig's totally right -
> > transient variables will not be re-initialized.   You can deal with
> > this by adding the log() method, or by providing an implementation
> > of:
> >
> >  private void readObject(ObjectInputStream in)
> >
> > ... which can re-initialize any transient values.
> >
> > I am *so* thankful that java.util.logging doesn't force any of
> > this pain on its users.
> >
> > -- Adam
> >
> >
> >
> > On 2/19/06, Craig McClanahan <cr...@apache.org> wrote:
> > >
> > >
> > >
> > > On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
> > > > On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:
> > > >
> > > > > Simon,
> > > > >
> > > > > Could you do me a favor and publicize this in the Struts community
> as
> > > > > well?  The framework code there is littered with static log
> instances
> > > > > to.
> > > >
> > > > Will do.
> > > >
> > > > >  You might also want to add some notes related to using Log
> instances
> > > > > in Serializable classes (see below).
> > > >
> > > > Will do that also.
> > > >
> > > > >
> > > > > MyFaces folks,
> > > > >
> > > > > There *is* a JSF-specific consideration to think about, if you
> have
> > > > > classes that implement StateHolder (like a UIComponent
> > > > > implementation).  Log instances will generally *not* be
> serializable,
> > > > > so you will need to deal specially with them in saveState() and
> > > > > restoreState() methods.  The simplest thing is to just not save
> them,
> > > > > and do a "new" operation again in restoreState().
> > > >
> > > > Sorry but I don't understand. Why won't the normal approach work?
> > > >
> > > >   public class SomeComponent .... {
> > > >     private Log log = LogFactory.getLog(SomeComponent.class);
> > > >     ...
> > > >   }
> > > >
> > > > AIUI, the log object won't be saved in the saveState method, but it
> will
> > > > be recreated nicely during the RestoreView phase when a new instance
> is
> > > > created for the state to be restored into.
> > > >
> > > > >
> > > > > Along the same lines, if your class implements Serializable, you
> will
> > > > > need to mark the instance variable transient.  I've started using
> the
> > > > > following pattern in my Serializable classes, which would work
> inside
> > > > > a StateHolder as well:
> > > > >
> > > > >     private transient Log log = null;
> > > > >
> > > > >     private Log log() {
> > > > >         if (log == null) {
> > > > >             log = LogFactory.getLog(...);
> > > > >         }
> > > > >         return log;
> > > > >     }
> > > > >
> > > > > and a typical call looks like:
> > > > >
> > > > >     if (log().isDebugEnabled()) {
> > > > >        log().debug("...");
> > > > >     }
> > > >
> > > > Ok, transient is needed here. But apart from that why won't the
> standard
> > > > approach work?
> > > >
> > > >   public class SomeThing implements Serializable {
> > > >     private transient Log log = LogFactory.getLog (SomeThing.class);
> > > >     ...
> > > >     if (log.isDebugEnabled()) {
> > > >       log.debug("...");
> > > >     }
> > > >   }
> > > >
> > > > Doesn't the log object get recreated when the deserialization
> occurs?
> > >
> > > No, AIUI.  When an object is deserialized, it does *not* execute the
> > > variable initializer expressions.  Since it was declared transient,
> there's
> > > no state for that object to be restored.
> > >
> > > > The log() method is quite a lot of boilerplate, and also imposes an
> > > > additional method call for every isDebugEnabled() call. [The extra
> call
> > > > inside the guard is not really relevant as output *is* going to
> occur at
> > > > this point which greatly outweighs the price of the method call].
> > >
> > > You can reduce that by one call by protecting only the conditional
> > > expression, because if you get inside you know there's an object ...
> but
> > > that means you are relying on the implicit contract between the log
> instance
> > > variable and the log() method.
> > >
> > > > Cheers,
> > > >
> > > > Simon
> > > >
> > > >
> > > Craig
> > >
> > >
> >
>
>
> --
>
> http://www.irian.at
>
> Your JSF powerhouse -
> JSF Consulting, Development and
> Courses in English and German
>
> Professional Support for Apache MyFaces
>

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Simon Kitching <sk...@apache.org>.
On Mon, 2006-02-20 at 07:59 +0100, Martin Marinschek wrote:
> Indeed.
> 
> this really means I'd be willing to switch to JDK logging. What was
> the reason again we couldn't do that?

The JSF 1.1 spec requires java 1.3 compatibility. At least that's what
this email stated:

http://marc.theaimsgroup.com/?l=myfaces-dev&m=113398269804780&w=2


Cheers,

Simon


Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Martin Marinschek <ma...@gmail.com>.
Indeed.

this really means I'd be willing to switch to JDK logging. What was
the reason again we couldn't do that?

regards,

Martin

On 2/20/06, Adam Winer <aw...@gmail.com> wrote:
> Weeellll....  if you implement StateHolder, this isn't an issue.
> The public no-arg constructor will be used, variable initializer
> expressions will run, etc.
>
> If you implement Serializable instead, then Craig's totally right -
> transient variables will not be re-initialized.   You can deal with
> this by adding the log() method, or by providing an implementation
> of:
>
>  private void readObject(ObjectInputStream in)
>
> ... which can re-initialize any transient values.
>
> I am *so* thankful that java.util.logging doesn't force any of
> this pain on its users.
>
> -- Adam
>
>
>
> On 2/19/06, Craig McClanahan <cr...@apache.org> wrote:
> >
> >
> >
> > On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
> > > On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:
> > >
> > > > Simon,
> > > >
> > > > Could you do me a favor and publicize this in the Struts community as
> > > > well?  The framework code there is littered with static log instances
> > > > to.
> > >
> > > Will do.
> > >
> > > >  You might also want to add some notes related to using Log instances
> > > > in Serializable classes (see below).
> > >
> > > Will do that also.
> > >
> > > >
> > > > MyFaces folks,
> > > >
> > > > There *is* a JSF-specific consideration to think about, if you have
> > > > classes that implement StateHolder (like a UIComponent
> > > > implementation).  Log instances will generally *not* be serializable,
> > > > so you will need to deal specially with them in saveState() and
> > > > restoreState() methods.  The simplest thing is to just not save them,
> > > > and do a "new" operation again in restoreState().
> > >
> > > Sorry but I don't understand. Why won't the normal approach work?
> > >
> > >   public class SomeComponent .... {
> > >     private Log log = LogFactory.getLog(SomeComponent.class);
> > >     ...
> > >   }
> > >
> > > AIUI, the log object won't be saved in the saveState method, but it will
> > > be recreated nicely during the RestoreView phase when a new instance is
> > > created for the state to be restored into.
> > >
> > > >
> > > > Along the same lines, if your class implements Serializable, you will
> > > > need to mark the instance variable transient.  I've started using the
> > > > following pattern in my Serializable classes, which would work inside
> > > > a StateHolder as well:
> > > >
> > > >     private transient Log log = null;
> > > >
> > > >     private Log log() {
> > > >         if (log == null) {
> > > >             log = LogFactory.getLog(...);
> > > >         }
> > > >         return log;
> > > >     }
> > > >
> > > > and a typical call looks like:
> > > >
> > > >     if (log().isDebugEnabled()) {
> > > >        log().debug("...");
> > > >     }
> > >
> > > Ok, transient is needed here. But apart from that why won't the standard
> > > approach work?
> > >
> > >   public class SomeThing implements Serializable {
> > >     private transient Log log = LogFactory.getLog (SomeThing.class);
> > >     ...
> > >     if (log.isDebugEnabled()) {
> > >       log.debug("...");
> > >     }
> > >   }
> > >
> > > Doesn't the log object get recreated when the deserialization occurs?
> >
> > No, AIUI.  When an object is deserialized, it does *not* execute the
> > variable initializer expressions.  Since it was declared transient, there's
> > no state for that object to be restored.
> >
> > > The log() method is quite a lot of boilerplate, and also imposes an
> > > additional method call for every isDebugEnabled() call. [The extra call
> > > inside the guard is not really relevant as output *is* going to occur at
> > > this point which greatly outweighs the price of the method call].
> >
> > You can reduce that by one call by protecting only the conditional
> > expression, because if you get inside you know there's an object ... but
> > that means you are relying on the implicit contract between the log instance
> > variable and the log() method.
> >
> > > Cheers,
> > >
> > > Simon
> > >
> > >
> > Craig
> >
> >
>


--

http://www.irian.at

Your JSF powerhouse -
JSF Consulting, Development and
Courses in English and German

Professional Support for Apache MyFaces

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Adam Winer <aw...@gmail.com>.
On 2/20/06, Simon Kitching <sk...@apache.org> wrote:
> On Mon, 2006-02-20 at 11:51 -0800, Adam Winer wrote:
> > IIRC, you have a personal stake in this issue, but the
> > plain truth is that there is no war anymore - java.util.logging
> > won by Sun's fiat.  Technical superiority is not the ultimate
> > arbiter.
> >
>
> Yes, I am a commons-logging committer. That doesn't mean I believe it's
> perfect; I work on it because I need it, and because it *does* have
> flaws that need work.
>
> I don't have any interest in defending JCL against true complaints; the
> ClassCastException problems experienced with 1.0.4 and earlier are an
> example (though one that is at least partially caused by what I consider
> to be bad container design in many cases).
>
> The recent problems pointed out about Log not being Serializable and the
> implications thereof are another; that's truly ugly. However it appears
> that no-one has ever bothered to point this out on the email lists or
> bugzilla. I've reported this to the right lists, and there may well be a
> fix in the upcoming release.
>
> However there is a lot of truly incorrect information floating around
> about JCL; one person makes a false claim, another quotes it, then it
> becomes accepted as "truth" despite the fact that it is complete
> garbage. Unfortunately a number of articles linked to from the log4j
> website fall into this category. I do try to correct such claims when I
> see them because having false info does no-one any favours.
>
> BTW, I also agree that j.u.logging will eventually be *the* logging API,
> and I'll be glad when that day comes and JCL can be retired. Logging
> definitely should be in the language core. It's a shame Sun failed to
> consult more widely with the community on design but nevertheless j.u.l
> is *useable*. However there's a whole lot of people on pre-1.4 JVMs, and
> that's going to continue to be the case for a number of years.
>
> >
> > > > I am *so* thankful that java.util.logging doesn't force any of
> > > > this pain on its users.
> > >
> > > Well, it does this by not providing the ability for EITHER of:
> > > (a) logging implementations in webapps, or
> > > (b) logging configurations in webapps
> >
> > Not exactly true:  it's not enabled out-of-the-box (which I agree
> > is lousy), but a solid JDK 1.4 application server can enable
> > it.  I know OC4J does.
> >
> > > The moment a non-standard java.util.logging implementation tries to do
> > > either, exactly this problem reappears. And then the problem is not
> > > documented in the API the user is using!
> >
> > The problem only reappears if someone other than the
> > application server tries to provide the feature.  If the app
> > server provides it, it is fully in control of the classloaders
> > used, and can ensure that the Logger classes in use
> > are loaded by the parent classloader.  (The fact that there
> > is one and only one LogManager necessarily puts the
> > onus on the app server.)
>
> I would *really* be interested in more info on how OC4J can do this. It
> sure seems impossible to me.

Hrm - I  think I have to eat some crow here;  Just checked,
and OC4J *might* be able to do it, but the included
configuration webapp only allows configuration at a global
level, not per-webapp.  So it almost certainly can't.

>
> The static field on the shared class points to exactly ONE Log object,
> yes? And that Log object must have been configured from exactly ONE of:
> (a) config info in webapp A
> (b) config info in webapp B
> (c) config info in the container
>
> So how is it possible for calls from webappA and webappB to both behave
> correctly if they are accessing a shared class with a static Log member?

Shared class or not, it can't, not without proxying or additional
lookup effort.

> NB: The Log object could actually be a "proxy" where each call to each
> method looks up the TCCL then dispatches to an appropriate *real* Log
> object, but that has horrible performance implications.

Indeed, it would;  the absolute best I could imagine is that
the container configures the Log to have the most verbose
level requested by any webapp, then have a Filter
check the TCCL and trim out ones that don't apply to
the current webapp.  This *might* be acceptable, but
I can easily imagine circumstances where it would not -
crank up insanely verbose levels on a test app while
leaving up the real app that's getting normal test loads.
You'd be churning out LogRecords, though at least the
log files wouldn't get flooded.

> Note that we are *not* talking about classloaders at all here, except
> that the TCCL is used as a "key" for different logging configurations.
> ClassCastException issues are a different problem.

Yep.  TCCL;  alternatively, stash the key on a ThreadLocal,
which is probably faster still.  We use ThreadLocals quite
a bit, and I keep waiting for them to show up in any profile
as a bottleneck - they never have yet.

> > Pressure should be applied to app servers to get this
> > important feature right.  Tomcat doesn't, AFAIK, which
> > is basically just a big missing feature of Tomcat, not
> > a missing featurer of java.util.logging.
>
> If you can give a hint on how it's possible I'd be happy to work to see
> this gets into tomcat.

It would seem that hallucinations of imagined behavior
are the first step to implementing the feature. ;)

> > > It's easy to avoid bugs by not providing functionality. I can provide
> > > you with a totally bug-free web presentation tier in 30 seconds --
> > > provided all it ever does is display "hello world".
> > >
> > > And actually, it's not a bug - it's an architectural issue due to (IMO)
> > > the poor Java classloader model. If static variables weren't shared
> > > between webapps then the problem wouldn't occur. Ecch, the sheer
> > > ugliness of a "container" framework that causes or allows that kind of
> > > interaction between supposedly independent "component" applications!
> >
> > "It's not a bug" is of scant consolation to users (like myself)
> > who have to swear at their computer when it's throwing
> > ClassCastExceptions because code they don't control
> > didn't get the memo on not creating static Log instances.
> >
>
> Agreed. However the JCL 1.1 release has a solution for this; it's
> possible to disable tccl classloading completely. Of course that
> disables useful functionality (reducing things to the default
> j.u.logging level) but it definitely fixes any ClassCastExceptions.

Good to know.

> > For MyFaces at this time, it's a non-issue at least for the
> > API and IMPL core, since JSF 1.1 needs to support JDK 1.3,
> > and that makes java.util.logging a non-starter for those
> > parts of MyFaces.  (And, IMO, it'd be odd for Tomahawk
> > to have a different JDK requirement than the JSF impl.)
>
> Yep.
>
> Regards,
>
> Simon

-- Adam

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Simon Kitching <sk...@apache.org>.
On Mon, 2006-02-20 at 11:51 -0800, Adam Winer wrote:
> IIRC, you have a personal stake in this issue, but the
> plain truth is that there is no war anymore - java.util.logging
> won by Sun's fiat.  Technical superiority is not the ultimate
> arbiter.
> 

Yes, I am a commons-logging committer. That doesn't mean I believe it's
perfect; I work on it because I need it, and because it *does* have
flaws that need work. 

I don't have any interest in defending JCL against true complaints; the
ClassCastException problems experienced with 1.0.4 and earlier are an
example (though one that is at least partially caused by what I consider
to be bad container design in many cases). 

The recent problems pointed out about Log not being Serializable and the
implications thereof are another; that's truly ugly. However it appears
that no-one has ever bothered to point this out on the email lists or
bugzilla. I've reported this to the right lists, and there may well be a
fix in the upcoming release.

However there is a lot of truly incorrect information floating around
about JCL; one person makes a false claim, another quotes it, then it
becomes accepted as "truth" despite the fact that it is complete
garbage. Unfortunately a number of articles linked to from the log4j
website fall into this category. I do try to correct such claims when I
see them because having false info does no-one any favours. 

BTW, I also agree that j.u.logging will eventually be *the* logging API,
and I'll be glad when that day comes and JCL can be retired. Logging
definitely should be in the language core. It's a shame Sun failed to
consult more widely with the community on design but nevertheless j.u.l
is *useable*. However there's a whole lot of people on pre-1.4 JVMs, and
that's going to continue to be the case for a number of years.

> 
> > > I am *so* thankful that java.util.logging doesn't force any of
> > > this pain on its users.
> >
> > Well, it does this by not providing the ability for EITHER of:
> > (a) logging implementations in webapps, or
> > (b) logging configurations in webapps
> 
> Not exactly true:  it's not enabled out-of-the-box (which I agree
> is lousy), but a solid JDK 1.4 application server can enable
> it.  I know OC4J does.
> 
> > The moment a non-standard java.util.logging implementation tries to do
> > either, exactly this problem reappears. And then the problem is not
> > documented in the API the user is using!
> 
> The problem only reappears if someone other than the
> application server tries to provide the feature.  If the app
> server provides it, it is fully in control of the classloaders
> used, and can ensure that the Logger classes in use
> are loaded by the parent classloader.  (The fact that there
> is one and only one LogManager necessarily puts the
> onus on the app server.)

I would *really* be interested in more info on how OC4J can do this. It
sure seems impossible to me. 

The static field on the shared class points to exactly ONE Log object,
yes? And that Log object must have been configured from exactly ONE of:
(a) config info in webapp A
(b) config info in webapp B
(c) config info in the container

So how is it possible for calls from webappA and webappB to both behave
correctly if they are accessing a shared class with a static Log member?

NB: The Log object could actually be a "proxy" where each call to each
method looks up the TCCL then dispatches to an appropriate *real* Log
object, but that has horrible performance implications.

Note that we are *not* talking about classloaders at all here, except
that the TCCL is used as a "key" for different logging configurations.
ClassCastException issues are a different problem.

> 
> Pressure should be applied to app servers to get this
> important feature right.  Tomcat doesn't, AFAIK, which
> is basically just a big missing feature of Tomcat, not
> a missing featurer of java.util.logging.

If you can give a hint on how it's possible I'd be happy to work to see
this gets into tomcat.

> 
> > It's easy to avoid bugs by not providing functionality. I can provide
> > you with a totally bug-free web presentation tier in 30 seconds --
> > provided all it ever does is display "hello world".
> >
> > And actually, it's not a bug - it's an architectural issue due to (IMO)
> > the poor Java classloader model. If static variables weren't shared
> > between webapps then the problem wouldn't occur. Ecch, the sheer
> > ugliness of a "container" framework that causes or allows that kind of
> > interaction between supposedly independent "component" applications!
> 
> "It's not a bug" is of scant consolation to users (like myself)
> who have to swear at their computer when it's throwing
> ClassCastExceptions because code they don't control
> didn't get the memo on not creating static Log instances.
> 

Agreed. However the JCL 1.1 release has a solution for this; it's
possible to disable tccl classloading completely. Of course that
disables useful functionality (reducing things to the default
j.u.logging level) but it definitely fixes any ClassCastExceptions.

> For MyFaces at this time, it's a non-issue at least for the
> API and IMPL core, since JSF 1.1 needs to support JDK 1.3,
> and that makes java.util.logging a non-starter for those
> parts of MyFaces.  (And, IMO, it'd be odd for Tomahawk
> to have a different JDK requirement than the JSF impl.)

Yep.

Regards,

Simon


Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Adam Winer <aw...@gmail.com>.
On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
> On Sun, 2006-02-19 at 22:33 -0800, Adam Winer wrote:
> > Weeellll....  if you implement StateHolder, this isn't an issue.
> > The public no-arg constructor will be used, variable initializer
> > expressions will run, etc.
> >
> > If you implement Serializable instead, then Craig's totally right -
> > transient variables will not be re-initialized.   You can deal with
> > this by adding the log() method, or by providing an implementation
> > of:
> >
> >  private void readObject(ObjectInputStream in)
> >
> > ... which can re-initialize any transient values.
>
> Thanks for the info.
>
> >
> > I am *so* thankful that java.util.logging doesn't force any of
> > this pain on its users.
>
> Well, it does this by not providing the ability for EITHER of:
> (a) logging implementations in webapps, or
> (b) logging configurations in webapps

Not exactly true:  it's not enabled out-of-the-box (which I agree
is lousy), but a solid JDK 1.4 application server can enable
it.  I know OC4J does.

> The moment a non-standard java.util.logging implementation tries to do
> either, exactly this problem reappears. And then the problem is not
> documented in the API the user is using!

The problem only reappears if someone other than the
application server tries to provide the feature.  If the app
server provides it, it is fully in control of the classloaders
used, and can ensure that the Logger classes in use
are loaded by the parent classloader.  (The fact that there
is one and only one LogManager necessarily puts the
onus on the app server.)

Pressure should be applied to app servers to get this
important feature right.  Tomcat doesn't, AFAIK, which
is basically just a big missing feature of Tomcat, not
a missing featurer of java.util.logging.

> It's easy to avoid bugs by not providing functionality. I can provide
> you with a totally bug-free web presentation tier in 30 seconds --
> provided all it ever does is display "hello world".
>
> And actually, it's not a bug - it's an architectural issue due to (IMO)
> the poor Java classloader model. If static variables weren't shared
> between webapps then the problem wouldn't occur. Ecch, the sheer
> ugliness of a "container" framework that causes or allows that kind of
> interaction between supposedly independent "component" applications!

"It's not a bug" is of scant consolation to users (like myself)
who have to swear at their computer when it's throwing
ClassCastExceptions because code they don't control
didn't get the memo on not creating static Log instances.

IIRC, you have a personal stake in this issue, but the
plain truth is that there is no war anymore - java.util.logging
won by Sun's fiat.  Technical superiority is not the ultimate
arbiter.

For MyFaces at this time, it's a non-issue at least for the
API and IMPL core, since JSF 1.1 needs to support JDK 1.3,
and that makes java.util.logging a non-starter for those
parts of MyFaces.  (And, IMO, it'd be odd for Tomahawk
to have a different JDK requirement than the JSF impl.)

Regards,
Adam

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Simon Kitching <sk...@apache.org>.
On Sun, 2006-02-19 at 22:33 -0800, Adam Winer wrote:
> Weeellll....  if you implement StateHolder, this isn't an issue.
> The public no-arg constructor will be used, variable initializer
> expressions will run, etc.
> 
> If you implement Serializable instead, then Craig's totally right -
> transient variables will not be re-initialized.   You can deal with
> this by adding the log() method, or by providing an implementation
> of:
> 
>  private void readObject(ObjectInputStream in)
> 
> ... which can re-initialize any transient values.

Thanks for the info.

> 
> I am *so* thankful that java.util.logging doesn't force any of
> this pain on its users.

Well, it does this by not providing the ability for EITHER of:
(a) logging implementations in webapps, or
(b) logging configurations in webapps

The moment a non-standard java.util.logging implementation tries to do
either, exactly this problem reappears. And then the problem is not
documented in the API the user is using!

It's easy to avoid bugs by not providing functionality. I can provide
you with a totally bug-free web presentation tier in 30 seconds --
provided all it ever does is display "hello world". 

And actually, it's not a bug - it's an architectural issue due to (IMO)
the poor Java classloader model. If static variables weren't shared
between webapps then the problem wouldn't occur. Ecch, the sheer
ugliness of a "container" framework that causes or allows that kind of
interaction between supposedly independent "component" applications!


Regards,

Simon


Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Adam Winer <aw...@gmail.com>.
Weeellll....  if you implement StateHolder, this isn't an issue.
The public no-arg constructor will be used, variable initializer
expressions will run, etc.

If you implement Serializable instead, then Craig's totally right -
transient variables will not be re-initialized.   You can deal with
this by adding the log() method, or by providing an implementation
of:

 private void readObject(ObjectInputStream in)

... which can re-initialize any transient values.

I am *so* thankful that java.util.logging doesn't force any of
this pain on its users.

-- Adam



On 2/19/06, Craig McClanahan <cr...@apache.org> wrote:
>
>
>
> On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
> > On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:
> >
> > > Simon,
> > >
> > > Could you do me a favor and publicize this in the Struts community as
> > > well?  The framework code there is littered with static log instances
> > > to.
> >
> > Will do.
> >
> > >  You might also want to add some notes related to using Log instances
> > > in Serializable classes (see below).
> >
> > Will do that also.
> >
> > >
> > > MyFaces folks,
> > >
> > > There *is* a JSF-specific consideration to think about, if you have
> > > classes that implement StateHolder (like a UIComponent
> > > implementation).  Log instances will generally *not* be serializable,
> > > so you will need to deal specially with them in saveState() and
> > > restoreState() methods.  The simplest thing is to just not save them,
> > > and do a "new" operation again in restoreState().
> >
> > Sorry but I don't understand. Why won't the normal approach work?
> >
> >   public class SomeComponent .... {
> >     private Log log = LogFactory.getLog(SomeComponent.class);
> >     ...
> >   }
> >
> > AIUI, the log object won't be saved in the saveState method, but it will
> > be recreated nicely during the RestoreView phase when a new instance is
> > created for the state to be restored into.
> >
> > >
> > > Along the same lines, if your class implements Serializable, you will
> > > need to mark the instance variable transient.  I've started using the
> > > following pattern in my Serializable classes, which would work inside
> > > a StateHolder as well:
> > >
> > >     private transient Log log = null;
> > >
> > >     private Log log() {
> > >         if (log == null) {
> > >             log = LogFactory.getLog(...);
> > >         }
> > >         return log;
> > >     }
> > >
> > > and a typical call looks like:
> > >
> > >     if (log().isDebugEnabled()) {
> > >        log().debug("...");
> > >     }
> >
> > Ok, transient is needed here. But apart from that why won't the standard
> > approach work?
> >
> >   public class SomeThing implements Serializable {
> >     private transient Log log = LogFactory.getLog (SomeThing.class);
> >     ...
> >     if (log.isDebugEnabled()) {
> >       log.debug("...");
> >     }
> >   }
> >
> > Doesn't the log object get recreated when the deserialization occurs?
>
> No, AIUI.  When an object is deserialized, it does *not* execute the
> variable initializer expressions.  Since it was declared transient, there's
> no state for that object to be restored.
>
> > The log() method is quite a lot of boilerplate, and also imposes an
> > additional method call for every isDebugEnabled() call. [The extra call
> > inside the guard is not really relevant as output *is* going to occur at
> > this point which greatly outweighs the price of the method call].
>
> You can reduce that by one call by protecting only the conditional
> expression, because if you get inside you know there's an object ... but
> that means you are relying on the implicit contract between the log instance
> variable and the log() method.
>
> > Cheers,
> >
> > Simon
> >
> >
> Craig
>
>

Re: logging (was Re: svn commit: r378805 - /myfaces/core/trunk/impl/src/main/java/org/apache/myfaces/application/ApplicationFactoryImpl.java)

Posted by Craig McClanahan <cr...@apache.org>.
On 2/19/06, Simon Kitching <sk...@apache.org> wrote:
>
> On Sun, 2006-02-19 at 17:56 -0800, Craig McClanahan wrote:
>
> > Simon,
> >
> > Could you do me a favor and publicize this in the Struts community as
> > well?  The framework code there is littered with static log instances
> > to.
>
> Will do.
>
> >  You might also want to add some notes related to using Log instances
> > in Serializable classes (see below).
>
> Will do that also.
>
> >
> > MyFaces folks,
> >
> > There *is* a JSF-specific consideration to think about, if you have
> > classes that implement StateHolder (like a UIComponent
> > implementation).  Log instances will generally *not* be serializable,
> > so you will need to deal specially with them in saveState() and
> > restoreState() methods.  The simplest thing is to just not save them,
> > and do a "new" operation again in restoreState().
>
> Sorry but I don't understand. Why won't the normal approach work?
>
>   public class SomeComponent .... {
>     private Log log = LogFactory.getLog(SomeComponent.class);
>     ...
>   }
>
> AIUI, the log object won't be saved in the saveState method, but it will
> be recreated nicely during the RestoreView phase when a new instance is
> created for the state to be restored into.
>
> >
> > Along the same lines, if your class implements Serializable, you will
> > need to mark the instance variable transient.  I've started using the
> > following pattern in my Serializable classes, which would work inside
> > a StateHolder as well:
> >
> >     private transient Log log = null;
> >
> >     private Log log() {
> >         if (log == null) {
> >             log = LogFactory.getLog(...);
> >         }
> >         return log;
> >     }
> >
> > and a typical call looks like:
> >
> >     if (log().isDebugEnabled()) {
> >        log().debug("...");
> >     }
>
> Ok, transient is needed here. But apart from that why won't the standard
> approach work?
>
>   public class SomeThing implements Serializable {
>     private transient Log log = LogFactory.getLog(SomeThing.class);
>     ...
>     if (log.isDebugEnabled()) {
>       log.debug("...");
>     }
>   }
>
> Doesn't the log object get recreated when the deserialization occurs?


No, AIUI.  When an object is deserialized, it does *not* execute the
variable initializer expressions.  Since it was declared transient, there's
no state for that object to be restored.

The log() method is quite a lot of boilerplate, and also imposes an
> additional method call for every isDebugEnabled() call. [The extra call
> inside the guard is not really relevant as output *is* going to occur at
> this point which greatly outweighs the price of the method call].


You can reduce that by one call by protecting only the conditional
expression, because if you get inside you know there's an object ... but
that means you are relying on the implicit contract between the log instance
variable and the log() method.

Cheers,
>
> Simon
>
> Craig