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

    Bad deployment cleanup issues?

    Scott Stark Master

      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?
          Scott Stark Master

          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 Master

            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.

            • 3. Re: Bad deployment cleanup issues?
              Scott Stark Master

              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.