+ Start a Discussion
MaxPMageeMaxPMagee 

Streaming API Fails with error: 402, Unknown Client

I built the Java/Bayaex example here:

http://www.salesforce.com/us/developer/docs/api_streaming/index_Left.htm#StartTopic=Content/code_sample_java_add_source.htm

 

After adding some waiting to the busy loop, adding my credentials (and after setting up a streaming topic in our SalesForce database), the example works great.  It authenticates, connects to the topic, and receives data as per normal until it gets to the 71st "heartbeat" connection, at which point it fails with the following message:

 

[CHANNEL:META_CONNECT]: {"id":"71","error":"402::Unknown client","successful":false,"advice":{"interval":500,"reconnect":"handshake"},"channel":"/meta/connect"}

 

Slightly more detailed error output says, Error during CONNECT: 402::Unknown client

 

The way we use the Streaming API client, we want it to always be up, and testing it overnight last night showed that after each connection error and restart, the client would get to the 70th heartbeat just fine, but on the 71st, it would have the same error each time.

 

(Our backend code processes the output of the streaming client and currently prints any messages received to a log file):

...

2012-03-26 16:32:42,316 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"67","successful":true,"channel":"/meta/connect"}
2012-03-26 16:34:32,117 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"68","successful":true,"channel":"/meta/connect"}
2012-03-26 16:36:22,174 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"69","successful":true,"channel":"/meta/connect"}
2012-03-26 16:36:55,122 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"70","successful":true,"channel":"/meta/connect"}
2012-03-26 16:36:55,630 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"71","error":"402::Unknown client","successful":false,"advice":{"interval":500,"reconnect":"handshake"},"channel":"/meta/connect"}
2012-03-26 16:36:56,143 - DEBUG - Received stream data: Error during CONNECT: 402::Unknown client
2012-03-26 16:36:56,658 - DEBUG - Received stream data: Exiting...
2012-03-26 16:37:04,791 - WARNING - Status poll of StreamingAPI indicates status '1'- not alive.

Is this normal behavior?  Has anyone run into this before?

 

-Max

Best Answer chosen by Admin (Salesforce Developers) 
VinodMVinodM

This is a temporary restriction for a release or two, due to some restrictions in our network configuration. It will go away soon. Yes we do realize that this timeout should be based on activity.

 

Regarding a recommended action, clients should restart with a handshake whenever they encounter "error: 402, Unknown Client". It can come because of various issues. The timeout is just one of them. Again we are working on improving our implementation and infrastructure to eliminate all those possibilies.

 

Regards,

Vinod.

All Answers

VinodMVinodM

What is the time difference between the time handshake was done and the time when you receive "Error during CONNECT: 402::Unknown client".

 

Thanks!

Vinod.

MaxPMageeMaxPMagee

The time between each handshake to the Unknown Client error, almost exactly 2 hours passes.  Here's an example of a full cycle from last night with a handshake of 11:29:02 PM and the error occurring at 01:29:01 AM 1 hour 59 minutes and 59 seconds later:

 

