Connection never recovered sometimes [Java]

Printable View

February 28th, 2015, 10:51 AM
romainmoreau

Connection never recovered sometimes [Java]

Hello,

I'm using a LSProxy to receive various updates using the latest client (2.5.2 build 1110).

The LSProxy is initialized in a pretty straightforward way :

Code:

ProxyInfo proxyInfo = new ProxyInfo(); proxyInfo.onFailedConnectionRetry = true; proxyInfo.connectionRetryTimeoutMillis = 30000; LSProxy lsProxy = new LSProxy(proxyInfo, this, this); ConnectionInfo connectionInfo = new ConnectionInfo(); connectionInfo.pushServerUrl = "..."; connectionInfo.user = "..."; connectionInfo.password = "..."; lsProxy.startPushConnection(connectionInfo);

It works great most of time but sometimes I get this behaviour :

Code:

2015-02-25 01:24:38.691 INFO 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Stalled 2015-02-25 01:24:42.035 WARN 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Streaming failure 2015-02-25 01:24:42.036 INFO 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Disconnected 2015-02-25 01:24:42.046 INFO 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Retry on streaming failure 2015-02-25 01:24:42.061 ERROR 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Retrying connection com.lightstreamer.ls_proxy.PushException: No data from server at com.lightstreamer.ls_proxy.ConnectionHandler$ExtendedConnectionListener.onFailure(ConnectionHandler.java:245) at com.lightstreamer.ls_client.ExtConnectionListener$10.run(ExtConnectionListener.java:195) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 2015-02-25 01:24:42.068 INFO 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Connecting 2015-02-25 01:24:54.207 INFO 4034 --- [Thread-11] f.r.ig.common.AbstractStreamingClient : Disconnected 2015-02-25 01:24:54.208 WARN 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Reconnection failure 2015-02-25 01:25:24.208 INFO 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Retry after reconnection failure 2015-02-25 01:25:24.209 INFO 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Connecting 2015-02-25 01:25:24.339 INFO 4034 --- [Thread-14] f.r.ig.common.AbstractStreamingClient : Disconnected 2015-02-25 01:25:24.340 WARN 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Reconnection attempt failure 2015-02-25 01:25:54.340 INFO 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Retry after reconnection failure 2015-02-25 01:25:54.341 INFO 4034 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Connecting 2015-02-25 01:26:24.342 INFO 4034 --- [Thread-16] f.r.ig.common.AbstractStreamingClient : Disconnected 2015-02-25 01:26:24.343 WARN 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Reconnection attempt failure 2015-02-25 01:26:54.344 INFO 4034 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Retry after reconnection failure

The "Connecting, Disconnected, Reconnection attempt failure, Retry after reconnection failure" pattern keeps repeating itself, the connection is never recovered.

What could be the cause of such kind of problem ?

Thanks.
March 2nd, 2015, 10:37 AM
DarioCrivelli

The pattern is strange, because the first attempt fails in 8 seconds, the second one fails immediately, then the subsequent ones fail after 30 seconds (which is the default connection timeout).

If you can replicate the issue locally, please expand the log, by configuring the level for the "com.lightstreamer.ls_proxy.connection", "com.lightstreamer.ls_client.session", and "com.lightstreamer.ls_client.stream" loggers as FINER, then attach the log.
This should clarify what happens during the connection attempts.
March 2nd, 2015, 09:36 PM
romainmoreau

Thanks for your answer, I can't replicate on demand but I modified the levels and I will post here the log when it happens again ; until now, it was at most once a week.
March 8th, 2015, 05:22 PM
romainmoreau

It seems like the server is being rebooted ; since the password I use is dynamic (session related) and the old one is used to reconnect, the following behaviour keeps happening :

Code:

2015-03-07 00:40:51.707 INFO 29175 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Retry after reconnection failure 2015-03-07 00:40:51.707 DEBUG 29175 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Connection attempt for https://xxxx.com - NO CONSTRAINTS 2015-03-07 00:40:51.708 INFO 29175 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient : Connecting 2015-03-07 00:40:51.708 DEBUG 29175 --- [Background connection opening] com.lightstreamer.ls_proxy.connection : Opening new connection 2015-03-07 00:40:51.709 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.session : Connecting for a new session 2015-03-07 00:40:51.710 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.protocol : Opening stream connection 2015-03-07 00:40:51.710 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.protocol : Connection params: {LS_password=XXXXXXXXXXXXX, LS_adapter_set=DEFAULT, LS_content_length=50000000, LS_report_info=true, LS_user=XXXXXXXX} 2015-03-07 00:40:51.710 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.stream : Opening connection to https://xxxx.com/lightstreamer/create_session.txt 2015-03-07 00:40:51.817 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.session : Starting new session 2015-03-07 00:40:51.818 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.actions : Notifying an exception on the current connection 2015-03-07 00:40:51.818 DEBUG 29175 --- [Thread-121] com.lightstreamer.ls_client.stream : Closing create connection 2015-03-07 00:40:51.819 DEBUG 29175 --- [Thread-120] com.lightstreamer.ls_proxy.connection : Failed to open new connection 2015-03-07 00:40:51.819 INFO 29175 --- [Thread-120] f.r.ig.common.AbstractStreamingClient : Disconnected 2015-03-07 00:40:51.819 DEBUG 29175 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Connection attempt unsuccessful for https://xxxx.com - NO CONSTRAINTS 2015-03-07 00:40:51.819 WARN 29175 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Reconnection attempt failure 2015-03-07 00:40:51.819 DEBUG 29175 --- [Stream-sense queue] com.lightstreamer.ls_proxy.connection : Reconnection attempt failure com.lightstreamer.ls_proxy.ConnectException: User/password check failed at com.lightstreamer.ls_proxy.ConnectionHandler$1.run(ConnectionHandler.java:319)

The problem is that my client doesn't know that it needs to recreate a new password because the only callbacks called are PushStatusListener.onConnecting and PushStatusListener.onDisconnected (highlighted in bold in the previous log).

How could my client find out that the reconnection attempt failure is because of a user/password check failed ?
March 9th, 2015, 11:15 AM
DarioCrivelli

I see; the simple recovery mechanism offered by the ls_proxy layer is too simple for this case.
This means that you cannot take advantage of the internal reconnection loop that follows when you set connectionRetryTimeoutMillis to a nonzero value.
By setting connectionRetryTimeoutMillis to 0, your code will receive a onFailedReconnection invocation on the PushErrorListener, with a suitable PushException. Then, by invoking rethrow() on this exception, you will get the original PushUserException with the relevant error code, based on which you should setup the proper recovery action.
Sorry for the hassle.
March 9th, 2015, 06:20 PM
romainmoreau

No problem, thanks for your help.