MQTT – setup and use
-
@akbooer I hate to add more to the pile... but I'm still seeing a receive error for the connection to mosquitto. openLuup 2021.04.29b
Here's the log error:
2021-05-01 14:22:38.815 openLuup.io.server:: MQTT:1882 connection closed tcp{client}: 0x5579919e9c58 2021-05-01 14:22:38.816 openLuup.mqtt:: RECEIVE ERROR: closed tcp{client}: 0x5579919e9c58 2021-05-01 14:22:43.935 luup.io.incoming:: bytes received: 51, status: OK tcp{client}: 0x557990e7f528 2021-05-01 14:22:48.435 luup.io.incoming:: bytes received: 51, status: OK tcp{client}: 0x557990e7f528 2021-05-01 14:22:49.763 luup.variable_set:: 10181.urn:micasaverde-com:serviceId:EnergyMetering1.KWHReading was: 1619904116 now: 1619904168 #hooks:0 2021-05-01 14:22:50.158 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x557991971ff8 2021-05-01 14:22:53.834 openLuup.io.server:: MQTT:1882 connection from 127.0.0.1 tcp{client}: 0x5579920dc0b8 2021-05-01 14:22:53.834 openLuup.mqtt:: client is in ERROR empty 2021-05-01 14:22:53.834 openLuup.mqtt:: credentials is in ERROR empty 2021-05-01 14:22:53.834 openLuup.mqtt:: subscriptions is in ERROR empty
using the below error trapping in function "MQTTservlet"
local function MQTTservlet (client) if client == nil then _log ("client is in ERROR nil") else if table.concat(client) == "" then _log ("client is in ERROR empty") else _log (table.concat {"MQTT ERROR: ", table.concat(client)}) end end if credentials == nil then _log ("credentials is in ERROR nil") else if table.concat(credentials) == "" then _log ("credentials is in ERROR empty") else _log (table.concat {"MQTT ERROR: ", table.concat(credentials)}) end end if subscriptions == nil then _log ("subscriptions is in ERROR nil") else if table.concat(subscriptions) == "" then _log ("subscriptions is in ERROR empty") else _log (table.concat {"MQTT ERROR: ", table.concat(subscriptions)}) end end return function () incoming (client, credentials, subscriptions) end end
I can't find a deeper layer in the stack where I can trap for the incoming message to see what's in the message that is throwing the error. As near as I can tell, if openLuup tries to connect to a running mosquitto instance, then it fails to see the topics and messages, and passes empty--but not nil--strings when the servlet interface sees incoming bytes.
If I restart mosquitto, openLuup then sees the topics and messages and the error messages stop--and the connection to mosquitto remains stable.
This behavior does not occur when I aim an IOT device directly at openLuup--in that the connection to the device always resumes when openLuup reloads--in other words, I don't need to restart the IOT device to enable the connection.
-
I simply cannot reproduce this error, so can I ask you to try it again after having added this line to openLuup Startup (which enables debog logging for the MQTT server):
luup.attr_set ("openLuup.MQTT.DEBUG", true)
That may give a little more to go on.
I've have tried everything I can think of, deleting the Shelly plugin, and reproducing the announce message from your device. It all works just fine.
-
I added "luup.attr_set (" openLuup.MQTT.DEBUG ", true)"
and I did a RELOAD
here is the log2021-05-02 14:03:57.914 openLuup.io.server:: MQTT:1883 connection from 192.168.1.149 tcp{client}: 0x11320b0 2021-05-02 14:03:57.941 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.941 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/online : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.943 luup.shelly:87: New Shelly announced: shellyplug-s-20E453 2021-05-02 14:03:57.944 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:226: attempt to index field '?' (a nil value) 2021-05-02 14:03:57.944 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/announce : ./L_ShellyBridge.lua:226: attempt to index field '?' (a nil value) 2021-05-02 14:03:57.945 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.946 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/announce : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.947 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.947 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0/power : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.949 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.949 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0/energy : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.989 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.989 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0 : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.994 openLuup.server:: request completed (664 bytes, 1 chunks, 1140 ms) tcp{client}: 0x1403478 2021-05-02 14:03:57.995 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.995 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/temperature : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.997 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.997 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/temperature_f : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.998 openLuup.context_switch:: ERROR: [dev #87] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:57.999 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/overtemperature : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 14:03:58.000 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/command tcp{client}: 0x11320b0 2021-05-02 14:03:58.002 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/shellyplug-s-20E453/command tcp{client}: 0x11320b0 2021-05-02 14:03:58.003 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/shellyplug-s-20E453/relay/0/command tcp{client}: 0x11320b0
-
Just what I needed to see, thanks, I’ll work on it.
-
Can can give v21.5.2 from the testing branch a go?
-
disabled MQTT on the Shelly socket
I deleted on OpenLuup- the Shelly device in NoRoom
- the Shellies piece
I did a Reload
I installed version 2021.05.02
I did a Reload
Enabled MQTT on the Shelly socket
I did a Reload
Creation of the Shelly Bridge (88) in NoRoom
Creation of the piece Shelly
I still have the same problem
2021-05-02 17:51:56.712 openLuup.io.server:: MQTT:1883 connection from 192.168.1.149 tcp{client}: 0x184b970 2021-05-02 17:51:56.745 luup.create_device:: [88] D_ShellyBridge.xml / I_ShellyBridge.xml / D_ShellyBridge.json (ShellyBridge) 2021-05-02 17:51:56.746 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.746 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/online : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.747 openLuup.scheduler:: [88] Shelly device startup 2021-05-02 17:51:56.747 luup.set_failure:: status = 0 2021-05-02 17:51:56.747 luup.variable_set:: 88.urn:micasaverde-com:serviceId:HaDevice1.CommFailure was: EMPTY now: 0 #hooks:0 2021-05-02 17:51:56.748 luup.variable_set:: 88.urn:micasaverde-com:serviceId:HaDevice1.CommFailureTime was: EMPTY now: 0 #hooks:0 2021-05-02 17:51:56.748 openLuup.scheduler:: [88] Shelly device startup completed: status=true, msg=OK, name=ShellyBridge 2021-05-02 17:51:56.749 luup.shelly:0: New Shelly announced: shellyplug-s-20E453 2021-05-02 17:51:56.749 openLuup.luup:: creating room [10] Shellies 2021-05-02 17:51:56.750 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:226: attempt to index field '?' (a nil value) 2021-05-02 17:51:56.750 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/announce : ./L_ShellyBridge.lua:226: attempt to index field '?' (a nil value) 2021-05-02 17:51:56.751 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.751 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/announce : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.752 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.752 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0/power : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.753 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.754 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0/energy : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.789 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.790 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/relay/0 : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.791 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.791 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/temperature : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.792 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.792 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/temperature_f : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.793 openLuup.context_switch:: ERROR: [dev #0] ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.793 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/shellyplug-s-20E453/overtemperature : ./L_ShellyBridge.lua:343: attempt to index field 'hadevice' (a nil value) 2021-05-02 17:51:56.795 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/command tcp{client}: 0x184b970 2021-05-02 17:51:56.796 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/shellyplug-s-20E453/command tcp{client}: 0x184b970 2021-05-02 17:51:56.797 openLuup.mqtt:: shellyplug-s-20E453 SUBSCRIBE to shellies/shellyplug-s-20E453/relay/0/command tcp{client}: 0x184b970 2021-05-02 17:51:57.208 openLuup.server:: request completed (1033 bytes, 1 chunks, 3858 ms) tcp{client}: 0x197dd68 2021-05-02 17:51:57.209 openLuup.io.server:: HTTP:3480 connection closed openLuup.server.receive closed tcp{client}: 0x197dd68
-
I’m speechless. No explanation.
-
ok thanks for trying to solve my problem.
in the near future i will try to reinstall OpenLuup on my Raspbery, maybe this will fix this problem.
Sorry for taking your precious time -
I haven’t given up. I can only think that, somehow, we are not running the same version of the code. You did confirm that your last install was, in fact, v21.5.2?
-
Is @christian_fabre bridged to mosquitto? As when I reload OpenLuup I have to restart mosquitto to get them talking again.
-
-
@akbooer I will probably add more log, to see the exact payload sent. Sometimes those things are generating strange telemetry data, so maybe that's the case. I'll probably log what's going on around hadevice property as well. I was unable to re-produce it in my own install, so it should be something related to this particular model and its messages.
-
If you are still interested, testing v21.5.3 is available. I have made considerable changes.
-
-
@christian_fabre said in MQTT – setup and use:
Merci bien
Je vous en pris.
Believe me... I'm happy. So sorry for all the mis-steps, but I learned a few things along the way, so it was a worthwhile exercise!
-
Now that you got that figured out, one awesome thing which could be done would be integrate this:
By creating a bridge supporting it on openLuup. It would enable me to move zigbee from home assistant to run directly to openLuup and I would likely take advantage of it to get rid of my hue hub as well, running a single zigbee network through mqtt...
-
@buxton said in MQTT – setup and use:
As near as I can tell, if openLuup tries to connect to a running mosquitto instance, then it fails to see the topics and messages, and passes empty--but not nil--strings when the servlet interface sees incoming bytes.
OK, I’m ready to take a look at this. However the above statement makes no sense to me, since the server never connects to anything (because it’s a server – clients connect to it.)
-
@akbooer Yes, that was poorly worded as it makes it sound like openLuup initiates the connection to Mosquitto.
The symptoms of the problem are that:
- if luup reloads, an occasional message that is sent to openLuup from Mosquitto causes a receive error in openLuup. It is unknown what that/those message(s) are.
- if mosquitto reloads, the openLuup error messages stop, so something changes in the way that openLuup sees the mosquitto data.
- this behavior does not occur with IOT devices.
A possible way to trouble shoot this is to place debug code at the incoming interface that will trap and display packets headed to the MQTT port. By comparing incoming timestamps with the error message timestamp, I should be able to tell what message is causing the receive error message--even though the message variable is empty at the time it causes the luup error. What is odd to me is that there is a lot of error trapping for bad messages in your code, but this message(s) seems to bypass all of that and arrives at the incoming routine empty.....
-
I think we are being misled by your error messages. These tables are not empty...
local x = {a = 1, b = 2} local y = table.concat (x) print (y == '')
yields the expected result
true
.
88/107