[
https://issues.apache.org/jira/browse/CAMEL-16370?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Claus Ibsen resolved CAMEL-16370.
---------------------------------
Resolution: Fixed
> Camel Salesforce component unable to reconnect after disconnect from
> Salesforce
> -------------------------------------------------------------------------------
>
> Key: CAMEL-16370
> URL: https://issues.apache.org/jira/browse/CAMEL-16370
> Project: Camel
> Issue Type: Bug
> Components: camel-salesforce
> Affects Versions: 3.8.0, 3.11.0
> Environment: Running in a spring-boot (v2.1.18.RELEASE) app in a
> linux container deployed to openshift 3.11
> Reporter: Jason
> Priority: Major
> Fix For: 3.14.0
>
>
> We are consuming Salesforce platform-events following the documented
> recommendations and our connection will not reconnect after being
> disconnected, apparently, from Salesforce. I am not quite certain as to the
> circumstances that Salesforce sends some sort of disconnect signal, but that
> is what's logged from the SubscriptionHelper class. Our initial connection to
> Salesforce is successful and we are able to receive platform-events up until
> the point of the spontaneous disconnection. Re-connection fails consistently
> and always in the same way. Logging is slightly different across version,
> but the behavior seems to always be the same.
> Our only work around for this is to run our service consuming this message
> like a cron job and restart it every 15 minutes (period we settled on through
> experimentation). This is not how we'd prefer to sun this service, it's
> quite hacky and we'd like to not have to force a restart to work around what
> appears to an issue with how the reconnect is handled.
>
> Here is the stacktrace:
> [DEBUG] 2021-03-17 13:30:48,513
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$5
> [SalesforceHttpClient@60c73e58-25 ] - Received messages
> [{clientId=[--------redacted--------], channel=/meta/connect, id=21,
> successful=true}][DEBUG] 2021-03-17 13:30:48,513
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-25 ] - [CHANNEL:META_CONNECT]:
> {clientId=[--------redacted--------], channel=/meta/connect, id=21,
> successful=true}
> [DEBUG] 2021-03-17 13:32:38,588
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$5
> [SalesforceHttpClient@60c73e58-25 ] - Received messages
> [{clientId=[--------redacted--------], channel=/meta/connect, id=22,
> successful=true}]
> [DEBUG] 2021-03-17 13:32:38,589
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-25 ] - [CHANNEL:META_CONNECT]:
> {clientId=[--------redacted--------], channel=/meta/connect, id=22,
> successful=true}
> [DEBUG] 2021-03-17 13:34:28,665
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$5
> [SalesforceHttpClient@60c73e58-25 ] - Received messages
> [{clientId=[--------redacted--------], channel=/meta/connect, id=23,
> successful=true}]
> [DEBUG] 2021-03-17 13:34:28,666
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-25 ] - [CHANNEL:META_CONNECT]:
> {clientId=[--------redacted--------], channel=/meta/connect, id=23,
> successful=true}[DEBUG] 2021-03-17 13:34:28,766
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$5
> [SalesforceHttpClient@60c73e58-32 ] - Received messages
> [{channel=/meta/disconnect}, {clientId=[--------redacted--------],
> advice={reconnect=none, interval=0}, channel=/meta/connect, id=24,
> error=401::Authentication invalid, successful=false}]
> [INFO ] 2021-03-17 13:34:28,769
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Restarting on unexpected disconnect
> from Salesforce...
> [DEBUG] 2021-03-17 13:34:28,769
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Waiting to disconnect...
> [DEBUG] 2021-03-17 13:34:28,770
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-32 ] - [CHANNEL:META_CONNECT]:
> {clientId=[--------redacted--------], advice={reconnect=none, interval=0},
> channel=/meta/connect, id=24, error=401::Authentication invalid,
> successful=false}[WARN ] 2021-03-17 13:34:28,771
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-32 ] - Connect failure:
> {clientId=[--------redacted--------], advice={reconnect=none, interval=0},
> channel=/meta/connect, id=24, error=401::Authentication invalid,
> successful=false}
> [DEBUG] 2021-03-17 13:34:33,769
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Pausing for 0 msecs before restart
> attempt
> [DEBUG] 2021-03-17 13:34:33,770
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Stopped the helper and destroyed the
> client
> [DEBUG] 2021-03-17 13:34:33,862
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$5
> [SalesforceHttpClient@60c73e58-30 ] - Received messages
> [{ext={sfdc={failureReason=401::Authentication invalid}, replay=true,
> payload.format=true}, advice={reconnect=none}, channel=/meta/handshake,
> id=25, error=403::Handshake denied, successful=false}][DEBUG] 2021-03-17
> 13:34:33,863
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-30 ] - [CHANNEL:META_HANDSHAKE]:
> {ext={sfdc={failureReason=401::Authentication invalid}, replay=true,
> payload.format=true}, advice={reconnect=none}, channel=/meta/handshake,
> id=25, error=403::Handshake denied, successful=false}
> [WARN ] 2021-03-17 13:34:33,863
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-30 ] - Handshake failure:
> {ext={sfdc={failureReason=401::Authentication invalid}, replay=true,
> payload.format=true}, advice={reconnect=none}, channel=/meta/handshake,
> id=25, error=403::Handshake denied, successful=false}
> [INFO ] 2021-03-17 13:34:33,863
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-30 ] - Cleaning session (logout) from
> SalesforceSession before restarting client
> [INFO ] 2021-03-17 13:34:33,867 org.cometd.bayeux.client.ClientSession
> [SalesforceHttpClient@60c73e58-30 ] - Exception while invoking listener
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$1...@7574cf75java.lang.NullPointerException:
> null at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$1.onMessage(SubscriptionHelper.java:148)
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyOnMessage(AbstractClientSession.java:583)
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyMessageListeners(AbstractClientSession.java:568)
> at
> org.cometd.common.AbstractClientSession.notifyListeners(AbstractClientSession.java:308)
> at
> org.cometd.common.AbstractClientSession.lambda$receive$4(AbstractClientSession.java:269)
> at org.cometd.bayeux.Promise$2.succeed(Promise.java:103) at
> org.cometd.common.AsyncFoldLeft$AbstractLoop.run(AsyncFoldLeft.java:199)
> at org.cometd.common.AsyncFoldLeft.run(AsyncFoldLeft.java:93) at
> org.cometd.common.AbstractClientSession.extendIncoming(AbstractClientSession.java:103)
> at
> org.cometd.common.AbstractClientSession.receive(AbstractClientSession.java:263)
> at org.cometd.client.BayeuxClient.failHandshake(BayeuxClient.java:721)
> at org.cometd.client.BayeuxClient.processHandshake(BayeuxClient.java:707)
> at org.cometd.client.BayeuxClient.processMessages(BayeuxClient.java:615)
> at org.cometd.client.BayeuxClient.access$2000(BayeuxClient.java:101) at
> org.cometd.client.BayeuxClient$MessageTransportListener.onMessages(BayeuxClient.java:1260)
> at
> org.cometd.client.transport.LongPollingTransport$2.onComplete(LongPollingTransport.java:240)
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:218)
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:210)
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:481)
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:461)
> at
> org.eclipse.jetty.client.HttpReceiver.responseSuccess(HttpReceiver.java:424)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.messageComplete(HttpReceiverOverHTTP.java:365)
> at
> org.eclipse.jetty.http.HttpParser.handleContentMessage(HttpParser.java:585)
> at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1702)
> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1531) at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:204)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:144)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:79)
> at
> org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:131)
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:169)
> at
> org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
> at
> org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:540)
> at
> org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:395)
> at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161)
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at
> org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
> at
> org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
> at java.base/java.lang.Thread.run(Thread.java:834)
> [ERROR] 2021-03-17 13:36:23,773
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Error restarting: Exception during
> HANDSHAKE: 401::Authentication invalidorg.apache.camel.CamelException:
> Exception during HANDSHAKE: 401::Authentication invalid at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.connect(SubscriptionHelper.java:223)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.doStart(SubscriptionHelper.java:212)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.performClientRestart(SubscriptionHelper.java:304)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.access$1000(SubscriptionHelper.java:60)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$4.run(SubscriptionHelper.java:249)
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
> at java.base/java.lang.Thread.run(Thread.java:834)Caused by:
> org.apache.camel.component.salesforce.api.SalesforceException:
> 401::Authentication invalid at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.getFailure(SubscriptionHelper.java:340)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper.access$300(SubscriptionHelper.java:60)
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$1.onMessage(SubscriptionHelper.java:132)
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyOnMessage(AbstractClientSession.java:583)
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyMessageListeners(AbstractClientSession.java:568)
> at
> org.cometd.common.AbstractClientSession.notifyListeners(AbstractClientSession.java:308)
> at
> org.cometd.common.AbstractClientSession.lambda$receive$4(AbstractClientSession.java:269)
> at org.cometd.bayeux.Promise$2.succeed(Promise.java:103) at
> org.cometd.common.AsyncFoldLeft$AbstractLoop.run(AsyncFoldLeft.java:199)
> at org.cometd.common.AsyncFoldLeft.run(AsyncFoldLeft.java:93) at
> org.cometd.common.AbstractClientSession.extendIncoming(AbstractClientSession.java:103)
> at
> org.cometd.common.AbstractClientSession.receive(AbstractClientSession.java:263)
> at org.cometd.client.BayeuxClient.failHandshake(BayeuxClient.java:721)
> at org.cometd.client.BayeuxClient.processHandshake(BayeuxClient.java:707)
> at org.cometd.client.BayeuxClient.processMessages(BayeuxClient.java:615)
> at org.cometd.client.BayeuxClient.access$2000(BayeuxClient.java:101) at
> org.cometd.client.BayeuxClient$MessageTransportListener.onMessages(BayeuxClient.java:1260)
> at
> org.cometd.client.transport.LongPollingTransport$2.onComplete(LongPollingTransport.java:240)
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:218)
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:210)
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:481)
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:461)
> at
> org.eclipse.jetty.client.HttpReceiver.responseSuccess(HttpReceiver.java:424)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.messageComplete(HttpReceiverOverHTTP.java:365)
> at
> org.eclipse.jetty.http.HttpParser.handleContentMessage(HttpParser.java:585)
> at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1702)
> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1531) at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:204)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:144)
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:79)
> at
> org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:131)
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:169)
> at
> org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
> at
> org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:540)
> at
> org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:395)
> at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161)
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) at
> org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
> at
> org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
> ... 3 common frames omitted
> [ERROR] 2021-03-17 13:36:23,774
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper
> [SalesforceHttpClient@60c73e58-26 ] - Failed to restart after pausing for 0
> msecs
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
