JavaScript error "Expecting a different value" when sharing between tabs.

Printable View

August 22nd, 2016, 06:57 AM
palcov

JavaScript error "Expecting a different value" when sharing between tabs.

Hello. We are using LS server 6.0.1 Moderato and JS adapter 7.0.2 build 1710. When enabled connection sharing with

lsClient.enableSharing(new Lightstreamer.ConnectionSharing("XXX", "ATTACH", "CREATE"));

we are getting "randomly" exceptions "Expecting a different value" (here is screenshot https://s3.postimg.io/q3osla4xv/2016_08_17_1.png). It happends in "slave" browser tab. Tested in Google Chrome. When we disable connection sharing, these problems disappears. Can you tell us what this error means or what can we do to prevent it? Thanks.
August 23rd, 2016, 11:54 AM
DarioCrivelli

Hello. This is not a known issue.
Does the client still work normally when you see this log?
Can you see if the log lines correspond to updates coming from the Server?
We must collect information by enriching the client log.
Please add the following block at the beginnig of your Lightstreamer-related code.

Code:

require(["SimpleLoggerProvider","ConsoleAppender","LightstreamerClient","LogMessages"], function(SimpleLoggerProvider,ConsoleAppender,LightstreamerClient) { var loggerProvider = new SimpleLoggerProvider(); LightstreamerClient.setLoggerProvider(loggerProvider); loggerProvider.addLoggerAppender(new ConsoleAppender("DEBUG","lightstreamer.sharing")); loggerProvider.addLoggerAppender(new ConsoleAppender("DEBUG","lightstreamer.subscriptions")); });

Note that if you make many subscriptions the log may be huge. In that case, please try to set up a shorter test case.
September 1st, 2016, 10:52 AM
palcov

Hello. This happens as far as we noticed in Google Chrome (previous and current version 53.0.2785.89 m). Not noticed it in other browsers, but cannot be totaly sure, because this error does not happen in 100% cases. But always it is in shared connection scenario in slave tab. Client works normally in sense it updates content of HTML fields, but then throw exception before exectuing our callbacks (so we cannot do additional DOM updates).
Here is debug consoles:

Master:

Quote:

lightstreamer.js:495
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,653 | 2] Broadcasting setting to shared LightstreamerClient instances {serverAddress http://push.www.onlajnylocal.com:8080/ }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,657 | 2] Broadcasting setting to shared LightstreamerClient instances {adapterSet ONLAJNY }
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:29,677 | 325] A sharing will now be searched {}
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:29,678 | 297] Start search for an engine {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,679 | 307] Searching for available sharing {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,679 | 312] check shared storage to find a valid engine {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,681 | 321] no valid engine values found, check again in {200 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,880 | 320] No compatible sharing detected {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,881 | 313] storage inspection complete {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,881 | 314] no valid engine found {}
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:29,881 | 298] No sharing was found, a new sharing will be created {}
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:29,882 | 296] Stop search for an engine {}
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:29,887 | 267] SharedStatus remote sharing is ready {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,889 | 2] Broadcasting setting to shared LightstreamerClient instances {clientsCount 1 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,889 | 22] New client attached to engine {[|PushPageCollectionHandler|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,890 | 2] Broadcasting setting to shared LightstreamerClient instances {connectionRequested true }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,891 | 2] Broadcasting setting to shared LightstreamerClient instances {sessionId NULL }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,892 | 2] Broadcasting setting to shared LightstreamerClient instances {serverSocketName NULL }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:29,892 | 2] Broadcasting setting to shared LightstreamerClient instances {serverInstanceAddress NULL }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,23 | 2] Broadcasting setting to shared LightstreamerClient instances {sessionId Sd8b19001d8342289T4229902 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,24 | 2] Broadcasting setting to shared LightstreamerClient instances {serverSocketName Lightstreamer HTTP Server }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,24 | 2] Broadcasting setting to shared LightstreamerClient instances {serverInstanceAddress http://push.www.onlajnylocal.com:8080/ }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,111 | 2] Broadcasting setting to shared LightstreamerClient instances {keepaliveInterval 5000 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,113 | 2] Broadcasting setting to shared LightstreamerClient instances {maxBandwidth 0 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,246 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | INFO | ibbid=BBID-01-0116789343678501311:42:30,275 | 269] Started refresh thread {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:30,306 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:31,332 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:31,332 | 274] No engines {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:31,333 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:32,350 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:32,351 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:32,352 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,399 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,399 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,400 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,703 | 2] Broadcasting setting to shared LightstreamerClient instances {clientsCount 2 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,704 | 22] New client attached to engine {[|PushPageCollectionHandler|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,719 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:33,725 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:34,632 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:34,633 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:34,633 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,579 | 2] Broadcasting setting to shared LightstreamerClient instances {clientsCount 3 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,580 | 22] New client attached to engine {[|PushPageCollectionHandler|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,604 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,605 | 26] Notify back to the client that the subscription was handled {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,632 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,632 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:35,633 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,632 | 23] Dismissing client {[|PushPageCollectionHandler|] 1 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,634 | 2] Broadcasting setting to shared LightstreamerClient instances {clientsCount 2 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,641 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,642 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,643 | 278] Write engine shared status {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,650 | 25] Can't find page anymore {}
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:36,652 | 25] Can't find page anymore {}
2lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:37,599 | 23] Dismissing client {[|PushPageCollectionHandler|] 1 }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:37,649 | 273] Checking status {[SharedStatus|488|OnlajnyConnection|] }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:37,649 | 275] Checking shared status to verify if there are similar engines alive {OnlajnyConnection }
lightstreamer.sharing | DEBUG | ibbid=BBID-01-0116789343678501311:42:37,649 | 278] Write engine shared status {}

