Lightstreamer getting issue on connection get grows

Printable View

June 20th, 2018, 01:21 PM
rvkvino

Lightstreamer getting issue on connection get grows

Hello,
We are facing the issue like connection getting disconnect on particular time(We are facing this issue on every day 6.30 PM exactly Indian time). We are using the Lightstreamer server with java remote adapter. Everything is working fine and client getting response from LS server. Adapter also working fine and sending data to LS server.

But for everyday 6.30 PM we are facing the issue like connection getting too over, we monitor the dashboard. Clients connection are getting close and reconnect or reopen the connection. LS server getting not responsible getting struggle to handle the connection.

I have attached some logs in this,
Suddenly got increased the connection and LS not respond to clients. I have faced some error on morning and also while facing the issue , I have below attached the errors from dashboard and screenshots. For Indian time 6.30 daily facing this issue. How to find whether my LS adapter code having issue or some other things getting issue.

13:47:06,260SERVER POOLED THREAD 7Unexpected error in notifyUser: Connection closed while facing request 620000016415aec77e:
13:47:06,260SERVER POOLED THREAD 7Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request 620000016415aec77e.
13:47:06,354SERVER POOLED THREAD 28Unexpected error in notifyUser: Connection closed while facing request 630000016415aec77e:
13:47:06,354SERVER POOLED THREAD 28Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request 630000016415aec77e.
13:47:11,783SERVER POOLED THREAD 31Unexpected error in notifyUser: Connection closed while facing request 640000016415aec77e:
13:47:11,783SERVER POOLED THREAD 31Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request 640000016415aec77e.

18:35:18,625SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fba0000016415b1fc70.
18:35:18,625SERVER POOLED THREAD 29Unexpected error in notifyUser: Connection closed while facing request f9fbb0000016415b1fc70:
18:35:18,625SERVER POOLED THREAD 29Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fbb0000016415b1fc70.
18:35:18,625SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request f9fbc0000016415b1fc70:
18:35:18,625SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fbc0000016415b1fc70.
18:35:18,641SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request f9fbd0000016415b1fc70:
18:35:18,859SERVER POOLED THREAD 25Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fd50000016415b1fc70.
18:35:18,859SERVER POOLED THREAD 5Unexpected error in notifyUser: Connection closed while facing request f9fd60000016415b1fc70:
18:35:18,859SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fd60000016415b1fc70.
18:35:18,875SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request f9fd70000016415b1fc70:
18:35:18,875SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fd70000016415b1fc70.
18:35:19,015SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fe60000016415b1fc70.
18:35:19,015SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request f9fe70000016415b1fc70:
18:35:19,015SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fe70000016415b1fc70.
18:35:19,046SERVER POOLED THREAD 5Unexpected error in notifyUser: Connection closed while facing request f9fe80000016415b1fc70:
18:35:19,046SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9fe80000016415b1fc70.
18:35:19,296SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9ffb0000016415b1fc70.
18:35:19,312SERVER POOLED THREAD 29Unexpected error in notifyUser: Connection closed while facing request f9ffc0000016415b1fc70:
18:35:19,312SERVER POOLED THREAD 29Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request f9ffc0000016415b1fc70.
18:35:19,343SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request f9ffd0000016415b1fc70:
18:35:19,673SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0140000016415b1fc70.
18:35:19,673SERVER POOLED THREAD 25Unexpected error in notifyUser: Connection closed while facing request fa0150000016415b1fc70:
18:35:19,673SERVER POOLED THREAD 25Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0150000016415b1fc70.
18:35:19,673SERVER POOLED THREAD 5Unexpected error in notifyUser: Connection closed while facing request fa0160000016415b1fc70:
18:35:19,673SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0160000016415b1fc70.
18:35:19,736SERVER POOLED THREAD 25Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa01f0000016415b1fc70.
18:35:19,736SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request fa0200000016415b1fc70:
18:35:19,736SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0200000016415b1fc70.
18:35:19,751SERVER POOLED THREAD 25Unexpected error in notifyUser: Connection closed while facing request fa0210000016415b1fc70:
18:35:19,751SERVER POOLED THREAD 25Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0210000016415b1fc70.
18:35:19,783SERVER POOLED THREAD 5Unexpected error in notifyUser: Connection closed while facing request fa0220000016415b1fc70:
18:35:19,783SERVER POOLED THREAD 29Unexpected error in notifyUser: Connection closed while facing request fa0230000016415b1fc70:
18:35:19,783SERVER POOLED THREAD 5Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0220000016415b1fc70.
18:35:19,783SERVER POOLED THREAD 29Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0230000016415b1fc70.
18:35:19,798SERVER POOLED THREAD 19Unexpected error in notifyUser: Connection closed while facing request fa0240000016415b1fc70:
18:35:19,798SERVER POOLED THREAD 19Failure in request processing: External error while managing the request: Unexpected error in notifyUser: Connection closed while facing request fa0240000016415b1fc70.
June 21st, 2018, 09:02 AM
giuseppe.corti

I can confirm that errors you reported us are due to a connection interruption between the Lightstreamer server and your remote Metadata Adapter.
Maybe the implementation of notifyUser method in the custom code of your Metatadata Adapter got some errors: it seems that instead of replying to the server your adapter closes the connection in the case of user validation request.

