This service will be undergoing maintenance at 00:00 UTC, 2016-08-01. It is expected to last about 1 hours

Bug 707759

Summary: Deployment of new WAR to EAP server fails due to thread timeout - Need configurable thread timeout
Product: [Other] RHQ Project Reporter: Larry O'Leary <loleary>
Component: Plugin ContainerAssignee: Jay Shaughnessy <jshaughn>
Status: CLOSED CURRENTRELEASE QA Contact: Mike Foley <mfoley>
Severity: high Docs Contact:
Priority: high    
Version: 4.0.1CC: ccrouch, hrupp, skondkar
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 4.1 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
: 707782 (view as bug list) Environment:
JON 2.4.1 JBoss EAP 5.1 Deployment of application (WAR) which requires a couple of minutes to fully start.
Last Closed: 2013-09-03 13:02:32 EDT Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Bug Depends On:    
Bug Blocks: 707782    

Description Larry O'Leary 2011-05-25 16:48:11 EDT
A user is attempting to deploy a WAR to an EAP server using JON but the deployment fails because the WAR is taking too long to start-up. The result is the thread invoking the application startup is failing with the following stack trace:

ERROR [org.apache.catalina.core.ContainerBase.[jboss.web].[localhost].[/caprev]] (ResourceContainer.invoker.nonDaemon-5) Exception starting filter struts2
java.lang.InterruptedException - Class: com.opensymphony.xwork2.inject.util.ReferenceCache
File: ReferenceCache.java
Method: internalCreate
Line: 90 - com/opensymphony/xwork2/inject/util/ReferenceCache.java:90:-1
   at org.apache.struts2.dispatcher.Dispatcher.init(Dispatcher.java:431)
   at org.apache.struts2.dispatcher.FilterDispatcher.init(FilterDispatcher.java:190)
   at org.apache.catalina.core.ApplicationFilterConfig.getFilter(ApplicationFilterConfig.java:234)
   at org.apache.catalina.core.ApplicationFilterConfig.setFilterDef(ApplicationFilterConfig.java:332)
   at org.apache.catalina.core.ApplicationFilterConfig.<init>(ApplicationFilterConfig.java:90)
   at org.apache.catalina.core.StandardContext.filterStart(StandardContext.java:3783)
   at org.apache.catalina.core.StandardContext.start(StandardContext.java:4409)
   at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performDeployInternal(TomcatDeployment.java:310)
   at org.jboss.web.tomcat.service.deployers.TomcatDeployment.performDeploy(TomcatDeployment.java:142)
   at org.jboss.web.deployers.AbstractWarDeployment.start(AbstractWarDeployment.java:461)
   at org.jboss.web.deployers.WebModule.startModule(WebModule.java:118)
   at org.jboss.web.deployers.WebModule.start(WebModule.java:97)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:157)
   at org.jboss.mx.server.Invocation.dispatch(Invocation.java:96)
   at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
   at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
   at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:668)
   at org.jboss.system.microcontainer.ServiceProxy.invoke(ServiceProxy.java:206)
   at $Proxy38.start(Unknown Source)
   at org.jboss.system.microcontainer.StartStopLifecycleAction.installAction(StartStopLifecycleAction.java:42)
   at org.jboss.system.microcontainer.StartStopLifecycleAction.installAction(StartStopLifecycleAction.java:37)
   at org.jboss.dependency.plugins.action.SimpleControllerContextAction.simpleInstallAction(SimpleControllerContextAction.java:62)
   at org.jboss.dependency.plugins.action.AccessControllerContextAction.install(AccessControllerContextAction.java:71)
   at org.jboss.dependency.plugins.AbstractControllerContextActions.install(AbstractControllerContextActions.java:51)
   at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:348)
   at org.jboss.system.microcontainer.ServiceControllerContext.install(ServiceControllerContext.java:297)
   at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1633)
   at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:935)
   at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:1083)
   at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:985)
   at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:823)
   at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:553)
   at org.jboss.system.ServiceController.doChange(ServiceController.java:688)
   at org.jboss.system.ServiceController.start(ServiceController.java:460)
   at org.jboss.system.deployers.ServiceDeployer.start(ServiceDeployer.java:163)
   at org.jboss.system.deployers.ServiceDeployer.deploy(ServiceDeployer.java:99)
   at org.jboss.system.deployers.ServiceDeployer.deploy(ServiceDeployer.java:46)
   at org.jboss.deployers.spi.deployer.helpers.AbstractSimpleRealDeployer.internalDeploy(AbstractSimpleRealDeployer.java:62)
   at org.jboss.deployers.spi.deployer.helpers.AbstractRealDeployer.deploy(AbstractRealDeployer.java:50)
   at org.jboss.deployers.plugins.deployers.DeployerWrapper.deploy(DeployerWrapper.java:171)
   at org.jboss.deployers.plugins.deployers.DeployersImpl.doDeploy(DeployersImpl.java:1440)
   at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1158)
   at org.jboss.deployers.plugins.deployers.DeployersImpl.doInstallParentFirst(DeployersImpl.java:1179)
   at org.jboss.deployers.plugins.deployers.DeployersImpl.install(DeployersImpl.java:1099)
   at org.jboss.dependency.plugins.AbstractControllerContext.install(AbstractControllerContext.java:348)
   at org.jboss.dependency.plugins.AbstractController.install(AbstractController.java:1633)
   at org.jboss.dependency.plugins.AbstractController.incrementState(AbstractController.java:935)
   at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:1083)
   at org.jboss.dependency.plugins.AbstractController.resolveContexts(AbstractController.java:985)
   at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:823)
   at org.jboss.dependency.plugins.AbstractController.change(AbstractController.java:553)
   at org.jboss.deployers.plugins.deployers.DeployersImpl.process(DeployersImpl.java:782)
   at org.jboss.deployers.plugins.main.MainDeployerImpl.process(MainDeployerImpl.java:702)
   at org.jboss.system.server.profileservice.repository.MainDeployerAdapter.process(MainDeployerAdapter.java:117)
   at org.jboss.profileservice.management.upload.remoting.AbstractDeployHandler.start(AbstractDeployHandler.java:324)
   at org.jboss.profileservice.management.upload.remoting.AbstractDeployHandler.invoke(AbstractDeployHandler.java:238)
   at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:897)
   at org.jboss.remoting.transport.local.LocalClientInvoker.invoke(LocalClientInvoker.java:106)
   at org.jboss.remoting.Client.invoke(Client.java:1927)
   at org.jboss.remoting.Client.invoke(Client.java:770)
   at org.jboss.profileservice.management.client.upload.StreamingDeploymentTarget.invoke(StreamingDeploymentTarget.java:304)
   at org.jboss.profileservice.management.client.upload.StreamingDeploymentTarget.start(StreamingDeploymentTarget.java:189)
   at org.jboss.profileservice.management.client.upload.DeploymentProgressImpl.start(DeploymentProgressImpl.java:232)
   at org.jboss.profileservice.management.client.upload.DeploymentProgressImpl.run(DeploymentProgressImpl.java:89)
   at org.rhq.plugins.jbossas5.util.DeploymentUtils.run(DeploymentUtils.java:155)
   at org.rhq.plugins.jbossas5.util.DeploymentUtils.deployArchive(DeploymentUtils.java:116)
   at org.rhq.plugins.jbossas5.deploy.AbstractDeployer.deploy(AbstractDeployer.java:110)
   at org.rhq.plugins.jbossas5.ApplicationServerComponent.createContentBasedResource(ApplicationServerComponent.java:436)
   at org.rhq.plugins.jbossas5.ApplicationServerComponent.createResource(ApplicationServerComponent.java:258)
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
   at java.lang.reflect.Method.invoke(Method.java:597)
   at org.rhq.core.pc.inventory.ResourceContainer$ComponentInvocationThread.call(ResourceContainer.java:525)
   at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
   at java.util.concurrent.FutureTask.run(FutureTask.java:138)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
   at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.RuntimeException: java.lang.InterruptedException
   at com.opensymphony.xwork2.inject.util.ReferenceCache.internalCreate(ReferenceCache.java:90)
   at com.opensymphony.xwork2.inject.util.ReferenceCache.get(ReferenceCache.java:116)
   at com.opensymphony.xwork2.inject.ContainerImpl$ConstructorInjector.<init>(ContainerImpl.java:348)
   at com.opensymphony.xwork2.inject.ContainerImpl$5.create(ContainerImpl.java:305)
   at com.opensymphony.xwork2.inject.ContainerImpl$5.create(ContainerImpl.java:301)
   at com.opensymphony.xwork2.inject.util.ReferenceCache$CallableCreate.call(ReferenceCache.java:150)
   at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
   at java.util.concurrent.FutureTask.run(FutureTask.java:138)
   at com.opensymphony.xwork2.inject.util.ReferenceCache.internalCreate(ReferenceCache.java:76)
   at com.opensymphony.xwork2.inject.util.ReferenceCache.get(ReferenceCache.java:116)
   at com.opensymphony.xwork2.inject.ContainerImpl.getConstructor(ContainerImpl.java:594)
   at com.opensymphony.xwork2.inject.ContainerBuilder$5.create(ContainerBuilder.java:204)
   at com.opensymphony.xwork2.inject.Scope$2$1.create(Scope.java:51)
   at com.opensymphony.xwork2.inject.ContainerBuilder$3.create(ContainerBuilder.java:93)
   at com.opensymphony.xwork2.inject.ContainerBuilder$7.call(ContainerBuilder.java:487)
   at com.opensymphony.xwork2.inject.ContainerBuilder$7.call(ContainerBuilder.java:484)
   at com.opensymphony.xwork2.inject.ContainerImpl.callInContext(ContainerImpl.java:574)
   at com.opensymphony.xwork2.inject.ContainerBuilder.create(ContainerBuilder.java:484)
   at com.opensymphony.xwork2.config.impl.DefaultConfiguration.createBootstrapContainer(DefaultConfiguration.java:241)
   at com.opensymphony.xwork2.config.impl.DefaultConfiguration.reloadContainer(DefaultConfiguration.java:182)
   at com.opensymphony.xwork2.config.ConfigurationManager.getConfiguration(ConfigurationManager.java:55)
   at org.apache.struts2.dispatcher.Dispatcher.init_PreloadConfiguration(Dispatcher.java:374)
   at org.apache.struts2.dispatcher.Dispatcher.init(Dispatcher.java:418)
   ... 82 more
