Page 1 of 3 123 LastLast
Results 1 to 10 of 30
  1. #1
    Member
    Join Date
    Nov 2008
    Location
    Boston
    Posts
    24

    Sync errors in server log

    Hi,

    I found the following log output in the LS server log. It seems the LS server created a new session with id Sb50bef2560eac1cbT3950716, but still was trying to control the old session with old id S4040fce00115c0a5T5129274.

    When this happened, the browser will show a Javascript alert, saying "Exception thrown and not caught". The LS steaming was stopped afterwards. Can anyone please comment on what could have caused the Sync errors?

    Thanks,
    Richard

    Below are the log output:
    ------------------------------------------------

    2009-08-10 10:39:50,264 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1774&LS_domain=currensee.com& from 82.81.254.65:2397>
    2009-08-10 10:39:50,264 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2397>
    2009-08-10 10:39:50,600 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/create_session.js?LS_phase=1775&LS_domain=currense e.com&LS_polling=true&LS_polling_millis=1109&LS_id le_millis=30000&LS_client_version=4.3&LS_adapter=F OREXPERT&LS_user=8&LS_password=[...]&LS_old_session=S4040fce00115c0a5T5129274& from 82.81.254.65:2399>
    2009-08-10 10:39:50,716 INFO [LightstreamerLogger.requests] - <Starting new session: Sb50bef2560eac1cbT3950716 from 82.81.254.65:2399>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/control.html?LS_session=S4040fce00115c0a5T5129274& LS_window=11&LS_win_phase=5&LS_op=add&LS_req_phase =103&LS_mode1=MERGE&LS_id1=FXCMPriceUpdates%20thom sonNewsEvent%20publish-8%20consume-8%20Discussions%20jms.thomson.reports%20PlatformAn nouncements%20economicEventTopic%20publish-59%20publish-321%20publish-457%20publish-227%20publish-1%20publish-296%20publish-200%20publish-429%20publish-10%20publish-373%20publish-872%20publish-160%20publish-135%20publish-416%20publish-598%20publish-3%20publish-48%20publish-247%20publish-214%20publish-313%20publish-427%20publish-21%20publish-418%20publish-195%20publish-33%20publish-507%20publish-228%20publish-1356%20publish-92%20publish-194%20publish-264%20publish-1384%20publish-162%20publish-119%20publish-35%20publish-58%20publish-417%20publish-419%20publish-325%20publish-86%20publish-276%20publish-185%20publish-80%20publish-204%20publish-275%20publish-38%20publish-47%20publish-234%20publish-105%20publish-508%20publish-1073%20publish-331%20publish-145%20publish-350%20publish-362%20publish-611%20publish-215%20publish-232%20publish-613%20publish-188%20publish-211%20publish-473%20publish-30%20publish-502%20publish-1088%20publish-565%20publish-236%20publish-170%20publish-346%20publish-231%20publish-361%20publish-193%20publish-168%20publish-240%20publish-229%20publish-312%20publish-37%20publish-212%20publish-394%20publish-123%20publish-609%20publish-79%20publish-399%20publish-2%20publish-253%20publish-316%20publish-237%20publish-15%20publish-332%20publish-39%20publish-326%20publish-300%20publish-73%20publish-72%20publish-448%20publish-420%20publish-307%20publish-266%20publish-265%20publish-52%20publish-217%20publish-343%20publish-256%20publish-510%20publish-561&LS_schema1=message&LS_unique=13 from 82.81.254.65:2401>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2401>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2401>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Serving multiple request: /lightstreamer/control.html?{9 subrequests} from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 1: LS_session=S4040fce00115c0a5T5129274&LS_window=12& LS_win_phase=5&LS_op=add&LS_req_phase=104&LS_mode1 =MERGE&LS_id1=feed-1&LS_schema1=message&LS_unique=14 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 2: LS_session=S4040fce00115c0a5T5129274&LS_window=13& LS_win_phase=5&LS_op=add&LS_req_phase=105&LS_mode1 =MERGE&LS_id1=feed-2&LS_schema1=message&LS_unique=15 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 3: LS_session=S4040fce00115c0a5T5129274&LS_window=14& LS_win_phase=5&LS_op=add&LS_req_phase=106&LS_mode1 =MERGE&LS_id1=feed-3&LS_schema1=message&LS_unique=16 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 4: LS_session=S4040fce00115c0a5T5129274&LS_window=15& LS_win_phase=5&LS_op=add&LS_req_phase=107&LS_mode1 =MERGE&LS_id1=feed-4&LS_schema1=message&LS_unique=17 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 5: LS_session=S4040fce00115c0a5T5129274&LS_window=16& LS_win_phase=5&LS_op=add&LS_req_phase=108&LS_mode1 =MERGE&LS_id1=feed-6&LS_schema1=message&LS_unique=18 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 6: LS_session=S4040fce00115c0a5T5129274&LS_window=17& LS_win_phase=5&LS_op=add&LS_req_phase=109&LS_mode1 =MERGE&LS_id1=feed-8&LS_schema1=message&LS_unique=19 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 7: LS_session=S4040fce00115c0a5T5129274&LS_window=18& LS_win_phase=5&LS_op=add&LS_req_phase=110&LS_mode1 =MERGE&LS_id1=feed-9&LS_schema1=message&LS_unique=20 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 8: LS_session=S4040fce00115c0a5T5129274&LS_window=19& LS_win_phase=5&LS_op=add&LS_req_phase=111&LS_mode1 =MERGE&LS_id1=feed-15&LS_schema1=message&LS_unique=21 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 9: LS_session=S4040fce00115c0a5T5129274&LS_window=20& LS_win_phase=5&LS_op=add&LS_req_phase=112&LS_mode1 =MERGE&LS_id1=feed-16&LS_schema1=message&LS_unique=22 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>

  2. #2
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    972
    The outdated control requests for the first session occur a very short time after the session has been dismissed, hence they can just be late.
    This would not be a problem, provided that the client were able to switch to the new session.
    However, you say this is not the case.
    Is there any way to replicate the problem and get more information on the javascript exception received?

    What's strange in this log snippet is that the first session is replaced just after being successfully rebound. Normally, a session is replaced after it has not been available for several seconds.
    Is it possible that all the logged requests have been delayed on the network for some time?
    May you please attach a longer log snippet, with the whole story of session S4040fce00115c0a5T5129274?

    Which version/build of the web client library are you using?

  3. #3
    Member
    Join Date
    Nov 2008
    Location
    Boston
    Posts
    24
    We are using Lightstreamer Moderato Server version 3.5 build 1422. I don't have a way to reproduce this issue either. It just happened intermittently. But I found hundreds of such <Sync error> log statements in the daily LS server log file.

    Here are the relevant log entries related to the particular user.

    2009-08-10 08:51:29,250 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/create_session.js?LS_phase=1702&LS_domain=currense e.com&LS_polling=true&LS_polling_millis=0&LS_idle_ millis=30000&LS_client_version=4.3&LS_adapter=FORE XPERT&LS_user=8&LS_password=[...]& from 82.81.254.65:4605>
    2009-08-10 08:51:29,274 INFO [LightstreamerLogger.requests] - <Starting new session: S4040fce00115c0a5T5129274 from 82.81.254.65:4605>
    2009-08-10 08:51:29,942 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/control.html?LS_session=S4040fce00115c0a5T5129274& LS_window=1&LS_win_phase=4&LS_op=add&LS_req_phase= 93&LS_mode1=MERGE&LS_id1=FXCMPriceUpdates%20thomso nNewsEvent%20publish-8%20consume-8%20Discussions%20jms.thomson.reports%20PlatformAn nouncements%20economicEventTopic%20publish-59%20publish-321%20publish-457%20publish-227%20publish-1%20publish-296%20publish-200%20publish-429%20publish-10%20publish-373%20publish-872%20publish-160%20publish-135%20publish-416%20publish-598%20publish-3%20publish-48%20publish-247%20publish-214%20publish-313%20publish-427%20publish-21%20publish-418%20publish-195%20publish-33%20publish-507%20publish-228%20publish-1356%20publish-92%20publish-194%20publish-264%20publish-1384%20publish-162%20publish-119%20publish-35%20publish-58%20publish-417%20publish-419%20publish-325%20publish-86%20publish-276%20publish-185%20publish-80%20publish-204%20publish-275%20publish-38%20publish-47%20publish-234%20publish-105%20publish-508%20publish-1073%20publish-331%20publish-145%20publish-350%20publish-362%20publish-611%20publish-215%20publish-232%20publish-613%20publish-188%20publish-211%20publish-473%20publish-30%20publish-502%20publish-1088%20publish-565%20publish-236%20publish-170%20publish-346%20publish-231%20publish-361%20publish-193%20publish-168%20publish-240%20publish-229%20publish-312%20publish-37%20publish-212%20publish-394%20publish-123%20publish-609%20publish-79%20publish-399%20publish-2%20publish-253%20publish-316%20publish-237%20publish-15%20publish-332%20publish-39%20publish-326%20publish-300%20publish-73%20publish-72%20publish-448%20publish-420%20publish-307%20publish-266%20publish-265%20publish-52%20publish-217%20publish-343%20publish-256%20publish-510%20publish-561&LS_schema1=message&LS_unique=1 from 82.81.254.65:4605>
    2009-08-10 08:51:29,942 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4605>
    2009-08-10 08:51:30,214 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1703&LS_domain=currensee.com& from 82.81.254.65:4609>
    2009-08-10 08:51:30,214 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:4609>
    2009-08-10 08:52:59,383 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1704&LS_domain=currensee.com& from 82.81.254.65:4715>
    2009-08-10 08:52:59,383 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:4715>
    2009-08-10 08:54:19,412 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/control.html?LS_session=S4040fce00115c0a5T5129274& LS_window=2&LS_win_phase=4&LS_op=add&LS_req_phase= 94&LS_mode1=MERGE&LS_id1=feed-1&LS_schema1=message&LS_unique=2 from 82.81.254.65:4803>
    2009-08-10 08:54:19,412 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Serving multiple request: /lightstreamer/control.html?{8 subrequests} from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 1: LS_session=S4040fce00115c0a5T5129274&LS_window=3&L S_win_phase=4&LS_op=add&LS_req_phase=95&LS_mode1=M ERGE&LS_id1=feed-2&LS_schema1=message&LS_unique=3 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 2: LS_session=S4040fce00115c0a5T5129274&LS_window=4&L S_win_phase=4&LS_op=add&LS_req_phase=96&LS_mode1=M ERGE&LS_id1=feed-3&LS_schema1=message&LS_unique=4 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 3: LS_session=S4040fce00115c0a5T5129274&LS_window=5&L S_win_phase=4&LS_op=add&LS_req_phase=97&LS_mode1=M ERGE&LS_id1=feed-4&LS_schema1=message&LS_unique=5 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 4: LS_session=S4040fce00115c0a5T5129274&LS_window=6&L S_win_phase=4&LS_op=add&LS_req_phase=98&LS_mode1=M ERGE&LS_id1=feed-6&LS_schema1=message&LS_unique=6 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 5: LS_session=S4040fce00115c0a5T5129274&LS_window=7&L S_win_phase=4&LS_op=add&LS_req_phase=99&LS_mode1=M ERGE&LS_id1=feed-8&LS_schema1=message&LS_unique=7 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 6: LS_session=S4040fce00115c0a5T5129274&LS_window=8&L S_win_phase=4&LS_op=add&LS_req_phase=100&LS_mode1= MERGE&LS_id1=feed-9&LS_schema1=message&LS_unique=8 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 7: LS_session=S4040fce00115c0a5T5129274&LS_window=9&L S_win_phase=4&LS_op=add&LS_req_phase=101&LS_mode1= MERGE&LS_id1=feed-15&LS_schema1=message&LS_unique=9 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Subrequest 8: LS_session=S4040fce00115c0a5T5129274&LS_window=10& LS_win_phase=4&LS_op=add&LS_req_phase=102&LS_mode1 =MERGE&LS_id1=feed-16&LS_schema1=message&LS_unique=10 from 82.81.254.65:4803>
    2009-08-10 08:54:20,680 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:21,112 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:21,540 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:22,036 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:22,484 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:22,896 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:23,348 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:23,908 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:26,992 INFO [LightstreamerLogger.requests] - <Serving multiple request: /lightstreamer/control.html?{2 subrequests} from 82.81.254.65:4803>
    2009-08-10 08:54:26,992 INFO [LightstreamerLogger.requests] - <Subrequest 1: LS_session=S4040fce00115c0a5T5129274&LS_window=9&L S_win_phase=4&LS_op=add&LS_req_phase=101&LS_mode1= MERGE&LS_id1=feed-15&LS_schema1=message&LS_unique=11 from 82.81.254.65:4803>
    2009-08-10 08:54:26,992 INFO [LightstreamerLogger.requests] - <Subrequest 2: LS_session=S4040fce00115c0a5T5129274&LS_window=10& LS_win_phase=4&LS_op=add&LS_req_phase=102&LS_mode1 =MERGE&LS_id1=feed-16&LS_schema1=message&LS_unique=12 from 82.81.254.65:4803>
    2009-08-10 08:54:26,992 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:27,396 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:54:38,185 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1705&LS_domain=currensee.com& from 82.81.254.65:4803>
    2009-08-10 08:54:38,185 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:4803>
    2009-08-10 08:56:07,874 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1706&LS_domain=currensee.com& from 82.81.254.65:4875>
    2009-08-10 08:56:07,874 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:4875>
    2009-08-10 08:57:33,919 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1707&LS_domain=currensee.com& from 82.81.254.65:4942>
    2009-08-10 08:57:33,919 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:4942>

    [...] Skipped many repetition of STREAMING_IN_PROGRESS log entries

    2009-08-10 10:33:30,707 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1770&LS_domain=currensee.com& from 82.81.254.65:2315>
    2009-08-10 10:33:30,707 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2315>
    2009-08-10 10:35:06,508 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1771&LS_domain=currensee.com& from 82.81.254.65:2337>
    2009-08-10 10:35:06,508 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2337>
    2009-08-10 10:36:43,742 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1772&LS_domain=currensee.com& from 82.81.254.65:2353>
    2009-08-10 10:36:43,742 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2353>
    2009-08-10 10:38:16,423 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1773&LS_domain=currensee.com& from 82.81.254.65:2377>
    2009-08-10 10:38:16,423 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2377>
    2009-08-10 10:39:50,264 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S4040fce00115c0a5 T5129274&LS_phase=1774&LS_domain=currensee.com& from 82.81.254.65:2397>
    2009-08-10 10:39:50,264 INFO [LightstreamerLogger.requests] - <Attaching session: S4040fce00115c0a5T5129274 from 82.81.254.65:2397>
    2009-08-10 10:39:50,600 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/create_session.js?LS_phase=1775&LS_domain=currense e.com&LS_polling=true&LS_polling_millis=1109&LS_id le_millis=30000&LS_client_version=4.3&LS_adapter=F OREXPERT&LS_user=8&LS_password=[...]&LS_old_session=S4040fce00115c0a5T5129274& from 82.81.254.65:2399>
    2009-08-10 10:39:50,716 INFO [LightstreamerLogger.requests] - <Starting new session: Sb50bef2560eac1cbT3950716 from 82.81.254.65:2399>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Serving request: /lightstreamer/control.html?LS_session=S4040fce00115c0a5T5129274& LS_window=11&LS_win_phase=5&LS_op=add&LS_req_phase =103&LS_mode1=MERGE&LS_id1=FXCMPriceUpdates%20thom sonNewsEvent%20publish-8%20consume-8%20Discussions%20jms.thomson.reports%20PlatformAn nouncements%20economicEventTopic%20publish-59%20publish-321%20publish-457%20publish-227%20publish-1%20publish-296%20publish-200%20publish-429%20publish-10%20publish-373%20publish-872%20publish-160%20publish-135%20publish-416%20publish-598%20publish-3%20publish-48%20publish-247%20publish-214%20publish-313%20publish-427%20publish-21%20publish-418%20publish-195%20publish-33%20publish-507%20publish-228%20publish-1356%20publish-92%20publish-194%20publish-264%20publish-1384%20publish-162%20publish-119%20publish-35%20publish-58%20publish-417%20publish-419%20publish-325%20publish-86%20publish-276%20publish-185%20publish-80%20publish-204%20publish-275%20publish-38%20publish-47%20publish-234%20publish-105%20publish-508%20publish-1073%20publish-331%20publish-145%20publish-350%20publish-362%20publish-611%20publish-215%20publish-232%20publish-613%20publish-188%20publish-211%20publish-473%20publish-30%20publish-502%20publish-1088%20publish-565%20publish-236%20publish-170%20publish-346%20publish-231%20publish-361%20publish-193%20publish-168%20publish-240%20publish-229%20publish-312%20publish-37%20publish-212%20publish-394%20publish-123%20publish-609%20publish-79%20publish-399%20publish-2%20publish-253%20publish-316%20publish-237%20publish-15%20publish-332%20publish-39%20publish-326%20publish-300%20publish-73%20publish-72%20publish-448%20publish-420%20publish-307%20publish-266%20publish-265%20publish-52%20publish-217%20publish-343%20publish-256%20publish-510%20publish-561&LS_schema1=message&LS_unique=13 from 82.81.254.65:2401>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2401>
    2009-08-10 10:39:51,084 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2401>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Serving multiple request: /lightstreamer/control.html?{9 subrequests} from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 1: LS_session=S4040fce00115c0a5T5129274&LS_window=12& LS_win_phase=5&LS_op=add&LS_req_phase=104&LS_mode1 =MERGE&LS_id1=feed-1&LS_schema1=message&LS_unique=14 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 2: LS_session=S4040fce00115c0a5T5129274&LS_window=13& LS_win_phase=5&LS_op=add&LS_req_phase=105&LS_mode1 =MERGE&LS_id1=feed-2&LS_schema1=message&LS_unique=15 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 3: LS_session=S4040fce00115c0a5T5129274&LS_window=14& LS_win_phase=5&LS_op=add&LS_req_phase=106&LS_mode1 =MERGE&LS_id1=feed-3&LS_schema1=message&LS_unique=16 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 4: LS_session=S4040fce00115c0a5T5129274&LS_window=15& LS_win_phase=5&LS_op=add&LS_req_phase=107&LS_mode1 =MERGE&LS_id1=feed-4&LS_schema1=message&LS_unique=17 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 5: LS_session=S4040fce00115c0a5T5129274&LS_window=16& LS_win_phase=5&LS_op=add&LS_req_phase=108&LS_mode1 =MERGE&LS_id1=feed-6&LS_schema1=message&LS_unique=18 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 6: LS_session=S4040fce00115c0a5T5129274&LS_window=17& LS_win_phase=5&LS_op=add&LS_req_phase=109&LS_mode1 =MERGE&LS_id1=feed-8&LS_schema1=message&LS_unique=19 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 7: LS_session=S4040fce00115c0a5T5129274&LS_window=18& LS_win_phase=5&LS_op=add&LS_req_phase=110&LS_mode1 =MERGE&LS_id1=feed-9&LS_schema1=message&LS_unique=20 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 8: LS_session=S4040fce00115c0a5T5129274&LS_window=19& LS_win_phase=5&LS_op=add&LS_req_phase=111&LS_mode1 =MERGE&LS_id1=feed-15&LS_schema1=message&LS_unique=21 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Subrequest 9: LS_session=S4040fce00115c0a5T5129274&LS_window=20& LS_win_phase=5&LS_op=add&LS_req_phase=112&LS_mode1 =MERGE&LS_id1=feed-16&LS_schema1=message&LS_unique=22 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,204 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Controlling session: S4040fce00115c0a5T5129274 from 82.81.254.65:2403>
    2009-08-10 10:39:51,208 INFO [LightstreamerLogger.requests] - <Sync error (transient): Can't find session from 82.81.254.65:2403>

  4. #4
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    972
    The history of session S4040fce00115c0a5T5129274, until it is replaced by session Sb50bef2560eac1cbT3950716, is normal.
    The high number of STREAMING_IN_PROGRESS requests may be due to a huge amount of pushed data against a short content-length setting in the Server configuration file (can you confirm?).

    However, the replicated control request at 08:54:26,992 refers to subscriptions that were processed by the Server several seconds before;
    this confirms that some delays occur in the client-server communication
    (for instance, do you notice any CPU overload on the client side?).
    If a similar delay had affected the rebind request at 10:39:50,264
    this would explain the replacement of the session
    (which is the setting for <session_timeout_millis> in the Server configuration file?).
    Moreover, if a similar delay had affected the subsequent control requests,
    this would explain the sync errors.

    I'm afraid we need to identify the javascript error that occurred after the establishment of session Sb50bef2560eac1cbT3950716,
    in order to understand what caused the new session not to start correctly.

  5. #5
    Member
    Join Date
    Nov 2008
    Location
    Boston
    Posts
    24
    The content length was changed from the default 300,000 to 1,000,000.

    <content_length>
    <default>1000000</default>
    </content_length>

    The session_timeout_millis was changed from the default 5000 to 60000.

    <session_timeout_millis>60000</session_timeout_millis>

    We do push a lot of data to the client. The client CPU load is often quite high, sometimes 80% of CPU usage.

    Unfortunately, I don't have more info about the JS exception.

  6. #6
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    972
    Do you mean that the session_timeout_millis and the content-length had already been increased when the reported log was produced?

  7. #7
    Member
    Join Date
    Nov 2008
    Location
    Boston
    Posts
    24
    Yes. We changed the configuration about 6 months ago. The Sync Errors have been in the LS server logs always.

  8. #8
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    972
    About the content-length:
    Continuously rebinding after about one and a half minute
    may still be consistent with your setting.
    It means 1 MB of update traffic within 90 seconds.

    About the session_timeout_millis:
    I was mistaken. If a rebind request is affected by a delay,
    the first timeout involved is on the client side.
    After a reconnection request has not provided an answer in 4 seconds,
    the client gives up and retries with a new connection request,
    which, however, would open a new session.

    Hence, the unexpected replacement of the session
    is still consistent with the assumption of a delay
    in the client-server communication.
    For instance, the brwser might have been overwhelmed by the updates
    and might hava not been able to elaborate the Server answer in time.
    And, as said, any trailing control request that was also delayed
    would have experienced the "sync error".

    The exception after the session replacement is the only event
    that cannot be explained in terms of overload.
    Let us know if the issue happens again.

  9. #9
    Member
    Join Date
    Feb 2010
    Location
    Madurai
    Posts
    3
    I am getting a similar case of 'Sync error: Can't find session from '

    I am not able to identify if the client or server delay causes the session get closed and create new session.

    From this thread, I understood that client server communication delay may cause this issue and can be solved by changing content-length and session_timeout_millis

    I have tried both and getting same issue still. I am attaching server log with default configurations and config changes.

    Please help me to identify the casue of the issue.

    Thanks & Regards,
    Krishna
    Attached Files Attached Files

  10. #10
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    972
    First of all, in the attached file you mention a value of 10 ms for <session_timeout_millis>, but I assume you mean 10 seconds.

    Indeed, your client seems to be receiving a lot of data to be elaborated, about 300KB in 15 seconds at least.
    This may cause the browser to be overwhelmed. May you please confirm that by direct observation of the client machine?
    This would explain the "Sync error", as the page would issue the request of rebinding to the session long time after the previous connection has closed.

    Note that you might increase the <session_timeout_millis> and the content-length, but that would just postpone the problem. In fact, in the third case (with the increased content-length), before the whole content-length has been consumed, the client opens a new session in polling mode. This is a recovery mechanism adopted by Lightstreamer web client library when it detects that the update processing is slower than the incoming update rate.

    Just in case, the log shows that you have not configured a free license properly.
    This causes the Server to work with some annoying limitations.

 

 

Similar Threads

  1. Sync Errors
    By wwatts in forum Client APIs
    Replies: 1
    Last Post: February 20th, 2012, 09:14 AM
  2. Sync Errors
    By colmfield in forum Client APIs
    Replies: 2
    Last Post: September 22nd, 2010, 09:06 AM
  3. web client is not updating , no errors in server console
    By kishorekkk in forum Adapter APIs
    Replies: 1
    Last Post: April 10th, 2009, 08:33 AM
  4. StockListDemo (sync on different windows)
    By CitiMan in forum General
    Replies: 4
    Last Post: November 21st, 2006, 11:14 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:53 AM.