[
https://issues.apache.org/jira/browse/CAMEL-12871?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16645993#comment-16645993
]
Hemang Ajmera commented on CAMEL-12871:
---------------------------------------
Hi
# From salesforce we get 403 error every 2-3 hours. We currently do not know
the reason, and we are trying to seek help for sf.
# In log one, upon 403 error, camel was able to reconnect back to salesforce.
After that it was able to subscribed to the topic. This is repeated every 2-3
hours
# As you rightly said, something went wrong during log 2, and camel was not
able to subscribe to salesforce
# In log three, camel tried to log in again to salesforce, but this time
camel is not trying to subscribe the topic at all.
# So my question here is why is camel to trying to subscribe again after
failure in log 2? Shouldn't it try to come out of error?
# If I restart camel code, everything just works fine
# I think when we get error in log 2, camel maintains list of topics and
replay id to be connected to salesforce. From that list this topic is removed.
Thus in all future tried, camel does not have any topic to connect. What we
should fix is that camel should continue to try to connect to topic and not
drop it.
> Camel-salesforce component drops the streaming topic
> ----------------------------------------------------
>
> Key: CAMEL-12871
> URL: https://issues.apache.org/jira/browse/CAMEL-12871
> Project: Camel
> Issue Type: Bug
> Components: camel-salesforce
> Affects Versions: 2.21.1
> Reporter: Hemang Ajmera
> Priority: Blocker
>
> h1. Summary
> Salesforce component tries to reconnect to salesforce, if it gets disconnect.
> Most of the time it is succeeded. However, there is case when re-connect does
> not work. At that time salesforce component drops the topic which is
> subscribe and reconnects back. Everything looks normal again, however, no new
> streaming messages are received, as the component has dropped the topic.
> h1. Observation
> Here is the logs which show good reconnect. We can see that camel attempts to
> subscribe to topic /topic/AccountOwner
> {quote}
> 2018-09-12 02:54:23.530 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=410,
> error=403::Unknown client, successful=false}]
> 2018-09-12 02:54:23.531 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=410,
> error=403::Unknown client, successful=false}
> 2018-09-12 02:54:23.531 WARN 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : Connect failure:
> {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=410,
> error=403::Unknown client, successful=false}
> 2018-09-12 02:54:23.588 DEBUG 1 --- [ent@2362f559-21]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=p1t17l7111gqk4p6eff60893qeev,
> supportedConnectionTypes=[Ljava.lang.Object;@471ebac8,
> channel=/meta/handshake, id=411, version=1.0, successful=true}]
> 2018-09-12 02:54:23.589 DEBUG 1 --- [ent@2362f559-21]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_HANDSHAKE]:
> {ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=p1t17l7111gqk4p6eff60893qeev,
> supportedConnectionTypes=[Ljava.lang.Object;@471ebac8,
> channel=/meta/handshake, id=411, version=1.0, successful=true}
> 2018-09-12 02:54:23.625 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=p1t17l7111gqk4p6eff60893qeev, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=412, successful=true}]
> 2018-09-12 02:54:23.625 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {clientId=p1t17l7111gqk4p6eff60893qeev, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=412, successful=true}
> 2018-09-12 02:54:23.625 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : Refreshing subscriptions to 1
> channels on reconnect
> 2018-09-12 02:54:23.626 INFO 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : Set Replay extension to replay
> from `-2` for channel `/topic/AccountOwners`
> 2018-09-12 02:54:23.626 INFO 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper : Subscribing to channel
> /topic/AccountOwners...
> 2018-09-12 02:54:23.693 DEBUG 1 --- [ent@2362f559-21]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=p1t17l7111gqk4p6eff60893qeev, channel=/meta/subscribe, id=413,
> subscription=/topic/AccountOwners, successful=true}]
> 2018-09-12 02:54:23.693 DEBUG 1 --- [ent@2362f559-21]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_SUBSCRIBE]:
> {clientId=p1t17l7111gqk4p6eff60893qeev, channel=/meta/subscribe, id=413,
> subscription=/topic/AccountOwners, successful=true}
> 2018-09-12 02:54:23.693 INFO 1 --- [ent@2362f559-21]
> o.a.c.c.s.i.s.SubscriptionHelper : Subscribed to channel
> /topic/AccountOwners
> 2018-09-12 02:54:25.453 DEBUG 1 --- [ent@2362f559-20]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages ....
> {quote}
> Here is the logs which shows connection fails. Camel tries to reconnect, but
> fails. Then camel reconnects after dropping the topic. After this incident,
> no new messages are received.
> {quote}
> 2018-09-22 05:26:17.121 WARN 1 --- [ent@2362f559-23]
> o.a.c.c.s.i.s.SubscriptionHelper : Connect failure:
> {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=8770,
> error=403::Unknown client, successful=false}
> 2018-09-22 05:26:18.738 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=5vgmiblu8etx0q3typo6d5tgn,
> supportedConnectionTypes=[Ljava.lang.Object;@5814852c,
> channel=/meta/handshake, id=8771, version=1.0, successful=true}]
> 2018-09-22 05:26:18.738 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_HANDSHAKE]:
> {ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=5vgmiblu8etx0q3typo6d5tgn,
> supportedConnectionTypes=[Ljava.lang.Object;@5814852c,
> channel=/meta/handshake, id=8771, version=1.0, successful=true}
> 2018-09-22 05:26:18.775 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8772, successful=true}]
> 2018-09-22 05:26:18.776 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8772, successful=true}
> 2018-09-22 05:26:18.776 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : Refreshing subscriptions to 1
> channels on reconnect
> 2018-09-22 05:26:18.776 INFO 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : Set Replay extension to replay
> from `-2` for channel `/topic/AccountOwners`
> 2018-09-22 05:26:18.776 INFO 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : Subscribing to channel
> /topic/AccountOwners...
> 2018-09-22 05:26:19.013 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{channel=/meta/disconnect}, {clientId=5vgmiblu8etx0q3typo6d5tgn,
> advice={reconnect=none, interval=0}, channel=/meta/connect, id=8774,
> error=403::Unknown client, successful=false}]
> 2018-09-22 05:26:19.014 INFO 1 --- [ent@2362f559-22]
> o.a.c.c.s.i.s.SubscriptionHelper : Restarting on unexpected
> disconnect from Salesforce...
> 2018-09-22 05:26:19.014 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=none, interval=0},
> channel=/meta/connect, id=8774, error=403::Unknown client, successful=false}
> 2018-09-22 05:26:19.014 WARN 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : Connect failure:
> {clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=none, interval=0},
> channel=/meta/connect, id=8774, error=403::Unknown client, successful=false}
> 2018-09-22 05:26:19.014 DEBUG 1 --- [ent@2362f559-22]
> o.a.c.c.s.i.s.SubscriptionHelper : Waiting to disconnect...
> 2018-09-22 05:26:19.014 DEBUG 1 --- [ent@2362f559-22]
> o.a.c.c.s.i.s.SubscriptionHelper : Pausing for 1000 msecs before
> restart attempt
> 2018-09-22 05:26:19.043 DEBUG 1 --- [ent@2362f559-23]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=handshake,
> interval=0}, channel=/meta/subscribe, id=8773,
> subscription=/topic/AccountOwners, error=403::Unknown client,
> successful=false}]
> 2018-09-22 05:26:19.043 DEBUG 1 --- [ent@2362f559-23]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_SUBSCRIBE]:
> {clientId=5vgmiblu8etx0q3typo6d5tgn, advice={reconnect=handshake,
> interval=0}, channel=/meta/subscribe, id=8773,
> subscription=/topic/AccountOwners, error=403::Unknown client,
> successful=false}
> 2018-09-22 05:26:19.054 WARN 1 --- [ent@2362f559-23]
> o.a.c.c.salesforce.SalesforceConsumer : Error subscribing to
> AccountOwners: 403::Unknown client. Caused by:
> [org.apache.camel.component.salesforce.api.SalesforceException - Error
> subscribing to AccountOwners: 403::Unknown client]
> org.apache.camel.component.salesforce.api.SalesforceException: Error
> subscribing to AccountOwners: 403::Unknown client
> at
> org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$7.onMessage(SubscriptionHelper.java:404)
> [camel-salesforce-2.21.1.jar!/:2.21.1]
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyOnMessage(AbstractClientSession.java:594)
> [cometd-java-common-3.1.2.jar!/:na]
> at
> org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyMessageListeners(AbstractClientSession.java:579)
> [cometd-java-common-3.1.2.jar!/:na]
> at
> org.cometd.common.AbstractClientSession.notifyListeners(AbstractClientSession.java:291)
> [cometd-java-common-3.1.2.jar!/:na]
> at
> org.cometd.common.AbstractClientSession.receive(AbstractClientSession.java:257)
> [cometd-java-common-3.1.2.jar!/:na]
> at org.cometd.client.BayeuxClient.processMessage(BayeuxClient.java:822)
> [cometd-java-client-3.1.2.jar!/:na]
> at
> org.cometd.client.BayeuxClient.processMessages(BayeuxClient.java:618)
> [cometd-java-client-3.1.2.jar!/:na]
> at org.cometd.client.BayeuxClient.access$3100(BayeuxClient.java:100)
> [cometd-java-client-3.1.2.jar!/:na]
> at
> org.cometd.client.BayeuxClient$MessageTransportListener.onMessages(BayeuxClient.java:1189)
> [cometd-java-client-3.1.2.jar!/:na]
> at
> org.cometd.client.transport.LongPollingTransport$2.onComplete(LongPollingTransport.java:236)
> [cometd-java-client-3.1.2.jar!/:na]
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:193)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:185)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.HttpReceiver.terminateResponse(HttpReceiver.java:464)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.HttpReceiver.responseSuccess(HttpReceiver.java:410)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.messageComplete(HttpReceiverOverHTTP.java:301)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.http.HttpParser.handleContentMessage(HttpParser.java:628)
> [jetty-http-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at org.eclipse.jetty.http.HttpParser.parseContent(HttpParser.java:1594)
> [jetty-http-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:1442)
> [jetty-http-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.parse(HttpReceiverOverHTTP.java:173)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.process(HttpReceiverOverHTTP.java:134)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpReceiverOverHTTP.receive(HttpReceiverOverHTTP.java:72)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpChannelOverHTTP.receive(HttpChannelOverHTTP.java:133)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.client.http.HttpConnectionOverHTTP.onFillable(HttpConnectionOverHTTP.java:155)
> [jetty-client-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
> [jetty-io-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:319)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:175)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:133)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:754)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:672)
> [jetty-util-9.4.9.v20180320.jar!/:9.4.9.v20180320]
> at java.lang.Thread.run(Thread.java:748) [na:1.8.0_171]
> 2018-09-22 05:26:20.070 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=91ffaqyez0nsf71n1yganknag4o,
> supportedConnectionTypes=[Ljava.lang.Object;@249260ff,
> channel=/meta/handshake, id=8775, version=1.0, successful=true}]
> 2018-09-22 05:26:20.070 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_HANDSHAKE]:
> {ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=91ffaqyez0nsf71n1yganknag4o,
> supportedConnectionTypes=[Ljava.lang.Object;@249260ff,
> channel=/meta/handshake, id=8775, version=1.0, successful=true}
> 2018-09-22 05:26:20.108 DEBUG 1 --- [ent@2362f559-23]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=91ffaqyez0nsf71n1yganknag4o, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8776, successful=true}]
> 2018-09-22 05:26:20.108 DEBUG 1 --- [ent@2362f559-23]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {clientId=91ffaqyez0nsf71n1yganknag4o, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8776, successful=true}
> 2018-09-22 05:26:20.108 INFO 1 --- [ent@2362f559-22]
> o.a.c.c.s.i.s.SubscriptionHelper : Successfully restarted!
> {quote}
> Here are the logs afterward, where on getting 403 error camel tries to
> reconnect, but does not subscribe to topic
> {quote}
> 2018-09-22 08:27:54.440 WARN 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : Connect failure:
> {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=8876,
> error=403::Unknown client, successful=false}
> 2018-09-22 08:27:54.489 DEBUG 1 --- [ent@2362f559-19]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=8318v3qm6whrb71uj5d6w2qv97q,
> supportedConnectionTypes=[Ljava.lang.Object;@1b0b2091,
> channel=/meta/handshake, id=8877, version=1.0, successful=true}]
> 2018-09-22 08:27:54.489 DEBUG 1 --- [ent@2362f559-19]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_HANDSHAKE]:
> {ext={replay=true, payload.format=true}, minimumVersion=1.0,
> clientId=8318v3qm6whrb71uj5d6w2qv97q,
> supportedConnectionTypes=[Ljava.lang.Object;@1b0b2091,
> channel=/meta/handshake, id=8877, version=1.0, successful=true}
> 2018-09-22 08:27:54.526 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=8318v3qm6whrb71uj5d6w2qv97q, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8878, successful=true}]
> 2018-09-22 08:27:54.527 DEBUG 1 --- [ent@2362f559-24]
> o.a.c.c.s.i.s.SubscriptionHelper : [CHANNEL:META_CONNECT]:
> {clientId=8318v3qm6whrb71uj5d6w2qv97q, advice={reconnect=retry, interval=0,
> timeout=110000}, channel=/meta/connect, id=8878, successful=true}
> 2018-09-22 08:29:44.566 DEBUG 1 --- [ent@2362f559-19]
> o.a.c.c.s.i.s.SubscriptionHelper$5 : Received messages
> [{clientId=8318v3qm6whrb71uj5d6w2qv97q, channel=/meta/connect, id=8879,
> successful=true}]
> {quote}
> h1. Desired functionality
> Salesforce component to continue to try reconnect *without* dropping the topic
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
