Effective October 27, 2012, online and email support for FuseSource products will move to Red Hat support channels. For more information, please see the JIRA Migration to Red Hat FAQ.
As of October 27th, please open all new issues in the Red Hat Customer Portal .
Issue Details (XML | Word | Printable)

Key: ESB-1397
Type: Bug Bug
Status: Resolved Resolved
Resolution: Fixed
Priority: Major Major
Assignee: Gert Vanthienen
Reporter: Joe Luo
Votes: 0
Watchers: 2
Operations

If you were logged in you would be able to see more operations.
FUSE ESB

HTTP Consumer timeout handling is incorrect

Created: 24/Feb/11 06:41 PM   Updated: 02/Mar/12 09:00 PM
Component/s: None
Affects Version/s: None
Fix Version/s: 3.3.1.26-fuse, 3.4.0.6-fuse, 3.5.0-fuse-01-00, 3.6.0-fuse-00-35, 4.2.0-fuse-xx-00, 4.3.0-fuse-xx-00, 4.3.1-fuse-02-xx, 4.4.0-fuse-xx-00

File Attachments: 1. Text File components-pom-2010.02.0-fuse-00-00.second.patch (21 kB)
2. Text File servicemix-http-3.3.1.patch (19 kB)


 Description  « Hide
I'm still getting: 
2011-02-09 04:44:15,353 [pool-flow.seda.servicemix-eip-thread-247] ERROR org.apache.servicemix.http.HttpComponent - 
Error processing exchange InOut[id: ID:10.209.8.87-12e099f306b-6:82790
status: Active
role: consumer
service: {https://webservices.mycompany.com/websvc}ConsumerStaticRoutingSlipService
endpoint: sws
in: (...)
out: <?xml version="1.0" encoding="UTF-8"?><soap-env:Envelope xmlns:soap-env="http://schemas.xmlsoap.org/soap/envelope/">...
]
java.lang.Exception: HTTP request has timed out for exchange: ID:10.209.8.87-12e099f306b-6:82790
at org.apache.servicemix.http.endpoints.HttpConsumerEndpoint.process(HttpConsumerEndpoint.java:251)
at org.apache.servicemix.common.AsyncBaseLifeCycle.doProcess(AsyncBaseLifeCycle.java:617)
at org.apache.servicemix.common.AsyncBaseLifeCycle.processExchange(AsyncBaseLifeCycle.java:588)
at org.apache.servicemix.common.AsyncBaseLifeCycle.onMessageExchange(AsyncBaseLifeCycle.java:525)
at org.apache.servicemix.common.SyncLifeCycleWrapper.onMessageExchange(SyncLifeCycleWrapper.java:60)
at org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.processInBound(DeliveryChannelImpl.java:632)
at org.apache.servicemix.jbi.nmr.flow.AbstractFlow.doRouting(AbstractFlow.java:185)
at org.apache.servicemix.jbi.nmr.flow.seda.SedaFlow.doRouting(SedaFlow.java:168)
at org.apache.servicemix.jbi.nmr.flow.seda.SedaQueue$1.run(SedaQueue.java:134)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-02-09 04:44:15,354 [pool-flow.seda.servicemix-eip-thread-247] ERROR org.apache.servicemix.http.HttpComponent - 
Error setting exchange status to ERROR 7-12e099f306b-6:82790
at org.apache.servicemix.jbi.messaging.MessageExchangeImpl.setError(MessageExchangeImpl.java:264)
at org.apache.servicemix.common.AsyncBaseLifeCycle.onMessageExchange(AsyncBaseLifeCycle.java:540)
at org.apache.servicemix.common.SyncLifeCycleWrapper.onMessageExchange(SyncLifeCycleWrapper.java:60)
at org.apache.servicemix.jbi.messaging.DeliveryChannelImpl.processInBound(DeliveryChannelImpl.java:632)
at org.apache.servicemix.jbi.nmr.flow.AbstractFlow.doRouting(AbstractFlow.java:185)
at org.apache.servicemix.jbi.nmr.flow.seda.SedaFlow.doRouting(SedaFlow.java:168)
at org.apache.servicemix.jbi.nmr.flow.seda.SedaQueue$1.run(SedaQueue.java:134)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.Exception: HTTP request has timed out for exchange: ID:10.209.8.87-12e099f306b-6:82790
at org.apache.servicemix.http.endpoints.HttpConsumerEndpoint.process(HttpConsumerEndpoint.java:251)
at org.apache.servicemix.common.AsyncBaseLifeCycle.doProcess(AsyncBaseLifeCycle.java:617)
at org.apache.servicemix.common.AsyncBaseLifeCycle.processExchange(AsyncBaseLifeCycle.java:588)
at org.apache.servicemix.common.AsyncBaseLifeCycle.onMessageExchange(AsyncBaseLifeCycle.java:525)
... 8 more

There are several issues relating to HTTP consumer timeout handling.

In a nutshell:

  • there was no synchronization where continuation were already resumed() and process(request,respone) was invoked for the second time.
  • there exceptions thrown in process(exchange) method are misleading.
  • They really mean that we has received a late response from the JBI bus, but the response with a timeout has been already sent to the client.
  • The test ConsumerEndpointTest.xtestHttpInOutUnderLoad can be uncommented now, because it passes all the time now.

Attached is a patch based on servicemix-http-2010.02.0-fuse-00-00.

 All   Comments   Change History      Sort Order: Ascending order - Click to sort in descending order
[ Permlink | « Hide ]
Claudio Corsi added a comment - 05/May/11 06:38 AM
This patch contains the fix that can be applied to the 3.3.1 stream.

[ Permlink | « Hide ]
Gert Vanthienen added a comment - 03/Jun/11 03:27 PM
The patch can basically be translated into two distinct issues to be fixed:

[ Permlink | « Hide ]
Gert Vanthienen added a comment - 07/Jun/11 01:15 PM
Both issues have been resolved at Apache by now - the fixes still need to get merged into the right branches at FuseSource.

However, in the meanwhile, would it be possible to get back in touch with the customer and check if these two fixes are meeting their requirements. In particular, the proposed fix had a pluggable LateResponseListener but since the main goal there was to avoid throwing exceptions or failing exchanges for timed out HTTP requests and there's really not that much you can do inside the ESB once the request has timed out, I left the extra listener interface out and allowed for configuring the behaviour through a simple 'lateResponseStrategy' flag (cfr. https://issues.apache.org/jira/browse/SMXCOMP-881) instead.


[ Permlink | « Hide ]
Gert Vanthienen added a comment - 08/Jun/11 09:09 PM
Joe,

For SMXCOMP-880, I do agree with Mateusz that the original implementation was broken, but I think the refactoring addresses the original issue as well. For the logging remarks, I'll modify those statements to reuse the existing exchange id variable. With the upgrade to SLF4J a while ago however, we removed the extraneous if (logger.isDebugEnabled()) for all the cases where we can pass the message and a single parameter. Those if-clauses will be there again when this patch gets backported to branches that are using LOG4J though.

For SMXCOMP-881, I can see how the exceptions used for a late response can be altered to better reflect what's going on instead of using "HTTP request has timed out..." all over the place, so I'll make that change. I left out the explicit LateResponseListener but allowed for configuring both the behavior in the proposed patch (WARN en end with status DONE) as well as the original behaviour of the component (end the exchange with ERROR). I couldn't really imagine any other way to terminate the MessageExchange, but I could obviously add a callback somewhere for them to implement something else if they have a use case for that?

Regards,

Gert


[ Permlink | « Hide ]
Gert Vanthienen added a comment - 11/Jun/11 02:14 PM
FIxed the remaining remarks by Mateusz in http://svn.apache.org/viewvc?view=revision&revision=1134568

Backported this fix into the 2011.02-fuse and 2011.01-fuse branches
Powered by Atlassian JIRA the Professional Issue Tracker. (Enterprise Edition, Version: 3.13.2-#335) - Bug/feature request - Atlassian news - Contact Administrators