Session closed

EWANG

We noticed some strange behavior. Some users stopped receiving messages after session established, and the time it happened after new session seems random from 1 minute to more than 20 minutes. Connection was still valid, but server received notifySessionClose().

Any clue why this happens? And suggestion for troubleshooting?

Thanks

Dario Crivelli

Do you mean that, when notifySessionClose was invoked, the connection was still valid on the client side or on the server side? (the latter case would be quite unexpected).
After stopping receiving updates, did the client detect the problem and go into STALLED state and eventually start a new session?
Can you identify the case on the Server log and show us a significant snippet?

EWANG

Thank you Dario for responding.

The session was still valid on client side and was waiting for new messages which server will never push to anymore.

One more thing. If client is in polling mode, and the message pushed between two polling request, will the message still be pushed to client? Even for some reason some polling request not reached server? Like this (29-33 missing)
09:30:00 10.35.56.153 10.35.56.153 Polling (28) to session: S384410adb026c838T2016441
09:30:48 10.35.56.153 10.35.56.153 Polling (34) to session: S384410adb026c838T2016441

Thanks

Dario Crivelli

The push to polling sessions is complete: updates are not discarded, though they may be filtered, if filtering rules apply. Polling works very similar to streaming with bandwidth restrictions.
Only a few of the polling requests are logged, but the reported numbers ensure that all the counted polls have occurred (the full log is available at DEBUG level).

Your case is still unclear.
A web client should not be waiting forever for data if the corresponding session has been closed on the server side.
In fact, the client would no longer receive the "probe" messages and would eventually enter STALLED state and finally try a reconnection.
Can you confirm that the client did not recover?
It might have happened something different, but we need more details to make any guess.

EWANG

this case happened when user in the polling mode so it makes things more strange. Since it's polling, there is no persistent connection. What could make client think the session is still valid even the session is closed on the server?

Mone

hi EWANG,
which client build are you using?

EWANG

it happens to two type clients:
Lightstreamer Silverlight Client Library version 1.1.3537.25900
Lightstreamer Web Client Library version 4.3.1 build 1355.3

here is the sequence for one example:

Server log:
12:23:20,754 |INFO |LightstreamerLogger.requests |SERVER POOLED THREAD 2 |Starting new session: Sb84ee213e3d2eb08T2320753 from 10.35.185.113:40654
12:23:21,055 |INFO |LightstreamerLogger.requests |SERVER POOLED THREAD 8 |Serving request: /lightstream/control.txt?LS_session=Sb84ee213e3d2eb08T2320753&LS_op=add&LS_table=1&LS_id=ADAPTER&LS_mode=RAW&LS_schema=MESSAGEID+DATA+MESSAGE_TS&LS_data_adapter=DATA_ADAPTER from 10.35.185.113:40654
12:23:21,056 |INFO |LightstreamerLogger.requests |SERVER POOLED THREAD 8 |Controlling session: Sb84ee213e3d2eb08T2320753 from 10.35.185.113:40654
12:23:51,297 |INFO |LightstreamerLogger.requests |SERVER POOLED THREAD 2 |Polling (2) to session: Sb84ee213e3d2eb08T2320753 from 10.35.185.113:40652
.....
13:04:30,879 |INFO |LightstreamerLogger.requests |SERVER POOLED THREAD 1 |Polling (83) to session: Sb84ee213e3d2eb08T2320753 from 10.35.185.113:41139

In the metadata adapter log:
13:05:05,885 |INFO |Logger.METADATA |FOR PUMPS PARKING DESTROYER|User 139d2143-e865-4757-9d24-9e56b13071af has 0 concurrent session(s).

But after this all the bin_session.txt request still got 200 back but client stopped receiving data

Thanks

Dario Crivelli

If I understand well, after 13:05:05, the client performs polling requests that get a 200 answer,
but you can't find any corresponding log on the server side
and the client receives no data.

This has no explaination. In order to investigate on this, we would need some details, which means:

the full Server log after 13:05:05;
note that not all bind_session requests are logged by default, but you can have all of them logged (in a test environment) by setting the LightstreamerLogger.requests.polling category to INFO level.
a concrete evidence of the successful responses got by the client;
did you find them through a packet sniffing?