Results 1 to 5 of 5
  1. #1
    Member
    Join Date
    Jan 2021
    Location
    Frankfurt am Main
    Posts
    4

    Error message "Subscribe request come too late"

    Recently we started receiving following error messages, which we think come from the Lightstreamer library:

    29-Dec-20 07:10:03,867|ERROR|Adapters.OURPROXYNAME.DEFAULT|pter.DEFAULT Reply Receiver|Exception caught while subscribing to item 'OUR_PRODUCT_IDENTIFIER'
    com.lightstreamer.interfaces.data.SubscriptionExce ption: Subscribe request come too late
    at com.lightstreamer.adapters.proxy.data.DataProvider Protocol.readSubscribe(DataProviderProtocol.java:1 44)
    at com.lightstreamer.adapters.proxy.data.RemoteDataPr ovider$2.onReplyReceived(RemoteDataProvider.java:2 18)
    at com.lightstreamer.adapters.proxy.request_reply.Req uestSender.onNotifyReceived(RequestSender.java:389 )
    at com.lightstreamer.adapters.proxy.request_reply.Not ifyReceiver.onNotifyReceived(NotifyReceiver.java:2 44)
    at com.lightstreamer.adapters.proxy.request_reply.Not ifyReceiver.run(NotifyReceiver.java:115)
    Would you be able to tell us what may be the cause of the error above?
    We were not seeing those errosr before and we think it may be related to the performance of the infrastructure.
    LS version used: 7.2.0

  2. #2
    Administrator
    Join Date
    Feb 2012
    Location
    Milano
    Posts
    716
    Hi Tomas,

    Yes I can confirm that this kind of error may be due to slowdowns in the execution of client requests.
    In particular this specific error means that a subscribe request from a client was processed once the client session involved was already closed.

    You could also double check the server log looking for messages like this: "Current delay for tasks scheduled on thread pool ... is ... seconds".
    And also look at the "Queued tasks" metric in the MonitorText lines: if the values are consistently greater than zero then client requests are accumulating delays.

    Then you should look for the causes of these delays, they could be due to external slowdowns such as calls to external services in your adapters which sometimes take longer than normal.
    Or the load is simply too high for the environment deployed. But for this type of analysis it is necessary to have more information.

    Please also confirm that there is a typo in the Lightstreamer server version in use, did you mean 7.1.2?


    Regards,
    Giuseppe

  3. #3
    Member
    Join Date
    Jan 2021
    Location
    Frankfurt am Main
    Posts
    4
    Good morning Giuseppe,
    thank you very much for your fast reply.
    I checked the log files from the particular days and the Queued tasks value is always in the range 0 - 100, while it rarely grows over 40, mostly it is 0. I checked all cases before this error message appeared and only in one case the Queued tasks value was 8, otherwise it was 8. The number of threads is roughly around 300, almost throughout the whole day.
    I did not find the other message about "Current delay" you mentioned. Is it supposed to be in the same logfile?
    However, I found this:
    Granted time expired for session Se2d7c076a1d1975fM507T1447423: requesting a rebind
    and the other log entry which appears after such an error is:
    Session S1e5c2fce3ae39e30M507T1826214 resumed from 104
    So that confirms very much your answer.

    I can also confirm that I made a typo in the version number. It is Version: 7.0.3 build 1885.8. Should we potentially to a higher version? Can it have impact on the error message mentioned in my previous message?

    Could you also tell me what is the lifetime of a client session? Is this value configurable?

    Thank you in advance.
    Best regards,
    Tomas
    Last edited by tomas.walek-ext@sgcib.com; January 5th, 2021 at 08:54 AM.

  4. #4
    Administrator
    Join Date
    Feb 2012
    Location
    Milano
    Posts
    716
    Hi Tomas,

    Yes, the "Current delay" messages are printed in the same log file (unless special customizations), so we can assume that your Lightstreamer is not suffering from generalized delays due to overload.
    But, please could you confirm the log level of LightstreamerMonitorText logger? Because, with INFO level you have a Monitor line every 2 minutes, so any episodes of short crises, less than 1 minute, can be completely missed or not clearly identifiable.
    In the case, you can switch to TRACE level, that means a Monitor line every 2 seconds, without excessively increasing the verbosity of the log it allows analysis of problems like this more accurately.

    A client session is considered closed by the Lightstreamer server under various circumstances.
    The most obvious is when it receives an explicit disconnect request from the client.
    In other cases it is the server that takes the initiative, particularly when it detects network problems on the client session's streaming connection.
    In some of these circumstances the server holds the client session for a few seconds for the possible rebind request from the client that would allow the session to be recovered.
    And that's what actually happened with the message you attached: "Session S1e5c2fce3ae39e30M507T1826214 resumed from 104 ".
    If messages like these recur frequently it is possible that the issue is due to temporary network outages (client-side or server-side).

    Actually the recovery timeout can be configured, please refer to these parameters in the lightstreamer_conf.xml:

    <session_recovery_millis>
    <max_recovery_length>
    <max_recovery_poll_length>


    Upgrading at your earliest convenience to the latest available version is something we always recommend, but in this specific case I don't think it will impact your issue.

    Regards,
    Giuseppe

  5. #5
    Member
    Join Date
    Jan 2021
    Location
    Frankfurt am Main
    Posts
    4
    Hello Giuseppe,
    thank you kindly for your reply.
    We have been using the level INFO so far, but we will switch to TRACE to extract a more exact timing information and use this information for further investigation. I will come back to you once I have some results.
    Have a nice day.
    Best regards,
    Tomas

 

 

Similar Threads

  1. Replies: 0
    Last Post: December 19th, 2014, 11:37 AM
  2. Replies: 1
    Last Post: August 6th, 2014, 11:13 AM
  3. Register with Command only to "ADD" and "REMOVE"
    By lidanh in forum Client SDKs
    Replies: 4
    Last Post: August 6th, 2013, 06:27 PM
  4. Replies: 3
    Last Post: February 19th, 2010, 12:14 AM
  5. Get <WARN> message: Reply too late.
    By aikobit in forum Adapter SDKs
    Replies: 9
    Last Post: July 8th, 2008, 02:57 AM

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 09:30 PM.