openLuup email server

[akbooer]

No, they don’t.

[toggledbits]

OK. While waiting, was testing some other things... it sure looks like the orphan/unclosed sockets are part of the issue.

[akbooer]

To me, it’s the protocol name. You might simply try to change that on line 363 in mqtt.lua.

[toggledbits]

Protocol name is the Home Assistant issue. I think we're past that -- it's a non-starter.

What I've been talking about my last couple of messages is that the NodeJS MQTT client library cannot reconnect to openLuup. The initial connection works, but if openLuup is restarted, the client can't reconnect to the openLuup MQTT broker. Here is the progress of debug for initial connection:

2021-11-24 11:46:32.961   openLuup.io.server:: MQTT:1883 connection from 192.168.0.66 tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.056   openLuup.mqtt:: CONNECT tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.056   openLuup.mqtt:: ClientId: reactor_mqtt
2021-11-24 11:46:33.056   openLuup.mqtt:: WillTopic: reactor/mqtt/LWT
2021-11-24 11:46:33.056   openLuup.mqtt:: WillMessage: offline
2021-11-24 11:46:33.057   openLuup.mqtt:: UserName:
2021-11-24 11:46:33.057   openLuup.mqtt:: Password:
2021-11-24 11:46:33.082   openLuup.mqtt:: SUBSCRIBE tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.082   openLuup.mqtt:: Packet Id: 0x17d0
2021-11-24 11:46:33.082   openLuup.mqtt:: Topic: #
2021-11-24 11:46:33.082   openLuup.mqtt:: reactor_mqtt SUBSCRIBE to # tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.098   openLuup.mqtt:: PUBLISH tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.099   openLuup.mqtt:: PUBLISH tcp{client}: 0x560c3a0fdca8
2021-11-24 11:46:33.099   openLuup.mqtt:: PUBLISH tcp{client}: 0x560c3a0fdca8

All good and works fine until openLuup is restarted. Then things come a gutser.

Here is the progress of messages after openLuup is restarted, when the NodeJS MQTT client attempts to reconnect:

2021-11-24 11:47:56.357   openLuup.io.server:: starting MQTT:1883 server on port: 1883 tcp{server}: 0x5581839b06d8
2021-11-24 11:47:56.359   luup_log:2: starting MQTT round-robin device status messages
2021-11-24 11:47:56.359   luup_log:2: starting MQTT $SYS/broker statistics
2021-11-24 11:48:02.518   openLuup.io.server:: MQTT:1883 connection from 192.168.0.66 tcp{client}: 0x558183c2ccc8
2021-11-24 11:48:02.520   openLuup.mqtt:: CONNECT tcp{client}: 0x558183c2ccc8
2021-11-24 11:48:02.520   openLuup.mqtt:: ClientId: reactor_mqtt
2021-11-24 11:48:02.520   openLuup.mqtt:: WillTopic: reactor/mqtt/LWT
2021-11-24 11:48:02.520   openLuup.mqtt:: WillMessage: offline
2021-11-24 11:48:02.520   openLuup.mqtt:: UserName:
2021-11-24 11:48:02.520   openLuup.mqtt:: Password:
2021-11-24 11:48:02.523   openLuup.mqtt:: PUBLISH tcp{client}: 0x558183c2ccc8
2021-11-24 11:50:03.091   openLuup.io.server:: MQTT:1883 connection closed EXPIRED tcp{client}: 0x558183c2ccc8
2021-11-24 11:50:08.099   openLuup.io.server:: MQTT:1883 connection from 192.168.0.66 tcp{client}: 0x558183ee52b8
2021-11-24 11:50:08.100   openLuup.mqtt:: CONNECT tcp{client}: 0x558183ee52b8
2021-11-24 11:50:08.100   openLuup.mqtt:: ClientId: reactor_mqtt
2021-11-24 11:50:08.100   openLuup.mqtt:: WillTopic: reactor/mqtt/LWT
2021-11-24 11:50:08.100   openLuup.mqtt:: WillMessage: offline
2021-11-24 11:50:08.100   openLuup.mqtt:: UserName:
2021-11-24 11:50:08.101   openLuup.mqtt:: Password:
2021-11-24 11:50:08.103   openLuup.mqtt:: PUBLISH tcp{client}: 0x558183ee52b8

The entire dialog stalls on the first PUBLISH after reconnect, and eventually the connection expires and is recycled, and that loop continues forever more. On the MSR end, the MQTT client library never sends the connected event, so apparently something in the handshake hasn't completed. I have no idea what is causing this, but it is unique to openLuup's MQTT server. This does not happen with other brokers I've tried (e.g. Mosquitto).

[akbooer]

Thanks for the logs, I’ll take a look.

[ArcherS]

@toggledbits said in openLuup: MQTT server:

Also I can't connect my Home Assistant 2021.11.5 to the broker. This in the logs:

I may have missed this, but was this solved?

The reason is that I am currently on Home Assistant 2021.10.06 and was planning to upgrade to the latest 2021.11.5.
On 2021.10.6 I am using the Mqtt server in OpenLuup and it is working fine.

[ArcherS]

Answering my own question, perhaps of some use for someone else.

Today I upgraded my Home Assistant to 2021.11.5 and the connection to the OpenLuup Mqtt server seems so far to work as it should.
(Running on OpenLuup v21.11.8)

[ronluna]

Would be awesome to get ZWaveJS2Mqtt added to openluup. As much as ZWay has proven to be faster and much more reliable than Vera... ZWaveJS has a bright future...

[akbooer]

No idea what’s involved in that, since I haven’t played with it at all (and JS is not my expertise.)

