RFXtrx: warning: Bad starting message; ignore byte messages

Plugins & Plugin Development USB RFXtrx Transceiver
#1

Hi I’m getting loads of RFXtrx433 log entries, is anyone else ?

Any idea of the cause?
Is there anything I can do ?

06 10/28/20 23:04:54.286 Device_Variable::m_szValue_set device: 242 service: upnp-rfxcom-com:serviceId:rfxtrx1 variable: VeraTime was: 1603926284 now: 1603926294 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x71659520>
02 10/28/20 23:04:54.287 luup_log:242: RFXtrx: warning: No decode method for message: 0D 0A 3C 6D 73 67 3E 3C 73 72 63 3E 43 43 <0x71659520>
02 10/28/20 23:04:54.424 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 31 <0x71659520>
02 10/28/20 23:04:54.425 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 32 <0x71659520>
02 10/28/20 23:04:54.426 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 38 <0x71659520>
02 10/28/20 23:04:54.426 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 2D <0x71659520>
02 10/28/20 23:04:54.427 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 76 <0x71659520>
02 10/28/20 23:04:54.429 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 31 <0x71659520>
02 10/28/20 23:04:54.430 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 2E <0x71659520>
02 10/28/20 23:04:54.430 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 32 <0x71659520>
02 10/28/20 23:04:54.431 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 39 <0x71659520>
02 10/28/20 23:04:54.436 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 3C <0x71659520>
02 10/28/20 23:04:54.437 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 2F <0x71659520>
02 10/28/20 23:04:54.439 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 73 <0x71659520>
02 10/28/20 23:04:54.440 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 72 <0x71659520>
02 10/28/20 23:04:54.441 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 63 <0x71659520>
02 10/28/20 23:04:54.441 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 3E <0x71659520>
02 10/28/20 23:04:54.442 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 3C <0x71659520>
02 10/28/20 23:04:54.443 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 64 <0x71659520>
02 10/28/20 23:04:54.443 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 73 <0x71659520>
02 10/28/20 23:04:54.444 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 62 <0x71659520>
02 10/28/20 23:04:54.445 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 3E <0x71659520>
02 10/28/20 23:04:54.445 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 30 <0x71659520>
02 10/28/20 23:04:54.446 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 32 <0x71659520>
02 10/28/20 23:04:54.447 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 34 <0x71659520>
02 10/28/20 23:04:54.447 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 37 <0x71659520>
02 10/28/20 23:04:54.448 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 39 <0x71659520>
02 10/28/20 23:04:54.449 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 3C <0x71659520>
02 10/28/20 23:04:54.449 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 2F <0x71659520>
02 10/28/20 23:04:54.450 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 64 <0x71659520>
02 10/28/20 23:04:54.452 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 73 <0x71659520>
02 10/28/20 23:04:54.453 luup_log:242: RFXtrx: warning: Bad starting message; ignore byte 62 <0x71659520>

Etc etc…

#2

To give you an idea of the scale, looking at the LuaUPnpLog,

3587 related lines out of 7133 lines; just over half are related to this message (@tinman any ideas?)

image
image1774×604 367 KB

#3

I see this on a restart sometimes - it’s not really a problem, If the RFXtrx for some reason is sending data to the Vera hub when the hub is doing a reload then messaging gets out of sync. The plugin code must receive the start of a message. If it’s receiving data but it’s not a message start then the data is ignored. Once a message start is recognized things operate normally.

#4

Thanks @tinman

  • Is there anything that can be done to lessen the number or maybe have it sync up sooner ? -

As you can see I have been getting quite a lot of these, and I’m trying to use my logs to check on things more and this is impacting the log load times :frowning:

#5

It shouldn’t be happening very often at all. If it is happening frequently something else may wrong. I have an old log that covers more than 50 hours and it only shows three instances of this problem occurring and for each occurrence there are 4 or less warning messages.
In the next release of the plugin I’ll modify the code so that a warning will be logged on the first bad starting byte and another message will be logged on the first good starting byte after bad starting byte.

#6

Thanks @tinman

At the moment I’m trying out various new bits of code, so I can end up reloading luup many times - so I’m obviously not helping myself :slight_smile: