Hi Andy, I think I didn't understand your previous email correctly. Just to try to understand better is this how you tested: you blocked connections on the firewall, waited for the failure to establish connection and then unblocked on the firewall to see that the connection was reestablished but the subscriptions were not resubscribed?
I'm looking at the SubscriptionHelper, and I'm not too happy with how we have that `reconnecting` boolean, doesn't seem thread safe. Which could be part of the problem also. I'll have a look at this, I think I can reproduce this in an integration test using a tool like Sniffy, and I can't recall now there was a proxy that could be used for tests. zoran On Mon, Dec 7, 2020 at 11:05 PM Andy Stebbing <stebbingtow...@gmail.com> wrote: > > 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 <zo...@regvart.com> 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 <stebbingtow...@gmail.com> > > 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 <stebbingtow...@gmail.com> > > > 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 <zo...@regvart.com> 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 > > > > > <stebbingtow...@gmail.com> 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 > > > > > > <stebbingtow...@gmail.com> 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 <zo...@regvart.com> > > > > > > > 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 > > > > > > > > <stebbingtow...@gmail.com> 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 -- Zoran Regvart
