[logging] LoadTest

classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|

[logging] LoadTest

Brian Stansberry
I've been testing my new implementation of
LogFactoryImpl and it's looking good except it fails
the "testInContainer" test of o.a.c.l.LoadTest.  This
test sets up a parent-last (aka child-first)
classloader hierarchy that has JCL and a class that
calls JCL in the child.  JCL is also visible in the
parent.  It then performs various tests, setting the
thread context class loader to various values and
trying to log.

This test is designed to fail if logging succeeds when
the TCCL is set to the system classloader or the
parent classloader.  

The old implementation of LogFactoryImpl does throw a
LogConfigurationException in this situation, as
discovery finds an adapter in the parent that is
binary incompatible with the LogFactoryImpl in the
child.

The new implementation does not throw an LCE, as it
detects the incompatibility and retries loading the
adapter using the LogFactoryImpl's classloader.  But,
because logging succeeds, this unit test does not
pass.

It is my interpretation that this unit test is really
checking for *consistent* behavior of the old
implementation, not for *correct* behavior.  It would
catch things like a change to the old implementation
that caused it to forget to try the TCCL.  But IMHO an
implementation that was specifically designed to
handle this situation shouldn't cause a unit test
failure.

Any thoughts on this one?  Have I missed something?

BTW, LoadTest is not invoked by the ant test target.

Regards,

Brian



               
__________________________________
Do you Yahoo!?
Yahoo! Small Business - Try our new Resources site
http://smallbusiness.yahoo.com/resources/

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
On Sun, 2005-05-29 at 21:17 -0700, Brian Stansberry wrote:

> I've been testing my new implementation of
> LogFactoryImpl and it's looking good except it fails
> the "testInContainer" test of o.a.c.l.LoadTest.  This
> test sets up a parent-last (aka child-first)
> classloader hierarchy that has JCL and a class that
> calls JCL in the child.  JCL is also visible in the
> parent.  It then performs various tests, setting the
> thread context class loader to various values and
> trying to log.
>
> This test is designed to fail if logging succeeds when
> the TCCL is set to the system classloader or the
> parent classloader.  
>
> The old implementation of LogFactoryImpl does throw a
> LogConfigurationException in this situation, as
> discovery finds an adapter in the parent that is
> binary incompatible with the LogFactoryImpl in the
> child.

I suspect it actually fails because LogFactoryImpl finds Log4JLogger in
the parent, but log4j classes are not in the parent. It is a fundamental
implication of the logging design that the XXLogger must be able to load
the library it maps to via normal java classloader lookup (ie no using
the context classloader). It's not "binary incompatibility", I think,
but a complete failure to link Log4JLogger to its referenced classes.

> The new implementation does not throw an LCE, as it
> detects the incompatibility and retries loading the
> adapter using the LogFactoryImpl's classloader.  But,
> because logging succeeds, this unit test does not
> pass.
>
> It is my interpretation that this unit test is really
> checking for *consistent* behavior of the old
> implementation, not for *correct* behavior.  It would
> catch things like a change to the old implementation
> that caused it to forget to try the TCCL.  But IMHO an
> implementation that was specifically designed to
> handle this situation shouldn't cause a unit test
> failure.

I agree that the test is not relevant to your new code. It was really
documenting the behaviour of the old system, and could be updated.

An updated test really ought to verify that when context=system, logging
falls back to jdk14 (when running with java14) or to SimpleLog. But if
this is too much work, just asserting that logging still works would be
ok by me.

> BTW, LoadTest is not invoked by the ant test target.

Then that should probably be fixed too. Nicely spotted!

Regards,

Simon



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

rdonkin
On Mon, 2005-05-30 at 18:40 +1200, Simon Kitching wrote:

> On Sun, 2005-05-29 at 21:17 -0700, Brian Stansberry wrote:
> > I've been testing my new implementation of
> > LogFactoryImpl and it's looking good except it fails
> > the "testInContainer" test of o.a.c.l.LoadTest.  This
> > test sets up a parent-last (aka child-first)
> > classloader hierarchy that has JCL and a class that
> > calls JCL in the child.  JCL is also visible in the
> > parent.  It then performs various tests, setting the
> > thread context class loader to various values and
> > trying to log.
> >
> > This test is designed to fail if logging succeeds when
> > the TCCL is set to the system classloader or the
> > parent classloader.  
> >
> > The old implementation of LogFactoryImpl does throw a
> > LogConfigurationException in this situation, as
> > discovery finds an adapter in the parent that is
> > binary incompatible with the LogFactoryImpl in the
> > child.
>
> I suspect it actually fails because LogFactoryImpl finds Log4JLogger in
> the parent, but log4j classes are not in the parent.

