Topics

WSJT-X v2.3.0-rc2 WSJTXModule.HandleData: Datagram contains another message that doesn't start with a magic number


K0BBC
 
Edited

I've been testing WSJT-X v2.3.0-rc2 and have been recording this error in SC_WSJTX_Errorlog.txt
I have not been able to duplicate this error in General Availability (GA) release:  WSJT-X 2.2.2
The error appears to be generated when I click "Log QSO" in WSJT-X and the handoff begins to DXLab.
The QSO still gets logged and I see no ill-effects form this error, but, thought I would share in case other users see it.
#WSJT-X #beta

2021-01-07 15:03:34.847 > WSJTXModule.HandleData: Datagram contains another message that doesn't start with a magic number: MessageLength = 147, LastMessagePos = 143
2021-01-07 15:03:34.848 > Message Type = 5
2021-01-07 15:03:34.849 > WSJTXModule.HandleData Datagram contained another message, but that nessage is missing a magic number; flushing it
2021-01-07 15:03:34.849 >                                                                     W   S   J   T   -   X                       %       V       ;   .                           Y   O   4   S   X                   K   N   4   4                                                   F   T   8                   -   1   0                   -   2   4                   3   2   0                                                       %       V       :                               K   0   B   B   C                   K   0   B   B   C                   F   N   3   1                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     
2021-01-07 15:03:34.850 >   173 188 203 218 000 000 000 002 000 000 000 005 000 000 000 006 087 083 074 084 045 088 000 000 000 000 000 037 134 086 003 059 046 169 001 000 000 000 005 089 079 052 083 088 000 000 000 004 075 078 052 052 000 000 000 000 000 214 197 227 000 000 000 003 070 084 056 000 000 000 003 045 049 048 000 000 000 003 045 050 052 000 000 000 003 051 050 048 000 000 000 000 000 000 000 000 000 000 000 000 000 037 134 086 003 058 187 214 001 000 000 000 005 075 048 066 066 067 000 000 000 005 075 048 066 066 067 000 000 000 004 070 078 051 049 000 000 000 000 000 000 000 000 255 255 255 255 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 
 


Dave AA6YQ
 

+ AA6YQ comments below

I've been testing WSJT-X v2.3.0-rc2 and have been recording this error in SC_WSJTX_Errorlog.txt I have not been able to duplicate this error in General Availability (GA) release: WSJT-X 2.2.2 The error appears to be generated when I click "Log QSO" in WSJT-X and the handoff begins to DXLab.
The QSO still gets logged and I see no ill-effects form this error, but, thought I would share in case other users see it.
#WSJT-X #beta


2021-01-07 15:03:34.847 > WSJTXModule.HandleData: Datagram contains another message that doesn't start with a magic number: MessageLength = 147, LastMessagePos = 143
2021-01-07 15:03:34.848 > Message Type = 5
2021-01-07 15:03:34.849 > WSJTXModule.HandleData Datagram contained another message, but that nessage is missing a magic number; flushing it
2021-01-07 15:03:34.849 > W S J T - X % V ; . Y O 4 S X K N 4 4 F T 8 - 1 0 - 2 4 3 2 0 % V : K 0 B B C K 0 B B C F N 3 1
2021-01-07 15:03:34.850 > 173 188 203 218 000 000 000 002 000 000 000 005 000 000 000 006 087 083 074 084 045 088 000 000 000 000 000 037 134 086 003 059 046 169 001 000 000 000 005 089 079 052 083 088 000 000 000 004 075 078 052 052 000 000 000 000 000 214 197 227 000 000 000 003 070 084 056 000 000 000 003 045 049 048 000 000 000 003 045 050 052 000 000 000 003 051 050 048 000 000 000 000 000 000 000 000 000 000 000 000 000 037 134 086 003 058 187 214 001 000 000 000 005 075 048 066 066 067 000 000 000 005 075 048 066 066 067 000 000 000 004 070 078 051 049 000 000 000 000 000 000 000 000 255 255 255 255 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000

+ The error message is caused by the unexpected appearance of 4 bytes

255 255 255 255

+ after a valid "QSO Logged" message. Since these bytes do not appear within the framework of a valid message, they are discarded.

+ Bill G4WJS, are these 4 bytes being intentionally sent in WSJT-X v2.3.0-rc2 ?

73,

Dave, AA6YQ


g4wjs
 

On 07/01/2021 21:29, Dave AA6YQ wrote:
+ AA6YQ comments below

