JBoss EAP 6.1 undeployed application

[sbityakov]

All,

We had an issue last week where JBoss seemed to have silently undeployed a war application.  The steps that led to this were:

* I was attempting to update another war app by doing an exploded deployment, with .dodeploy file, etc. and jboss would not deploy the app.

* I then restarted the service and the war app was then deployed fine.

* The deployed war app was updated correctly, but this other war app never came up after the restart.

* I did not see anything in the logs around undeploying any applications

Any help would be really appreciated.

Thanks!

[jaikiran]

Collect the logs from the setup for now and then see if this issue can be reproduced. Attach the logs to this thread and maybe it has enough hints to tell us what the issue is.

[sbityakov]

Thanks for your reply.  Below is some information from the logs.

When the server was stopped to enable deployment of the war the following was found in the logs:

2016-12-01 10:08:58,837  INFO  web - JBAS018224: Unregister web context: /MichelinServices

2016-12-01 10:08:58,838  INFO  web - JBAS018224: Unregister web context: /MichelinAdmin

2016-12-01 10:08:58,838  INFO  web - JBAS018224: Unregister web context: /MichelinESB

2016-12-01 10:08:59,103  INFO  ra - HQ151003: HornetQ resource adaptor stopped

2016-12-01 10:08:59,267  WARN  client - HQ212037: Connection failure has been detected: HQ119015: The connection was disconnected because of server shutdown [code=DISCONNECTED]

2016-12-01 10:08:59,277  WARN  CachingConnectionFactory - Encountered a JMSException - resetting the underlying JMS Connection

javax.jms.JMSException: HornetQException[errorType=DISCONNECTED message=HQ119015: The connection was disconnected because of server shutdown]

        at org.hornetq.jms.client.HornetQConnection$JMSFailureListener.connectionFailed(HornetQConnection.java:703)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl.callSessionFailureListeners(ClientSessionFactoryImpl.java:961)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl.failoverOrReconnect(ClientSessionFactoryImpl.java:740)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl.handleConnectionFailure(ClientSessionFactoryImpl.java:580)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl.access$100(ClientSessionFactoryImpl.java:85)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl$DelegatingFailureListener.connectionFailed(ClientSessionFactoryImpl.java:1672)

        at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.callFailureListeners(RemotingConnectionImpl.java:570)

        at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.fail(RemotingConnectionImpl.java:341)

        at org.hornetq.core.client.impl.ClientSessionFactoryImpl$CloseRunnable.run(ClientSessionFactoryImpl.java:1631)

        at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:106)

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

        at java.lang.Thread.run(Thread.java:745)

Caused by: HornetQException[errorType=DISCONNECTED message=HQ119015: The connection was disconnected because of server shutdown]

        ... 5 more

2016-12-01 10:08:59,281  ERROR DefaultJmsMessageListenerContainer - Listener exception overridden by rollback exception

javax.jms.IllegalStateException: Session is closed

        at org.hornetq.jms.client.HornetQSession.checkClosed(HornetQSession.java:1014)

        at org.hornetq.jms.client.HornetQSession.getTransacted(HornetQSession.java:200)

        at sun.reflect.GeneratedMethodAccessor125.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:606)

        at org.springframework.jms.connection.CachingConnectionFactory$CachedSessionInvocationHandler.invoke(CachingConnectionFactory.java:384)

        at com.sun.proxy.$Proxy254.getTransacted(Unknown Source)

        at org.springframework.jms.listener.AbstractMessageListenerContainer.commitIfNecessary(AbstractMessageListenerContainer.java:710)

        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.doReceiveAndExecute(AbstractPollingMessageListenerContainer.java:341)

        at org.springframework.jms.listener.AbstractPollingMessageListenerContainer.receiveAndExecute(AbstractPollingMessageListenerContainer.java:226)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.invokeListener(DefaultMessageListenerContainer.java:1144)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.executeOngoingLoop(DefaultMessageListenerContainer.java:1136)

        at org.springframework.jms.listener.DefaultMessageListenerContainer$AsyncMessageListenerInvoker.run(DefaultMessageListenerContainer.java:1033)

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

        at java.lang.Thread.run(Thread.java:745)

2016-12-01 10:08:59,379  INFO  [/MichelinServices] - Closing Spring root WebApplicationContext

2016-12-01 10:08:59,382  INFO  [/MichelinAdmin] - Closing Spring root WebApplicationContext

2016-12-01 10:08:59,381  INFO  [/MichelinESB] - Closing Spring root WebApplicationContext

