Hi Frank,

Interesting problem... and a very thorough report! :-)

Normally this should not happen as internally Cactus reads the whole
servlet response *before* calling again the server side to get the test
result. This, in order to prevent such a race condition ... 

There is one limitation in the current Cactus version: only one test can
be run at a time. You're not running concurrent tests, are you?

The problem with these kinds of errors is that it is difficult to
reproduce. 

I have written a new test case (see attached file) that I have tried
running from 100 times to 500 times and it never failed. I am on Windows
XP with Tomcat 4.1.12.

As you can see from the test case, there are several kind of tests,
including some prohibited creation of threads...

Can you try to run it on your side and tell me if you get some errors?

Thanks
-Vincent

> -----Original Message-----
> From: Frank Baxter [mailto:frank@;baxres.org]
> Sent: 21 October 2002 20:16
> To: [EMAIL PROTECTED]
> Subject: Apparent race condition in Cactus?
> 
> I'm using Cactus and I'm running into a strange problem.  About half
the
> time, my tests fail, and it appears to be caused by GET_RESULT being
> invoked before the results are saved to the context.
> 
>  From the server log:
> 
>     ...
>     02:39:27,096 [HttpProcessor[8080][3]] DEBUG
>     ache.cactus.ServiceEnumeration  - <equals([GET_RESULTS])
>     02:39:27,096 [HttpProcessor[8080][3]] DEBUG
>     ache.cactus.ServiceEnumeration  - >equals = [true]02:39:27,096
>     [HttpProcessor[8080][3]] DEBUG s.server.AbstractWebTestCaller  -
>     Test Result = [null]
>     02:39:27,130 [HttpProcessor[8080][4]] DEBUG
>     s.server.AbstractWebTestCaller  - Test result : [Test ok]
>     02:39:27,131 [HttpProcessor[8080][4]] DEBUG
>     s.server.AbstractWebTestCaller  - Result saved in context scope
>     ...
> 
> 
>  From the client log:
> 
>     ...
>     02:39:27,091 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.write(byte[])
>     02:39:27,091 [main] INFO  httpclient.wire                 - >>
"GET
>     /test/ServletRedirector?Cactus_Service=GET_RESULTS HTTP/1.1
>     "
>     02:39:27,091 [main] DEBUG httpclient.HttpMethod           -
>     HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection)
>     02:39:27,091 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.write(byte[])
>     02:39:27,091 [main] INFO  httpclient.wire                 - >>
>     "Host: localhost
>     "
>     02:39:27,092 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.write(byte[])
>     02:39:27,092 [main] INFO  httpclient.wire                 - >>
>     "User-Agent: Jakarta HTTP Client/2.0.0a1
>     "
>     02:39:27,092 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.write(byte[])
>     02:39:27,092 [main] INFO  httpclient.wire                 - >>
>     "Content-type: application/x-www-form-urlencoded
>     "
>     02:39:27,092 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.writeLine()
>     02:39:27,092 [main] INFO  httpclient.wire                 - >>
\r\n
>     02:39:27,108 [main] DEBUG httpclient.HttpMethod           -
>     HttpMethodBase.readResponse(HttpState,HttpConnection)
>     02:39:27,108 [main] DEBUG httpclient.HttpMethod           -
>     HttpMethodBase.readStatusLine(HttpState,HttpConnection)
>     02:39:27,108 [main] DEBUG httpclient.HttpConnection       -
>     HttpConnection.readLine()
>     02:39:27,109 [main] INFO  httpclient.wire                 - <<
>     "HTTP/1.1 500 Internal Server Error" [\r\n]
> 
>     ...
> 
>     02:39:27,115 [main] INFO  httpclient.wire                 - <<
>     "<html><head><title>Apache Tomcat/4.1.12 - Error
>     report</title><STYLE><!--H1{font-family :
>     sans-serif,Arial,Tahoma;color : white;background-color : #0086b2;}
>     H3{font-family : sans-serif,Arial,Tahoma;color :
>     white;background-color : #0086b2;} BODY{font-family :
>     sans-serif,Arial,Tahoma;color : black;background-color : white;}
>     B{color : white;background-color : #0086b2;} HR{color : #0086b2;}
>     --></STYLE> </head><body><h1>HTTP Status 500 - Internal Server
>     Error</h1><HR size="1" noshade><p><b>type</b> Exception
>     report</p><p><b>message</b> <u>Internal Server
>     Error</u></p><p><b>description</b> <u>The server encountered an
>     internal error (Internal Server Error) that prevented it from
>     fulfilling this request.</u></p><p><b>exception</b>
>     <pre>java.lang.NullPointerException
>             at
> 
>
org.apache.cactus.server.AbstractWebTestCaller.doGetResults(AbstractWebT
es
> tCaller.java:196)
>             at
> 
>
org.apache.cactus.server.AbstractWebTestController.dispatch87_handleRequ
es
>
t(AbstractWebTestController.java;org/apache/cactus/util/log/LogAspect.aj
(1
> k):131)
> 
>     ...
> 
> It appears that one server thread is trying to get the results (thread
> 3) before the other (thread 4) has posted them.  The times that the
> tests work, I notice from the logs that the client sent the
GET_RESULTS
> request a few ms after the results were already posted:
> 
>  From the server.log:
> 
>     03:08:13,388 [HttpProcessor[8080][4]] DEBUG
>     s.server.AbstractWebTestCaller  - Test result : [Test ok]
>     03:08:13,388 [HttpProcessor[8080][4]] DEBUG
>     s.server.AbstractWebTestCaller  - Result saved in context scope
> 
>  From the client.log:
> 
>     03:08:13,424 [main] INFO  httpclient.wire                 - >>
"GET
>     /test/ServletRedirector?Cactus_Service=GET_RESULTS HTTP/1.1
>     "
>     03:08:13,425 [main] DEBUG httpclient.HttpMethod           -
>     HttpMethodBase.writeRequestHeaders
> 
> 
> I'm not doing anything too different than the examples.  The only real
> difference is that my Servlet inherits from a class in the Barracuda
> framework, so I pass the request/response into a different method:
> 
>   public void testDailySchedule()
>   {
>     try
>     {
>       OCSGateway servlet = new OCSGateway();
> 
>       servlet.init(config);
>       servlet.handleDefault(request, response);
> 
>       theLog.debug("CHECKING SESSION!!!!");
>       assertNotNull(session);
>       theLog.debug("Mode: " + session.getAttribute(OCS.MODE));
>       theLog.debug("Date: " + session.getAttribute(OCS.DATE));
>       theLog.debug("Schd: " + session.getAttribute(OCS.SCHEDULE));
> 
>       theLog.debug("DONE WITH TEST!!!!");
>     }
>     catch (Exception e)
>     {
>       theLog.error("Unable to complete request:", e);
>       fail(e.getMessage());
>     }
>   }
> 
> I also tried "servlet.service(request, response)", but the results
were
> the same.
> 
> BTW, when I turn on full debug, it works more often.  It took a
looping
> script 49 tries to finally get it to fail so I could include the full
> debug at the top of the message.
> 
> I'm running the tests from Ant using Tomcat 4.1.12 with Cactus
> 1.3-1.4.1.  Any ideas would be greatly appreciated!
> 
> Thank you,
> 
> Frank

Attachment: TestServletTestCaseRepeat.java
Description: Binary data

--
To unsubscribe, e-mail:   <mailto:cactus-user-unsubscribe@;jakarta.apache.org>
For additional commands, e-mail: <mailto:cactus-user-help@;jakarta.apache.org>

Reply via email to