Results 1 to 6 of 6
  1. #1
    Member
    Join Date
    May 2010
    Location
    London
    Posts
    18

    Hundreds of connections from single user

    Hi,

    I have a web front-end using Lightstreamer Vivace, connecting to a .Net MetaDataAdapter and DataAdapter running as a Windows service. I am using the RobustNetworkedMetadataProvider.

    In my MetadataAdapter I log the fact a user has logged on in the notifyUser method in the database.

    For some users (about 5 out of 200), I see that their access has been logged up to 1000 times a day, compared to other users being about 10-15. Any idea what could be causing this? The users themselves report no issues with the data delivery, and I see no errors in the LS logs (with these users).

    Cheers,
    Colm

  2. #2
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    975
    Please try to follow the activity of one of such users in the Server log and identify a sequence of "create_session" requests.
    If possible, show us a snippet of the original log including such a sequence (of, let's say, 10 requests).

  3. #3
    Member
    Join Date
    May 2010
    Location
    London
    Posts
    18
    Hi Dario,

    From yesterday's log:

    Code:
    20-Sep-10 07:48:18,866 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 2     |Serving request: /lightstreamer/create_session.js --> LS_phase=4802&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]& from XXX.XXX.XXX.XXX:47995
    20-Sep-10 07:48:19,101 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 10    |Starting new session: Sfabc90480438aab8T4819101 from XXX.XXX.XXX.XXX:47995
    20-Sep-10 07:48:19,257 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=Sfabc90480438aab8T4819101&LS_phase=4803&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:47995
    20-Sep-10 07:48:19,257 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Attaching session: Sfabc90480438aab8T4819101 from XXX.XXX.XXX.XXX:47995
    20-Sep-10 07:48:19,913 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 1     |Serving request: /lightstreamer/control.js --> LS_session=Sfabc90480438aab8T4819101&LS_table=0&LS_win_phase=104&LS_op=add&LS_req_phase=886&LS_mode=MERGE&LS_id=X1%20X2%20X3%20X4%20X5&LS_schema=price%20quantity&LS_data_adapter=PRICES_ADAPTER&LS_snapshot=true&LS_unique=1& from XXX.XXX.XXX.XXX:48001
    20-Sep-10 07:48:19,913 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 2     |Controlling session: Sfabc90480438aab8T4819101 from XXX.XXX.XXX.XXX:48001
    20-Sep-10 07:48:20,054 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 3     |Serving request: /lightstreamer/control.js --> LS_session=Sfabc90480438aab8T4819101&LS_table=1&LS_win_phase=104&LS_op=add&LS_req_phase=887&LS_mode=MERGE&LS_id=Control&LS_schema=item%20message&LS_data_adapter=PRICES_ADAPTER&LS_unique=2& from XXX.XXX.XXX.XXX:48001
    20-Sep-10 07:48:20,054 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 4     |Controlling session: Sfabc90480438aab8T4819101 from XXX.XXX.XXX.XXX:48001
    20-Sep-10 08:33:40,536 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=Sfabc90480438aab8T4819101&LS_phase=4804&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48185
    20-Sep-10 08:33:40,536 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Attaching session: Sfabc90480438aab8T4819101 from XXX.XXX.XXX.XXX:48185
    20-Sep-10 08:33:44,021 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 1     |Serving request: /lightstreamer/create_session.js --> LS_phase=4805&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=Sfabc90480438aab8T4819101& from XXX.XXX.XXX.XXX:48188
    20-Sep-10 08:33:44,271 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Starting new session: S79e0ab93c467ea19T3344271 from XXX.XXX.XXX.XXX:48188
    20-Sep-10 08:33:44,521 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S79e0ab93c467ea19T3344271&LS_phase=4806&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48188
    20-Sep-10 08:33:44,521 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Attaching session: S79e0ab93c467ea19T3344271 from XXX.XXX.XXX.XXX:48188
    20-Sep-10 08:33:56,896 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 3     |Serving request: /lightstreamer/create_session.js --> LS_phase=4807&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=S79e0ab93c467ea19T3344271& from XXX.XXX.XXX.XXX:48192
    20-Sep-10 08:33:57,115 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 6     |Starting new session: S914dac92125c69f8T3357115 from XXX.XXX.XXX.XXX:48192
    20-Sep-10 08:33:57,271 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 4     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S914dac92125c69f8T3357115&LS_phase=4808&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48192
    20-Sep-10 08:33:57,271 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 4     |Attaching session: S914dac92125c69f8T3357115 from XXX.XXX.XXX.XXX:48192
    20-Sep-10 08:34:17,615 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 3     |Serving request: /lightstreamer/create_session.js --> LS_phase=4809&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=S914dac92125c69f8T3357115& from XXX.XXX.XXX.XXX:48203
    20-Sep-10 08:34:17,850 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Starting new session: Seda8cc6f1b6e2879T3417850 from XXX.XXX.XXX.XXX:48203
    20-Sep-10 08:34:18,084 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 6     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=Seda8cc6f1b6e2879T3417850&LS_phase=4810&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48203
    20-Sep-10 08:34:18,084 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 6     |Attaching session: Seda8cc6f1b6e2879T3417850 from XXX.XXX.XXX.XXX:48203
    20-Sep-10 08:34:46,491 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 5     |Serving request: /lightstreamer/create_session.js --> LS_phase=4811&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=Seda8cc6f1b6e2879T3417850& from XXX.XXX.XXX.XXX:48208
    20-Sep-10 08:34:46,726 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 10    |Starting new session: S1eb9e55ef72c27a3T3446726 from XXX.XXX.XXX.XXX:48208
    20-Sep-10 08:34:46,882 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 5     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S1eb9e55ef72c27a3T3446726&LS_phase=4812&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48208
    20-Sep-10 08:34:46,882 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 5     |Attaching session: S1eb9e55ef72c27a3T3446726 from XXX.XXX.XXX.XXX:48208
    20-Sep-10 08:35:17,164 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 5     |Serving request: /lightstreamer/create_session.js --> LS_phase=4813&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=S1eb9e55ef72c27a3T3446726& from XXX.XXX.XXX.XXX:48211
    20-Sep-10 08:35:17,399 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Starting new session: Se987c80313e52877T3517399 from XXX.XXX.XXX.XXX:48211
    20-Sep-10 08:35:17,555 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=Se987c80313e52877T3517399&LS_phase=4814&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48211
    20-Sep-10 08:35:17,555 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 8     |Attaching session: Se987c80313e52877T3517399 from XXX.XXX.XXX.XXX:48211
    20-Sep-10 08:35:47,853 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Serving request: /lightstreamer/create_session.js --> LS_phase=4815&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=Se987c80313e52877T3517399& from XXX.XXX.XXX.XXX:48214
    20-Sep-10 08:35:48,056 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 9     |Starting new session: S308e92637b559c81T3548056 from XXX.XXX.XXX.XXX:48214
    20-Sep-10 08:35:48,275 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S308e92637b559c81T3548056&LS_phase=4816&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48214
    20-Sep-10 08:35:48,275 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 7     |Attaching session: S308e92637b559c81T3548056 from XXX.XXX.XXX.XXX:48214
    20-Sep-10 08:36:18,541 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 4     |Serving request: /lightstreamer/create_session.js --> LS_phase=4817&LS_domain=xxx.com&LS_polling=true&LS_polling_millis=0&LS_idle_millis=0&LS_client_version=4.4&LS_adapter_set=PROXY_FIXADAPTER&LS_user=XXX%7C1060311%7C1546239&LS_password=[...]&LS_old_session=S308e92637b559c81T3548056& from XXX.XXX.XXX.XXX:48217
    20-Sep-10 08:36:18,760 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 3     |Starting new session: S765c8a2cde84d2caT3618760 from XXX.XXX.XXX.XXX:48217
    20-Sep-10 08:36:18,916 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 10    |Serving request: /lightstreamer/STREAMING_IN_PROGRESS?LS_session=S765c8a2cde84d2caT3618760&LS_phase=4818&LS_domain=xxx.com& from XXX.XXX.XXX.XXX:48217
    20-Sep-10 08:36:18,916 |INFO |LightstreamerLogger.requests     |SERVER POOLED THREAD 10    |Attaching session: S765c8a2cde84d2caT3618760 from XXX.XXX.XXX.XXX:48217
    Colm

  4. #4
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    975
    Unfortunately, we have never noticed a similar pattern.

    1) The first session has a normal life until the content length expires. Then, the rebind seems to be unsuccessful: the answer might be either delayed or blocked.
    Could you see any "sync error" around 8:33:40/44?
    Did you report the original log (which means that only activity from this client happened between 7:48 and 8:35) or did you filter the log by IP?

    2) After the first failed rebind, it seems that all subsequent streaming connection attempts fail.
    As a consequence, no subscription requests are issued for the new sessions, hence no data can reach the client in this phase.
    You say that the clients reported no issue, but do you have any evidence that the clients also get data?
    Again, did you report the original log or could there be other messages in the middle?
    By the way, do you configure any specific timeout on your LightstreamerEngine.Policy instance?

  5. #5
    Member
    Join Date
    May 2010
    Location
    London
    Posts
    18
    Quote Originally Posted by DarioCrivelli
    The first session has a normal life until the content length expires. Then, the rebind seems to be unsuccessful: the answer might be either delayed or blocked.
    Could you see any "sync error" around 8:33:40/44?
    Did you report the original log (which means that only activity from this client happened between 7:48 and 8:35) or did you filter the log by IP?
    I didn't report the full log, but there are no sync errors around those times. There are hundreds of lines between 07:48 and 08:33, so I won't include them here unless you want them. There are sync errors for other users in that time, and immediately before the 08:33:40,536 there is an "SSL read error", but I understand these shouldn't be logged as errors at all.

    2) After the first failed rebind, it seems that all subsequent streaming connection attempts fail.
    As a consequence, no subscription requests are issued for the new sessions, hence no data can reach the client in this phase.
    You say that the clients reported no issue, but do you have any evidence that the clients also get data?[/QUOTE]

    It happens to ca.10 users, some of whom are based in my office, and I've looked at their PCs whilst it is happening and can see the data coming through ok. I haven't obviously checked with all users but am confident they would complain if it wasn't working for them - especially considering the fact they're logged on for such a long period,

    By the way, do you configure any specific timeout on your LightstreamerEngine.Policy instance?
    Nope, just using the default timeout here.

  6. #6
    Administrator
    Join Date
    Jul 2006
    Location
    Milan
    Posts
    975
    There must be some key information missing.
    Session Sfabc90480438aab8T4819101 is the only one for which subscriptions are requested and it is supposed to terminate at 8:33:44:021, when it is declared as "old" upon opening of session S79e0ab93c467ea19T3344271.
    After that time, no data can flow to the client.

    Fortunately, you can manage to replicate the issue.
    Would it be possible for you to use a slightly modified version of your client page only on one client host in your office (in which the issue can be reproduced)?
    This would allow you to collect client side log (we would give you instructions).

    Are you using a single Server instance or a cluster?

    Just in case any interesting log message were hidden in hundred lines, may you please send us the full log between 8:33:40 and 8:34:20?
    You could send it to support@lightstreamer.com

 

 

Similar Threads

  1. Replies: 7
    Last Post: September 11th, 2012, 10:32 AM
  2. Single Linux server with 2 IP addresses
    By anselme in forum General
    Replies: 4
    Last Post: March 30th, 2012, 09:37 AM
  3. Deployment with IIS on a single server
    By vampug in forum General
    Replies: 4
    Last Post: April 12th, 2010, 10:23 AM
  4. Multiple Connections
    By mnfjorge in forum Client APIs
    Replies: 1
    Last Post: March 24th, 2010, 09:52 AM
  5. Replies: 3
    Last Post: February 8th, 2007, 10:11 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 06:37 AM.