Ideas anyone?

[ronluna]

Based out L_ShellyBridge.lua I've created initial L_ZWaveBridge.lua made changes in virtualfilesystem.lua to create D_ZWaveBridge.xml, D_ZWaveBridge.json and subcribed to zwave topic. which is how the MQTT messages are sent from ZWaveJS2MQTT by default.

my startup lua looks like:

luup.attr_set ("openLuup.MQTT.Username", "*********")
luup.attr_set ("openLuup.MQTT.Password", "*********")
luup.attr_set ("openLuup.MQTT.Port", 1811)
luup.attr_set ("openLuup.MQTT.PublishVariableUpdates", true)
luup.attr_set ("openLuup.MQTT.DEBUG", true)

With my short mqtt understanding ZWaveJS is connecting and authenticating just fine to openluup although I've been unable to properly modify L_ZWaveBridge.lua to capture and parse the messages that ZWaveJS is sending.

[therealdb]

@akbooer it’s just a bunch of mqtt messages. You’ll find their format in the docs.

It’s probably safer to just support ZwaveJS, but its interface is based on web sockets, if my memory is not failing at 6 in the morning.

[akbooer]

@ronluna said in openLuup: MQTT server:

With my short mqtt understanding ZWaveJS is connecting and authenticating just fine to openluup although I've been unable to properly modify L_ZWaveBridge.lua to capture and parse the messages that ZWaveJS is sending.

OK, well that's good.

I wouldn't necessarily start from L_ShellyBridge.lua, since it has a few features (like creating the bridge device itself) which you may not need. It's written that way because it's part of the system, unlike other add-on plugins. Similarly, if you write it as a standard plugin then there's no need to modify virtualfilesystem.lua.

If the standard approach to subscribing to the zwave/# works just fine, I'd start from there. Not sure what problem you're finding with parsing the messages. I haven't yet looked at the docs mentioned by @therealdb above.

[ronluna]

I'm currently having a problem where the only way to get openluup to start processing messages from subscribed topics is by restarting the ZWaveJS service. When the ZWaveJS MQTT service is restarted the ZWaveJS Clients send the subscribe messages to openluup and only then is when messages start to get processed.

Testing with the following inserted in the startup:

local json = require "openLuup.json"

function MyMQTThandler (topic, message)
  local info = json.decode (message)
  local currentLevel = info.value
  luup.variable_set ("urn:upnp-org:serviceId:Dimming1", "LoadLevelStatus",  currentLevel, 68)
  luup.log("Processed")
end
 
luup.register_handler ("MyMQTThandler", "mqtt:zwave/Hallway_2/DImmer_1/38/0/currentValue")

I Couldn't find anything on ZWaveJS nor in openluup that might explain this behavior and my short mqtt knowledge is not helpful either.

Any ideas?

[akbooer]

You can get more information about what’s going on by enabling debug logging for MQTT in Lua Startup.

luup.attr_set ("openLuup.MQTT.DEBUG", true)

[ronluna]

@akbooer with DEBUG enabled the logs show:

2022-03-20 15:54:54.501   openLuup.mqtt:: CONNECT tcp{client}: 0x55ae0e8b8318
2022-03-20 15:54:54.501   openLuup.mqtt:: ClientId: ZWAVE_GATEWAY-Zwavejs2Mqtt
2022-03-20 15:54:54.501   openLuup.mqtt:: WillTopic: zwave/_CLIENTS/ZWAVE_GATEWAY-Zwavejs2Mqtt/status
2022-03-20 15:54:54.501   openLuup.mqtt:: WillMessage: {"value":false}
2022-03-20 15:54:54.502   openLuup.mqtt:: UserName: ********
2022-03-20 15:54:54.502   openLuup.mqtt:: Password: ********
2022-03-20 15:54:54.502   openLuup.io.server:: MQTT:1829 connection closed  tcp{client}: 0x55ae0a5f7e78
2022-03-20 15:54:54.502   openLuup.mqtt:: RECEIVE ERROR: closed tcp{client}: 0x55ae0a5f7e78
2022-03-20 15:54:54.519   openLuup.server:: request completed (16415 bytes, 2 chunks, 1068 ms) tcp{client}: 0x55ae0c39f788
2022-03-20 15:54:54.587   openLuup.server:: error 'closed' sending 6 bytes to tcp{client}: 0x55ae0dfce198
2022-03-20 15:54:54.587   openLuup.server:: ...only 0 bytes sent
2022-03-20 15:54:54.587   openLuup.server:: error 'closed' sending 94946 bytes to tcp{client}: 0x55ae0dfce198
2022-03-20 15:54:54.587   openLuup.server:: ...only 0 bytes sent
2022-03-20 15:54:54.587   openLuup.server:: error 'closed' sending 2 bytes to tcp{client}: 0x55ae0dfce198

Seems like is related to what @toggledbits has shared a couple weeks ago. clues?

[ronluna]

I had to disable the MQTT Handler from the startup as it was crashing the entire engine.

[akbooer]

I think this (the restart issue) may be due to wildcard subscriptions not receiving retained messages… although that’s nothing to do with the TCP errors in your log. I’ll try to fix that soon, although, I should point out that this is not inconsistent with the specification for a level 0 server:

“If the Server receives a QoS 0 message with the RETAIN flag set to 1 it MUST discard any message previously retained for that topic. It SHOULD store the new QoS 0 message as the new retained message for that topic, but MAY choose to discard it at any time - if this happens there will be no retained message for that topic.
[MQTT-3.3.1-7].

[ronluna]

If there is something I can do to help, please let me know.