forcedotcom / EMP-Connector

A simplified cometd connector for Enterprise Messaging Platform
BSD 3-Clause "New" or "Revised" License
185 stars 243 forks source link

Disconnecting after few mins #15

Closed rmadireddy closed 6 years ago

rmadireddy commented 7 years ago

Working fine initially but disconnecting after few minutes. We are sending salesforce account events to kafka bus.

LOG: 2017-08-08T21:02:34.047Z DEBUG <> [HttpClient@1874542689-91] c.o.s.empconnector.EmpConnector$2 - Processing /meta/connect {clientId=ja3en1s5e7cy7n1w765gzi8nrgz, channel=/meta/connect, id=32, successful=true} 2017-08-08T21:02:34.047Z DEBUG <> [HttpClient@1874542689-91] c.o.s.empconnector.EmpConnector$2 - State update: CONNECTED -> CONNECTED 2017-08-08T21:02:34.050Z DEBUG <> [pool-9-thread-1] c.o.s.empconnector.EmpConnector$2 - Connecting, transport com.opentable.salesforceinternalservice.empconnector.EmpConnector$1@795f8317 2017-08-08T21:02:34.050Z DEBUG <> [pool-9-thread-1] c.o.s.empconnector.EmpConnector$2 - Sending messages [{clientId=ja3en1s5e7cy7n1w765gzi8nrgz, channel=/meta/connect, id=33, connectionType=long-polling}] 2017-08-08T21:02:34.149Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$1 - Received messages [{channel=/meta/disconnect}, {clientId=ja3en1s5e7cy7n1w765gzi8nrgz, advice={reconnect=none, interval=0}, channel=/meta/connect, id=33, error=403::Unknown client, successful=false}] 2017-08-08T21:02:34.149Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$2 - Processing /meta/disconnect {channel=/meta/disconnect} 2017-08-08T21:02:34.150Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$2 - State update: CONNECTED -> TERMINATING 2017-08-08T21:02:34.151Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$2 - State update: TERMINATING -> DISCONNECTED 2017-08-08T21:02:34.151Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$2 - Processing /meta/connect {clientId=ja3en1s5e7cy7n1w765gzi8nrgz, advice={reconnect=none, interval=0}, channel=/meta/connect, id=33, error=403::Unknown client, successful=false} 2017-08-08T21:02:34.151Z DEBUG <> [HttpClient@1874542689-95] c.o.s.empconnector.EmpConnector$2 - State not updateable: DISCONNECTED -> TERMINATING

Please help me on this.

ractive commented 6 years ago

We also have the issue that the connection dies after 3 hours after an 403::Unknown client error. Issue #4 already mentioned this as well and it seems as if the token expires:

07:12:08.430    Processing /meta/connect {clientId=2jxijyli6r7ff2cn19vzjchfb1zk5, channel=/meta/connect, id=103, successful=true}
07:12:08.430    State update: CONNECTED -> CONNECTED
07:12:08.430    Connecting, transport com.salesforce.emp.connector.EmpConnector$1@40b317f1
07:12:08.431    Sending messages [{clientId=2jxijyli6r7ff2cn19vzjchfb1zk5, channel=/meta/connect, id=104, connectionType=long-polling}]
07:12:08.453    State update: CONNECTED -> REHANDSHAKING
07:12:08.453    Handshaking on transport com.salesforce.emp.connector.EmpConnector$1@40b317f1: {supportedConnectionTypes=[long-polling], channel=/meta/handshake org.cometd.client.callback=com.salesforce.emp.connector.EmpConnector$$Lambda$49/995544028@1fe4e8d6, version=1.0}
07:12:08.453    Processing /meta/connect {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=104, error=403::Unknown client, successful=false}
07:12:08.453    Sending messages [{ext={replay=true}, supportedConnectionTypes=[long-polling], channel=/meta/handshake, id=105, version=1.0}]
07:12:08.467    Processing /meta/handshake {ext={sfdc={failureReason=401::Request requires authentication}, replay=true, payload.format=true}, advice={reconnect=none}, channel=/meta/handshake, id=105 error=403::Handshake denied, successful=false}
07:12:08.469    State update: REHANDSHAKING -> TERMINATING
07:12:08.470    State update: TERMINATING -> DISCONNECTED

Re-handshaking fails as shown in the logs. What is the proper way to re-authenticate?

BeingSujeetK commented 6 years ago

Hi @sfdc-hhildebrand , An update on this issue would be really helpful. In our case, the EmpConnector is disconnecting after approx 2 days.

The client subscribes :-

2017-11-27 12:16:37 [main] INFO c.t.esi.empclient.EmpClient - Subscribed : Subscription [/event/MarketingAutomationEvent__e:-2]

The client receives error=403::Unknown client :-

2017-11-29 13:29:58 [HttpClient@1007653873-22] DEBUG c.s.emp.connector.EmpConnector$1 - Received messages [{advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=2258, error=403::Unknown client, successful=false}] 2017-11-29 13:29:58 [HttpClient@1007653873-22] DEBUG org.cometd.client.BayeuxClient - Processing /meta/connect {advice={reconnect=handshake, interval=0}, channel=/meta/connect, id=2258, error=403::Unknown client, successful=false} 2017-11-29 13:29:58 [HttpClient@1007653873-22] DEBUG org.cometd.client.BayeuxClient - State update: CONNECTED -> REHANDSHAKING

The client receives 401::Request requires authentication :-

2017-11-29 13:29:58 [HttpClient@1007653873-23] DEBUG c.s.emp.connector.EmpConnector$1 - Received messages [{ext={sfdc={failureReason=401::Request requires authentication}, replay=true, payload.format=true}, advice={reconnect=none}, channel=/meta/handshake, id=2259, error=403::Handshake denied, successful=false}] 2017-11-29 13:29:58 [HttpClient@1007653873-23] DEBUG org.cometd.client.BayeuxClient - Processing /meta/handshake {ext={sfdc={failureReason=401::Request requires authentication}, replay=true, payload.format=true}, advice={reconnect=none}, channel=/meta/handshake, id=2259, error=403::Handshake denied, successful=false} 2017-11-29 13:29:58 [HttpClient@1007653873-23] DEBUG org.cometd.client.BayeuxClient - State update: REHANDSHAKING -> TERMINATING 2017-11-29 13:29:58 [HttpClient@1007653873-23] DEBUG org.cometd.client.BayeuxClient - State update: TERMINATING -> DISCONNECTED

pbn-sfdc commented 6 years ago

EmpConnector has a method to set auth failure callback, so clients can re-auth and pass the new session id /token to continue.

pbn-sfdc commented 6 years ago

Closing this.