I've been testing WSJT-X v2.3.0-rc2 and have been recording this error in SC_WSJTX_Errorlog.txt I have not been able to duplicate this error in General Availability (GA) release: WSJT-X 2.2.2 The error appears to be generated when I click "Log QSO" in WSJT-X and the handoff begins to DXLab.
The QSO still gets logged and I see no ill-effects form this error, but, thought I would share in case other users see it.
#WSJT-X #beta


2021-01-07 15:03:34.847 > WSJTXModule.HandleData: Datagram contains another message that doesn't start with a magic number: MessageLength = 147, LastMessagePos = 143
2021-01-07 15:03:34.848 > Message Type = 5
2021-01-07 15:03:34.849 > WSJTXModule.HandleData Datagram contained another message, but that nessage is missing a magic number; flushing it
2021-01-07 15:03:34.849 > W S J T - X % V ; . Y O 4 S X K N 4 4 F T 8 - 1 0 - 2 4 3 2 0 % V : K 0 B B C K 0 B B C F N 3 1
2021-01-07 15:03:34.850 > 173 188 203 218 000 000 000 002 000 000 000 005 000 000 000 006 087 083 074 084 045 088 000 000 000 000 000 037 134 086 003 059 046 169 001 000 000 000 005 089 079 052 083 088 000 000 000 004 075 078 052 052 000 000 000 000 000 214 197 227 000 000 000 003 070 084 056 000 000 000 003 045 049 048 000 000 000 003 045 050 052 000 000 000 003 051 050 048 000 000 000 000 000 000 000 000 000 000 000 000 000 037 134 086 003 058 187 214 001 000 000 000 005 075 048 066 066 067 000 000 000 005 075 048 066 066 067 000 000 000 004 070 078 051 049 000 000 000 000 000 000 000 000 255 255 255 255 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000 000

+ The error message is caused by the unexpected appearance of 4 bytes

255 255 255 255

+ after a valid "QSO Logged" message. Since these bytes do not appear within the framework of a valid message, they are discarded.

+ Bill G4WJS, are these 4 bytes being intentionally sent in WSJT-X v2.3.0-rc2 ?

73,

Dave, AA6YQ
Hi Dave,

yes, there is a new field added to the QSO Logged(5) UDP message. It is the propagation mode which is available as a drop down list in the WSJT-X "Log QSO" dialog.

This should not be an issue, the WSJT-X UDP protocol is intended to be extendable by adding new fields to the end of existing messages, applications written before the field specification was extended should not be caring about messages arriving that are longer than they expected, or shorter either as they may emanate fro an older version of WSJT-X. I do realize that the nasty behaviour of the VB6 WinInet control, where it can sometimes concatenate multiple received datagrams with no mechanism to separate them, is not helpful but you should look for the magic number field that is at the start of every datagram and any data after a message should be silently ignored unless a second or subsequent magic number field is discovered. Likewise short messages should be parsed with default values for any fields that are missing.




--
73

Bill

G4WJS.


Dave AA6YQ
 

+ AA6YQ comments below
yes, there is a new field added to the QSO Logged(5) UDP message. It is the propagation mode which is available as a drop down list in the WSJT-X "Log QSO" dialog.

This should not be an issue, the WSJT-X UDP protocol is intended to be extendable by adding new fields to the end of existing messages, applications written before the field specification was extended should not be caring about messages arriving that are longer than they expected, or shorter either as they may emanate fro an older version of WSJT-X. I do realize that the nasty behaviour of the VB6 WinInet control, where it can sometimes concatenate multiple received datagrams with no mechanism to separate them, is not helpful but you should look for the magic number field that is at the start of every datagram and any data after a message should be silently ignored unless a second or subsequent magic number field is discovered.

+ That's exactly how incoming messages from WSJT-X are handled. Unexpected fields are discarded -- but they are noted in the errorlog if "log debugging info" is enabled.

        73,

              Dave, AA6YQ

 

Likewise short messages should be parsed with default values for any fields that are missing.


g4wjs
 

On 08/01/2021 00:56, Dave AA6YQ wrote:
+ AA6YQ comments below
yes, there is a new field added to the QSO Logged(5) UDP message. It is the propagation mode which is available as a drop down list in the WSJT-X "Log QSO" dialog.

This should not be an issue, the WSJT-X UDP protocol is intended to be extendable by adding new fields to the end of existing messages, applications written before the field specification was extended should not be caring about messages arriving that are longer than they expected, or shorter either as they may emanate fro an older version of WSJT-X. I do realize that the nasty behaviour of the VB6 WinInet control, where it can sometimes concatenate multiple received datagrams with no mechanism to separate them, is not helpful but you should look for the magic number field that is at the start of every datagram and any data after a message should be silently ignored unless a second or subsequent magic number field is discovered.