Caused by: java.lang.InterruptedException
   at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1215)
   at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:218)
   at java.util.concurrent.FutureTask.get(FutureTask.java:83)
   at com.opensymphony.xwork2.inject.util.ReferenceCache.internalCreate(ReferenceCache.java:77)
   ... 104 more



It appears that the thread is timing out at 60 seconds and that this value is hard-coded. Can we expose this (and any other) timeouts as configurable options so that they can be overridden by in the JON configuration?
Comment 1 Jay Shaughnessy 2011-05-25 17:38:20 EDT
Fix part1: master commit c4432f792961c2ce406cf0f9a0be4847842260f7

Provide overrides for the default 60 second timeout of create and
delete child actions.

In general 60s may be enough but for applications that need time to deploy,
or perhaps to shut down gracefully, this can be too short.  The overrides
are blunt in that they affect all types. And it should be noted that while
creating(deploying) or deleting the child resource, the parent resource will
be write-locked, meaning deferred metric reporting etc. So, it it recommended
that when possible fast create and delete is performed for these facet
implementations.


Fix part2 will be the addition to the create wizard of a timeout setting
that can be used to override the timeout for that single create operation.
Comment 2 Jay Shaughnessy 2011-05-27 16:22:51 EDT
fix part2: master commit ac0d61b0935d756ce9752b37680760ed77f00004