2016-12-01 10:08:59,382  INFO  AnnotationConfigWebApplicationContext - Closing Root WebApplicationContext: startup date [Thu Nov 17 10:06:24 EST 2016]; root of context hierarchy

2016-12-01 10:08:59,437  INFO  BusApplicationContext - Closing org.apache.cxf.bus.spring.BusApplicationContext@3fd6c7f5: startup date [Thu Nov 17 10:06:46 EST 2016]; parent: Root WebApplicationContext

2016-12-01 10:08:59,438  INFO  BusApplicationContext - Closing org.apache.cxf.bus.spring.BusApplicationContext@27ff1ad1: startup date [Thu Nov 17 10:06:45 EST 2016]; parent: Root WebApplicationContext

2016-12-01 10:08:59,439  INFO  BusApplicationContext - Closing org.apache.cxf.bus.spring.BusApplicationContext@91faec0: startup date [Thu Nov 17 10:06:45 EST 2016]; parent: Root WebApplicationContext

2016-12-01 10:08:59,440  INFO  BusApplicationContext - Closing org.apache.cxf.bus.spring.BusApplicationContext@336f0250: startup date [Thu Nov 17 10:06:43 EST 2016]; parent: Root WebApplicationContext

2016-12-01 10:08:59,469  INFO  server - HQ221002: HornetQ Server version 2.3.5.Final-redhat-2 (Monster Bee, 123) [a3d0d90c-734c-11e5-b3a7-07d5f3cc5775] stopped

2016-12-01 10:08:59,546  INFO  SpringCamelContext - Apache Camel 2.15.2 (CamelContext: camel-1) is shutting down

2016-12-01 10:08:59,582  INFO  DefaultShutdownStrategy - Starting to graceful shutdown 15 routes (timeout 300 seconds)

2016-12-01 10:08:59,645  INFO  [/MichelinServices] - Shutting down log4j

2016-12-01 10:08:59,661  INFO  [/MichelinAdmin] - Shutting down log4j

As you can see, all three web context were undeployed (/MichelinServices, /MichelinAdmin, /MichelinESB)

When the server was started back the following happened:

10:13:00,788 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinESB.war in deployment directory. To trigger deployment create a file called MichelinESB.war.dodeploy

10:13:00,789 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinAdmin.war in deployment directory. To trigger deployment create a file called MichelinAdmin.war.dodeploy

10:13:00,789 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinServices.war in deployment directory. To trigger deployment create a file called MichelinServices.war.dodeploy

10:13:06,824 WARN  [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016012: Deployment deployment "MichelinESB.war" contains CDI annotations but beans.xml was not found.

10:13:06,938 INFO  [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-7) JBAS010404: Deploying non-JDBC-compliant driver class com.mysql.jdbc.Driver (version 5.1)

10:13:06,940 WARN  [org.jboss.weld.deployer] (MSC service thread 1-7) JBAS016012: Deployment deployment "MichelinAdmin.war" contains CDI annotations but beans.xml was not found.

10:13:06,945 INFO  [org.jboss.web] (ServerService Thread Pool -- 70) JBAS018210: Register web context: /MichelinESB

10:13:06,987 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinESB]] (ServerService Thread Pool -- 70) No Spring WebApplicationInitializer types detected on classpath

10:13:06,988 INFO  [org.jboss.web] (ServerService Thread Pool -- 72) JBAS018210: Register web context: /MichelinAdmin

10:13:07,007 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinAdmin]] (ServerService Thread Pool -- 72) No Spring WebApplicationInitializer types detected on classpath

10:13:07,056 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinAdmin]] (ServerService Thread Pool -- 72) Initializing log4j from [file:///appserver/michelin/config/admin/log4j.xml]

10:13:07,064 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinESB]] (ServerService Thread Pool -- 70) Initializing log4j from [file:///appserver/michelin/config/esb/log4j.xml]

10:13:07,231 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinESB]] (ServerService Thread Pool -- 70) Initializing Spring root WebApplicationContext

10:13:07,231 INFO  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/MichelinAdmin]] (ServerService Thread Pool -- 72) Initializing Spring root WebApplicationContext

10:13:10,663 INFO  [org.hibernate.validator.internal.util.Version] (ServerService Thread Pool -- 70) HV000001: Hibernate Validator 4.3.1.Final-redhat-1

As you can see only two of the three contexts came back; /MichelinServices was never deployed back.

Any help will be greatly appreciated.  Thanks!

[jaikiran]

