3 Replies Latest reply on Feb 8, 2007 12:31 PM by starksm64

Bad deployment cleanup issues?

starksm64 Feb 8, 2007 11:28 AM

There are some tests that excercise bad war deployment that are failing inconsistently. Two are:

http://jira.jboss.com/jira/browse/JBAS-4085
http://jira.jboss.com/jira/browse/JBAS-4031

In the example I looked at, jbossweb is claiming a given webapp is not available even though the server log indicates otherwise:

The test.log shows that jbossweb claims that no such webapp exists:

2007-02-08 08:12:06,843 DEBUG [org.jboss.test.util.web.HttpUtils] RequestURI: http://localhost:8080/redeploy/index.html
2007-02-08 08:12:06,843 DEBUG [org.apache.commons.httpclient.HttpConnection] Open connection to localhost:8080
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] >> "GET /redeploy/index.html HTTP/1.1[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [org.apache.commons.httpclient.HttpMethodBase] Adding Host request header
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] >> "User-Agent: Jakarta Commons-HttpClient/3.0[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] >> "Host: localhost:8080[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] >> "[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "HTTP/1.1 503 This application is not currently available[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "Server: Apache-Coyote/1.1[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "Content-Type: text/html[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "Transfer-Encoding: chunked[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "Date: Thu, 08 Feb 2007 16:12:06 GMT[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [httpclient.wire.header] << "Connection: close[\r][\n]"
2007-02-08 08:12:06,843 DEBUG [org.apache.commons.httpclient.HttpConnection] Input data available
2007-02-08 08:12:06,843 DEBUG [org.jboss.test.util.web.HttpUtils] responseCode=503, response=This application is not currently available


Even though the server.log indicates it was started:
2007-02-08 08:12:06,750 DEBUG [org.jboss.system.ServiceController] starting service jboss.web.deployment:war=good-web.war,id=627826940
2007-02-08 08:12:06,750 DEBUG [org.jboss.web.WebModule] Starting jboss.web.deployment:war=good-web.war,id=627826940
2007-02-08 08:12:06,750 DEBUG [org.jboss.web.tomcat.service.TomcatDeployer] webContext: /redeploy
...
2007-02-08 08:12:06,828 DEBUG [org.jboss.web.tomcat.service.TomcatDeployer] Initialized: {WebApplication: /C:/svn/JBossAS/Branch_4_2/build/output/jboss-4.2.0.CR1/server/jacc/tmp/deploy/tmp44326jbosstest-good.ear-contents/good-web-exp.war/, URL: file:/C:/svn/JBossAS/Branch_4_2/build/output/jboss-4.2.0.CR1/server/jacc/tmp/deploy/tmp44326jbosstest-good.ear-contents/good-web-exp.war/, classLoader: java.net.FactoryURLClassLoader@248f34:2395956} jboss.web:j2eeType=WebModule,name=//localhost/redeploy,J2EEApplication=none,J2EEServer=none
2007-02-08 08:12:06,828 DEBUG [org.jboss.web.WebModule] Started jboss.web.deployment:war=good-web.war,id=627826940
2007-02-08 08:12:06,828 DEBUG [org.jboss.system.ServiceController] Starting dependent components for: jboss.web.deployment:war=good-web.war,id=627826940 dependent components: []
2007-02-08 08:12:06,843 DEBUG [org.jboss.deployment.MainDeployer] End deployment start on package: good-web.war

There is no NPE in the log as Brian saw in another issue. I have had the failing test switch from testBadWarRedeploy to testBadEarRedeploy to no failure.

1. Re: Bad deployment cleanup issues?

starksm64 Feb 8, 2007 11:32 AM (in response to starksm64)

Brian thinks this is due to http://jira.jboss.com/jira/browse/JBAS-4060.

Looking earlier in the log I do see another war undeployment resulting in an NPE:

2007-02-08 08:09:33,828 DEBUG [org.jboss.web.WebModule] Destroyed jboss.web.deployment:war=manifest-web.war,id=995861669
2007-02-08 08:09:33,843 ERROR [org.apache.coyote.http11.Http11Processor] Error processing request
java.lang.NullPointerException
 at org.apache.catalina.session.StandardSession.endAccess(StandardSession.java:638)
 at org.apache.catalina.connector.Request.recycle(Request.java:419)
 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:239)
 at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
 at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:624)
 at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:445)
 at java.lang.Thread.run(Thread.java:595)

I'm not clear on how this affects subsequent deployments that claim they were successfully deployed.

2. Re: Bad deployment cleanup issues?

brian.stansberry Feb 8, 2007 11:47 AM (in response to starksm64)

I'm speculating that the NPE from within Request.recycle() leaves the Request object in an inconsistent state. There are a number of cleanup operations that happen after the point where the NPE is thrown. Next request that uses the same processor has a problem.
Actions
3. Re: Bad deployment cleanup issues?

starksm64 Feb 8, 2007 12:31 PM (in response to starksm64)

Ok. If that is the case we need better error reporting on why a 503 is being generated as it would seem that some assertion that should apply to a successful deployment is not satisfied.
Actions

Go to original post