Connection never recovered sometimes [Java]

romainmoreau

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 :

ProxyInfo proxyInfo = new ProxyInfo();
[B]proxyInfo.onFailedConnectionRetry = true;
proxyInfo.connectionRetryTimeoutMillis = 30000;[/B]

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 :

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.

Dario Crivelli

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.

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.

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 :

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
[B]2015-03-07 00:40:51.708  INFO 29175 --- [Stream-sense queue] f.r.ig.common.AbstractStreamingClient    : Connecting[/B]
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
[B]2015-03-07 00:40:51.819  INFO 29175 ---  [Thread-120]f.r.ig.common.AbstractStreamingClient    : Disconnected[/B] 
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 ?

Dario Crivelli

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.

romainmoreau

No problem, thanks for your help.