[
https://issues.apache.org/jira/browse/CAMEL-14138?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17259389#comment-17259389
]
Jeremy Ross commented on CAMEL-14138:
-------------------------------------
I've dug into this a little more, but I don't have the camel-core chops to know
how to fix. Here's what I think is happening:
* AbstractClientBase#doHttpRequest calls salesforce, passing a Listener
instance to the HttpClient.
* Jetty client calls the Listener's
[onComplete|https://github.com/apache/camel/blob/f735261d75a296b1ed6baf5b947e9d2710fda368/components/camel-salesforce/camel-salesforce-component/src/main/java/org/apache/camel/component/salesforce/internal/client/AbstractClientBase.java#L193].
A key point here is that onComplete gets blocked
[here|https://github.com/apache/camel/blob/f735261d75a296b1ed6baf5b947e9d2710fda368/components/camel-salesforce/camel-salesforce-component/src/main/java/org/apache/camel/component/salesforce/internal/client/AbstractClientBase.java#L248]
and never returns (#1 in screen shot).
* Camel continues to the second (synchronous) query. I've confirmed via
debugging proxy that this query returns successfully, however HttpClient uses a
*single* thread [for all
listeners|https://www.eclipse.org/jetty/documentation/jetty-9/index.html#http-client]:
{quote}The implementation invokes these listeners in the same thread that is
used to process the request or response. Therefore,* if the application code in
these listeners takes a long time to execute, the request or response
processing is delayed until the listener returns*.
{quote}
* Because the first call Listener#onComplete is blocked, HttpClient never
calls the second query's Listener, and things get stuck at #2 in screen shot.
* Then IdleTimeout exception happens.
*
[Invoking|https://github.com/apache/camel/blob/f735261d75a296b1ed6baf5b947e9d2710fda368/components/camel-salesforce/camel-salesforce-component/src/main/java/org/apache/camel/component/salesforce/internal/client/AbstractClientBase.java#L248]
the Camel callback in a new thread "solves" the problem, however this probably
is not playing nice with the camel threading/reactive system:
{code:java}
new Thread() {
@Override
public void run() {
callback.onResponse(getContentAsInputStream(), headers, null);
}
}.start();
{code}
Paging [~zregvart] and [~davsclaus] for help.
!Call stack.png!
> Salesforce: a synchronous call that follow an asynchronous call will always
> result in a TimeoutException
> --------------------------------------------------------------------------------------------------------
>
> Key: CAMEL-14138
> URL: https://issues.apache.org/jira/browse/CAMEL-14138
> Project: Camel
> Issue Type: Bug
> Components: camel-salesforce
> Affects Versions: 3.0.0.RC3
> Reporter: Jeremy Ross
> Priority: Major
> Fix For: 3.x
>
> Attachments: Call stack.png, thread-dump.txt
>
>
> Using the {{synchronous}} URL option, a synchronous operation following an
> asynchronous operation will result in a
> {{java.util.concurrent.TimeoutException}}. Subsequent synchronous operations
> will succeed. Despite the {{TimeoutException}}, the operation can still be
> successful on the salesforce side. I've yet to determine why Camel thinks the
> operation is timing out.
> Repro:
> {code:java}
> from("direct:synchronousTest")
> .setBody(() -> {
> Contact c = new Contact();
> c.setLastName("Test");
> return c;
> })
> .to("salesforce:createSObject?synchronous=false") // no issues
> .setBody(() -> {
> Contact c = new Contact();
> c.setLastName("Test");
> return c;
> })
> .to("salesforce:createSObject?synchronous=true"); // TimeoutException
> {code}
> stack trace:
> {noformat}
> org.apache.camel.component.salesforce.api.SalesforceException: Unexpected
> error {0:null} executing
> {POST:https://cs44.salesforce.com/services/data/v45.0/sobjects/Contact}
> at
> org.apache.camel.component.salesforce.internal.client.AbstractClientBase$1.onComplete(AbstractClientBase.java:206)
> ~[camel-salesforce-3.0.0-SNAPSHOT.jar:3.0.0-SNAPSHOT]
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:196)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:188)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:441)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at org.eclipse.jetty.client.HttpReceiver.abort(HttpReceiver.java:523)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.HttpChannel.abortResponse(HttpChannel.java:156)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at org.eclipse.jetty.client.HttpChannel.abort(HttpChannel.java:149)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:257)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:766)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.abort(HttpConnectionOverHTTP.java:204)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.close(HttpConnectionOverHTTP.java:190)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onIdleExpired(HttpConnectionOverHTTP.java:145)
> ~[jetty-client-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.io.ssl.SslConnection.onIdleExpired(SslConnection.java:302)
> ~[jetty-io-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.io.AbstractEndPoint.onIdleExpired(AbstractEndPoint.java:401)
> ~[jetty-io-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:171)
> ~[jetty-io-9.4.19.v20190610.jar:9.4.19.v20190610]
> at org.eclipse.jetty.io.IdleTimeout.idleCheck(IdleTimeout.java:113)
> ~[jetty-io-9.4.19.v20190610.jar:9.4.19.v20190610]
> at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> ~[na:na]
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> ~[na:na]
> at
> java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
> ~[na:na]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
> ~[na:na]
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
> ~[na:na]
> at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]
> Caused by: java.util.concurrent.TimeoutException: Idle timeout 10000 ms
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