Given the periodic recurrence, the issue could be caused by a burst of requests that always occurs regularly at the same time.
What do you do within the notifyUser method? Maybe some request to DB or other external services that can saturate and get stuck in case of overload?

Regards,
Giuseppe
June 21st, 2018, 02:16 PM
rvkvino

Hello,
In this notifyuser method i'm only doing following check

String origin = (String) httpHeaders.get("origin");
String un = (String) httpHeaders.get("username");

if ((origin == null) || VALUES.contains(origin)) {
if ((un == null) || !un.equalsIgnoreCase("sitekey")) {
throw new AccessException("Invalid User Access");
}
} else {
if ((un == null) || !un.equalsIgnoreCase("appkey")) {
throw new AccessException("Invalid User Access");
}
}
didn't check any database check and all. Only checking request(client) coming from my domains. Here we are serving the response to 30 domains. Is it will any issue?
And also I have one more doubt for this every 30 domains having many clients request and this adapter writing the log about items details in console. Is this will get affect or get any memory leak?
June 21st, 2018, 05:09 PM
giuseppe.corti

So this means that the Metadata Adapter was already down but didn't reconnect or reconnect with some delays.

You should look in the log file for the exact moment where the Metadata Adapters go down, and messages like this "Reply receiver '...' stopped". Once identified the moment of the disconnection we will try to understand the causes.

Regards,
Giuseppe
June 22nd, 2018, 07:20 AM
rvkvino

Hello,
I have checked my log fully I couldn't find the text as like Reply receiver or stopped.
I can see Monitor Text log as like below,
MonitorText|Timer-0 |Total threads = 460, Total heap = 244318208 (free = 22652368), Sessions = 3159 (max = 3175), New sessions = [+20, -11], Connections = 3481 (max = 3575), New connections = [+57, -53], In-pool threads = 128, Active threads = 3, Available threads = 124, Queued tasks = 2, Pool queue wait = 0, NIO write queue = 84, NIO write queue wait = 1872051, NIO write selectors = 32, NIO total selectors = 128, Subscribed items = 47 (for 25462 subscriptions), Inbound throughput = 118.29 updates/s (pre-filtered = 118.29), Outbound throughput = 12841.95 updates/s (7242.07 kbit/s, max = 11693.98), Lost updates = 0 (total = 0), Total bytes sent = 9256882462, Client messages throughput = 0 msgs/s (0 kbit/s, max = 0), Total messages handled = 0, Extra sleep = 0, Notify delay = 0

MonitorText|Timer-0 |Total threads = 460, Total heap = 240648192 (free = 47881336), Sessions = 3159 (max = 3175), New sessions = [+15, -16], Connections = 3433 (max = 3575), New connections = [+48, -37], In-pool threads = 128, Active threads = 0, Available threads = 128, Queued tasks = 0, Pool queue wait = 1, NIO write queue = 81, NIO write queue wait = 1944088, NIO write selectors = 32, NIO total selectors = 128, Subscribed items = 47 (for 25492 subscriptions), Inbound throughput = 48.21 updates/s (pre-filtered = 48.21), Outbound throughput = 8369.78 updates/s (4749.05 kbit/s, max = 11693.98), Lost updates = 0 (total = 0), Total bytes sent = 9257904075, Client messages throughput = 0 msgs/s (0 kbit/s, max = 0), Total messages handled = 0, Extra sleep = 0, Notify delay = 0

MonitorText|Timer-0 |Total threads = 460, Total heap = 236453888 (free = 83240984), Sessions = 3121 (max = 3175), New sessions = [+1, -9], Connections = 3496 (max = 3575), New connections = [+87, -28], In-pool threads = 128, Active threads = 34, Available threads = 94, Queued tasks = 395, Pool queue wait = 206, NIO write queue = 59, NIO write queue wait = 2665444, NIO write selectors = 32, NIO total selectors = 128, Subscribed items = 47 (for 25074 subscriptions), Inbound throughput = 71.04 updates/s (pre-filtered = 70.54), Outbound throughput = 10539.99 updates/s (3668.51 kbit/s, max = 11693.98), Lost updates = 0 (total = 0), Total bytes sent = 9260424295, Client messages throughput = 0 msgs/s (0 kbit/s, max = 0), Total messages handled = 0, Extra sleep = 2, Notify delay = 0

MonitorText|Timer-0 |Total threads = 460, Total heap = 231735296 (free = 16710304), Sessions = 3148 (max = 3175), New sessions = [+16, -12], Connections = 3473 (max = 3575), New connections = [+52, -37], In-pool threads = 128, Active threads = 4, Available threads = 124, Queued tasks = 0, Pool queue wait = 0, NIO write queue = 64, NIO write queue wait = 2457239, NIO write selectors = 32, NIO total selectors = 128, Subscribed items = 47 (for 25363 subscriptions), Inbound throughput = 116.3 updates/s (pre-filtered = 116.3), Outbound throughput = 13418.99 updates/s (6259.6 kbit/s, max = 11693.98), Lost updates = 0 (total = 0), Total bytes sent = 9265303321, Client messages throughput = 0 msgs/s (0 kbit/s, max = 0), Total messages handled = 0, Extra sleep = 0, Notify delay = 0
June 22nd, 2018, 09:29 AM
giuseppe.corti

