openLuup: MQTT server
-
OMG. Genius. Many thanks indeed! Note to self - for Shelly .. Internet & Security/Advanced - Developer Settings/Enable MQTT
-
The first Shelly I tried worked with the bridge created and device created in the Shellies room. The next ones also appear in openLuup/Servers/Received Connections list but don't appear as devices. Have I missed a step?
-
No, I don't think so. Where are you looking at the devices (AltUI / openLuup console)?
Anything in the log?
-
Should have looked first ! Red highlights a win here; am seeing this ... (is there a proper way of copying and pasting?)
2021-06-12 11:10:01.904 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=492370363&Timeout=60&MinimumDelay=1500&_=1623492371898 HTTP/1.1 tcp{client}: 0x1e96db0
2021-06-12 11:10:19.108 openLuup.io.server:: MQTT:1883 connection from 192.168.1.156 tcp{client}: 0x1d97790
2021-06-12 11:10:19.152 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/command tcp{client}: 0x1d97790
2021-06-12 11:10:19.153 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/shellyht-E01A8B/command tcp{client}: 0x1d97790
2021-06-12 11:10:19.156 luup.shelly:83: New Shelly announced: shellyht-E01A8B
2021-06-12 11:10:19.279 openLuup.context_switch:: ERROR: [dev #83] ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header
2021-06-12 11:10:19.280 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/announce : ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header
2021-06-12 11:10:19.393 openLuup.server:: request completed (1891 bytes, 1 chunks, 17488 ms) tcp{client}: 0x1e96db0 -
akbooerreplied to powisquare on Jun 12, 2021, 2:55 PM last edited by akbooer Jun 12, 2021, 10:56 AM
@powisquare said in openLuup: MQTT server:
Should have looked first ! Red highlights a win here; am seeing this ... (is there a proper way of copying and pasting?)
2021-06-12 11:10:01.904 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=492370363&Timeout=60&MinimumDelay=1500&_=1623492371898 HTTP/1.1 tcp{client}: 0x1e96db0
2021-06-12 11:10:19.108 openLuup.io.server:: MQTT:1883 connection from 192.168.1.156 tcp{client}: 0x1d97790
2021-06-12 11:10:19.152 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/command tcp{client}: 0x1d97790
2021-06-12 11:10:19.153 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/shellyht-E01A8B/command tcp{client}: 0x1d97790
2021-06-12 11:10:19.156 luup.shelly:83: New Shelly announced: shellyht-E01A8B
2021-06-12 11:10:19.279 openLuup.context_switch:: ERROR: [dev #83] ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header
2021-06-12 11:10:19.280 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/announce : ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header
2021-06-12 11:10:19.393 openLuup.server:: request completed (1891 bytes, 1 chunks, 17488 ms) tcp{client}: 0x1e96db0Yes, there is, there's a little code icon </> in the full Reply window (not the Quick one):
2021-06-12 11:10:01.904 openLuup.server:: GET /data_request?id=lu_status2&output_format=json&DataVersion=492370363&Timeout=60&MinimumDelay=1500&_=1623492371898 HTTP/1.1 tcp{client}: 0x1e96db0 2021-06-12 11:10:19.108 openLuup.io.server:: MQTT:1883 connection from 192.168.1.156 tcp{client}: 0x1d97790 2021-06-12 11:10:19.152 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/command tcp{client}: 0x1d97790 2021-06-12 11:10:19.153 openLuup.mqtt:: shellyht-E01A8B SUBSCRIBE to shellies/shellyht-E01A8B/command tcp{client}: 0x1d97790 2021-06-12 11:10:19.156 luup.shelly:83: New Shelly announced: shellyht-E01A8B 2021-06-12 11:10:19.279 openLuup.context_switch:: ERROR: [dev #83] ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header 2021-06-12 11:10:19.280 openLuup.mqtt:: ERROR publishing application message for mqtt:shellies/announce : ./openLuup/client.lua:96: missing realm or nonce in received WWW-Authenticate header 2021-06-12 11:10:19.393 openLuup.server:: request completed (1891 bytes, 1 chunks, 17488 ms) tcp{client}: 0x1e96db0
Oooh, that's a nasty error. I don't have any HT devices, I see that they are battery operated and wake up from time to time. I do have a button 1, which does a similar thing, but I haven't seen this problem.
It may be that the device's HTTP server isn't active during the MQTT Announce – the Shelly plugin normally gets a full configuration over HTTP, not MQTT, so I may have to change this approach for certain devices. I see there is a 120ms delay between the Announce message and the HTTP error – a long time for things to have happened in between...
...I will read up more on the device. Any thoughts anyone??
= = = = = =
Edit: have you set a Username and Password? ...perhaps that's an issue.
-
powisquarewrote on Jun 12, 2021, 2:59 PM last edited by powisquare Jun 12, 2021, 11:01 AM
Yes I have - on all of them. I seem to recall, when setting up the first one, that openLuup recognised a button press. Perhaps that's how it worked. These sensors wake up on an hourly basis, but when you wake them up manually they are awake for a minute or so (it seems).
-
powisquarewrote on Jun 12, 2021, 3:03 PM last edited by powisquare Jun 12, 2021, 11:31 AM
Sorry - my bad. Device that's working does not have a password. I'll have another go.
Boom - all working
-
So, I need to fix HTTP access for device with a password, it seems. That makes sense given the 'nonce' error message.
-
I have a Mqtt device that reads the electrical consumption in the house and posts it via Mqtt to OpenLuup. The device posts this every minute:
What I have in Lua Startup for this sensor is (for 8 of the reported values):
function ElmatareMatarstallning (topic, message) local matare=message/1000 -- local matare_clean=tointeger(matare) luup.variable_set ("urn:micasaverde-com:serviceId:GenericSensor1", "CurrentLevel", matare, 95) --set value to device end ... luup.register_handler ("ElmatareMatarstallning", "mqtt:sensors/power/p1meter/consumption")
In general this works really well!
I have on some occations seen errors in the log related to this reporting and also a few crashes. At least once the last entry in the log was the following and then it crashed:
2021-08-15 11:03:52.703 openLuup.context_switch:: ERROR: [dev #0] ./openLuup/mqtt.lua:477: attempt to get length of local 'TopicName' (a nil value) 2021-08-15 11:03:52.704 luup.incoming_callback:: function: 0x23d2a88 ERROR: ./openLuup/mqtt.lua:477: attempt to get length of local 'TopicName' (a nil value)
I have seen in MqttExplorer that the device very seldom but sometimes also has sent rouge messages for some reason, e.g:
I am not sure why the messages sometimes get wrong or even nil, I will see what could be done on the device, it could be that I need to send less often, that the device deteriorates over time, intermitent bad wifi-connection, or something else. I have not seen this behaviour on any other device.
Another thought is if it would be possible to make to mqtt handler code more robust so that OpenLuup does not crash when this happens? By looking at the log above the topic name is reported being "nil" just before the crash. On the other hand; on at least one other occation I have seen this and it did not crash, so maybe at least it does not lead to a crash every time.
2021-08-15 21:26:29.714 luup.variable_set:: 89.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 507 now: 510 #hooks:0 2021-08-15 21:26:29.718 luup.variable_set:: 90.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 756 now: 791 #hooks:0 2021-08-15 21:26:29.722 luup.variable_set:: 91.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 1491 now: 1486 #hooks:0 2021-08-15 21:26:29.739 openLuup.context_switch:: ERROR: [dev #0] ./openLuup/mqtt.lua:477: attempt to get length of local 'TopicName' (a nil value) 2021-08-15 21:26:29.739 luup.incoming_callback:: function: 0x1e8b230 ERROR: ./openLuup/mqtt.lua:477: attempt to get length of local 'TopicName' (a nil value) 2021-08-15 21:26:29.740 openLuup.io.server:: MQTT:1883 connection closed tcp{client}: 0x213f010 2021-08-15 21:26:29.740 openLuup.mqtt:: PUBREL: UNIMPLEMENTED packet type: 6 tcp{client}: 0x213f010 2021-08-15 21:26:29.836 openLuup.io.server:: MQTT:1883 connection from 192.168.1.191 tcp{client}: 0x25faaf0
I have had problems in the past with OpenLuup crashing when I setup Mqtt initially (before I had the electrical reporting device). Since then I now run a new OpenLuup on a Raspberry Pi 4 (my Zway server is on a Pi 3B on the same network). I still on rather rare occations get OpenLuup crashes unfortunately. I never quite got down to the reason behind the crashes that time. However reducing the mqtt load by disabling some devices has usually stopped OpenLuup from crashing when it occurs.
During summer I had a series of crashes when I was out of the house (naturally ). Checking over my VPN I could see that the power device had gone down, so the above could be the reason that time also. Since I was not at home I could not restart the power Mqtt device (it is not Tasmota and lacks that possibility unfortunately).
The Pi is currently on OpenLuup v21.6.12 and AltUi v2.53c.
Sorry for a slightly disorganised post, any advice or clues would be welcome on what this could be and hopefully how to mitigate it would be much appreciated.
-
Thanks for reporting this in detail.
I'll take a look at the MQTT server and have a go at making it more robust.
-
OK, development version 21.8.16 has a fix (I hope).
-
@akbooer and @therealdb thank you both for your quick response.
Version 21.8.16 installed, I will monitor the logs and report back what I can see.
-
After I updated OpenLuup I have not seen the TopicName nil error. Good progress in other words. This could mean that the correction takes care of that kind of problem in mqtt messages.
I have however had a few errors in the log after the update:
2021-08-16 22:38:21.187 openLuup.io.server:: MQTT:1883 connection closed tcp{client}: 0x1ea35e0 2021-08-16 22:38:21.187 openLuup.mqtt:: socket.select() not ready to send tcp{client}: 0x1ea35e0 tcp{client}: 0x1ea35e0 2021-08-16 22:38:21.187 openLuup.mqtt:: mqtt-explorer-bc5a61ca UNSUBSCRIBE from # tcp{client}: 0x1ea35e0 2021-08-16 22:38:21.188 openLuup.mqtt:: mqtt-explorer-bc5a61ca UNSUBSCRIBE from $SYS/# tcp{client}: 0x1ea35e0 2021-08-16 22:38:21.188 openLuup.mqtt:: ERROR publishing application message for mqtt:openLuup/update/97/ReactorGroup/GroupStatus_grp174eydz3 : socket.select() not ready to send tcp{client}: 0x1ea35e0 2021-08-16 22:38:21.188 luup.variable_set:: 97.urn:toggledbits-com:serviceId:ReactorGroup.GroupStatus_grp174eydz3 was: 1 now: 0 #hooks:0 2021-08-16 22:38:21.188 luup.variable_set:: 97.urn:toggledbits-com:serviceId:ReactorSensor.Message was: Not tripped now: Not tripped #hooks:0 2021-08-16 22:38:21.191 luup.variable_set:: 88.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 2692 now: 2664 #hooks:0 2021-08-16 22:38:21.195 luup.variable_set:: 89.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 466 now: 466 #hooks:0 2021-08-16 22:38:21.198 luup.variable_set:: 90.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 760 now: 729 #hooks:0 2021-08-16 22:38:21.201 luup.variable_set:: 91.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 1465 now: 1468 #hooks:0 2021-08-16 22:38:21.251 luup.variable_set:: 92.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 1.9 now: 2 #hooks:0 2021-08-16 22:38:21.263 luup.variable_set:: 93.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 3.5 now: 3.3 #hooks:0 2021-08-16 22:38:21.267 luup.variable_set:: 94.urn:micasaverde-com:serviceId:GenericSensor1.CurrentLevel was: 6.4 now: 6.4 #hooks:0 2021-08-16 22:38:26.910 openLuup.io.server:: HTTP:3480 connection closed EXPIRED tcp{client}: 0xb16a38
These errors are similar to what I have seen on and off since setting up mqtt.
This morning OpenLuup crashed. Everything seemed fine in the evening, responsive, ok cpu load and no errors for quite some time. When checking the log the last entries are 06:53 and look normal. At 06:16 I had some errors, but after that it looks ok from what I can see.
2021-08-19 06:16:00.105 luup_log:0: 35Mb, 3.3%cpu, 2.4days 2021-08-19 06:16:16.644 openLuup.io.server:: MQTT:1883 connection closed tcp{client}: 0x187ca48 2021-08-19 06:16:16.645 openLuup.mqtt:: RECEIVE ERROR: closed tcp{client}: 0x187ca48 2021-08-19 06:16:17.753 openLuup.io.server:: MQTT:1883 connection from 192.168.1.191 tcp{client}: 0x19f3790
At the moment I have not got a clue why OpenLuup crashes, back to square zero as it feels. I have restarted and we will see what will happen.
After the restart this morning I have had no errors, the server is responsive and normal load (approx 4%). I have also checked the obvious like the temperature and Pi cpu on the Pi and it is ok. Lots of disk space available also. -
I'm wonder if the first error messages you shown are simply the fact that you have MQTT Inspector running on an, essentially, unattended machine, and it just goes to sleep for a while... I know that this is exactly what mine does.
I've become fairly convinced that these errors are something deep within the LuaSocket library. I've always have something like this from time to time, be it the HTTP server, or MQTT now, or other things. I doubt that this is directly related to your 'crash' (freeze?) but I wouldn't rule out a network issue.
I've just reloaded my main openLuup instance (running on Synology Docker) for a system updata, and that's been rock solid for the last 50 days, which is not unusual for all the openLuup systems I used to run.
-
@akbooer said in openLuup: MQTT server:
I'm wonder if the first error messages you shown are simply the fact that you have MQTT Inspector running on an, essentially, unattended machine, and it just goes to sleep for a while... I know that this is exactly what mine does.
I think you are correct, I have seen similar error messages before and as you said I had Mqtt Explorer running on my PC over night.
I've become fairly convinced that these errors are something deep within the LuaSocket library. I've always have something like this from time to time, be it the HTTP server, or MQTT now, or other things. I doubt that this is directly related to your 'crash' (freeze?) but I wouldn't rule out a network issue.
I've just reloaded my main openLuup instance (running on Synology Docker) for a system updata, and that's been rock solid for the last 50 days, which is not unusual for all the openLuup systems I used to run.It sounds reasonable that it could be something socket related, it looks like it on the errors. I wonder if the fact that I have my Zway server on another server could be the reason for these socket errors and the crashing/freezing. I assume that there is a lot of communication between the bridge and the zway server. My old server was rock solid before I set up Mqtt, perhaps the added load on the sockets gets too high at times.
-
If you don't have to run MQTT Inspector, then don't! It subscribes to all messages and that certainly increases traffic.
-
@akbooer said in openLuup: MQTT server:
If you don't have to run MQTT Inspector, then don't! It subscribes to all messages and that certainly increases traffic
@akbooer I have now been running my Pi server for 26 days without any crashes. So far, so good!
Version 21.8.16 seems to give less errors in the log (almost none in fact) and also to be more stable.
I also have taken note not to have MqttExplorer up and running to lessen the load.Yesterday just for fun I set up Home Assistant Supervised. I managed to get it up and running of an old Athom PC with Ubuntu and Docker on.
Something new to learn.
I will also test MSR of course when I have got the grip of HA.A related topic to the Mqtt load above is that in HA there is a Mqtt Integration that I thought could be interesting to test together with OpenLuup.
The question is if anyone is using this together with OpenLuup as broker and if this would have the same risk of (over)loading the traffic on the OpenLuup server?
In other words not to use Mosquitto but instead the OpenLuup broker to get some of the published info into HA.
Or if there is a better way of doing this? -
I guess the answer is "it depends"... most notably on what you choose to let HA subscribe to.
-
@akbooer yes that makes sense of course!
If I have understood it right you do it in two steps in HA, step one is to point it to the broker and step two is then to add Mqtt devices.
In other words I hope that the first step does not then subscribe to "everything" as MqttExplorer perhaps does.