[
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 [76...@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.sedaqueu...@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.
