servicemix-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ryan Moquin (JIRA)" <j...@apache.org>
Subject [jira] Commented: (SM-1931) Threading problem in Servicemix-HTTP which renders the component unusable.
Date Thu, 04 Feb 2010 20:59:34 GMT

    [ https://issues.apache.org/activemq/browse/SM-1931?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=57389#action_57389
] 

Ryan Moquin commented on SM-1931:
---------------------------------

I just noticed while debugging my timeout issues with the servicemix-http component, that
when I build the 2009.02 servicemix-http component, there are a bunch of InvalidStatusResponseExceptions
that are thrown during the testHttpInOutUnderLoad test in org.apache.servicemix.http.ConsumerEndpointTest.
 When I look at the log4j log in the target directory, I notice that that same test is ALSO
generating timeout exceptions due to other issues that occur during the test (here is a snippet):

2010-02-04 15:44:07,601 [a.echo-thread-8] DEBUG SedaFlow                       - Called Flow
send
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"<?xml version='1.0' encoding='UTF-8'?><error><![CDATA[java.lang.IllegalStateException:
Exchange not found[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.apache.servicemix.http.endpoints.HttpConsumerEndpoint.process(HttpConsumerEndpoint.java:365)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.apache.servicemix.http.HttpBridgeServlet.service(HttpBridgeServlet.java:56)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at javax.servlet.http.HttpServlet.service(HttpServlet.java:806)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:363)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.Server.handle(Server.java:320)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.HttpConnection.hand"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"le(HttpConnection.java:397)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-515     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:363)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-508     ] DEBUG content                        - <<
"[0x9]at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.nio.SelectChannelConnector$RetryContinuation.run(SelectChannelConnector.java:525)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[0x9]at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:522)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"]]></error>"
2010-02-04 15:44:07,601 [p133-12 - /ep1/] DEBUG jetty                          - RESPONSE
/ep1/  500
2010-02-04 15:44:07,601 [Thread-518     ] DEBUG header                         - <<
"HTTP/1.1 500 Internal Server Error[\r][\n]"
2010-02-04 15:44:07,601 [Thread-503     ] DEBUG content                        - <<
"[\n]"
2010-02-04 15:44:07,601 [Thread-503     ] DEBUG content                        - <<
"0"
2010-02-04 15:44:07,601 [Thread-503     ] DEBUG content                        - <<
"[\r]"
2010-02-04 15:44:07,601 [Thread-503     ] DEBUG content                        - <<
"[\n]"
2010-02-04 15:44:07,601 [76322@qtp133-12] DEBUG jetty                          - continuation
still pending null
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[\r]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[\n]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"0"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[\r]"
2010-02-04 15:44:07,601 [Thread-512     ] DEBUG content                        - <<
"[\n]"
2010-02-04 15:44:07,601 [Thread-508     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.nio.SelectChannelConnector$RetryContinuation.run(SelectChannelConnector.java:525)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-515     ] DEBUG content                        - <<
"[0x9]at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:766)[\r][\n]"
2010-02-04 15:44:07,601 [Thread-507     ] DEBUG content                        - <<
"[0x9]at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)[\r][\n]"
2010-02-04 15:44:07,601 [.echo-thread-15] DEBUG SedaQueue                      - org.apache.servicemix.jbi.nmr.flow.seda.SedaQueue$1@187b08d
dequeued exchange: InOut[
  id: ID:10.40.16.105-1269ab95e1e-386:120
  status: Error
  role: provider
  service: {urn:test}echo
  endpoint: endpoint
  in: class javax.xml.transform.stream.StreamSource
  out: class javax.xml.transform.stream.StreamSource
  error: java.lang.Exception: HTTP request has timed out for exchange: ID:10.40.16.105-1269ab95e1e-386:120
]

Is this expected?  The test just collects a list of these errors and prints them out in the
end, but passes anyhow.  This is the output I see on the console when I run the tests....
 It seems to me that the unit test is might actually already reproducing my issue and the
tests are just ignoring it:

[Fatal Error] :1:22: The markup in the document following the root element must be well-formed.
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
org.apache.servicemix.components.http.InvalidStatusResponseException: Invalid status response
code: 500
        at org.apache.servicemix.http.ConsumerEndpointTest$6.run(ConsumerEndpointTest.java:658)
Retrieving document at 'http://localhost:8193/ep1/?wsdl'.
Retrieving document at 'porttypedef.wsdl', relative to 'http://localhost:8193/ep1/?wsdl'.
Tests run: 13, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.015 sec
Running org.apache.servicemix.http.HttpConfigurationTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.016 sec
Running org.apache.servicemix.http.jetty.JaasUserRealmTest
Tests run: 7, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0 sec

Results :

Tests run: 111, Failures: 0, Errors: 0, Skipped: 0


> Threading problem in Servicemix-HTTP which renders the component unusable.
> --------------------------------------------------------------------------
>
>                 Key: SM-1931
>                 URL: https://issues.apache.org/activemq/browse/SM-1931
>             Project: ServiceMix
>          Issue Type: Bug
>          Components: servicemix-http
>    Affects Versions: 3.3.1
>         Environment: Windows XP, servicemix-http component 2009.02
>            Reporter: Ryan Moquin
>            Priority: Blocker
>
> In most of the servicemix-http component versions, including the latest, there is a variable
called isSTFlow which is a class variable.  This variable appears to be shared among all threads
that access a deployed servicemix-http component.  The problem with this is that isSTFlow
is set by a certain request based upon the state of it's continuation when the exchange response
is processed here:
> if (!cont.isPending()) {
>             isSTFlow = true;
>             System.out.println("isSTFlow set to true because continuation isn't pending.");
>         } else {
>             isSTFlow = false;
>             System.out.println("isSTFlow set to false because continuation is pending.");
> If isSTFlow is set to true during that response.. all future requests that come in will
then end up executing this code block on line 348:
> } else {
>                         String id = (String)request.getAttribute(MessageExchange.class.getName());
>                         System.out.println("STFlow was true, removing exchange with id:
" + id);
>                         locks.remove(id);
>                         exchange = exchanges.remove(id);
>                         request.removeAttribute(MessageExchange.class.getName());
>                     }
> before the exchange associated with the request has had a chance to return.  Once that
exchange has returned, it can't be found, because it was removed and throws a timeout error.
 Once isSTFlow becomes true, the component hits a race condition where it checks isSTFlow
for true before the async call has a chance to return and immediately times out the exchange.
 This variable needs to be localized for each specific request, not global to all requests.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message