OTMonitor 6.3 stops updating state when MQTT enabled

[mvdp]

I recently switched to OTMonitor version 6.3. I kept the firmware on version 4.3. This monitor is running on a raspberry pi starting from systemd.

The monitor is connected with Domoticz. I know that the standard Domoticz client keeps the monitor in PS=1 mode. That's why I have a script running that fires a PS=0 command every minute. That way both the OTMonitor webgui and Domoticz are kept up to date.
This setup was working fine until I upgraded to 6.3.

After a while I noticed that monitor was kind of stuck. Domoticz nor the otmonitor status window shows updated values.
journalctl -u shows me this console output:

Code: Select all

Dec 12 08:29:27 pi systemd[1]: Started otmonitor.
Dec 12 16:48:51 pi otmonitor[717]: can't read "mqtt": no such variable
Dec 12 16:48:51 pi otmonitor[717]:     while executing
Dec 12 16:48:51 pi otmonitor[717]: "$mqtt publish $topic [json build object json2 $d] $qos $retain"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "json2" line 6)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "json2 {def {"" string} value {T00630000,
Dec 12 16:48:51 pi otmonitor[717]: R801C0000}}"
Dec 12 16:48:51 pi otmonitor[717]:     (in namespace eval "::json::layout" script line 1)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "namespace eval layout [list $layout {*}$args]"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "build" line 2)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "json build object json2 $data"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "mqttpub" line 8)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "mqttpub $cfg(mqtt,eventtopic)/Message $data 0"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "mqttmessage" line 4)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "mqttmessage $src"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "otmessage" line 5)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "otmessage $us $line [expr {$type & 7}] $id $data"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "process" line 13)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "process [append data $line]"
Dec 12 16:48:51 pi otmonitor[717]:     (procedure "receive" line 6)
Dec 12 16:48:51 pi otmonitor[717]:     invoked from within
Dec 12 16:48:51 pi otmonitor[717]: "receive"
Dec 12 23:48:52 pi systemd[1]: Stopping otmonitor...
Dec 12 23:48:52 pi systemd[1]: Stopped otmonitor.
Dec 12 23:48:52 pi systemd[1]: Started otmonitor.
Dec 13 06:44:53 pi otmonitor[19675]: can't read "mqtt": no such variable
Dec 13 06:44:53 pi otmonitor[19675]:     while executing
Dec 13 06:44:53 pi otmonitor[19675]: "$mqtt publish $topic [json build object json2 $d] $qos $retain"
Dec 13 06:44:53 pi otmonitor[19675]:     (procedure "json2" line 6)
Dec 13 06:44:53 pi otmonitor[19675]:     invoked from within
Dec 13 06:44:53 pi otmonitor[19675]: "json2 {def {"" string} value {BE01C0000,
Dec 13 06:44:53 pi otmonitor[19675]: AC0091200}}"

I'm now running otmonitor with mqtt disabled and the problem has not occurred yet.

When "can't read "mqtt": no such variable" is thrown I was not interacting myself with otmonitor.
Is this a known issue? Is there more I can do to find the cause of the can't read "mqtt" error?
I have no logs for the times mentioned above. I've enabled full logging while my experiment with mqtt disabled is running.

In the end I want to enable mqtt again to allow for the latest version of the firmware so I can still feed the Opentherm data into Domoticz.

[hvxl]

I'm not aware that anything changed in this area for a long time, so I haven't specifically tested it before releasing OTmonitor 6.3. I will look into it.

If I understand correctly, domoticz sends PS=1 every 30 seconds. By asynchronously sending PS=0 every minute, you will still miss many messages. If you have an OTGW with a NodeMCU or Wemos, you may be interested in using rvdbreemen's OTGW-firmware with an alternative domoticz integration that doesn't use the PS=1 command, so it doesn't deprive other applications from getting all available information.

[hvxl]

Your journalctl output shows that the problem only happens after otmonitor has been running for several hours. Secondly, you somehow seem to have received a report containing two opentherm messages, separated by a comma and a newline. I don't know how that can happen, but I suspect it may be caused by sending a PS=0 command, while the OTGW is in the middle of sending a PS=1 report. I have tried to reproduce that situation, but apparently haven't managed to recreate the exact conditions needed.

The error pointed to a real problem, but you should never get to that part of the code under normal circumstances. I have fixed it, but in case of mangled lines you would still run into another error. So I have also added some more checks to OTmonitor that should filter out malformed messages. In addition, I catch errors that happen when sending mqtt messages, so even in unforeseen circumstances otmonitor should not get stuck.

These fixes are available in the latest check-in on github.

[mvdp]

If I understand correctly, domoticz sends PS=1 every 30 seconds. By asynchronously sending PS=0 every minute, you will still miss many messages.

Thanks for looking into this. I am aware that the PS=0 command every minute gives a reduced view on all the messages. This was the simplest solution I could think of to allow both providing the otmonitor info in Domoticz and to show info on the otmonitor webgui.
The best solution would be to configure Domoticz to send the PS=0 command after it has send the PS=1 command and processed its response.

I will change my temporary solution to wait for the PS=1 command from Domoticz and after a short timeout send the PS=0 command again.

[hvxl]

OTmonitor currently will send a PS=0 after a PS=1 report when collecting a capability log. Maybe I should make it an option to do that always.

But the best solution is to use the alternative domoticz integration I pointed to.

[mvdp]

Thanks. I will look into the alternative solution.

[Bartb]

OTmonitor currently will send a PS=0 after a PS=1 report when collecting a capability log. Maybe I should make it an option to do that always.

I second that. Would make reading things a lot easier and be very usefull.