Add the ability to set a timeout on an individual resource create (in the
wizard) and pass that on with the agent request.  This value allows a long
running create/deploy to avoid timeout issues without having to override
the create timeout globally in the rhq-agent-env (although that ability is
still there).

So, we have:
- a 60s default timeout
- an agent-side property for global override of the default
- an ability to set a specific timeout in the create wizard, for a
  specific create

Questions:
1) is 60s too short a default

Remember that increasing the default means a hanging request will
keep the parent locked for a longer period of time.

2) how does this play with embedded console, which also does deploys.
   Can EC utilize the expanded API and supply a timeout like the 
   create wizard? (see EMBJOPR-176)
Comment 3 Ian Springer 2011-05-29 10:59:06 EDT
In answer to 2), the current fix used in EmbJopr of increasing the timeout to 10m should suffice for EmbJopr's needs. Jay's changes will not affect the EAP 5.x admin console, since it has its own dedicated RHQ branch, which will be used for any blocking fixes that need to go into future EAP 5.x releases.
Comment 4 Jay Shaughnessy 2011-05-31 09:39:30 EDT
OK, so embedded console should be good as is. This work is done in master, so setting to ON_QA.

Test Notes:  It's possible to try and test this with a slow deploying app and exceeding the default timeout of 1 minute, but an easier way may be to just take a small app that does deploy with the default, and then try again, decreasing the timeout via the gui, and show that it does in fact timeout.
Comment 5 Sunil Kondkar 2011-06-09 07:31:07 EDT
Verified on build116 (Version: 4.1.0-SNAPSHOT Build Number: 6ae3b13) 

Inventoried an EAP5 instance and navigated to the Inventory->Child Resources tab of the resource. Clicked on Create Child->Web Application(WAR).
Uploaded a small war file on step 2 and clicked Next button. The 3rd step displays a Timeout field with a dropdown values seconds/minutes and a help icon which displays the text as "A timeout duration. If specified will override the default timeout for child resource creation (on the RHQ Agent). Useful for particularly long create actions, like deployment of a large application. Usually used if a previous attempt suffered a timeout failure."

Deployed the WAR with default timeout successfully and then deleted it from the child resources. Again tried to deploy the WAR with timeout option set to 2 seconds. It failed with below TimeoutException.

org.rhq.core.pc.inventory.TimeoutException: Call to [org.rhq.plugins.jbossas5.ApplicationServerComponent.createResource()] with args [[CreateResourceReport: ResourceType=[ResourceType[id=0, category=Service, name=Web Application (WAR), plugin=JBossAS5]], ResourceKey=[null]]] timed out. Invocation thread will be interrupted.

Marking as verified.
Comment 6 Charles Crouch 2011-09-30 15:03:34 EDT
removing bad depends bzs
Comment 7 Heiko W. Rupp 2013-09-03 13:02:32 EDT
Bulk closing of old issues that are in VERIFIED state.