I'm really puzzled that you didn't find any evidence of adapter disconnections.
Please consider that the disconnection may have happened a long time (several hours) before than the error messages you reported. Furthermore maybe your porxy adapter log settings are not as expected.

So I think it's better if you focus on your remote Adapter program and check if continues to run non-stop and if there is any loss of communication with the server.

Regards,
Giuseppe
June 22nd, 2018, 02:41 PM
rvkvino

Hello,
This issue we have temporarily solved as restart adapter for twice per day. So today we restart the LS server on morning 6.30 A.M and after noon 2 P.M we closed and reopened the remote adapter so we didn't face this issue like connection close on 6 P.M to 7.P.M range. We think any memory leak on this whether LS server or remote adapter. Is there any way to clear the screen of adapter or memory.
June 25th, 2018, 09:35 AM
giuseppe.corti

Hi Vinoth Kumar,

The only way to influence the memory held by the server is through the 'clear snapshot' request that your Data Adapter can issue for the subscribed Items.
But it would be preferable to investigate the issue to determine where the leak resides and resolve it.

Regards,
Giuseppe
June 28th, 2018, 06:12 AM
rvkvino

Hello,
i have created an adopter and connecting XXX number of different sites and streaming the data. on each time gap for example from the start time of the adopter on every 12 hours approximately it get stuck in peak hours. We need to know is there any memory limitations for each adopter which we build or any other limitation to be cleared on periodical basis.

If I restart my adapter 2 times per day then working fine without any issue.

And also I need to know how dynamically clear snapshot and recreate snapshot. It should be clear if data adapter held my memory issue or if it is any periodically need to clear the snapshot.
June 29th, 2018, 10:17 AM
giuseppe.corti

Are there in your adapters code some data structure as a queue or a map? Indeed these are potential candidates to generate memory leaks since they can grow indefinitely if not properly managed.
The Lightstreamer server releases the memory occupied by the snapshot for an Item in two cases:
1. no more client subscribe the involved Item;
2. the Data Adapter esplicitily call the clearSnapshot.

That said, have you tried to check the statistics of the memory occupied looking for the MonitorText logger lines?
If configured at the trace level it records the information every 2 seconds and can give a general overview of the progress of the memory.

Regards,
Giuseppe
July 13th, 2018, 11:34 AM
rvkvino

Hello,
Now I have an issue like when the user close the tab that time session and connection automatically managed by lightstreamer. But when I check in my windows server currPorts in 8080 lot of connection in Time Wait and Close Wait status. Could you please let me know how the connection properly close in LS adapter or LS server. Because If connection in Close Wait or Time_Wait means lot of resources are using and getting memory leak and high CPU usages. So Please let me know the proper way to avoid this issue.
July 16th, 2018, 09:09 AM
giuseppe.corti

Hi Vinoth Kumar,

You could call explicitly the disconnect() method but I don't know if in your client you can properly identify how trigger the call.
In any case TIME_WAIT and CLOSE_WAIT on the tcp sockets are strongly dependent on any network intermediary like proxies or other devices in the middle between client and server.

Regards,
Giuseppe
July 19th, 2018, 08:57 AM
giuseppe.corti

Hi Vinoth Kumar,

No, I confirm that no java.exe have to start for each new client connection.
The picture you attached is quite small, but it seems however that the process id is always the same and therefore correctly all the tcp connections are handle by the same jvm running the Lightstreamer server.

The jvm running the Lightstreamer server listens on the tcp ports defined in your lightstreamer_conf.xml and then for each a client connection a dedicated tcp connection is established.
You can check the number of tcp connections established managed by the server in the log (MonitorText lines) or in the Monitoring Dashboard.

Regards,
Giuseppe
July 20th, 2018, 08:15 AM
giuseppe.corti

Hi Vinoth Kumar,

As you can see from the process id column, which always contains the same value, the java.exe process is just only one.
The situation is correct, as you have to expect a connection established for each client connected to the server.

This is not an issue.

Regards,
Giuseppe
July 20th, 2018, 08:53 AM
rvkvino

Hello,
But my server persons are saying there is the cause of the issue is due to the java application that's being run and is creating many connections to the server and not closing them properly. And the servers seems to have usage and there are many "ESTABLISHED" states in 8080 port. They are saying more process in 8080 with established and Time_wait state for java.exe. This only issue to get 100% cpu usages. I need your suggestion and help to solve this issue.
July 20th, 2018, 09:34 AM
giuseppe.corti

Hi Vinoth Kumar,

But please let me stress out that this is not an issue, it is normal that your server has an established connection for each connected client.
If you want to handle 50K concurrent clients you have to expect 50K tcp ports established in your server.
And also a certain number of tcp connections in Time_Wait or Close_Wait is also expected especially if you have a high rate of session turnover, ie sessions that start and end continuously.

Regards,
Giuseppe