Aled Sage created BROOKLYN-316:
----------------------------------
Summary: jetty loginService used in karaf: can cause
ConstraintSecurityHandler's to fail
Key: BROOKLYN-316
URL: https://issues.apache.org/jira/browse/BROOKLYN-316
Project: Brooklyn
Issue Type: Bug
Reporter: Aled Sage
In a downstream project of Brooklyn, trying to use karaf with Brooklyn master,
some UI modules failed to load. Whether it fails, and which modules fail, is
non-deterministic.
---
On doing a {{bundle:refresh}} for the ui module, it started up correctly.
Below is the exception from the logs. The second is probably the most relevant:
{noformat}
07:54:26,624 WARN 224 component.AbstractLifeCycle [pool-99-thread-3] FAILED
HttpServiceContext{httpContext=WebAppHttpContext{amp-ui-blueprint-composer -
13}}: java.lang.IllegalStateException: LoginService has different
IdentityService to org.eclipse.jetty.security.ConstraintSecurityHandler@315dd009
java.lang.IllegalStateException: LoginService has different IdentityService to
org.eclipse.jetty.security.ConstraintSecurityHandler@315dd009
at
org.eclipse.jetty.security.SecurityHandler.doStart(SecurityHandler.java:376)[220:org.eclipse.jetty.security:9.2.14.v20151106]
at
org.eclipse.jetty.security.ConstraintSecurityHandler.doStart(ConstraintSecurityHandler.java:449)[220:org.eclipse.jetty.security:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.ScopedHandler.doStart(ScopedHandler.java:120)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.server.session.SessionHandler.doStart(SessionHandler.java:116)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.ScopedHandler.doStart(ScopedHandler.java:120)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.ContextHandler.startContext(ContextHandler.java:784)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:294)[222:org.eclipse.jetty.servlet:9.2.14.v20151106]
at
org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:741)[221:org.eclipse.jetty.server:9.2.14.v20151106]
at
org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doStart(HttpServiceContext.java:245)[244:org.ops4j.pax.web.pax-web-jetty:4.2.4]
at
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)[224:org.eclipse.jetty.util:9.2.14.v20151106]
at
org.ops4j.pax.web.service.jetty.internal.JettyServerImpl$1.start(JettyServerImpl.java:259)[244:org.ops4j.pax.web.pax-web-jetty:4.2.4]
at
org.ops4j.pax.web.service.internal.HttpServiceStarted.end(HttpServiceStarted.java:1047)[246:org.ops4j.pax.web.pax-web-runtime:4.2.4]
at
org.ops4j.pax.web.service.internal.HttpServiceProxy.end(HttpServiceProxy.java:413)[246:org.ops4j.pax.web.pax-web-runtime:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.RegisterWebAppVisitorWC.end(RegisterWebAppVisitorWC.java:380)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.model.WebApp.accept(WebApp.java:692)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.register(WebAppPublisher.java:237)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:182)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.WebAppPublisher$WebAppDependencyListener.addingService(WebAppPublisher.java:135)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941)[org.osgi.core-6.0.0.jar:]
at
org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870)[org.osgi.core-6.0.0.jar:]
at
org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256)[org.osgi.core-6.0.0.jar:]
at
org.osgi.util.tracker.AbstractTracked.trackInitial(AbstractTracked.java:183)[org.osgi.core-6.0.0.jar:]
at
org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:318)[org.osgi.core-6.0.0.jar:]
at
org.osgi.util.tracker.ServiceTracker.open(ServiceTracker.java:261)[org.osgi.core-6.0.0.jar:]
at
org.ops4j.pax.web.extender.war.internal.WebAppPublisher.publish(WebAppPublisher.java:101)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.WebObserver.deploy(WebObserver.java:219)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.WebObserver$1.doStart(WebObserver.java:179)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.extender.SimpleExtension.start(SimpleExtension.java:59)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
org.ops4j.pax.web.extender.war.internal.extender.AbstractExtender$1.run(AbstractExtender.java:280)[242:org.ops4j.pax.web.pax-web-extender-war:4.2.4]
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)[:1.7.0_71]
at java.util.concurrent.FutureTask.run(FutureTask.java:262)[:1.7.0_71]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178)[:1.7.0_71]
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292)[:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)[:1.7.0_71]
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)[:1.7.0_71]
at java.lang.Thread.run(Thread.java:745)[:1.7.0_71]
{noformat}
Running this in the debugger, I see there is a race: multiple threads are doing
{{ConstraintSecurityHandler.doStart()}}. There is one thread per UI bundle.
These threads all share the same {{LoginService}} (which is defined in
Brooklyn's {{karaf/jetty-config/src/main/resources/jetty.xml}}. However, that
LoginService does not have an IdentityService.
Each thread executing doStart() will see that there is no IdentityService, will
instantiate one, and will set it on the shared LoginService.
The subsequent check that {{securityService.getLoginService() ==
_loginService}} then fails for some threads, depending on the interleaving.
The doStart() does the following to get the identityService:
* is there an identityService already set on the loginService (if so, use it)
* is there a bean for an identityService that it can use
* instantiate a new {{org.eclipse.jetty.security.DefaultIdentityService}}, and
use that.
The stacktraces below show the execution state of two threads. One or both is
about to fail (depending on subsequent interleaving, which I was controlling
through an attached debugger):
A solution would therefore be for Brooklyn to create the loginService bean with
an existing IdentityService instance.
{noformat}
Thread [pool-99-thread-2] (Suspended)
owns: Object (id=981)
owns: Object (id=982)
owns: Object (id=983)
owns: WebObserver$1 (id=984)
ConstraintSecurityHandler(SecurityHandler).doStart() line: 351
ConstraintSecurityHandler.doStart() line: 449
ConstraintSecurityHandler(AbstractLifeCycle).start() line: 68
SessionHandler(ContainerLifeCycle).start(LifeCycle) line: 132
SessionHandler(ContainerLifeCycle).doStart() line: 114
SessionHandler(AbstractHandler).doStart() line: 61
SessionHandler(ScopedHandler).doStart() line: 120
SessionHandler.doStart() line: 116
SessionHandler(AbstractLifeCycle).start() line: 68
HttpServiceContext(ContainerLifeCycle).start(LifeCycle) line: 132
HttpServiceContext(ContainerLifeCycle).doStart() line: 114
HttpServiceContext(AbstractHandler).doStart() line: 61
HttpServiceContext(ScopedHandler).doStart() line: 120
HttpServiceContext(ContextHandler).startContext() line: 784
HttpServiceContext(ServletContextHandler).startContext() line: 294
HttpServiceContext(ContextHandler).doStart() line: 741
HttpServiceContext.doStart() line: 245
HttpServiceContext(AbstractLifeCycle).start() line: 68
JettyServerImpl$1.start() line: 259
HttpServiceStarted.end(HttpContext) line: 1047
HttpServiceProxy.end(HttpContext) line: 413
RegisterWebAppVisitorWC.end() line: 380
WebApp.accept(WebAppVisitor) line: 692
WebAppPublisher$WebAppDependencyListener.register(WebAppDependencyHolder,
HttpService) line: 237
WebAppPublisher$WebAppDependencyListener.addingService(ServiceReference<WebAppDependencyHolder>)
line: 182
WebAppPublisher$WebAppDependencyListener.addingService(ServiceReference) line:
135
ServiceTracker$Tracked.customizerAdding(ServiceReference<S>,
ServiceEvent) line: 941
ServiceTracker$Tracked.customizerAdding(Object, Object) line: 870
ServiceTracker$Tracked(AbstractTracked<S,T,R>).trackAdding(S, R) line:
256
ServiceTracker$Tracked(AbstractTracked<S,T,R>).trackInitial() line: 183
ServiceTracker<S,T>.open(boolean) line: 318
ServiceTracker<S,T>.open() line: 261
WebAppPublisher.publish(WebApp) line: 101
WebObserver.deploy(WebApp) line: 219
WebObserver$1.doStart() line: 179
WebObserver$1(SimpleExtension).start() line: 59
AbstractExtender$1.run() line: 280
Executors$RunnableAdapter<T>.call() line: 471
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>(FutureTask<V>).run()
line: 262
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>.access$201(ScheduledThreadPoolExecutor$ScheduledFutureTask)
line: 178
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>.run() line: 292
ScheduledThreadPoolExecutor(ThreadPoolExecutor).runWorker(ThreadPoolExecutor$Worker)
line: 1145
ThreadPoolExecutor$Worker.run() line: 615
Thread.run() line: 745
Thread [pool-99-thread-1] (Suspended (breakpoint at line 374 in
SecurityHandler))
owns: Object (id=985)
owns: Object (id=986)
owns: Object (id=987)
owns: WebObserver$1 (id=988)
ConstraintSecurityHandler(SecurityHandler).doStart() line: 374
ConstraintSecurityHandler.doStart() line: 449
ConstraintSecurityHandler(AbstractLifeCycle).start() line: 68
SessionHandler(ContainerLifeCycle).start(LifeCycle) line: 132
SessionHandler(ContainerLifeCycle).doStart() line: 114
SessionHandler(AbstractHandler).doStart() line: 61
SessionHandler(ScopedHandler).doStart() line: 120
SessionHandler.doStart() line: 116
SessionHandler(AbstractLifeCycle).start() line: 68
HttpServiceContext(ContainerLifeCycle).start(LifeCycle) line: 132
HttpServiceContext(ContainerLifeCycle).doStart() line: 114
HttpServiceContext(AbstractHandler).doStart() line: 61
HttpServiceContext(ScopedHandler).doStart() line: 120
HttpServiceContext(ContextHandler).startContext() line: 784
HttpServiceContext(ServletContextHandler).startContext() line: 294
HttpServiceContext(ContextHandler).doStart() line: 741
HttpServiceContext.doStart() line: 245
HttpServiceContext(AbstractLifeCycle).start() line: 68
JettyServerImpl$1.start() line: 259
HttpServiceStarted.end(HttpContext) line: 1047
HttpServiceProxy.end(HttpContext) line: 413
RegisterWebAppVisitorWC.end() line: 380
WebApp.accept(WebAppVisitor) line: 692
WebAppPublisher$WebAppDependencyListener.register(WebAppDependencyHolder,
HttpService) line: 237
WebAppPublisher$WebAppDependencyListener.addingService(ServiceReference<WebAppDependencyHolder>)
line: 182
WebAppPublisher$WebAppDependencyListener.addingService(ServiceReference) line:
135
ServiceTracker$Tracked.customizerAdding(ServiceReference<S>,
ServiceEvent) line: 941
ServiceTracker$Tracked.customizerAdding(Object, Object) line: 870
ServiceTracker$Tracked(AbstractTracked<S,T,R>).trackAdding(S, R) line:
256
ServiceTracker$Tracked(AbstractTracked<S,T,R>).trackInitial() line: 183
ServiceTracker<S,T>.open(boolean) line: 318
ServiceTracker<S,T>.open() line: 261
WebAppPublisher.publish(WebApp) line: 101
WebObserver.deploy(WebApp) line: 219
WebObserver$1.doStart() line: 179
WebObserver$1(SimpleExtension).start() line: 59
AbstractExtender$1.run() line: 280
Executors$RunnableAdapter<T>.call() line: 471
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>(FutureTask<V>).run()
line: 262
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>.access$201(ScheduledThreadPoolExecutor$ScheduledFutureTask)
line: 178
ScheduledThreadPoolExecutor$ScheduledFutureTask<V>.run() line: 292
ScheduledThreadPoolExecutor(ThreadPoolExecutor).runWorker(ThreadPoolExecutor$Worker)
line: 1145
ThreadPoolExecutor$Worker.run() line: 615
Thread.run() line: 745
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
