Hi, I had the firewall closed during the restart, that's why the connection problems occurred when I issued a control bus restart of the route. After it fails I opened the firewall rule and I could see a new HTTP connection but the subscription part doesn't retry as it just gives up. Since I can't replicate a proper Salesforce outage, this is the only way I can make it give up on the connection, I would have expected after this connection failure it would be able to attempt resubscription after some amount of timeout.
A workaround I can think of is to capture the SalesforceException and to check the error to make sure its a 'Error subscribing to event' message in my error handler in that I could issue my own route restart using the control bus. This would at least create some sort of re-connection subscription ability. cheers andy On Mon, Dec 7, 2020 at 7:39 PM Zoran Regvart <[email protected]> wrote: > > Hi Andy, > just to double check, you did lift the firewall rule to allow the > traffic? The `Connection refused` error points to firewall dropping > packets. > > zoran > > On Sun, Dec 6, 2020 at 11:52 PM Andy Stebbing <[email protected]> > wrote: > > > > I did try the restartClient() call at the position you mentioned, but > > it didn't seem to make any difference. The subscription fails and > > never retries afterwards, the exception that occurs is as follows: > > > > Error subscribing to event/LMSUser__e: Connection refused. Caused by: > > [org.apache.camel.component.salesforce.api.SalesforceException - Error > > subscribing to event/LMSUser__e: Connection refused] > > > > org.apache.camel.component.salesforce.api.SalesforceException: Error > > subscribing to event/LMSUser__e: Connection refused > > at > > org.apache.camel.component.salesforce.internal.streaming.SubscriptionHelper$7.onMessage(SubscriptionHelper.java:453) > > ~[camel-salesforce-3.7.0-SNAPSHOT.jar:3.7.0-SNAPSHOT] > > at > > org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyOnMessage(AbstractClientSession.java:583) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AbstractClientSession$AbstractSessionChannel.notifyMessageListeners(AbstractClientSession.java:568) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AbstractClientSession.notifyListeners(AbstractClientSession.java:308) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AbstractClientSession.lambda$receive$4(AbstractClientSession.java:269) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at org.cometd.bayeux.Promise$2.succeed(Promise.java:103) > > ~[bayeux-api-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AsyncFoldLeft$AbstractLoop.run(AsyncFoldLeft.java:199) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at org.cometd.common.AsyncFoldLeft.run(AsyncFoldLeft.java:93) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AbstractClientSession.extendIncoming(AbstractClientSession.java:103) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at > > org.cometd.common.AbstractClientSession.receive(AbstractClientSession.java:263) > > ~[cometd-java-common-4.0.4.jar:4.0.4] > > at org.cometd.client.BayeuxClient.failMessage(BayeuxClient.java:810) > > ~[cometd-java-client-4.0.4.jar:4.0.4] > > at org.cometd.client.BayeuxClient.messageFailure(BayeuxClient.java:806) > > ~[cometd-java-client-4.0.4.jar:4.0.4] > > at org.cometd.client.BayeuxClient.messagesFailure(BayeuxClient.java:659) > > ~[cometd-java-client-4.0.4.jar:4.0.4] > > at > > org.cometd.client.BayeuxClient$MessageTransportListener.onFailure(BayeuxClient.java:1266) > > ~[cometd-java-client-4.0.4.jar:4.0.4] > > at > > org.cometd.client.transport.LongPollingTransport$2.onComplete(LongPollingTransport.java:218) > > ~[cometd-java-client-4.0.4.jar:4.0.4] > > at > > org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:218) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.ResponseNotifier.notifyComplete(ResponseNotifier.java:210) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.HttpExchange.notifyFailureComplete(HttpExchange.java:269) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at org.eclipse.jetty.client.HttpExchange.abort(HttpExchange.java:240) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.HttpConversation.abort(HttpConversation.java:149) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at org.eclipse.jetty.client.HttpRequest.abort(HttpRequest.java:812) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.HttpDestination.abort(HttpDestination.java:507) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.HttpDestination.failed(HttpDestination.java:253) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.AbstractConnectionPool$1.failed(AbstractConnectionPool.java:270) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at org.eclipse.jetty.util.Promise$Wrapper.failed(Promise.java:136) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at org.eclipse.jetty.client.HttpClient$1$1.failed(HttpClient.java:627) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.AbstractConnectorHttpClientTransport.connectFailed(AbstractConnectorHttpClientTransport.java:138) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.client.AbstractConnectorHttpClientTransport$ClientSelectorManager.connectionFailed(AbstractConnectorHttpClientTransport.java:188) > > ~[jetty-client-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector$Connect.failed(ManagedSelector.java:929) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector.processConnect(ManagedSelector.java:335) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector.access$1600(ManagedSelector.java:62) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector$SelectorProducer.processSelected(ManagedSelector.java:639) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:501) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905) > > ~[jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020] > > at java.base/java.lang.Thread.run(Thread.java:832) ~[na:na] > > Caused by: java.net.ConnectException: Connection refused > > at java.base/sun.nio.ch.Net.pollConnect(Native Method) ~[na:na] > > at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:589) ~[na:na] > > at > > java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:839) > > ~[na:na] > > at > > org.eclipse.jetty.io.SelectorManager.doFinishConnect(SelectorManager.java:355) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > at > > org.eclipse.jetty.io.ManagedSelector.processConnect(ManagedSelector.java:313) > > ~[jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020] > > ... 11 common frames omitted > > > > On Fri, Dec 4, 2020 at 9:35 AM Andy Stebbing <[email protected]> > > wrote: > > > > > > I'll give it a try, just give me a bit of time and I'll let you know. > > > > > > cheers > > > andy > > > > > > On Fri, Dec 4, 2020 at 9:07 AM Zoran Regvart <[email protected]> wrote: > > > > > > > > Hi Andy, > > > > that helps a lot, thanks! I *think* a `restartClient()` invocation > > > > might help if added here: > > > > > > > > https://github.com/apache/camel/blob/b140279d8235ae1aa7cf5010c0bc4945a529fe38/components/camel-salesforce/camel-salesforce-component/src/main/java/org/apache/camel/component/salesforce/internal/streaming/SubscriptionHelper.java#L174 > > > > > > > > i.e. when connection was not successful, that's when that "Connect > > > > failure" message is logged. > > > > > > > > Would you be able to build and test that change on your end? > > > > > > > > zoran > > > > > > > > On Thu, Dec 3, 2020 at 11:01 PM Andy Stebbing > > > > <[email protected]> wrote: > > > > > > > > > > The only way I could replicate the issue or at least see that a > > > > > connection is established but the subscription doesnt resubscribe. I > > > > > did the following: > > > > > > > > > > I used UFW to control the network connection so I can block it. For > > > > > initially starting the route I have the following UFW rule to allow > > > > > all connections to Salesforce IPs: > > > > > > > > > > 13.210.0.0/16 ALLOW OUT Anywhere > > > > > > > > > > I then start the camel routes and using "lsof -i tcp" I can see the > > > > > established connection to Salesforce and in the logs I can see the > > > > > subscription to our platform events: > > > > > > > > > > lsof: > > > > > 192.168.1.211:55510->13.210.6.47:https (ESTABLISHED) > > > > > > > > > > Camel log: > > > > > 2020-12-01 16:33:45.843 INFO 78386 --- [ent@11180750-31] > > > > > o.a.c.c.s.i.s.SubscriptionHelper : Subscribed to channel > > > > > /event/LMSUser__e > > > > > > > > > > I then disrrupt the connection using ss: > > > > > sudo ss -K dst 13.210.6.47 > > > > > > > > > > The following occurs in the log: > > > > > 2020-12-01 16:46:08.942 WARN 78386 --- [ent@11180750-26] > > > > > o.a.c.c.s.i.s.SubscriptionHelper : Connect failure: > > > > > {failure={exception=java.net.ConnectException: Connection refused, > > > > > message={clientId=2p21tj4qverluys8vnb9ww96hcue, advice={timeout=0}, > > > > > channel=/meta/connect, id=14, connectionType=long-polling}, > > > > > connectionType=long-polling}, channel=/meta/connect, id=14, > > > > > successful=false} > > > > > > > > > > and this successfully reconnects to Salesforce using a different IP > > > > > address and the subscription is still working fine. > > > > > > > > > > Now if I block all IP addresses to Salesforce using this UFW rule: > > > > > > > > > > ufw reject out to 13.210.0.0/16 > > > > > > > > > > and then I issue a control bus command to restart to the Salesforce > > > > > route in Camel (as to not restart the java process). The following > > > > > happens in the log: > > > > > > > > > > 2020-12-01 16:49:58.026 INFO 78386 --- [ - ShutdownTask] > > > > > o.a.c.c.s.i.s.SubscriptionHelper : Unsubscribing from channel > > > > > /event/LMSUser__e... > > > > > > > > > > 2020-12-01 16:51:56.340 ERROR 81511 --- [ent@11180750-30] > > > > > a.e.a.i.m.r.SalesforceContactEventRoutes : error > > > > > org.apache.camel.component.salesforce.api.SalesforceException: Error > > > > > subscribing to event/LMSUser__e: Connection refused.. > > > > > > > > > > and now if I change the UFW rule to allow connections to Salesforce > > > > > using: > > > > > > > > > > ufw allow out to 13.210.0.0/16 > > > > > > > > > > I can see in the lsof connections that a connection is established and > > > > > I can even disrrupt it using the ss command as above and in the log it > > > > > reports: > > > > > > > > > > 2020-12-01 16:53:45.634 WARN 81511 --- [ent@11180750-30] > > > > > o.a.c.c.s.i.s.SubscriptionHelper : Connect failure: > > > > > {failure={exception=java.io.EOFException: > > > > > HttpConnectionOverHTTP@78f09ebd::DecryptedEndPoint@38ed3138{l=/192.168.1.211:52890,r=aib--test.my.salesforce.com/13.210.4.109:443,OPEN,fill=-,flush=-,to=47747/340000}, > > > > > message={clientId=2y01uo3aroo464hdwshfmuasq2gx, channel=/meta/connect, > > > > > id=9, connectionType=long-polling}, connectionType=long-polling}, > > > > > channel=/meta/connect, id=9, successful=false} > > > > > > > > > > and it successfully reconnects using a different ip address. but the > > > > > event subscription never subscibes again and no events are handled > > > > > eventhough there is an active connection established. > > > > > > > > > > Does this expose the issue correctly? Its a bit hard to truly > > > > > replicate it when Salesforce goes down as its normally not just a > > > > > simple connection failure situation. > > > > > > > > > > thanks > > > > > Andy > > > > > > > > > > > > > > > On Tue, Dec 1, 2020 at 4:10 PM Andy Stebbing > > > > > <[email protected]> wrote: > > > > > > > > > > > > Hi, > > > > > > I did try it out with 3.7.0-SNAPSHOT but the outcome was the same. > > > > > > I'll put in a JIRA ticket and I'll provide details on how I was able > > > > > > to replicate the issue. I'll also post it on here. > > > > > > > > > > > > cheers > > > > > > andy > > > > > > > > > > > > On Mon, Nov 30, 2020 at 7:59 PM Zoran Regvart <[email protected]> > > > > > > wrote: > > > > > > > > > > > > > > Hi Andy, > > > > > > > sounds like an issue we would not encounter when > > > > > > > developing/running > > > > > > > integration tests. We have a number of issues (some of them have > > > > > > > been > > > > > > > fixed) relating to streaming/push APIs with Salesforce. > > > > > > > > > > > > > > Perhaps if you find that the recent versions did not fix your > > > > > > > issue > > > > > > > you could contribute the logic of your custom error handler. > > > > > > > Sounds > > > > > > > like you've also arrived at a setup where you can reproduce and > > > > > > > test > > > > > > > the fix. > > > > > > > > > > > > > > I'm guessing it could fit within the SubscriptionHelper class. > > > > > > > > > > > > > > zoran > > > > > > > > > > > > > > On Fri, Nov 27, 2020 at 4:14 AM Andy Stebbing > > > > > > > <[email protected]> wrote: > > > > > > > > > > > > > > > > Hi There, > > > > > > > > I'm using the salesforce component for receiving platform > > > > > > > > events and > > > > > > > > have been using it for a few months and is generally quite > > > > > > > > stable. > > > > > > > > > > > > > > > > My question is around the durability of the subscription, for > > > > > > > > normal > > > > > > > > network dropouts or timeouts etc, it handles it very well, but > > > > > > > > recently Salesforce have had some big outages in my org and it > > > > > > > > causes > > > > > > > > the subscription to stop working without re-subscribing again. > > > > > > > > > > > > > > > > I can replicate the issue locally, running my camel route so it > > > > > > > > initially subscribes to the events then I firewall block the > > > > > > > > Salesforce destination then i restart the route. It fails and > > > > > > > > then > > > > > > > > unsubscribes from the events and when i open the firewall it > > > > > > > > connects > > > > > > > > but never re-subscribes to the events again. Any new events from > > > > > > > > Salesforce are not consumed and the service remains offline. > > > > > > > > > > > > > > > > I've bridged the error handler to one I've defined within the > > > > > > > > same > > > > > > > > camel context so that I could detect the salesforce exception > > > > > > > > when it > > > > > > > > happens and then to use the control bus to restart the route > > > > > > > > which > > > > > > > > then does the subscription. But seems like an overkill, > > > > > > > > especially if > > > > > > > > this is a bug that might end up being fixed. > > > > > > > > > > > > > > > > Has anyone else experienced this? Are there any solutions to > > > > > > > > get around this? > > > > > > > > > > > > > > > > Many thanks! > > > > > > > > > > > > > > > > > > > > > > > > > > > > -- > > > > > > > Zoran Regvart > > > > > > > > > > > > > > > > -- > > > > Zoran Regvart > > > > -- > Zoran Regvart