i think that this may depend on the classpath used to run the test.

> It is a fundamental
> implication of the logging design that the XXLogger must be able to load
> the library it maps to via normal java classloader lookup (ie no using
> the context classloader). It's not "binary incompatibility", I think,
> but a complete failure to link Log4JLogger to its referenced classes.

i suspect that this is a test for exotic context classloader
configurations. i think that the mode of failure depends on the system
classpath used to run the test. (for example, maybe it was intended that
log4j would be defined by the system classloader) unless the intended
configuration is known, i think it'd be hard to work out the exact
diagnosis...

> > The new implementation does not throw an LCE, as it
> > detects the incompatibility and retries loading the
> > adapter using the LogFactoryImpl's classloader.  But,
> > because logging succeeds, this unit test does not
> > pass.
> >
> > It is my interpretation that this unit test is really
> > checking for *consistent* behavior of the old
> > implementation, not for *correct* behavior.  It would
> > catch things like a change to the old implementation
> > that caused it to forget to try the TCCL.  But IMHO an
> > implementation that was specifically designed to
> > handle this situation shouldn't cause a unit test
> > failure.
>
> I agree that the test is not relevant to your new code. It was really
> documenting the behaviour of the old system, and could be updated.

i suspect that the majority opinion was that JCL should refuse to run in
containers which didn't obey the rules. therefore, this was a legitimate
test. however, the current consensus is that (with hindsight) this
original decision was wrong. it was a semantic bug. i really cannot
think that any code could reasonably rely on JCL throwing a runtime
exception whenever exotic context classloader configurations are
encountered.

i agree that it should be updated.

> An updated test really ought to verify that when context=system, logging
> falls back to jdk14 (when running with java14) or to SimpleLog. But if
> this is too much work, just asserting that logging still works would be
> ok by me.

+1

> > BTW, LoadTest is not invoked by the ant test target.
>
> Then that should probably be fixed too. Nicely spotted!

+1

- robert


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Brian Stansberry
In reply to this post by Brian Stansberry

--- robert burrell donkin <[hidden email]> wrote:

> On Mon, 2005-05-30 at 18:40 +1200, Simon Kitching
> wrote:
> > On Sun, 2005-05-29 at 21:17 -0700, Brian
> Stansberry wrote:
> > > I've been testing my new implementation of
> > > LogFactoryImpl and it's looking good except it
> fails
> > > the "testInContainer" test of o.a.c.l.LoadTest.
> This
> > > test sets up a parent-last (aka child-first)
> > > classloader hierarchy that has JCL and a class
> that
> > > calls JCL in the child.  JCL is also visible in
> the
> > > parent.  It then performs various tests, setting
> the
> > > thread context class loader to various values
> and
> > > trying to log.
> > >
> > > This test is designed to fail if logging
> succeeds when
> > > the TCCL is set to the system classloader or the
> > > parent classloader.  
> > >
> > > The old implementation of LogFactoryImpl does
> throw a
> > > LogConfigurationException in this situation, as
> > > discovery finds an adapter in the parent that is
> > > binary incompatible with the LogFactoryImpl in
> the
> > > child.
> >
> > I suspect it actually fails because LogFactoryImpl
> finds Log4JLogger in
> > the parent, but log4j classes are not in the
> parent.
>

Your new diagnostics are really helpful here.  They
show exactly what happens.

First, by the design of the test JCL has to be visible
to "parent" classloader, which is the test case's
classloader.  This is because the child-first loader
the test creates actually uses the "parent"
classloader to find the class file.

When I run this either using ant or Eclipse, the
system classloader and the test case's loader are the
same (i.e. the testing framework does not add a
layer).

LogFactory and LogFactoryImpl are loaded by the child
loader.

TCCL is set to the parent/system.

Discovery analyzes the parent classloader.  If
log4j.jar is present, it discovers log4j.  If not, it
discovers jdk14.

