Page 1 of 2 12 LastLast
Results 1 to 10 of 13
  1. #1
    Senior Member
    Join Date
    Dec 2019
    Posts
    43

    Accumulated Delay

    Hi,

    My customers start complaining that there's an accumulated delay in receiving data, the client can be connected to different domains.

    I have the logs for both the server and the client, How can I know from the logs THAT THERE'S A DELAY IN THE STREAMING PROCESS,

    I can upload the logs.

    Regards

  2. #2
    Administrator
    Join Date
    Feb 2012
    Location
    Milano
    Posts
    692
    Hi ManKeer,

    If the delays involve only a subset of the clients and then we can exclude a general problem affecting the whole server you should look for the "NIO write queue" and "NIO write queue wait" metrics in the MonitorText logs.
    When these metrics show high values, and are constantly growing, it means that a part of the client sessions can not cope with the frequency of incoming real-time messages may be due to poor connectivity conditions or very slow devices, and the server accumulates delays in sending messages to them.

    Below an example of MonitorText log line with the mentioned metrics in evidence:

    "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 "


    In any case if the size of the logs is not very big you can send them to support@lightstreamer.com

    Regards,
    Giuseppe

  3. #3
    Senior Member
    Join Date
    Dec 2019
    Posts
    43
    Thank you very much @giuseppe.corti, I have sent the logs from my personal email "mankeer@gmail.com", I have attached the logs for both LS server and client,

    I need to know if this is a general problem [for all clients, I have about 7 to 10 clients keep claiming of this] or it's a specific problem for those clients only.

    I appreciate your help in this problem, I will be so thankful if you advice how can I distinguish this problem and how it can be solved.

    Regards

  4. #4
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    1,068
    Hi ManKeer,

    We have looked at the logs, but we too cannot find evidence of increasing delays, nor do we notice health problems on LS Server.
    Do you confirm that the client log you have sent us comes from one of your users who observed delays?
    The updates logged by the client library contain a timestamp coming from the Data Adapter and the difference between the client log timestamp and the data timestamp is stable at less than one second (apart from a timezone difference).
    As far as we can see, if a delay was in place, it must have occurred either in the Data Adapter, when acquiring the data, or in the client page, when visualizing the data.
    In fact, the update flow that reaches the client is significant, of various dozens of updates per second; hence slowness in processing, in some client scenarios, is a possibility.
    But, since the logs are huge, please ask your user to provide the exact time of a moment in which they see a delay and, if possible, a quantification of the delay; so we can focus the inspection.

    BTW, are you aware of the 61750 refusals of create_session requests by the Metadata Adapter occurring in a few hours, according to LS Server log?

  5. #5
    Senior Member
    Join Date
    Dec 2019
    Posts
    43
    Dear Dario,

    Thank you for your response, I have attached the logs of the data adapter in my emails.

    Unfortunately, I couldn't find any evidence for a delay from the data adapter side.

    Regarding the 61750 refusals, I have seen all of these but do these refusals can affect the LS performance?

    Regards

  6. #6
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    1,068
    The Adapter-side logs regard custom code and we aren't able to find clues about the update flow.
    Until we have a clear identification of the problem as the user perceives it, I don't think that we can proceed further.
    If you confirm that the issue affects only a few clients and doesn't affect the other ones, it is more likely that the problem is related with the client application's ability to keep the pace of the incoming updates while trying to process them.
    Please clarify if the client application's job is to visualize the data or to elaborate it internally.

    BTW, the client log regards February 27, that is, the day before the Server and Adapter logs.
    Could it be a mistake and perhaps the issue was observed on February 28 and never on February 27 ?

    The refusals don't seem to affect the performance. Only in case a client application gets several refusals before succeeding, this may be seen by the user as a delay. Until we have a clear identification of the problem as the user perceives it, this is also a possibility.
    Or perhaps this is just the evidence of another issue to be investigated.

  7. #7
    Senior Member
    Join Date
    Dec 2019
    Posts
    43
    Dear Dario,

    I have the following scenario on the server:

    Line 267015: 04-Apr-23 13:38:08,273|INFO |L.requests |SERVER POOLED THREAD 3380 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis =0&LS_idle_millis=0&LS_cid=pcYgxptg4pkpW39AN3R4hwL ri8L7R7q&LS_adapter_set=STOCKLISTDEMO&LS_user=2050 21&LS_password=[...]& on "Lightstreamer HTTP Server" from 10.244.210.1:22410
    Line 267016: 04-Apr-23 13:38:08,461|INFO |L.requests |SERVER POOLED THREAD 3379 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis =0&LS_idle_millis=0&LS_cid=pcYgxptg4pkpW39AN3R4hwL ri8L7R7q&LS_adapter_set=STOCKLISTDEMO&LS_user=2050 21&LS_password=[...]& on "Lightstreamer HTTP Server" from 10.244.210.1:57570
    Line 267023: 04-Apr-23 13:38:12,195|INFO |L.requests |SERVER POOLED THREAD 3428 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:26519
    Line 267024: 04-Apr-23 13:38:12,430|INFO |L.requests |SERVER POOLED THREAD 3427 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:48389
    Line 267035: 04-Apr-23 13:38:16,195|INFO |L.requests |SERVER POOLED THREAD 3433 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:51146
    Line 267036: 04-Apr-23 13:38:16,430|INFO |L.requests |SERVER POOLED THREAD 3433 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:9642
    Line 267044: 04-Apr-23 13:38:20,195|INFO |L.requests |SERVER POOLED THREAD 3433 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:16613
    Line 267051: 04-Apr-23 13:38:20,430|INFO |L.requests |SERVER POOLED THREAD 3395 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:61370
    Line 267107: 04-Apr-23 13:38:24,211|INFO |L.requests |SERVER POOLED THREAD 3410 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:20579
    Line 267108: 04-Apr-23 13:38:24,445|INFO |L.requests |SERVER POOLED THREAD 3408 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:13569
    Line 267117: 04-Apr-23 13:38:28,227|INFO |L.requests |SERVER POOLED THREAD 3297 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:15778
    Line 267118: 04-Apr-23 13:38:28,477|INFO |L.requests |SERVER POOLED THREAD 3411 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:7935
    Line 267138: 04-Apr-23 13:38:32,227|INFO |L.requests |SERVER POOLED THREAD 3445 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:28391
    Line 267139: 04-Apr-23 13:38:32,461|INFO |L.requests |SERVER POOLED THREAD 3445 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.create.timeout&LS_pol ling_millis=0&LS_idle_millis=0&LS_cid=pcYgxptg4pkp W39AN3R4hwLri8L7R7q&LS_adapter_set=STOCKLISTDEMO&L S_user=205021&LS_password=[...]&LS_old_session=& on "Lightstreamer HTTP Server" from 10.244.210.1:54842
    Line 267552: 04-Apr-23 13:39:31,764|INFO |L.requests |SERVER POOLED THREAD 3375 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis =0&LS_idle_millis=0&LS_cid=pcYgxptg4pkpW39AN3R4hwL ri8L7R7q&LS_adapter_set=STOCKLISTDEMO&LS_user=2050 21&LS_password=[...]& on "Lightstreamer HTTP Server" from 10.244.210.1:47873
    Line 267554: 04-Apr-23 13:39:31,795|INFO |L.requests |SERVER POOLED THREAD 3375 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis =0&LS_idle_millis=0&LS_cid=pcYgxptg4pkpW39AN3R4hwL ri8L7R7q&LS_adapter_set=STOCKLISTDEMO&LS_user=2050 21&LS_password=[...]& on "Lightstreamer HTTP Server" from 10.244.210.1:29280
    Line 267574: 04-Apr-23 13:39:32,686|INFO |L.requests |SERVER POOLED THREAD 3377 |Serving request: /lightstreamer/create_session.txt?LS_protocol=TLCP-2.1.0 --> LS_polling=true&LS_cause=new.api&LS_polling_millis =0&LS_idle_millis=0&LS_cid=pcYgxptg4pkpW39AN3R4hwL ri8L7R7q&LS_adapter_set=STOCKLISTDEMO&LS_user=2050 21&LS_password=[...]& on "Lightstreamer HTTP Server" from 10.244.210.1:9975



    Why do I receive multiple requests ? the client request one connection, so why do I receive this number of requests?

  8. #8
    Administrator
    Join Date
    Feb 2012
    Location
    Milano
    Posts
    692
    Hi ManKeer,

    If you are expecting only one client session, there are two strange things that can be inferred from this request list:

    1) It seems that there are two streams of parallel requests separated by about 200 milliseconds.
    Look for example at the first two, both of them with LS_cause=new.ap, that means that both are triggered by an explicit call of the connect method of the API.

    2) Then new attempts are noted every 4 seconds. This means that the client library fails to establish the session within the defined timeout, precisely 4 seconds, and then proceeds with a new attempt.
    Understanding why it fails is difficult with just this log excerpt, but it may be that the client is not receiving at all the create_request reply or the next attempt to bind is unsuccessful.
    Are you targeting a single instance of Lightstreamer server or a cluster of two or more instances? Because in the latter case maybe there are addressing problems, i.e. two requests from the same client end up at two different instances.

    Regards,
    Giuseppe

  9. #9
    Senior Member
    Join Date
    Dec 2019
    Posts
    43
    why do I receive this message " Unexpected update for item xxxx" ?

  10. #10
    Administrator
    Join Date
    Feb 2012
    Location
    Milano
    Posts
    692
    It means that the Lightstreamer server receives an update from the Data Adapter for an item name that actually doesn't currently have an active subscription for.

    Regards,
    Giuseppe

 

 

Similar Threads

  1. delay and strange behavior
    By ahmedsmart4tech in forum Adapter SDKs
    Replies: 7
    Last Post: August 19th, 2014, 02:11 PM
  2. Delay in retrieving data
    By New Soft in forum Client SDKs
    Replies: 3
    Last Post: July 7th, 2014, 09:57 AM
  3. Current delay in log file
    By faa666 in forum General
    Replies: 1
    Last Post: February 15th, 2012, 08:54 AM
  4. Unexpected Delay
    By omidqrose in forum General
    Replies: 2
    Last Post: May 23rd, 2011, 12:44 PM
  5. Delay in notifyUser() causes erratic create_session behavior
    By brianjohnson in forum Adapter SDKs
    Replies: 2
    Last Post: April 5th, 2010, 12:02 PM

Tags for this Thread

Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •  
All times are GMT +1. The time now is 01:35 AM.