To me, this looks like a bug in tomcat-embedded, not CXF.
Couple things:
1) Why is it's LogManager being used in OSGi instead of the
normal JDK one?
2) It's LogManager looks like it's designed for use in a J2EE
based system (not surprising, Tomcat implements J2EE specs as
well) and is making decisions based on the TCCL. Not sure
why it would do that in OSGi. If it's bad for CXF to set
the TCCL, why would it be OK for Tomcat to act upon it in OSGi?
Kind of have to wonder if pax-logging should prevent the
other LogManager's or provide one that is more OSGi friendly.
What happens if you set the system property:
-Djava.util.logging.manager=java.util.logging.LogManager
on the command line when you start your OSGi container (or
via etc/system.properties or whatever)?
Dan
On Feb 27, 2015, at 11:10 AM, Mike Wilson
<[email protected]> wrote:
Right, this sounds fair. If you (or the things you call) need to do
classname->class lookups then some kind of classloader
context is needed and
TCCL is the JEE way..
So what remains then is to constrain TCCL setup to only the
places where it
is really needed. Below I describe the Pax/Juli bug that
appears when
looking up loggers with TCCL set.
TL;DR: TCCL should not be set while executing getLogger(name) in an
OSGi/PaxLogging/Juli context.
CONFIGURATION
-------------
System classpath contains:
juli logging
Karaf bundles:
pax logging
cxf
mycxfbundle
Karaf logging config in etc/org.ops4j.pax.logging.cfg:
log4j.appender.cxf.file=cxf.log
log4j.logger.org.apache.cxf.services=INFO,cxf
WHAT HAPPENS AT DIFFERENT LEVELS
--------------------------------
MYCXFBUNDLE
Calling method on generated API to send WS message:
myCxfApi.sayHello();
CXF
Interceptor executed as part of message handling:
http://grepcode.com/file/repo1.maven.org/maven2/org.apache.cxf
/cxf-bundle/2.
7.14/org/apache/cxf/transport/ChainInitiationObserver.java
org.apache.cxf.transport.ChainInitiationObserver
ChainInitiationObserver(...)
// In OSGi the loader is set to an instance of
org.apache.cxf.bus.blueprint.BundleDelegatingClassLoader
loader = bus.getExtension(ClassLoader.class);
onMessage(Message)
if (loader != null) {
// Now TCCL is assigned to the
BundleDelegatingClassLoader
origLoader =
ClassLoaderUtils.setThreadContextClassloader(loader);
}
Logging interceptor executed a bit further down the stack:
http://grepcode.com/file/repo1.maven.org/maven2/org.apache.cxf
/cxf-bundle/2.
7.14/org/apache/cxf/interceptor/LoggingInInterceptor.java
org.apache.cxf.interceptor.LoggingInInterceptor
// The class's own logger will route through Pax's
handler as it is
looked
// up while TCCL is null
LOG = LogUtils.getLogger(LoggingInInterceptor.class)
handleMessage(...)
// This logger will route through Juli's handler as
it is looked up
// while TCCL is set
Logger logger = getMessageLogger(message)
PAX
This is how Pax Logging hooks into j.u.l logging used by CXF:
http://grepcode.com/file/repo1.maven.org/maven2/org.ops4j.pax.
logging/pax-lo
gging-service/1.8.1/org/ops4j/pax/logging/service/internal/Act
ivator.java
org.ops4j.pax.logging.service.internal.Activator
start()
// TCCL is not set so this RootLogger will be
located in the system
// classloader section below where most bundles will
also look
Logger rootLogger = manager.getLogger( "" );
...
m_JdkHandler = new JdkHandler( m_PaxLogging );
rootLogger.addHandler( m_JdkHandler );
JULI
Further down in the call hierarchy the lookup for a logger
arrives in Juli:
http://grepcode.com/file/repo1.maven.org/maven2/org.apache.tom
cat.embed/tomc
at-embed-logging-juli/8.0.15/org/apache/juli/ClassLoaderLogMan
ager.java
org.apache.juli.ClassLoaderLogManager
getLogger(String name)
// Juli partition loggers into different "domains"
depending on TCCL
ClassLoader classLoader =
Thread.currentThread().getContextClassLoader();
return getClassLoaderInfo(classLoader).loggers.get(name);
// The data structure that keeps the loggers will be
populated like
this:
classLoaderLoggers: {
<system classloader>: { // key used when TCCL==null
loggers: [
// Almost all bundles' loggers will be found here
"org.apache.cxf.interceptor.LoggingInInterceptor": Logger(no
handlers)
...
// This RootLogger is the one Pax locates
and patches to
route
// logging to its own handler
"": RootLogger(handlers -> Pax)
]
<mycxfbundle classloader>: { // TCCL was set so
creates a new entry
loggers: [
"...mycxfbundle": Logger(no handlers)
// This RootLogger is not found by Pax so it
keeps its
default
// Juli settings
"": RootLogger(handlers -> Juli)
]
}
}
Best regards
Mike
Daniel Kulp wrote:
On Feb 26, 2015, at 4:04 PM, Mike Wilson
<[email protected]> wrote:
Having the luxury of not understanding the implications in
the CXF codebase
I would choose to disagree ;-), and welcome removal of TCCL
usage as it
seems not to be set in normal JEE scenarios and is only set
when running in
OSGi, where it is explicitly unrecommended to do so.
Well, no. It's also set when using Spring to setup your
endpoints and services. There are other cases where it's
set as well.
Most importantly, there are a BUNCH of places in CXF and in
the libraries that CXF uses that require it. CXF being
primarily an implementation of J2EE specs in general uses the
recommendations and guidelines provided by J2EE which
includes the use of the TCCL. In particular, things like
loading the JAX-WS handlers from the @HandlerChain would
require the use of the TCCL to locate and "newInstance" them.
The xmlbeans and jibx data bindings would also require the
use of the TCCL for loading the various resources they need
to operate. The WS-Security stuff we have may use the TCCL
to load callback objects (although some of them can be passed
by reference to a bean instead of just a class name). Some
use of JAXB requires it (if you do a
JAXBContext.newInstance("com.foo.package") for example).
Even some of the CXF annotations themselves would require it.
For example, @Features(features = "org.apache.MyFeature")
would need it to load the appropriate feature. (Although all
the CXF annotations that do this have an alternative form
that takes the class object itself that could be used
instead. @Features(classes = MyFeature.class))
Some of them could be "fixed" by adding a bunch of
"ClassLoader" parameters to various methods and passing that
around, but that's a massive change and also a complete hack
IMO. The TCCL was created specifically for providing the
class loader of the current "context" to avoid having to do
all of that.
Those are just a couple off the top of my head. I'm sure
there are others.
Dan
Anyway, I'll put together a description of the bug and post
here (as it
seems this is where you prefer to do the discussion about it?).
Best regards
Mike
Sergey Beryozkin wrote:
On 26/02/15 12:58, Mike Wilson wrote:
Ok, let's see if other believe TCCL usage is possible to
remove altogether.
If not, I'll invest the time to create a ticket with the
details of the bug.
In short, it happens when CXF logging is routed to Juli.
Do you have more details re why it breaks with Juli involved
? How does
CXF setting TCCL affects Juli doing its work ?
IMHO the best way to get it moved forward is to have a
concrete case
discussion (as Christian suggested) and see what can be done
it make it
resolved as opposed to just considering completely removing
the use of
TCCL - might be risky, though may be Christian and Dan may
have another
view with respect to using an OSGI-specific loader in
the chain...
Cheers, Sergey
If configuring CXF
to route through Slf4j the problem goes away.
Best regards
Mike
Christian Schneider wrote:
I think it might make sense to remove the TCCL usage in OSGi
where ever
possible. This is not a small thing though as we have to be
careful not
to break existing code.
So for short term it will make more sense to work around
the problem.
Can you give a concrete example where it breaks for you?
Btw. I am using pax logging a lot and itworks fine with CXF.
I just use
the slf4j API in my own code and pax logging implements it.
Christian
On 24.02.2015 15:46, Mike Wilson wrote:
Yes, the undesired side-effect for us is that the
combination of CXF, Juli
and Pax Logging breaks down. Looking at the code it seems
all involved
parties have design decisions done with good intentions
and the only
questionable thing is CXF's use of TCCL, which is sort of
the trigger of the
problem. So I thought this would be the first thing worth
considering as it
is advised against in OSGi.
If not possible to remove TCCL entirely, then it might
still be possible to
only set it during the very calls into stuff that need it,
instead of during
the whole message cycle?
Best regards
Mike
--
Christian Schneider
http://www.liquid-reality.de
Open Source Architect
http://www.talend.com
--
Daniel Kulp
[email protected] - http://dankulp.com/blog
Talend Community Coder - http://coders.talend.com
--
Daniel Kulp
[email protected] - http://dankulp.com/blog
Talend Community Coder - http://coders.talend.com