etc ... last 3 rows repeat every 1 second from now, no other messages

(continue in next post due to message limit)
September 1st, 2016, 10:53 AM
palcov

1 Attachment(s)

Slave:

Quote:

lightstreamer.js:495
lightstreamer.sharing | DEBUG | 11:35:04,260 | 2] Broadcasting setting to shared LightstreamerClient instances {serverAddress http://push.www.XXX.com:8080/ }
lightstreamer.sharing | DEBUG | 11:35:04,264 | 2] Broadcasting setting to shared LightstreamerClient instances {adapterSet ONLAJNY }
lightstreamer.sharing | INFO | 11:35:04,274 | 325] A sharing will now be searched {}
lightstreamer.sharing | INFO | 11:35:04,275 | 297] Start search for an engine {}
lightstreamer.sharing | DEBUG | 11:35:04,276 | 307] Searching for available sharing {}
lightstreamer.sharing | DEBUG | 11:35:04,276 | 312] check shared storage to find a valid engine {}
lightstreamer.sharing | DEBUG | 11:35:04,278 | 313] storage inspection complete {}
lightstreamer.sharing | INFO | 11:35:04,279 | 304] valid engine values found, will try to connect to it {}
lightstreamer.sharing | DEBUG | 11:35:04,279 | 315] sharing through shared worker {}
lightstreamer.sharing | INFO | 11:35:04,279 | 302] A sharing was found, this will attach to it {}
lightstreamer.sharing | INFO | 11:35:04,293 | 296] Stop search for an engine {}
lightstreamer.subscriptions | DEBUG | 11:35:04,488 | 13] Restoring all pending Subscriptions {}
lightstreamer.subscriptions | DEBUG | 11:35:04,682 | 346] Adapter Set assigned {[|Subscription|1|0||0||] COMMENTS }
lightstreamer.subscriptions | DEBUG | 11:35:04,682 | 350] Snapshot Required assigned {[|Subscription|1|0||0||] yes }
lightstreamer.subscriptions | INFO | 11:35:04,692 | 10] Subscribing subscription {[|Subscription|1|0||0||] }
lightstreamer.subscriptions | INFO | 11:35:04,693 | 336] Subscription entered the active state {[|Subscription|5|0|1|1|2|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,693 | 12] sending Subscription to the engine {}
lightstreamer.subscriptions | DEBUG | 11:35:04,694 | 344] Subscription request generated {[|Subscription|5|0|1|1|2|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,695 | 340] Subscription waiting to be sent to server {[|Subscription|2|0|1|2|2|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,719 | 346] Adapter Set assigned {[|Subscription|1|0||0||] MATCHES }
lightstreamer.subscriptions | DEBUG | 11:35:04,720 | 350] Snapshot Required assigned {[|Subscription|1|0||0||] yes }
lightstreamer.subscriptions | INFO | 11:35:04,756 | 10] Subscribing subscription {[|Subscription|1|0||0||] }
lightstreamer.subscriptions | INFO | 11:35:04,756 | 336] Subscription entered the active state {[|Subscription|5|0|2|1|3|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,756 | 12] sending Subscription to the engine {}
lightstreamer.subscriptions | DEBUG | 11:35:04,757 | 344] Subscription request generated {[|Subscription|5|0|2|1|3|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,757 | 340] Subscription waiting to be sent to server {[|Subscription|2|0|2|2|3|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,819 | 341] Subscription queued to be sent to server {[|Subscription|3|0|1|2|2|] }
lightstreamer.subscriptions | DEBUG | 11:35:04,820 | 341] Subscription queued to be sent to server {[|Subscription|3|0|2|2|3|] }
lightstreamer.subscriptions | INFO | 11:35:05,28 | 337] Subscription is now subscribed to {[|Subscription|4|0|2|2|3|] }
lightstreamer.js:496 weswit.test | ERROR | ibbid=BBID-01-0116789343678501311:35:17,191 | 386] Expecting a different value {4 3 }
lightstreamer.js:496 weswit.test | ERROR | ibbid=BBID-01-0116789343678501311:35:17,231 | 386] Expecting a different value {4 3 }

And here is stack trace of error:
Attachment 208

Iam sorry for big logs, we can search for particular messages if you ask to. But as I said, we disabled sharing and problems are gone, so it is not fatal issue now.
September 2nd, 2016, 02:10 PM
DarioCrivelli

Hi, thank you for the collaboration.
The log shows that there is a message which is not received by the slave page, but we can't figure out a possible cause.
We must refine the log and, to do so, we have to provide you with an extended library.
I will send you a private message with instructions.

By the way, the log times in the "Master" and "Slave" logs don't match.
Can you confirm that they were taken at the same time?
This was not important, but will become so for logs taken with the extended library.
September 20th, 2016, 09:50 AM
DarioCrivelli

With Palcov's help we have finally found a bug in the library code.
The bug should be limited to "slave" pages in a connection sharing scenario and is triggered by unusual delays in the execution of internal tasks; one possible cause is a heavy page startup.

If anyone experiences similar problems, until a new release of Lightstreamer with the fixed library is available, it can be downloaded here.