You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@cxf.apache.org by "Clark, Chris" <ch...@eds.com> on 2009/07/30 10:08:14 UTC
Deadlock in CXF DOSGi implementation (latest 1.1 snapshot)
Hi
When trying to use the latest CXF DOSGi RI (multibundle) together with
Apache Felix 1.8.1 I noticed a thread deadlock when starting
Up - this occurs on the startup of the last bundle in the list,
cxf-dosgi-ri-dsw-cxf-1.1-SNAPSHOT.jar.
The last log entry I see is:
[FelixStartLevel] INFO org.apache.cxf.dosgi.dsw.hooks.AbstractClientHook
- looku
p discovery service: interface: org.osgi.service.event.EventHandler
filter: (|(e
vent.topics=\*)(event.topics=org/\*)(event.topics=org/osgi/\*)(event.top
ics=org/
osgi/service/\*)(event.topics=org/osgi/service/log/\*)(event.topics=org/
osgi/ser
vice/log/LogEntry/\*)(event.topics=org/osgi/service/log/LogEntry/LOG_DEB
UG))
[9818046@qtp-4171180-0 - /system/console/logs] DEBUG org.mortbay.jetty -
REQUEST
/system/console/logs on org.mortbay.jetty.HttpConnection@19b808a
When using jconsole (I am running on JDK 6.0 u14), these are the
deadlocks:
[1]
Name: FelixStartLevel
State: BLOCKED on java.util.Stack@39f16f owned by: Thread-4
Total blocked: 70 Total waited: 46
Stack trace:
org.apache.felix.log.LogListenerThread.addEntry(LogListenerThread.java:5
2)
org.apache.felix.log.Log.addEntry(Log.java:125)
- locked org.apache.felix.log.Log@1637d45
org.apache.felix.log.Log.serviceChanged(Log.java:263)
org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCal
lback(EventDispatcher.java:846)
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(Eve
ntDispatcher.java:704)
org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDi
spatcher.java:635)
org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:3443)
org.apache.felix.framework.Felix.access$000(Felix.java:39)
org.apache.felix.framework.Felix$1.serviceChanged(Felix.java:622)
org.apache.felix.framework.ServiceRegistry.fireServiceChanged(ServiceReg
istry.java:576)
org.apache.felix.framework.ServiceRegistry.servicePropertiesModified(Ser
viceRegistry.java:501)
org.apache.felix.framework.ServiceRegistrationImpl.setProperties(Service
RegistrationImpl.java:107)
org.apache.cxf.dosgi.dsw.hooks.AbstractClientHook.lookupDiscoveryService
(AbstractClientHook.java:218)
- locked org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook@1a0283e
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook.find(CxfFindListenerH
ook.java:95)
org.apache.felix.framework.Felix.getServiceReferences(Felix.java:2642)
org.apache.felix.framework.Felix.getAllowedServiceReferences(Felix.java:
2672)
org.apache.felix.framework.BundleContextImpl.getServiceReferences(Bundle
ContextImpl.java:310)
org.apache.felix.eventadmin.impl.handler.BlacklistingHandlerTasks.create
HandlerTasks(BlacklistingHandlerTasks.java:114)
org.apache.felix.eventadmin.impl.EventAdminImpl.postEvent(EventAdminImpl
.java:87)
org.apache.felix.eventadmin.impl.adapter.ServiceEventAdapter.serviceChan
ged(ServiceEventAdapter.java:135)
org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCal
lback(EventDispatcher.java:846)
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(Eve
ntDispatcher.java:704)
org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDi
spatcher.java:635)
org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:3443)
org.apache.felix.framework.Felix.access$000(Felix.java:39)
org.apache.felix.framework.Felix$1.serviceChanged(Felix.java:622)
org.apache.felix.framework.ServiceRegistry.fireServiceChanged(ServiceReg
istry.java:576)
org.apache.felix.framework.ServiceRegistry.servicePropertiesModified(Ser
viceRegistry.java:501)
org.apache.felix.framework.ServiceRegistrationImpl.setProperties(Service
RegistrationImpl.java:107)
org.apache.cxf.dosgi.dsw.hooks.AbstractClientHook.lookupDiscoveryService
(AbstractClientHook.java:218)
- locked org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook@1a0283e
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook.find(CxfFindListenerH
ook.java:95)
org.apache.felix.framework.Felix.getServiceReferences(Felix.java:2642)
org.apache.felix.framework.Felix.getAllowedServiceReferences(Felix.java:
2672)
org.apache.felix.framework.BundleContextImpl.getServiceReferences(Bundle
ContextImpl.java:310)
org.apache.felix.eventadmin.impl.handler.BlacklistingHandlerTasks.create
HandlerTasks(BlacklistingHandlerTasks.java:114)
org.apache.felix.eventadmin.impl.EventAdminImpl.postEvent(EventAdminImpl
.java:87)
org.apache.felix.eventadmin.impl.adapter.LogEventAdapter$1.logged(LogEve
ntAdapter.java:285)
org.ops4j.pax.logging.internal.LogReaderServiceImpl.fire(LogReaderServic
eImpl.java:129)
org.ops4j.pax.logging.internal.LogReaderServiceImpl.fireEvent(LogReaderS
erviceImpl.java:121)
org.ops4j.pax.logging.internal.PaxLoggingServiceImpl.handleEvents(PaxLog
gingServiceImpl.java:151)
org.ops4j.pax.logging.internal.PaxLoggerImpl.debug(PaxLoggerImpl.java:11
6)
org.ops4j.pax.logging.internal.PaxLoggingServiceImpl.log(PaxLoggingServi
ceImpl.java:140)
org.ops4j.pax.logging.internal.PaxLoggingServiceImpl.log(PaxLoggingServi
ceImpl.java:93)
org.ops4j.pax.logging.internal.PaxLoggingServiceImpl.log(PaxLoggingServi
ceImpl.java:88)
org.ops4j.pax.logging.internal.FrameworkHandler.serviceChanged(Framework
Handler.java:147)
org.apache.felix.framework.util.EventDispatcher.invokeServiceListenerCal
lback(EventDispatcher.java:846)
org.apache.felix.framework.util.EventDispatcher.fireEventImmediately(Eve
ntDispatcher.java:704)
org.apache.felix.framework.util.EventDispatcher.fireServiceEvent(EventDi
spatcher.java:635)
org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:3443)
org.apache.felix.framework.Felix.access$000(Felix.java:39)
org.apache.felix.framework.Felix$1.serviceChanged(Felix.java:622)
org.apache.felix.framework.ServiceRegistry.fireServiceChanged(ServiceReg
istry.java:576)
org.apache.felix.framework.ServiceRegistry.registerService(ServiceRegist
ry.java:86)
org.apache.felix.framework.Felix.registerService(Felix.java:2569)
org.apache.felix.framework.BundleContextImpl.registerService(BundleConte
xtImpl.java:252)
org.apache.cxf.dosgi.dsw.Activator.start(Activator.java:78)
org.apache.felix.framework.util.SecureAction.startActivator(SecureAction
.java:589)
org.apache.felix.framework.Felix.startBundle(Felix.java:1461)
org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:984)
org.apache.felix.framework.StartLevelImpl.run(StartLevelImpl.java:263)
java.lang.Thread.run(Unknown Source)
[2]
Name: Thread-4
State: BLOCKED on
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook@1a0283e owned by:
FelixStartLevel
Total blocked: 122 Total waited: 114
Stack trace:
org.apache.cxf.dosgi.dsw.hooks.AbstractClientHook.lookupDiscoveryService
(AbstractClientHook.java:201)
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook.find(CxfFindListenerH
ook.java:95)
org.apache.felix.framework.Felix.getServiceReferences(Felix.java:2642)
org.apache.felix.framework.Felix.getAllowedServiceReferences(Felix.java:
2672)
org.apache.felix.framework.BundleContextImpl.getServiceReferences(Bundle
ContextImpl.java:310)
org.apache.felix.eventadmin.impl.handler.BlacklistingHandlerTasks.create
HandlerTasks(BlacklistingHandlerTasks.java:114)
org.apache.felix.eventadmin.impl.EventAdminImpl.postEvent(EventAdminImpl
.java:87)
org.apache.felix.eventadmin.impl.adapter.LogEventAdapter$1.logged(LogEve
ntAdapter.java:285)
org.apache.felix.log.LogListenerThread.run(LogListenerThread.java:113)
- locked java.util.Vector@4478fe
- locked java.util.Stack@39f16f
Now, after logging in using a remote shell (I use the remote shell
service), and requesting the runtime state using the
'ps' command, I get an extra deadlock:
[3]
Name: telnetconsole.shell remote=/127.0.0.1:1898
State: BLOCKED on
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook@1a0283e owned by:
FelixStartLevel
Total blocked: 1 Total waited: 0
Stack trace:
org.apache.cxf.dosgi.dsw.hooks.AbstractClientHook.lookupDiscoveryService
(AbstractClientHook.java:201)
org.apache.cxf.dosgi.dsw.hooks.CxfFindListenerHook.find(CxfFindListenerH
ook.java:95)
org.apache.felix.framework.Felix.getServiceReferences(Felix.java:2642)
org.apache.felix.framework.Felix.getAllowedServiceReferences(Felix.java:
2672)
org.apache.felix.framework.BundleContextImpl.getServiceReferences(Bundle
ContextImpl.java:310)
org.apache.felix.framework.BundleContextImpl.getServiceReference(BundleC
ontextImpl.java:261)
org.apache.felix.shell.impl.PsCommandImpl.execute(PsCommandImpl.java:58)
org.apache.felix.shell.impl.Activator$ShellServiceImpl.executeCommand(Ac
tivator.java:291)
- locked
org.apache.felix.shell.impl.Activator$ShellServiceImpl@438e1e
org.apache.felix.shell.remote.Shell.run(Shell.java:109)
java.lang.Thread.run(Unknown Source)
So I had a look at the code for the AbstractClientHook, and pinned down
where the deadlock is...
(red area is where the deadlock occurs).
protected synchronized void lookupDiscoveryService(String
interfaceName, String filterValue) {
LOG.info("lookup discovery service: interface: " + interfaceName
+ " filter: " + filterValue);
boolean change = false;
if (interfaceName != null) {
change |= append(trackerProperties,
INTERFACE_MATCH_CRITERIA,
interfaceName);
}
if (filterValue != null) {
change |= append(trackerProperties,
FILTER_MATCH_CRITERIA,
filterValue);
}
if (change) {
trackerRegistration.setProperties(trackerProperties);
}
}
@SuppressWarnings("unchecked")
private boolean append(Dictionary properties, String key, String
additional) {
Collection existing = (Collection)properties.get(key);
if (existing == null) {
existing = new ArrayList<String>();
properties.put(key, existing);
}
if (!existing.contains(additional)) {
existing.add(additional);
return true;
} else {
return false;
}
}
Now the issue is - how is this deadlock occurring, and how can it be
avoided - is this an issue to do with
synchronized on the method? Is the LOG object not threadsafe?
The LOG object is defined at the start of the AbstractClientHook class,
public class AbstractClientHook extends AbstractHook {
private static final Logger LOG =
Logger.getLogger(AbstractClientHook.class.getName());
Anyone have any ideas on this?
TIA, Chris