Discovery fails because Log interface implemented by
discovered adapter is defined by the parent, while
LogFactoryImpl is defined by the child.

<snip>

>
> i suspect that the majority opinion was that JCL
> should refuse to run in
> containers which didn't obey the rules. therefore,
> this was a legitimate
> test. however, the current consensus is that (with
> hindsight) this
> original decision was wrong. it was a semantic bug.
> i really cannot
> think that any code could reasonably rely on JCL
> throwing a runtime
> exception whenever exotic context classloader
> configurations are
> encountered.
>
+1

> i agree that it should be updated.
>
> > An updated test really ought to verify that when
> context=system, logging
> > falls back to jdk14 (when running with java14) or
> to SimpleLog. But if
> > this is too much work, just asserting that logging
> still works would be
> > ok by me.
>
> +1

With the new code (aka rev 3b), if log4j.jar is
visible to the parent classloader it will be
discovered.  Assume the scenario above; log4j.jar is
visible tot the parent so discovery using the bogus
TCCL finds a binary incompatible Log4jLogger.  This
error will be caught, and an attempt will be made to
load Log4jLogger using the LogFactoryImpl's loader
(the child).  This will succeed, because log4j.jar can
be loaded via parent delegation.

I'm not sure if this is a flaw (maybe the child really
wanted jdk logging, and we're giving them log4j), but
basically we're discovering the log method made
available via the TCCL.

In any case, I don't think we can test for jdk or
SimpleLog being discovered; we can only test if
logging worked.

Brian


       
               
__________________________________
Do you Yahoo!?
Yahoo! Mail - You care about security. So do we.
http://promotions.yahoo.com/new_mail

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
On Mon, 2005-05-30 at 21:22 -0700, Brian Stansberry wrote:
> I'm not sure if this is a flaw (maybe the child really
> wanted jdk logging, and we're giving them log4j), but
> basically we're discovering the log method made
> available via the TCCL.

I think that if log4j *can* be used, and we find it, then that is right.
Autodiscovery is meant to find log4j before jdk14.

And I'm not too bothered by discovering the "wrong" logging
implementation anyway; users can always use a commons-logging.properties
or a META-INF/services file to specify which logging lib they want if
they really care.

What's important is that the discovered logging lib *works* (doesn't
throw an exception).

>
> In any case, I don't think we can test for jdk or
> SimpleLog being discovered; we can only test if
> logging worked.

Isn't it possible for the test to do this?
  if (running on jdk>= 1.4) {
    assertEquals(logObject.getClass(),
      "org.apache.commons.logging.impl.Jdk14Log");
  } else {
    assertEquals(logObject.getClass(),
      "org.apache.commons.logging.impl.SimpleLog");
  }

After all, that's stating what we expect - that in the setup used by
this test, we get logger Jdk14 or SimpleLog, and not Log4JLog. The only
tricky bit is that the unit test currently doesn't have access to the
Log object created, so it may mean a bit of refactoring of the test
code.

Regards,

Simon


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
PS:

Robert, you didn't reply on whether you agree with removing the
isXXXAvailable methods or not. Please see second paragraph of comment
#12, and Brian's response in comment#13:
  http://issues.apache.org/bugzilla/show_bug.cgi?id=34661

Brian: my comment re "copy/paste error in comments for Lumberjack test"
refer to this line:
    // Other throwables just mean couldn't load the adapter or j.u.l
in method discoverLogImplementation. I think the "or j.u.l" shouldn't be
there?

Regards,

Simon


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Brian Stansberry
In reply to this post by Brian Stansberry

--- Simon Kitching <[hidden email]> wrote:

> On Mon, 2005-05-30 at 21:22 -0700, Brian Stansberry
> wrote:
> > I'm not sure if this is a flaw (maybe the child
> really
> > wanted jdk logging, and we're giving them log4j),
> but
> > basically we're discovering the log method made
> > available via the TCCL.
>
> I think that if log4j *can* be used, and we find it,
> then that is right.
> Autodiscovery is meant to find log4j before jdk14.
>
> And I'm not too bothered by discovering the "wrong"
> logging
> implementation anyway; users can always use a
> commons-logging.properties
> or a META-INF/services file to specify which logging
> lib they want if
> they really care.
>
> What's important is that the discovered logging lib
> *works* (doesn't
> throw an exception).
>

+1

> >
> > In any case, I don't think we can test for jdk or
> > SimpleLog being discovered; we can only test if
> > logging worked.
>
> Isn't it possible for the test to do this?
>   if (running on jdk>= 1.4) {
>     assertEquals(logObject.getClass(),
>       "org.apache.commons.logging.impl.Jdk14Log");
>   } else {
>     assertEquals(logObject.getClass(),
>       "org.apache.commons.logging.impl.SimpleLog");
>   }
>
> After all, that's stating what we expect - that in
> the setup used by
> this test, we get logger Jdk14 or SimpleLog, and not
> Log4JLog. The only
> tricky bit is that the unit test currently doesn't
> have access to the
> Log object created, so it may mean a bit of
> refactoring of the test
> code.
>

Sorry, wasn't clear about what I meant.  The test
classpath used in the ant build includes Log4j, so it
will be discovered (unless we create a special
classpath for this one test).  In any case, whether or
not a particular adapter is discovered depends on
what's on the test classpath.  We could have the test
analyze its classpath in order to determine what
should have been discovered, so I guess we *could*
test to see if the right one was discovered.

Brian

> Regards,
>
> Simon
>
>
>
---------------------------------------------------------------------
> To unsubscribe, e-mail:
> [hidden email]
> For additional commands, e-mail:
> [hidden email]
>
>


               
__________________________________
Do you Yahoo!?
Yahoo! Small Business - Try our new Resources site
http://smallbusiness.yahoo.com/resources/

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Brian Stansberry
In reply to this post by Brian Stansberry
<snip>
--- Simon Kitching <[hidden email]> wrote:
>
> Brian: my comment re "copy/paste error in comments
> for Lumberjack test"
> refer to this line:
>     // Other throwables just mean couldn't load the
> adapter or j.u.l
> in method discoverLogImplementation. I think the "or
> j.u.l" shouldn't be
> there?

Jdk13LumberjackLogger imports java.util.logging :)

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around
http://mail.yahoo.com 

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
In reply to this post by Brian Stansberry
On Mon, 2005-05-30 at 22:44 -0700, Brian Stansberry wrote:
> Sorry, wasn't clear about what I meant.  The test
> classpath used in the ant build includes Log4j, so it
> will be discovered (unless we create a special
> classpath for this one test).  In any case, whether or
> not a particular adapter is discovered depends on
> what's on the test classpath.  We could have the test
> analyze its classpath in order to determine what
> should have been discovered, so I guess we *could*
> test to see if the right one was discovered.

The test doesn't set up its own clean classpath?! I thought that was
what the AppClassLoader private class was all about - though of course
it's hard to tell as there aren't any comments on it.

If the unit test doesn't properly set up a clean classpath before doing
classpath-related unit tests, then that really sucks.

Ah well, I don't think any of us have enough enthusiasm to fix the unit
tests as well as the code. So however you get the test to run is ok by
me.

Regards,

Simon



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
In reply to this post by Brian Stansberry
On Mon, 2005-05-30 at 22:48 -0700, Brian Stansberry wrote:

> <snip>
> --- Simon Kitching <[hidden email]> wrote:
> >
> > Brian: my comment re "copy/paste error in comments
> > for Lumberjack test"
> > refer to this line:
> >     // Other throwables just mean couldn't load the
> > adapter or j.u.l
> > in method discoverLogImplementation. I think the "or
> > j.u.l" shouldn't be
> > there?
>
> Jdk13LumberjackLogger imports java.util.logging :)

Ah! Sorry..



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Simon Kitching
In reply to this post by Simon Kitching
On Tue, 2005-05-31 at 17:59 +1200, Simon Kitching wrote:

> The test doesn't set up its own clean classpath?! I thought that was
> what the AppClassLoader private class was all about - though of course
> it's hard to tell as there aren't any comments on it.
>
> If the unit test doesn't properly set up a clean classpath before doing
> classpath-related unit tests, then that really sucks.
>
> Ah well, I don't think any of us have enough enthusiasm to fix the unit
> tests as well as the code. So however you get the test to run is ok by
> me.

Hmm. I just tried your patch to include LoadTest in TestAll. And the
test LoadTest fails for me with some problem in the "reload" method.
That's without having applied any of your patches, ie the current HEAD
version of the test fails against the current HEAD version of JCL.

