TODO warnings in log after migrating to OH3.1

Setup, Configuration and Use Beginners
1

After migrating to OH3.1 from 2.5.12, I am getting this type of warnings in my log;

2021-09-07 09:12:19.622 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:12:58.908 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:13:41.112 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:17:33.322 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:18:14.112 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:18:54.356 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:37:06.298 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:37:46.677 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:38:24.338 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:40:20.774 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:41:00.976 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
2021-09-07 09:41:38.725 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).

I believe they are related to the ZWAVE binding ? - but I am not sure…
Does anyone else have these - and/or know how I can narrow it down to a specific thing/device ?

I am running OH 3.1 on OpenHabian in Debian Linux…

2

Yes they’re ZWave messages so increase log level on org.openhab.binding.zwave.
I have seen them in 2.X and wouldn’t think they’re caused by the upgrade. Searching the forum for that should get you more information.

3

Hmm. Doing that gets me this in the ZWAVE log;

> 2021-09-07 16:15:08.186 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 15 00 49 40 11 0F 04 21 01 5E 31 70 85 80 84 32 5A 59 73 86 72 F1 
> 2021-09-07 16:15:08.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=64, payload=40 11 0F 04 21 01 5E 31 70 85 80 84 32 5A 59 73 86 72 
> 2021-09-07 16:15:08.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=64, payload=40 11 0F 04 21 01 5E 31 70 85 80 84 32 5A 59 73 86 72 
> 2021-09-07 16:15:08.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 3022: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 70
> 2021-09-07 16:15:08.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
> 2021-09-07 16:15:08.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 3022: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 70
> 2021-09-07 16:15:08.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 3022: (Callback 70)
> 2021-09-07 16:15:08.191 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=17, callback=64, payload=40 11 0F 04 21 01 5E 31 70 85 80 84 32 5A 59 73 86 72 
> 2021-09-07 16:15:08.191 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).
> 2021-09-07 16:15:08.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
> 2021-09-07 16:15:08.192 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.

Any idea what causes this ? - and what zwave device should I be looking at ?

4

None. As I said search the forum, I vaguely recall there was some message from @chris I think explaining it.

5

These TODO messages are not new - they have been in the binding from the very beginning so they are not causing a problem if it was working in an earlier version.

6

I did start getting these messages back in January on OH3. They did not start right away on the transition to OH3, but when I ttried to do a network heal. I never zeroed in on the problem and ended up rebuilding my zwave network, which was probably total overkill since everything was still basically working and I normally have the heal disabled unless I buy something new. Re-reading my posts with hindsight, I would suggest making sure that the Node ID of the controller is an exact match of the node ID in the Xml files. For some reason mine got out of sync in the transition.

Bob

7

This will not in any way change these messages. The messages are related to an incoming packet from the controller that is not processed by the binding. As I said above, this hasn’t changed over time, so should be the same for different versions of OH, and assuming the same controller.

If you maybe have changed to a new controller, with different features, then that might cause this. Also, while I’ve not looked at what these packets are, sometimes there are packets sent by secondary controllers to update the network that are ignored by the binding - so these sort of sporadic message might also cause this.

8

Just trying to help.
Having studied the binding, the serialmessage classes have been unchanged for some time; Agreed. I also can’t confirm the Node ID issue was involved with this message; so I’ll agree here too. So we’re all good on what it is not.

I did start getting the TODO message after an upgrade to OH3 and others apparently have also, including the person starting this thread. I did not change the controller and do not have any secondary controllers, but did experience some issues with the Node ID after the upgrade and trying to heal.

Maybe something changed in (or during) the upgrade to OH3 to make the binding “think” there was a new controller (at least during the heal process)? I used openhabian and had a couple of issues and had to back out the upgrade and redo. Anyway, as noted above I rebuilt my zwave network from scratch and don’t get the message anymore. That could be a solution, but it lacks finesse.

I found about 7 seconds of a debug file during a network heal from back in January with lots of the TODO messages. Maybe this could provide a clue to a solution? openhab.log (585.7 KB)

Bob

9

That’s possible - I’m not disputing that. On the other hand it’s often the case that people think this is the case, but when they look back at logs, whatever they think changed, was really there all along. This is really quite common - people will be “100% sure” that something changed, but it’s really only because they started looking at logs again that they see things they didn’t remember.

Who knows - all I can say is that the binding has not changed, and I suspect that such issues were probably there all along. The other possibility is that the additional traffic requested when the network is being reinitialised also causes some additional traffic that is not normally there. Either way, if the binding worked in OH2, and it hasn’t changed in OH3, then I think it’s safe to assume it will also work in OH3 :slight_smile:

What did you change? Again, as I said above, this could just be a transient issue - caused by the initialisation of the new network. Unless you have changed something specifically to account for this issue, then I don’t think you can claim that your recompiled version has changed this is and it’s a solution in any way at all.

10

OK. I read through the posts about the TODO’s and saw the ID thing mentioned. I deleted all zwave things, deleted the XMLs - removed my controller and set it up again in OH3. Warnings still come. The controller is unchanged - still an Aeontec Gen5 USB.

I may have overlooked that they were there before, as I removed logging on my ZWAVE binding specifically and havent looked too deep into my openhab log for some time before I migrated to OH3.

I will ignore it for now - everythiing seems to work, so no issues.

11

Hi
I also get these in my log been getting them for little a while with OH3 but as you say everything appears to work okay. Only thing that has changed for me is that I have added an additional Z-wave device, but I’m unsure if that was around the same time these messages started

2022-10-31 17:43:07.787 [WARN ] [essage.ApplicationUpdateMessageClass] - TODO: Implement Application Update Request Handling of New ID Assigned (64).