DISTINCT updates are NULL with recent LS server

[rsouissi]

Hi,

I upgraded the LS server I was using (3.4 build 1320) to the latest 3.4.7 and this has caused the following issue:

- I subscribe to a news item in DISTINCT mode
- When data adapter receives first time subscription, it calls listener.update(issnapshot=false) on all available news
- In the older version, I used to receive all updates
- With the latest version (with the old and new javascript libraries), I receive only NULL fields (getNewValue() returns NULL on all fields)

Any idea ?

This is the trace (the section highlighted below sometimes appears, sometimes it doesn't. When it appears, I only receive 1 news update instead of many more)



03.Mar.08 00:27:31,176 < INFO> Starting new session: S-756498897N9 from 127.0.0.1:54130
03.Mar.08 00:27:31,232 < INFO> Serving request: /lightstreamer/control.html?LS_session=S-756498897N9&LS_window=0&LS_win_phase=5&LS_op=add&LS_req_phase=51&LS_mode1=DISTINCT&LS_id1=BULLETIN&LS_schema1=%28ticker%29%28time%29%28text%29%28url%29%28language%29%28name_english%29%28name_other%29&LS_snapshot1=true&LS_requested_max_frequency1=1&LS_requested_buffer_size1=100&LS_unique=1 from 127.0.0.1:54132
03.Mar.08 00:27:31,234 < INFO> Controlling session: S-756498897N9 from 127.0.0.1:54132
03.Mar.08 00:27:31,237 <TRACE> Subscribing item BULLETIN on TADAWULDEMO
03.Mar.08 00:27:31,237 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,248 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,249 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XXX?, text=XXXX XX XX XX? XX XX? X XX CPIC XXXXXXX XX XX XX? XX XX? X XX CPIC XXX, time=2008/03/01 08:42:34, ticker=2160, shortname_other=XXXX, acronym_english=ABC, language=ar, name_english=ABC, name_other=XX XXXX XXX? XXXX, shortname_english=Amiantit}
03.Mar.08 00:27:31,249 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,250 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XXX?, text=No Translation, See the other Version No Translation, See the other Version, time=2008/03/01 08:42:34, ticker=2160, shortname_other=XXXX, acronym_english=ABC, language=en, name_english=ABC, name_other=XX XXXX XXX? XXXX, shortname_english=Amiantit}
03.Mar.08 00:27:31,250 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XX?, text=XX XXX? XXXXXXX XX X XXX? XXX? XXX? XXX? XXXX XXX? XXXXXXX XX X XXX? XXX? XXX? XXX? XX? XXX? X 31 XXX 2007? ., time=2008/02/29 09:00:29, ticker=2260, shortname_other=XXXXXXX, acronym_english=SPC, language=ar, name_english=Petrochemical Co, name_other=XX XXX? XXXXXXX, shortname_english=Petrochemical}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XX?, text=No Translation, See the other Versionb No Translation, See the other Version, time=2008/02/29 09:00:29, ticker=2260, shortname_other=XXXXXXX, acronym_english=SPC, language=en, name_english=Petrochemical Co, name_other=XX XXX? XXXXXXX, shortname_english=Petrochemical}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XX?, text=XX XXX? XXXXXXX XX X XXX? XXX? XXX? XXX? XXXX XXX? XXXXXXX XX X XXX? XXX? XXX? XXX? XXXXX? X 31 XXX 2007? ., time=2008/03/01 09:00:29, ticker=2260, shortname_other=XXXXXXX, acronym_english=SPC, language=ar, name_english=Petrochemical Co, name_other=XX XXX? XXXXXXX, shortname_english=Petrochemical}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=XX?, text=No Translation, See the other Version No Translation, See the other Version, time=2008/03/01 09:00:29, ticker=2260, shortname_other=XXXXXXX, acronym_english=SPC, language=en, name_english=Petrochemical Co, name_other=XX XXX? XXXXXXX, shortname_english=Petrochemical}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=? XX, text=XX XX? XXX XX X XXX? XXX? XXX? XX? XXX? XXXX XXX XX? XXX XX X XXX? XXX? XXX? XX? XXX? XXXX X 31/12/2007?., time=2008/02/29 10:06:04, ticker=3040, shortname_other=? XX, acronym_english=QACCO, language=ar, name_english=The Cement Co, name_other=XX XX? XXX, shortname_english=QACCO}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=? XX, text=No Translation, See the other Version No Translation, See the other Version, time=2008/02/29 10:06:04, ticker=3040, shortname_other=? XX, acronym_english=QACCO, language=en, name_english=The Cement Co, name_other=XX XX? XXX, shortname_english=QACCO}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=xxxxxxxxxxx XX XX? XXX XX X XXX? XXX? XXX? XX? XXX? XXXX X 31/12/2007?., time=2008/03/01 10:06:04, ticker=3040, shortname_other=? XX, acronym_english=AAAA, language=ar, name_english=AAAA, name_other=XX XX? XXX, shortname_english=QACCO}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> INCOMING DATA for BULLETIN --> {id=BULLETIN, acronym_other=? XX, text=No Translation, See the other Version No Translation, See the other Version, time=2008/03/01 10:06:04, ticker=3040, shortname_other=? XX, acronym_english=AAAA, language=en, name_english=AAAA, name_other=XX XX? XXX, shortname_english=QACCO}
03.Mar.08 00:27:31,308 <DEBUG> Manager: com.lightstreamer.f.gb@1f217ec
03.Mar.08 00:27:31,308 <TRACE> Pumping event in session S-756498897N9: c(6,5,0);setWin(0,5);
03.Mar.08 00:27:31,308 < WARN> Data type other than String or byte array received in update event
03.Mar.08 00:27:31,308 < INFO> Reused HTTP connection on Lightstreamer HTTP Server from 127.0.0.1:54132
03.Mar.08 00:27:31,511 <TRACE> Pumping event in session S-756498897N9: z(0,1,1,"#","#","#","#","#","#","#");z(0,1,1,"","","","","","","");z(0,1,1,"","","","","","","");z(0,1,1,"","","","","","","");z(0,1,1,"","","","","","","");z(0,1,1,"","","","","","","");z(0,1,1,"","","","","","","");n(0,1,1);
03.Mar.08 00:27:32,135 < INFO> Serving request: /td2/ls/lsblank.html from 127.0.0.1:54131
03.Mar.08 00:27:32,135 < INFO> Reused HTTP connection on Lightstreamer HTTP Server from 127.0.0.1:54131
03.Mar.08 00:27:32,518 <TRACE> Pumping event in session S-756498897N9: d(0,1,1,"3040","2008/03/01 10:06:04","\u0634\u0631\u0643\u0629 \u0627\u0633\u0645\u0646\u062A \u0627\u0644\u0642\u0635\u064A\u0645 \u062A\u0639\u0644\u0646 \u0639\u0646 \u0627\u0644\u0646\u062A\u0627\u0626\u062C \u0627\u0644\u0645\u0627\u0644\u064A\u0629 \u0627\u0644\u0645\u062F\u0642\u0642\u0629 \u0644\u0644\u0633\u0646\u0629 \u0627\u0644\u0645\u0627\u0644\u064A\u0629 \u0627\u0644\u0645\u0646\u062A\u0647\u064A\u0629 \u0641\u064A\u000A\u0634\u0631\u0643\u0629 \u0627\u0633\u0645\u0646\u062A \u0627\u0644\u0642\u0635\u064A\u0645 \u062A\u0639\u0644\u0646 \u0639\u0646 \u0627\u0644\u0646\u062A\u0627\u0626\u062C \u0627\u0644\u0645\u0627\u0644\u064A\u0629 \u0627\u0644\u0645\u062F\u0642\u0642\u0629 \u0644\u0644\u0633\u0646\u0629 \u0627\u0644\u0645\u0627\u0644\u064A\u0629 \u0627\u0644\u0645\u0646\u062A\u0647\u064A\u0629 \u0641\u064A\u000A 31/12/2007\u0645.","ar","The Cement Co","\u0634\u0631\u0643\u0629 \u0627\u0633\u0645\u0646\u062A \u0627\u0644\u0642\u0635\u064A\u0645");
03.Mar.08 00:27:33,532 <TRACE> Pumping event in session S-756498897N9: d(0,1,1,"","","No Translation, See the other Version\u000ANo Translation, See the other Version\u000A","","en","","");
03.Mar.08 00:27:35,544 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:37,556 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:39,569 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:41,581 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:43,594 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:45,606 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:47,618 <TRACE> Sending probe in session S-756498897N9
03.Mar.08 00:27:49,631 <TRACE> Sending probe in session S-756498897N9


Regards,
A

[DarioCrivelli]

We can't find an explaination. The Server does send a snapshot to the client, but all the fields are reported as NULL in the first event and as UNCHANGED (i.e. NULL) in the subsequent ones.
However, there is a WARN line which should be investigated further.
03.Mar.08 00:27:31,308 < WARN> Data type other than String or byte array received in update event
Consider that the Server issues this warning at most once every 10 seconds, hence the line shown may refer to multiple fields indeed.
Do you feel it's possible that some field values, despite being displayed correctly by the log (which is based on "toString"), are neither String objects not byte arrays?
Please, also check that the event objects are not reused by the Data Adapter (which is not allowed by the Data Adapter interface specifications). This could explain unexpected changes in field values, which would be due to race conditions; as a consequence, different behaviours exhibited by different Server versions would also be possible.

[rsouissi]

The same setup and data adapter works on the older version of LS, which means something in LS changed since then.

Regarding the warning, the log doesn't say which item, but if it was related to the DISTINCT BULLETIN item, then this is how it is notified:


public void subscribe(String itemName, boolean needsIterator) throws SubscriptionException
{
....
for(int i=0;i<history.size();i++)
{
ItemEvent data = history.get(i);
Map event = data.getEvent(true); // makes a HashMap copy
listener.update("BULLETIN", event, false);
}
}


This is the method ItemEvent.getEvent():

Map<String,String> event;
public Map<String,String> getEvent()
{
return (Map<String,String>)((HashMap)event).clone();
}


As you see, I clone every Map I send to LS.
Any idea ?

Thanks
A

[DarioCrivelli]

We have found the issue in the Server.
It only affects the cumulated snapshot for a DISTINCT item.
Note that, despite your setting of isSnapshot as false, your first updates are sent by the Server to your session as a snapshot, because the Server receives them before the subscription has completed.

We plan to release a fixed version within the current week.
Thank you very much for the notice.

[Alessandro]

Lightstreamer Server v.3.4.8 build 1398 is now available for download. This version fixes the issue reported in this thread.

Thanks,
Alessandro