You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@camel.apache.org by "Claus Ibsen (Jira)" <ji...@apache.org> on 2020/12/17 05:44:00 UTC
[jira] [Updated] (CAMEL-12871) Camel-salesforce component drops the
streaming topic
[ https://issues.apache.org/jira/browse/CAMEL-12871?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Claus Ibsen updated CAMEL-12871:
--------------------------------
Fix Version/s: 3.8.0
> 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: Major
> Fix For: 3.8.0
>
>
> 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
(v8.3.4#803005)