2012-03-28 23:28:58,613 - DEBUG - Starting Streaming API listener
2012-03-28 23:29:00,187 - DEBUG - Received stream data: Streaming API Connected
2012-03-28 23:29:00,695 - DEBUG - Received stream data: Endpoint: https://cs14-api.salesforce.com
2012-03-28 23:29:01,206 - DEBUG - Received stream data: Sessionid=00Dc00000000ST2!ARMAQBR5u_mxDejLUoib9bwy8Xsu1AVlBRFKQptSWIIX8YRalhrvMOHd304xoMOSXDSlh3j4oAtts.6OWlKmibwDIkDH.Jv1
2012-03-28 23:29:01,725 - DEBUG - Received stream data: Waiting for handshake
2012-03-28 23:29:02,233 - DEBUG - Received stream data: [CHANNEL:META_HANDSHAKE]: {"id":"1","minimumVersion":"1.0","supportedConnectionTypes":["long-polling"],"successful":true,"channel":"/meta/handshake","clientId":"8iklllclo2dpunrjqes3krgjzs","version":"1.0"}
2012-03-28 23:29:05,792 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"2","successful":true,"advice":{"interval":0,"reconnect":"retry","timeout":110000},"channel":"/meta/connect"}
2012-03-28 23:29:06,301 - DEBUG - Received stream data: Subscribing for channel: /topic/UnsignedXML
2012-03-28 23:29:06,810 - DEBUG - Received stream data: Ready to receive streaming data- waiting...
2012-03-28 23:29:07,320 - DEBUG - Received stream data: [CHANNEL:META_SUBSCRIBE]: {"id":"4","subscription":"/topic/UnsignedXML","successful":true,"channel":"/meta/subscribe"}
2012-03-28 23:29:10,881 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"3","successful":true,"channel":"/meta/connect"}
2012-03-28 23:31:03,476 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"5","successful":true,"channel":"/meta/connect"}
2012-03-28 23:33:01,731 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"6","successful":true,"channel":"/meta/connect"}
2012-03-28 23:34:50,973 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"7","successful":true,"channel":"/meta/connect"}
2012-03-28 23:36:41,166 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"8","successful":true,"channel":"/meta/connect"}
2012-03-28 23:38:31,212 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"9","successful":true,"channel":"/meta/connect"}
2012-03-28 23:40:21,284 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"10","successful":true,"channel":"/meta/connect"}
2012-03-28 23:42:11,350 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"11","successful":true,"channel":"/meta/connect"}
2012-03-28 23:44:01,087 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"12","successful":true,"channel":"/meta/connect"}
2012-03-28 23:45:51,362 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"13","successful":true,"channel":"/meta/connect"}
2012-03-28 23:47:41,225 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"14","successful":true,"channel":"/meta/connect"}
2012-03-28 23:49:31,517 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"15","successful":true,"channel":"/meta/connect"}
2012-03-28 23:51:21,281 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"16","successful":true,"channel":"/meta/connect"}
2012-03-28 23:53:11,776 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"17","successful":true,"channel":"/meta/connect"}
2012-03-28 23:55:01,537 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"18","successful":true,"channel":"/meta/connect"}
2012-03-28 23:56:51,774 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"19","successful":true,"channel":"/meta/connect"}
2012-03-28 23:58:41,880 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"20","successful":true,"channel":"/meta/connect"}
2012-03-29 00:00:31,689 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"21","successful":true,"channel":"/meta/connect"}
2012-03-29 00:02:22,210 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"22","successful":true,"channel":"/meta/connect"}
2012-03-29 00:04:11,984 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"23","successful":true,"channel":"/meta/connect"}
2012-03-29 00:06:01,876 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"24","successful":true,"channel":"/meta/connect"}
2012-03-29 00:07:51,994 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"25","successful":true,"channel":"/meta/connect"}
2012-03-29 00:09:42,277 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"26","successful":true,"channel":"/meta/connect"}
2012-03-29 00:11:32,108 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"27","successful":true,"channel":"/meta/connect"}
2012-03-29 00:13:22,335 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"28","successful":true,"channel":"/meta/connect"}
2012-03-29 00:15:12,596 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"29","successful":true,"channel":"/meta/connect"}
2012-03-29 00:17:02,451 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"30","successful":true,"channel":"/meta/connect"}
2012-03-29 00:18:52,691 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"31","successful":true,"channel":"/meta/connect"}
2012-03-29 00:20:42,519 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"32","successful":true,"channel":"/meta/connect"}
2012-03-29 00:22:32,840 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"33","successful":true,"channel":"/meta/connect"}
2012-03-29 00:24:22,661 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"34","successful":true,"channel":"/meta/connect"}
2012-03-29 00:26:12,779 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"35","successful":true,"channel":"/meta/connect"}
2012-03-29 00:28:03,026 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"36","successful":true,"channel":"/meta/connect"}
2012-03-29 00:29:52,606 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"37","successful":true,"channel":"/meta/connect"}
2012-03-29 00:31:43,097 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"38","successful":true,"channel":"/meta/connect"}
2012-03-29 00:33:33,186 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"39","successful":true,"channel":"/meta/connect"}
2012-03-29 00:35:23,042 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"40","successful":true,"channel":"/meta/connect"}
2012-03-29 00:37:13,265 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"41","successful":true,"channel":"/meta/connect"}
2012-03-29 00:39:03,607 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"42","successful":true,"channel":"/meta/connect"}
2012-03-29 00:40:53,440 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"43","successful":true,"channel":"/meta/connect"}
2012-03-29 00:42:43,725 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"44","successful":true,"channel":"/meta/connect"}
2012-03-29 00:44:33,367 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"45","successful":true,"channel":"/meta/connect"}
2012-03-29 00:46:23,605 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"46","successful":true,"channel":"/meta/connect"}
2012-03-29 00:48:13,931 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"47","successful":true,"channel":"/meta/connect"}
2012-03-29 00:50:03,688 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"48","successful":true,"channel":"/meta/connect"}
2012-03-29 00:51:53,957 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"49","successful":true,"channel":"/meta/connect"}
2012-03-29 00:53:43,790 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"50","successful":true,"channel":"/meta/connect"}
2012-03-29 00:55:34,036 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"51","successful":true,"channel":"/meta/connect"}
2012-03-29 00:57:23,727 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"52","successful":true,"channel":"/meta/connect"}
2012-03-29 00:59:13,914 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"53","successful":true,"channel":"/meta/connect"}
2012-03-29 01:01:03,853 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"54","successful":true,"channel":"/meta/connect"}
2012-03-29 01:02:53,812 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"55","successful":true,"channel":"/meta/connect"}
2012-03-29 01:04:44,315 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"56","successful":true,"channel":"/meta/connect"}
2012-03-29 01:06:34,119 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"57","successful":true,"channel":"/meta/connect"}
2012-03-29 01:08:24,351 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"58","successful":true,"channel":"/meta/connect"}
2012-03-29 01:10:14,264 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"59","successful":true,"channel":"/meta/connect"}
2012-03-29 01:12:04,522 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"60","successful":true,"channel":"/meta/connect"}
2012-03-29 01:13:54,281 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"61","successful":true,"channel":"/meta/connect"}
2012-03-29 01:15:44,488 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"62","successful":true,"channel":"/meta/connect"}
2012-03-29 01:17:34,766 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"63","successful":true,"channel":"/meta/connect"}
2012-03-29 01:19:24,529 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"64","successful":true,"channel":"/meta/connect"}
2012-03-29 01:21:14,763 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"65","successful":true,"channel":"/meta/connect"}
2012-03-29 01:23:04,955 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"66","successful":true,"channel":"/meta/connect"}
2012-03-29 01:24:54,749 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"67","successful":true,"channel":"/meta/connect"}
2012-03-29 01:26:44,971 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"68","successful":true,"channel":"/meta/connect"}
2012-03-29 01:28:35,006 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"69","successful":true,"channel":"/meta/connect"}
2012-03-29 01:29:00,989 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"70","successful":true,"channel":"/meta/connect"}
2012-03-29 01:29:01,495 - DEBUG - Received stream data: [CHANNEL:META_CONNECT]: {"id":"71","error":"402::Unknown client","successful":false,"advice":{"interval":500,"reconnect":"handshake"},"channel":"/meta/connect"}
2012-03-29 01:29:02,005 - DEBUG - Received stream data: Error during CONNECT: 402::Unknown client
2012-03-29 01:29:02,521 - DEBUG - Received stream data: Exiting...
2012-03-29 01:29:10,673 - WARNING - Status poll of StreamingAPI indicates status '1'- not alive.
2012-03-29 01:29:10,674 - INFO - Restarting StreamingAPI Listener

