[
https://issues.apache.org/jira/browse/CAMEL-12812?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Andrey Tyurin updated CAMEL-12812:
----------------------------------
Affects Version/s: 2.21.2
> Salesforce component tries to reconnect when unsubscribing from topic in case
> of "403::Handshake denied" error
> --------------------------------------------------------------------------------------------------------------
>
> Key: CAMEL-12812
> URL: https://issues.apache.org/jira/browse/CAMEL-12812
> Project: Camel
> Issue Type: Bug
> Components: camel-salesforce
> Affects Versions: 2.21.2, 2.22.1
> Reporter: Andrey Tyurin
> Priority: Major
>
> Hi.
> We've faced some strange behavior when salesforce component is shutting down.
> When SF component is unsubscribing from channel and it gets some error, e.g.
> "403::Handshake denied" it tries then reconnect to SF. But why? if it is
> shutting down.
> This causes long process of logout from SF: about 4 minutes.
> We do not have specific scenario, but only exceptions for this case.
>
> 2018-08-31 05:40:51.454 [SalesforceHttpClient@b9f06a7-293] INFO
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Restarting on unexpected disconnect from Salesforce... 2018-08-31
> 05:40:51.454 [SalesforceHttpClient@b9f06a7-293] DEBUG
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Waiting to disconnect... 2018-08-31 05:40:51.455
> [SalesforceHttpClient@b9f06a7-288] DEBUG
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> [CHANNEL:META_CONNECT]: \{clientId=kteskpq4fgf192z1zpdm0ml1ebe,
> advice={reconnect=none, interval=0}, channel=/meta/connect, id=29,
> error=401::Authentication invalid, successful=false} 2018-08-31 05:40:51.455
> [SalesforceHttpClient@b9f06a7-288] WARN
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Connect failure: \{clientId=kteskpq4fgf192z1zpdm0ml1ebe,
> advice={reconnect=none, interval=0}, channel=/meta/connect, id=29,
> error=401::Authentication invalid, successful=false} 2018-08-31 05:40:56.516
> [SalesforceHttpClient@b9f06a7-292] INFO
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Cleaning session (logout) from SalesforceSession before restarting client
> 2018-08-31 05:41:39.156 [Camel (camel-1) thread #105 - ShutdownTask] INFO
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Unsubscribing from channel /topic/myCompanyExtRoutPsr... ... 2018-08-31
> 05:42:19.156 [Camel (camel-1) thread #105 - ShutdownTask] WARN
> org.apache.camel.impl.DefaultShutdownStrategy - Error occurred while shutting
> down route:
> Consumer[salesforce-102-STREAMING://myCompanyExtRoutPsr?sObjectClass=com.myCompany.sfgateway.api.dto.PendingServiceRouting&sObjectQuery=SELECT+Id%2C+QueueId%2C+WorkItemId%2C+IsPushed%2C+ServiceChannelId%2C+LastDeclinedAgentSession%2C+CreatedDate%2C+IsDeleted%2C+IsPushAttempted%2C+IsTransfer+from+PendingServiceRouting+WHERE+RoutingModel+%3D+%27ExternalRouting%27&synchronous=true].
> This exception will be ignored. org.apache.camel.CamelException: Timeout
> error unsubscribing from topic myCompanyExtRoutPsr after 40 seconds at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.unsubscribe(SubscriptionHelper.java:519)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.component.salesforce.SalesforceConsumer.doStop(SalesforceConsumer.java:139)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.support.ServiceSupport.stop(ServiceSupport.java:102)
> ~[camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.util.ServiceHelper.stopService(ServiceHelper.java:142)
> ~[camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.impl.DefaultShutdownStrategy.shutdownNow(DefaultShutdownStrategy.java:381)
> [camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.impl.DefaultShutdownStrategy$ShutdownTask.run(DefaultShutdownStrategy.java:577)
> [camel-core-2.21.2.jar!/:2.21.2] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [?:1.8.0_102] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [?:1.8.0_102] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [?:1.8.0_102] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [?:1.8.0_102] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
> 2018-08-31 05:42:19.170 [Camel (camel-1) thread #105 - ShutdownTask] INFO
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Unsubscribing from channel /topic/myCompanyExtRoute... 2018-08-31
> 05:42:46.458 [SalesforceHttpClient@b9f06a7-293] ERROR
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Error restarting: Error during HANDSHAKE: 403::Handshake denied
> org.apache.camel.CamelException: Error during HANDSHAKE: 403::Handshake
> denied at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.doStart(SubscriptionHelper.java:215)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$4.run(SubscriptionHelper.java:278)
> [camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> java.lang.Thread.run(Thread.java:745) [?:1.8.0_102] 2018-08-31 05:42:59.170
> [Camel (camel-1) thread #105 - ShutdownTask] WARN
> org.apache.camel.impl.DefaultShutdownStrategy - Error occurred while shutting
> down route:
> Consumer[salesforce-102-STREAMING://myCompanyExtRoute?notifyForFields=ALL&sObjectClass=com.myCompany.sfgateway.api.dto.AgentWork&sObjectQuery=SELECT+Id%2C+IsDeleted%2C+Status%2C+UserId%2C+WorkItemId%2C+ServiceChannelId%2C+DeclineReason%2C+PendingServiceRoutingId+FROM+AgentWork&synchronous=true].
> This exception will be ignored. org.apache.camel.CamelException: Timeout
> error unsubscribing from topic myCompanyExtRoute after 40 seconds at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.unsubscribe(SubscriptionHelper.java:519)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.component.salesforce.SalesforceConsumer.doStop(SalesforceConsumer.java:139)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.support.ServiceSupport.stop(ServiceSupport.java:102)
> ~[camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.util.ServiceHelper.stopService(ServiceHelper.java:142)
> ~[camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.impl.DefaultShutdownStrategy.shutdownNow(DefaultShutdownStrategy.java:381)
> [camel-core-2.21.2.jar!/:2.21.2] at
> org.apache.camel.impl.DefaultShutdownStrategy$ShutdownTask.run(DefaultShutdownStrategy.java:577)
> [camel-core-2.21.2.jar!/:2.21.2] at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [?:1.8.0_102] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> [?:1.8.0_102] at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [?:1.8.0_102] at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [?:1.8.0_102] at java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
> 2018-08-31 05:45:56.519 [SalesforceHttpClient@b9f06a7-292] WARN
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper -
> Error while cleaning session: Logout request TIMEOUT!
> org.apache.camel.component.salesforce.api.SalesforceException: Logout request
> TIMEOUT! at
> org.apache.camel.component.salesforce.internal.SalesforceSession.logout(SalesforceSession.java:318)
> ~[camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$1.onMessage(SubscriptionHelper.java:142)
> [camel-salesforce-2.21.2.jar!/:2.21.2] at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyOnMessage(AbstractClientSession.java:594)
> [cometd-java-common-3.1.2.jar!/:?] at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyMessageListeners(AbstractClientSession.java:579)
> [cometd-java-common-3.1.2.jar!/:?] at
> org.cometd.common.AbstractClientSession.notifyListeners(AbstractClientSession.java:291)
> [cometd-java-common-3.1.2.jar!/:?] at
> org.cometd.common.AbstractClientSession.receive(AbstractClientSession.java:257)
> [cometd-java-common-3.1.2.jar!/:?] at
> org.cometd.client.BayeuxClient.failHandshake(BayeuxClient.java:735)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.cometd.client.BayeuxClient.processHandshake(BayeuxClient.java:721)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.cometd.client.BayeuxClient.processMessages(BayeuxClient.java:606)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.cometd.client.BayeuxClient.access$3100(BayeuxClient.java:100)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.cometd.client.BayeuxClient$MessageTransportListener.onMessages(BayeuxClient.java:1189)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.cometd.client.transport.LongPollingTransport$2.onComplete(LongPollingTransport.java:236)
> [cometd-java-client-3.1.2.jar!/:?] at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:216)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:208)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:470)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.HttpReceiver.responseSuccess(HttpReceiver.java:416)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.messageComplete(HttpReceiverOverHTTP.java:316)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.http.HttpParser.handleContentMessage(HttpParser.java:605)
> [jetty-http-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1675)
> [jetty-http-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1523)
> [jetty-http-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:172)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:135)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:73)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:155)
> [jetty-client-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
> [jetty-io-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:762)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:680)
> [jetty-util-9.4.11.v20180605.jar!/:9.4.11.v20180605] at
> java.lang.Thread.run(Thread.java:745) [?:1.8.0_102]
>
> Could you change SubscriptionHelper not to start again in restartClient when
> logout/unsubscribe is invoked (line 278 in
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> v2.21.2)
>
> and/or prevent reconnect in case of logout?
>
>
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
