0 Replies Latest reply on Sep 25, 2008 11:11 AM by Andrew Dinn

    Race Condition in WS Endpoint Startup

    Andrew Dinn Master

      I have a crash recovery test which employs two JBoss AS instances, call them A and B each running a JaxWS app, call them AppA and AppB. I arrange for a crash to happen in B when AppA first tries to invoke JaxWS service SB published by AppB. AppA makes repeated attempts to invoke a service SB, resending a request about once every 5 seconds.

      When B reboots the WS code deploys endpoints for service SB plus several other services SB1, SB2 etc. Some of these other endpoints are deployed before SB. So, an endpoint for SB (instance of class DefaultEndpoint) exists in state CREATED while SB1, SB2, etc are being transitioned from CREATED to STARTED by class UnifiedMetaDataDeploymentAspect.

      When a request comes in from AppA the request handling code calls startEndpoint and SB transitions to state STARTED even though UnifiedMetaDataDeploymentAspect has not initialised the endpoint. The requests fail initially with this error

      15:35:53,470 ERROR [[Participant]] Servlet.service() for servlet Participant threw exception
      java.lang.IllegalStateException: Deployment has no classloader associated
       at org.jboss.wsf.stack.jbws.RequestHandlerImpl.doPost(RequestHandlerImpl.java:197)
       at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:131)
       at org.jboss.wsf.stack.jbws.EndpointServlet.service(EndpointServlet.java:81)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
       at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
       at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
       at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
       at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:189)
       at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:91)
       at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:92)
       at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
       at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
       at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
       at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
       at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:325)
       at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:828)
       at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:601)
       at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
       at java.lang.Thread.run(Thread.java:595)
      


      This eventually gets resolved (not sure exactly how but it doesn't help :-). Subsequent requests fail with a different error because the endpoint has no associated metadata (UnifiedMetaDataDeploymentAspect has not yet added it as an attachment)

      15:36:03,752 ERROR [RequestHandlerImpl] Error processing web service request
      java.lang.IllegalStateException: Cannot obtain endpoint meta data
       at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleRequest(RequestHandlerImpl.java:240)
       at org.jboss.wsf.stack.jbws.RequestHandlerImpl.doPost(RequestHandlerImpl.java:205)
       at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:131)
       at org.jboss.wsf.stack.jbws.EndpointServlet.service(EndpointServlet.java:81)
       at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
       at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
       at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
       at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
       at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
       at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
       at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:189)
       at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:91)
       at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:92)
       at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
       at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
       at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
       at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
       at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:325)
       at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:828)
       at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:601)
       at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
       at java.lang.Thread.run(Thread.java:595)
      


      Finally, UnifiedMetaDataDeploymentAspect gets round to initialising the endpoint for SB and calls addAttachment(). This throws up because the endpoint is already in state STARTED and it expects it to be in state CREATED so it asserts.

      15:36:10,623 ERROR [AbstractKernelController] Error installing to Real: name=vfszip:/home/adinn/jboss/jbossas/JBoss_5_0_0_CR2/build/output/jboss-5.0.0.CR2/server/default2/deploy/jbossxts.sar state=PreReal mode=Manual requiredState=Real
      org.jboss.deployers.spi.DeploymentException: Error during deploy: vfszip:/home/adinn/jboss/jbossas/JBoss_5_0_0_CR2/build/output/jboss-5.0.0.CR2/server/default2/deploy/jbossxts.sar/ws-t11.war
       at org.jboss.deployers.spi.DeploymentException.rethrowAsDeploymentException(DeploymentException.java:49)
       at org.jboss.deployers.plugins.deployers.DeployerWrapper.deploy(DeployerWrapper.java:175)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doDeploy(DeployersImpl.java:1285)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1003)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1056)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.install(DeployersImpl.java:944)
       at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:348)
       at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1598)
       at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:934)
       at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:1062)
       at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:984)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:822)
       at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:553)
       at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:627)
       at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:541)
       at org.jboss.system.server.profileservice.hotdeploy.HDScanner.scan(HDScanner.java:290)
       at org.jboss.system.server.profileservice.hotdeploy.HDScanner.run(HDScanner.java:221)
       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:417)
       at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:280)
       at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:135)
       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:65)
       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:142)
       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:166)
       at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
       at java.lang.Thread.run(Thread.java:595)
      Caused by: java.lang.IllegalStateException: Cannot modify endpoint properties in state: STARTED
       at org.jboss.wsf.framework.deployment.DefaultEndpoint.assertEndpointSetterAccess(DefaultEndpoint.java:269)
       at org.jboss.wsf.framework.deployment.DefaultEndpoint.addAttachment(DefaultEndpoint.java:241)
       at org.jboss.wsf.stack.jbws.UnifiedMetaDataDeploymentAspect.start(UnifiedMetaDataDeploymentAspect.java:88)
       at org.jboss.wsf.framework.deployment.DeploymentAspectManagerImpl.start(DeploymentAspectManagerImpl.java:144)
       at org.jboss.wsf.container.jboss50.BareWSFRuntime.start(BareWSFRuntime.java:66)
       at org.jboss.wsf.container.jboss50.deployer.JAXWSDeployerHookPostJSE.deploy(JAXWSDeployerHookPostJSE.java:51)
       at org.jboss.wsf.container.jboss50.deployer.AbstractWebServiceDeployer.internalDeploy(AbstractWebServiceDeployer.java:60)
       at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.deploy(AbstractRealDeployer.java:50)
       at org.jboss.deployers.plugins.deployers.DeployerWrapper.deploy(DeployerWrapper.java:169)
       ... 24 more
      


      At this point the deployment backs out all of AppB's services.

      So, the problem is that the endpoint has been made visible as a target for requests when it is not yet fully configured. This will not normaly show up because it requires a request to arrive between publishing the CREATED endpoint and setting its WS metadat.

      This could be solved by adding a state between CREATED and STARTED called, for example, READY. State READY would only be transitioned to by UnifiedMetaDataDeploymentAspect once it had called addAttachment to complete initialisaton of the endpoint. If a request finds a READY endpoint it can start it. If it finds a CREATED endpoint it should throw an error to ensure that the request is rejected.

      Another alternative is to avoid exposing the CREATED endpoint until it is fully initialised (I assume the reason for exposing endpoints at all when they are in this state is to cater for the web.xml setting load-on-startup=0). This may be feasible but appears like it would require more rework.