VinodMVinodM

Ah this is as designed. Salesforce enforces a max connection time on every client irrespective of connectivity.

 

http://www.salesforce.com/us/developer/docs/api_streaming/index.htm

 

<documentation>

maximum CometD session: 3600 seconds
A client subscription is valid for a maximum of 3600 seconds, irrespective of activity on the connection, therefore the client must handshake, subscribe, and connect before the session is timed out on the server side. A new subscription creates a new server session: the server timeout clock restarts again.
</documentation>
Only thing is the document is slightly outdated. We increased the limit to 2 hours (from 1 hour), but this document was not updated.
We'll have it corrected asap.
Thanks!
Vinod.
MaxPMageeMaxPMagee

Ahhhh.  I did see that notice in the documentation- I was looking for anything about a two-hour timeout, but figured that since the connection was still active after twice the 3600 second limit, that was not the problem.

 

Is there a graceful/recommended way to deal with this?  Should I attempt another handshake  every hour an a half or so?  I guess I don't like the idea of handling an error every two hours for a client that should be up as close to 100% as possible.

 

Or another way to put this is, why is there a restriction on the streaming API subscription time regardless of connectivity?  Should it be a timeout based on lack of connectivity?

 

Thanks for investigating,

Max

VinodMVinodM

This is a temporary restriction for a release or two, due to some restrictions in our network configuration. It will go away soon. Yes we do realize that this timeout should be based on activity.

 

Regarding a recommended action, clients should restart with a handshake whenever they encounter "error: 402, Unknown Client". It can come because of various issues. The timeout is just one of them. Again we are working on improving our implementation and infrastructure to eliminate all those possibilies.

 

Regards,

Vinod.

This was selected as the best answer