Deployment hang and timeout, how to find the cause?

[lafr]

I have a problem deploying my application on a customer system running Windows Server 2012 R2 using Oracle JDK 1.8.0_92.

The same application works just fine when we run it on the same WildFly server version on Solaris SPARC using the same Java version.

So the problem is probably related to the target environment.

How can I find out what is holding up the deployment and causing the timeout?

03.06. 21:58:57,134 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/inventory
03.06. 21:58:57,134 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/external
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/sales
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/planning
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/costing
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/core
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/purchase
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/production
03.06. 21:58:57,154 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/distribution
03.06. 21:58:57,534 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi/fur-test-mbi/web
03.06. 21:58:57,564 INFO  [org.wildfly.extension.undertow#registerDeployment] WFLYUT0021: Registered web context: /mbi-ws/fur-test-mbi/common
03.06. 22:03:49,192 ERROR [org.jboss.as.controller.management-operation#awaitServiceContainerStability] WFLYCTL0348: Timeout after [300] seconds waiting for service container stability. Operation will roll back. Step that first updated the service container was 'deploy' at address '[("deployment" => "fur-test-mbi.ear")]'
03.06. 22:03:49,192 ERROR [org.jboss.as.server#handleResult] WFLYSRV0022: Deploy of deployment "fur-test-mbi.ear" was rolled back with no failure message
03.06. 22:03:49,242 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/sales
03.06. 22:03:49,242 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/inventory
03.06. 22:03:49,242 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/planning
03.06. 22:03:49,232 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/external
03.06. 22:03:49,252 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/purchase
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/common
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/production
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi/fur-test-mbi/web
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/core
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/costing
03.06. 22:03:49,262 INFO  [org.wildfly.extension.undertow#unregisterDeployment] WFLYUT0022: Unregistered web context: /mbi-ws/fur-test-mbi/distribution
03.06. 22:03:54,192 ERROR [org.jboss.as.controller.management-operation#handleResult] WFLYCTL0190: Step handler org.jboss.as.server.deployment.DeploymentHandlerUtil$1@134ff28c for operation {"operation" => "deploy","address" => [("deployment" => "fur-test-mbi.ear")],"owner" => [("subsystem" => "deployment-scanner"),("scanner" => "default")]} at address [("deployment" => "fur-test-mbi.ear")] failed handling operation rollback -- java.util.concurrent.TimeoutException: java.util.concurrent.TimeoutException
    at org.jboss.as.controller.OperationContextImpl.waitForRemovals(OperationContextImpl.java:511)
    at org.jboss.as.controller.AbstractOperationContext$Step.handleResult(AbstractOperationContext.java:1369)
    at org.jboss.as.controller.AbstractOperationContext$Step.finalizeInternal(AbstractOperationContext.java:1328)
    at org.jboss.as.controller.AbstractOperationContext$Step.finalizeStep(AbstractOperationContext.java:1301)
    at org.jboss.as.controller.AbstractOperationContext$Step.access$300(AbstractOperationContext.java:1185)
    at org.jboss.as.controller.AbstractOperationContext.executeResultHandlerPhase(AbstractOperationContext.java:767)
    at org.jboss.as.controller.AbstractOperationContext.processStages(AbstractOperationContext.java:644)
    at org.jboss.as.controller.AbstractOperationContext.executeOperation(AbstractOperationContext.java:370)
    at org.jboss.as.controller.OperationContextImpl.executeOperation(OperationContextImpl.java:1344)
    at org.jboss.as.controller.ModelControllerImpl.internalExecute(ModelControllerImpl.java:392)
    at org.jboss.as.controller.ModelControllerImpl.execute(ModelControllerImpl.java:217)
    at org.jboss.as.controller.ModelControllerImpl$3$1$1.run(ModelControllerImpl.java:748)
    at org.jboss.as.controller.ModelControllerImpl$3$1$1.run(ModelControllerImpl.java:742)
    at java.security.AccessController.doPrivileged(Native Method)
    at org.jboss.as.controller.ModelControllerImpl$3$1.run(ModelControllerImpl.java:742)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
    at org.jboss.threads.JBossThread.run(JBossThread.java:320)

[ctomc]

looks like your application is taking a long time to deploy / boot properly.

Could be that your solaris system is faster and boot completes faster that is why you are only see this on windows server.

Problem can be easily fixed by increasing deployment scanner time out and/or adjusting system property "jboss.as.management.blocking.timeout" 

Other solution would also be to give system some more cpu resources. or even trace why it is taking much longer to deploy the app.

maybe some external connection to DB or someting else are hanging in some connect timeout.

Thinking about it, there could also be some other problem at all, so could you do thread dump in the "moment" before the timeout happens, given it is 3 minutes before it fails. and please post the dump here

[nickarls]

Do you have any @Singletons etc. that might hang waiting for some resource in @PostConstruct when deploying? Just guessing here...