+ That's exactly how incoming messages from WSJT-X are handled. Unexpected fields are discarded -- but they are noted in the errorlog if "log debugging info" is enabled.

        73,

              Dave, AA6YQ

Hi Dave,

that's good, although the debug log message is not really accurate:

2021-01-07 15:03:34.847 > WSJTXModule.HandleData: Datagram contains another message that doesn't start with a magic number: MessageLength = 147, LastMessagePos = 143
2021-01-07 15:03:34.848 > Message Type = 5
2021-01-07 15:03:34.849 > WSJTXModule.HandleData Datagram contained another message, but that nessage is missing a magic number; flushing it

since there is no second datagram, just an unexpected field appended. Note also that there is a one-to-one relationship between messages and datagrams, the situation where two datagrams are combined by the the WinInet control implementation is purely artificial and does not reflect reality.


--
73

Bill

G4WJS.


Dave AA6YQ
 

+ AA6YQ comments below
that's good, although the debug log message is not really accurate:
+ The diagnostic message is sufficiently accurate for its sole audience: me.

       73,

              Dave, AA6YQ


Daniel Violette
 

By coincidence, I installed WSJT-X v2.3.0-rc3 tonight because of some minor issues I decided not to fight anymore with v2.2.0 and to try the latest RC.  I noticed the “see SC_WSJTX_Errorlog.txt” message and checked it.  My error log had grown to 8MB since it was being updated with new error (same as others listed) about every half second.  Then I read the last two days’ worth of DXLab group mails and see others with issue. I checked and all “Log Debugging Information” appear unchecked in all running modules but keeps logging the error.

 

Dan KI6X


Dave AA6YQ
 

+ AA6YQ comments below
By coincidence, I installed WSJT-X v2.3.0-rc3 tonight because of some minor issues I decided not to fight anymore with v2.2.0 and to try the latest RC.  I noticed the “see SC_WSJTX_Errorlog.txt” message and checked it.  My error log had grown to 8MB since it was being updated with new error (same as others listed) about every half second.  Then I read the last two days’ worth of DXLab group mails and see others with issue. I checked and all “Log Debugging Information” appear unchecked in all running modules but keeps logging the error.

+ The UDP messages emitted by WSJT-X do not include a "total message length" specifier. It is thus necessary for a recipient of these messages to sequentially inspect each field in order to locate the end of that message, even if the recipient knows from the "message kind" field at the beginning of the message that it has no interest in the message.

+ When a new version of WSJT-X appends new fields to a message type, the recipient's code must deal with the unexpected fields.

+ When I was informed that WSJT-X 2.2 would revoke some of "callsign coloring" functionality used in DXLab's direct interoperation with WSJT-X 2.1, I had to quickly re-architect SpotCollector's interoperation with WSJT-X to compensate. As Bill G4WJS mentions whenever he can, the UDP component in the Microsoft VB6 development environment I use to build DXLab applications has some deficiencies. There was no time to replace this component with a commercial alternative, much less develop one myself. So I added bulletproofing to prevent these weaknesses from causing malfunctions, and added instrumentation to detect any malfunctions that I might have missed. Until yesterday, no one has reported entries in SpotCollector's errorlog.txt file created by this instrumentation. 

+ WSJT-X 2.3, I now understand, has added fields to several of its UDP messages. The unexpected presence of these fields combined with the absence of a "total message length" specifier in WSJT-X messages triggers one aspect of the above instrumentation. Correct operation is in no way impeded, but new errorlog.txt file entries are created. Updating SpotCollector to expect these new fields when interoperating with WSJT-X 2.3 should be straightforward.

+ Expect this situation to recur whenever a new version of WSJT-X adds fields to its UDP messages. I'll try to remember to download the source code for new versions of WSJT-X to see if new fields have been appended to its UDP messages.

       73,

              Dave, AA6YQ

 

 

 

 

 


Dave AA6YQ
 

+ AA6YQ comments below
I've been testing WSJT-X v2.3.0-rc2 and have been recording this error in SC_WSJTX_Errorlog.txt
I have not been able to duplicate this error in General Availability (GA) release:  WSJT-X 2.2.2
The error appears to be generated when I click "Log QSO" in WSJT-X and the handoff begins to DXLab.
The QSO still gets logged and I see no ill-effects form this error, but, thought I would share in case other users see it.
#WSJT-X #beta

+ Matt, I've sent you and Dan KI6X a new version of SC_WSJTX that handles the additional field that handles the new fields in UDP messages reported by WSJT-X 2.3.0-rc3. Please let me know how it goes...

          73,

                 Dave, AA6YQ