Closing connection 50 seconds - No response in between

stefanos

Websocket API closes the connection. It never sends PING. Most of the times it doesn't even respond to Login.

What I do is:
- authenticate with https://api.edp.thomsonreuters.com/auth/oauth2/beta1/token to get an auth token
- fetch the services list from https://api.edp.thomsonreuters.com/streaming/pricing/v1/
- choose a websocket tr_json2 service and connect to it
- send Login request

Here's my logs. Timestamps show it's probably a connection timeout.

2018-09-19 19:09:24.929 DEBUG 21238 --- [ main] test.pricing.tr.TrPriceService : Restarting socket
2018-09-19 19:09:26.269 DEBUG 21238 --- [ main] test.pricing.tr.TrPriceService : Got authentication token
2018-09-19 19:09:26.630 DEBUG 21238 --- [ main] test.pricing.tr.TrPriceService : Preferred server amer-3.pricing.streaming.edp.thomsonreuters.com
2018-09-19 19:09:27.055 INFO 21238 --- [ main] test.pricing.App : Starting NATS RPC handlers
2018-09-19 19:09:27.750 DEBUG 21238 --- [er@974861985-59] test.pricing.tr.TrSocketHandler : Socket open, sending login
2018-09-19 19:10:17.727 ERROR 21238 --- [er@974861985-62] test.pricing.tr.TrSocketHandler : Socket transport error: null null
2018-09-19 19:10:17.729 DEBUG 21238 --- [er@974861985-62] test.pricing.tr.TrSocketHandler : Connection closed
2018-09-19 19:10:17.729 DEBUG 21238 --- [er@974861985-62] test.pricing.tr.TrPriceService : Restarting socket
2018-09-19 19:10:18.599 DEBUG 21238 --- [er@974861985-62] test.pricing.tr.TrPriceService : Got authentication token
2018-09-19 19:10:18.819 DEBUG 21238 --- [er@974861985-62] test.pricing.tr.TrPriceService : Preferred server amer-3.pricing.streaming.edp.thomsonreuters.com
2018-09-19 19:10:19.526 DEBUG 21238 --- [r@1819034250-77] test.pricing.tr.TrSocketHandler : Socket open, sending login
2018-09-19 19:11:09.525 ERROR 21238 --- [r@1819034250-80] test.pricing.tr.TrSocketHandler : Socket transport error: null null
2018-09-19 19:11:09.525 DEBUG 21238 --- [r@1819034250-80] test.pricing.tr.TrSocketHandler : Connection closed
2018-09-19 19:11:09.525 DEBUG 21238 --- [r@1819034250-80] test.pricing.tr.TrPriceService : Restarting socket
2018-09-19 19:11:10.511 DEBUG 21238 --- [r@1819034250-80] test.pricing.tr.TrPriceService : Got authentication token
2018-09-19 19:11:10.718 DEBUG 21238 --- [r@1819034250-80] test.pricing.tr.TrPriceService : Preferred server amer-3.pricing.streaming.edp.thomsonreuters.com
2018-09-19 19:11:11.409 DEBUG 21238 --- [er@566763811-89] test.pricing.tr.TrSocketHandler : Socket open, sending login
2018-09-19 19:11:11.525 DEBUG 21238 --- [er@566763811-92] test.pricing.tr.TrSocketHandler : Received message TextMessage payload=[[{"ID":-1,..], byteCount=816, last=true]
2018-09-19 19:11:11.526 DEBUG 21238 --- [er@566763811-92] test.pricing.tr.TrSocketHandler : Socket Message
2018-09-19 19:11:11.526 DEBUG 21238 --- [er@566763811-92] test.pricing.tr.TrSocketHandler : [{"ID":-1,"Type":"Refresh","Domain":"Login","Key":{"Name":"AQIC5wM2LY4SfcxUGSjazBbmE7EbB%2FxOWPc3QEFRFz2BXlI%3D%40AAJTSQACMjAAAlNLABQtODY2NjI3NzExNTMwNDgxMzA5MAACUzEAAjM0%23","Elements":{"AllowSuspectData":1,"ApplicationId":"256","ApplicationName":"ADS","AuthenticationErrorCode":0,"AuthenticationErrorText":{"Type":"AsciiString","Data":null},"AuthenticationTTReissue":1537373770,"Position":"127.0.1.1","ProvidePermissionExpressions":1,"ProvidePermissionProfile":0,"SingleOpen":1,"SupportEnhancedSymbolList":1,"SupportOMMPost":1,"SupportPauseResume":0,"SupportStandby":0,"SupportBatchRequests":7,"SupportViewRequests":1,"SupportOptimizedPauseResume":0}},"State":{"Stream":"Open","Data":"Ok","Text":"Login accepted by host ads-premium-az2-blue-3-main-prd.use1-az2."},"Elements":{"PingTimeout":30,"MaxMsgSize":61430}}]
2018-09-19 19:11:11.534 INFO 21238 --- [er@566763811-92] test.pricing.tr.TrSocketHandler : Socket connected and authenticated
2018-09-19 19:12:01.566 ERROR 21238 --- [er@566763811-89] test.pricing.tr.TrSocketHandler : Socket transport error: null null
2018-09-19 19:12:01.566 DEBUG 21238 --- [er@566763811-89] test.pricing.tr.TrSocketHandler : Connection closed
2018-09-19 19:12:01.566 DEBUG 21238 --- [er@566763811-89] test.pricing.tr.TrPriceService : Restarting socket
2018-09-19 19:12:02.343 DEBUG 21238 --- [er@566763811-89] test.pricing.tr.TrPriceService : Got authentication token
2018-09-19 19:12:02.597 DEBUG 21238 --- [er@566763811-89] test.pricing.tr.TrPriceService : Preferred server amer-3.pricing.streaming.edp.thomsonreuters.com
2018-09-19 19:12:03.301 DEBUG 21238 --- [@1108813670-104] test.pricing.tr.TrSocketHandler : Socket open, sending login
2018-09-19 19:12:53.299 ERROR 21238 --- [@1108813670-107] test.pricing.tr.TrSocketHandler : Socket transport error: null null
2018-09-19 19:12:53.300 DEBUG 21238 --- [@1108813670-107] test.pricing.tr.TrSocketHandler : Connection closed
2018-09-19 19:12:53.300 DEBUG 21238 --- [@1108813670-107] test.pricing.tr.TrPriceService : Restarting socket

stefanos

You are right, the example works.

I removed the authentication cookie and placed the access token in the Login message after socket is established and I got proper response and pings.

stefanos

That's 4 requests, the 3rd one actually got a Login response

nick.zincone

Hi @stefanos,

Can you provide more details around how you are logging in? Are you sending an explicit login request after you connect? Or are you using the TREP Authentication feature where you set the authentication token details within a cookie when you connect?

One thing to rule out is to go through the quick start and run the example code to see if you notice similar behavior.

When I connect, I notice a Ping message every 15 seconds or so. Are you able to log all traffic coming into your onWebSocketMessage callback?

stefanos

Hi @nick.zincone

Here's the details:

Handshake request headers: {Accept-Encoding=[gzip], Cache-Control=[no-cache], Connection=[Upgrade], Cookie=[AuthToken=*masked*;AuthPosition=127.0.1.1;applicationId=256;], Pragma=[no-cache], Sec-WebSocket-Extensions=[permessage-deflate], Sec-WebSocket-Key=[*masked*], Sec-WebSocket-Protocol=[tr_json2], Sec-WebSocket-Version=[13], Upgrade=[websocket], User-Agent=[Jetty/9.4.9.v20180320]} Handshake response headers: {Connection=[Upgrade], Sec-WebSocket-Accept=[*masked*], Sec-WebSocket-Extensions=[permessage-deflate], Sec-WebSocket-Protocol=[tr_json2], Upgrade=[websocket]}

I use the access_token I got from oauth as AuthToken

Handshake response headers: {Connection=[Upgrade], Sec-WebSocket-Accept=[*masked*], Sec-WebSocket-Extensions=[permessage-deflate], Sec-WebSocket-Protocol=[tr_json2], Upgrade=[websocket]}

When socket upgrades I send this:

{"Domain":"Login","ID":1,"Key":{"Elements":{"ApplicationId":"256","Position":"127.0.1.1"},"Name":"MyName"}}

nick.zincone

https://community.developers.refinitiv.com/discussion/comment/32255#Comment_32255

Hi @stefanos,

Great. I'm currently using the authentication cookie to login to the server. When you use the cookie, you don't need to send an explicit login message as well. I haven't actually tried to set the cookie and also send an explicit login but I would suspect it may produce unpredictable results. In either case, you will still need to send an explicit login to refresh your tokens.