10:13:00,788 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinESB.war in deployment directory. To trigger deployment create a file called MichelinESB.war.dodeploy

10:13:00,789 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinAdmin.war in deployment directory. To trigger deployment create a file called MichelinAdmin.war.dodeploy

10:13:00,789 INFO  [org.jboss.as.server.deployment.scanner] (DeploymentScanner-threads - 1) JBAS015003: Found MichelinServices.war in deployment directory. To trigger deployment create a file called MichelinServices.war.dodeploy

I see that after this, around 6 seconds later the deployment started for 2 of those web apps. Did you or some tool add that .dodeploy markers for those 2 apps? Was it also added for the MichelinServices.war? Can you paste the output of the directory listing of that deployments folder?

[sbityakov]

We only add the .dodeploy files when a new version of the app is being deployed.  Otherwise JBoss brings up the versions of the apps already deployed.  So in this case, after a restart JBoss normally would bring up the versions of the three apps that had been deployed previously.  In this case only two were brought up.

Here is the listing of the directory structure as it exists today:

$ ls -alt /data/jboss/jboss-eap-6.1/standalone/deployments/

total 52

drwxr-xr-x 5 jboss jboss 4096 Dec  1 17:30 .

-rw-rw-r-- 1 jboss jboss   17 Dec  1 10:10 MichelinAdmin.war.deployed

drwxrwxr-x 5 jboss jboss 4096 Dec  1 10:10 MichelinAdmin.war

-rw-rw-r-- 1 jboss jboss   15 Nov 17 10:05 MichelinESB.war.deployed

drwxrwxr-x 4 jboss jboss 4096 Nov 17 10:04 MichelinESB.war

-rw-rw-r-- 1 jboss jboss   20 Nov  3 11:24 MichelinServices.war.deployed

drwxrwxr-x 5 jboss jboss 4096 Nov  3 11:24 MichelinServices.war

drwxr-xr-x 7 jboss jboss 4096 Mar 12  2015 ..

-rw-r--r-x 1 jboss jboss 8870 Aug 20  2013 README.txt

Thanks!

[jaikiran]

Dan Sbityakov wrote:

Here is the listing of the directory structure as it exists today:

$ ls -alt /data/jboss/jboss-eap-6.1/standalone/deployments/

total 52

drwxr-xr-x 5 jboss jboss 4096 Dec 1 17:30 .

-rw-rw-r-- 1 jboss jboss 17 Dec 1 10:10 MichelinAdmin.war.deployed

drwxrwxr-x 5 jboss jboss 4096 Dec 1 10:10 MichelinAdmin.war

-rw-rw-r-- 1 jboss jboss 15 Nov 17 10:05 MichelinESB.war.deployed

drwxrwxr-x 4 jboss jboss 4096 Nov 17 10:04 MichelinESB.war

-rw-rw-r-- 1 jboss jboss 20 Nov 3 11:24 MichelinServices.war.deployed

drwxrwxr-x 5 jboss jboss 4096 Nov 3 11:24 MichelinServices.war

drwxr-xr-x 7 jboss jboss 4096 Mar 12 2015 ..

-rw-r--r-x 1 jboss jboss 8870 Aug 20 2013 README.txt

Thanks!

So looking at those timestamps on the marker files, I'm guessing that here's what happened - during the undeployment/shutdown process, for some reason the MichelinServices undeployment ran into some issue and did _not_ create a undeployed marker (or rather, it left around the .deployed marker). The next time the server was started, it noticed that the .deployed marker is present and considered this app to be already deployed and skipped it. Of course, I'm guessing that the file system deployment scanner behaves the way I think it does, I don't know if it has been improved to take into account these stale .deployed markers.

Either way, I suspect there's a bug in here. ehugonnet usually knows more about this area and might be able to help.

[ehugonnet]

What is your scanner configuration ?

Are all the war the 'same' : do you have archive and exploded wars or only exploded ?

[sbityakov]

All three wars deploy in exploded fashion.

This is all I could find in standalone-full.xml about the scanner config:

        <subsystem xmlns="urn:jboss:domain:deployment-scanner:1.1">

            <deployment-scanner path="deployments" relative-to="jboss.server.base.dir" scan-interval="5000"/>

        </subsystem>

Are there other places where configuration may reside?  What changes would you suggest?

Thanks very much!

[ehugonnet]

I "agree" with jaikiran in that this file is probably a leftover.

We have done much work in WildFly and EAP 7 to try to make the scanner more reliable and even support exploded deployments as managed content (cf. WFCORE-429).