I suspect the reason the test isn't in the standard suite is that it has
never actually worked properly at all. The custom ClassLoader user
probably doesn't properly isolate the test from the surrounding
environment meaning that the test will work for some people but not
others (eg you, but not me).

The subversion history shows that while license text etc. have been
updated in it, no-one has actually committed a *meaningful* change to it
since it was created at 2003-03-01.

I might try to find time to have a look at this, but as the test was
never part of the standard suite, I'm now generally in favour of just
ignoring it.

Regards,

Simon


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

Brian Stansberry
In reply to this post by Brian Stansberry

--- Simon Kitching <[hidden email]> wrote:
> On Tue, 2005-05-31 at 17:59 +1200, Simon Kitching
> wrote:
> > The test doesn't set up its own clean classpath?!
> I thought that was
> > what the AppClassLoader private class was all
> about - though of course
> > it's hard to tell as there aren't any comments on
> it.

It's just used to create the child-first child
classloader -- doesn't affect the parent classpath.  I
think its trying to do a similar thing as the
ClassReloader in beanutils.

> >
> > If the unit test doesn't properly set up a clean
> classpath before doing
> > classpath-related unit tests, then that really
> sucks.
> >
> > Ah well, I don't think any of us have enough
> enthusiasm to fix the unit
> > tests as well as the code. So however you get the
> test to run is ok by
> > me.
>
> Hmm. I just tried your patch to include LoadTest in
> TestAll. And the
> test LoadTest fails for me with some problem in the
> "reload" method.
> That's without having applied any of your patches,
> ie the current HEAD
> version of the test fails against the current HEAD
> version of JCL.
>

Strange.  I ran it against HEAD yesterday and it
worked, and just double checked and it still works.

> I suspect the reason the test isn't in the standard
> suite is that it has
> never actually worked properly at all. The custom
> ClassLoader user
> probably doesn't properly isolate the test from the
> surrounding
> environment meaning that the test will work for some
> people but not
> others (eg you, but not me).
>
> The subversion history shows that while license text
> etc. have been
> updated in it, no-one has actually committed a
> *meaningful* change to it
> since it was created at 2003-03-01.
>
> I might try to find time to have a look at this, but
> as the test was
> never part of the standard suite, I'm now generally
> in favour of just
> ignoring it.
>

Haven't looked carefully, but the tests using Wrapper
probably cover a lot of the same ground.

Brian


               
__________________________________
Discover Yahoo!
Find restaurants, movies, travel and more fun for the weekend. Check it out!
http://discover.yahoo.com/weekend.html 


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

rdonkin
In reply to this post by Simon Kitching
On Tue, 2005-05-31 at 16:42 +1200, Simon Kitching wrote:
> On Mon, 2005-05-30 at 21:22 -0700, Brian Stansberry wrote:
> > I'm not sure if this is a flaw (maybe the child really
> > wanted jdk logging, and we're giving them log4j), but
> > basically we're discovering the log method made
> > available via the TCCL.
>
> I think that if log4j *can* be used, and we find it, then that is right.
> Autodiscovery is meant to find log4j before jdk14.

+1

> And I'm not too bothered by discovering the "wrong" logging
> implementation anyway; users can always use a commons-logging.properties
> or a META-INF/services file to specify which logging lib they want if
> they really care.
>
> What's important is that the discovered logging lib *works* (doesn't
> throw an exception).

+1
 
- robert



---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: [logging] LoadTest

rdonkin
In reply to this post by Simon Kitching
On Tue, 2005-05-31 at 16:49 +1200, Simon Kitching wrote:
> PS:
>
> Robert, you didn't reply on whether you agree with removing the
> isXXXAvailable methods or not. Please see second paragraph of comment
> #12, and Brian's response in comment#13:
>   http://issues.apache.org/bugzilla/show_bug.cgi?id=34661

i did post quite an involved reply (but it was easy to miss). it boiled
down to: i agree with all your reasoning but think that breaking binary
compatibility will make *so* many problems for *so* many users that it's
better to leave the methods in.

if we break semantic compatibility we definitely need to push the
version to 1.1. we also need to add something strong in the release
notes and in the announcement.

- robert


---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]