search

Edubits / Zway-MQTT

Publishes the status of devices to a MQTT topic and is able to set values based on subscribed topics.
Apache License 2.0
29 stars 16 forks source link

Connection loss on Event Update #26

Open solariz opened 7 years ago

solariz commented 7 years ago

Hey,

I recently startet to play around with mosquitto and this MQTT module. If I request #/example/status by sending a 0 msg everything is fine, if I just wait for the device Events I only see errors in the log, no device update is pushed automatically into MQ.

For Example a Power Meter reporting it WATT:

[2017-08-09 20:49:37.869] [D] [zway] SENT ACK [2017-08-09 20:49:37.869] [D] [zway] SETDATA devices.8.data.lastReceived = 0 (0x00000000) [2017-08-09 20:49:37.869] [D] [zway] SETDATA devices.8.instances.0.commandClasses.49.data.4.deviceScale = 0 (0x00000000) [2017-08-09 20:49:37.869] [D] [zway] SETDATA devices.8.instances.0.commandClasses.49.data.4.scale = 0 (0x00000000) [2017-08-09 20:49:37.871] [D] [zway] SETDATA devices.8.instances.0.commandClasses.49.data.4.scaleString = "W" [2017-08-09 20:49:37.871] [D] [zway] SETDATA devices.8.instances.0.commandClasses.49.data.4.val = 26.900000 [2017-08-09 20:49:37.871] [D] [zway] SETDATA devices.8.instances.0.commandClasses.49.data.4 = Empty [2017-08-09 20:49:37.928] [I] [core] Notification: device-info (device-power): {"dev":"Power #8","l":"26.9 W","location":""} [2017-08-09 20:49:37.998] [I] [core] [BaseModule-16] Set lastLevel to 26.9 for ZWayVDev_zway_8-0-49-4 (was 258.7000064) [2017-08-09 20:49:38.021] [I] [core] [MQTT-17] Socket connection closed. [2017-08-09 20:49:38.025] [I] [core] [MQTT_17] Error: Disconnected, will retry to connect... at MQTT.BaseModule.error (automation/userModules/BaseModule/index.js:122:17) at MQTT.onDisconnect (automation/userModules/MQTT/index.js:139:7) at MQTTClient._disconnectCallback (automation/userModules/MQTT/index.js:92:46) at MQTTClient._onClose (automation/userModules/MQTT/lib/mqtt.js:303:10) at tcp._connection.onclose (automation/userModules/MQTT/lib/mqtt.js:173:10) [2017-08-09 20:49:38.046] [I] [core] [MQTT-17] Trying to reconnect (0)

Doesn't matter if Report is 0 or > 1 always disconnect. No Error in mosquitto log.

PoltoS commented 5 years ago

Can you guide us step by step how to reproduce it? We are still unable to catch it

alwalz commented 5 years ago

Hello, seems as if I'm having the same issue. I've installed the latest MQTT app (version 1.3 stable) and managed to establish a connection to my mosquitto server, which is running on another machine. I'm testing with a Door/Window sensor, that send a signal, whenever a windows opens or closes. In the ZWay elements overview, the status of the element updates accordingly. But the z-way-server log shows that the MQTT app looses the connection to the mosquitto server:

[2019-02-03 16:56:47.422] [I] [core] [MQTT-16] ----------------- {"creationTime":1544346059,"creatorId":1,"customIcons":{},"deviceType":"sensorBinary","h":1639081286,"hasHistory":false,"id":"ZWayVDev_zway_6-0-113-6-Door-A","location":1,"metrics":{"icon":"door","level":"on","title":"Door/Window (#6)","isFailed":false,"modificationTime":1549208948,"lastLevel":"off"},"nodeId":6,"order":{"rooms":0,"elements":0,"dashboard":0,"room":2},"permanently_hidden":false,"probeType":"alarm_door","tags":["mqtt"],"visibility":true,"updateTime":1549209407} [2019-02-03 16:56:47.422] [I] [core] [MQTT-16] +++++++++++++++++ {"first_start_up":"2018-12-02T10:07:40.798Z","count_of_reconnects":28,"emailInitialActivated":true,"firstaccess":false} [2019-02-03 16:56:47.451] [I] [core] Notification: device-info (device-OnOff): {"dev":"Door/Window (#6)","l":"on","location":1} [2019-02-03 16:56:47.501] [I] [core] [BaseModule-15] Set lastLevel to on for ZWayVDev_zway_6-0-113-6-Door-A (was off) [2019-02-03 16:56:47.520] [I] [core] [MQTT-16] Socket connection closed. [2019-02-03 16:56:47.524] [I] [core] [MQTT_16] Error: Disconnected, will retry to connect... at MQTT.BaseModule.error (automation/userModules/BaseModule/index.js:122:17) at MQTT.onDisconnect (automation/userModules/MQTT/index.js:139:7) at MQTTClient._disconnectCallback (automation/userModules/MQTT/index.js:92:46) at MQTTClient._onClose (automation/userModules/MQTT/lib/mqtt.js:303:10) at tcp._connection.onclose (automation/userModules/MQTT/lib/mqtt.js:173:10) [2019-02-03 16:56:47.545] [I] [core] [MQTT-16] Trying to reconnect (0) [2019-02-03 16:56:48.471] [I] [core] [MQTT-16] Socket connection opened. [2019-02-03 16:56:48.473] [I] [core] [MQTT-16] Connected to base [2019-02-03 16:56:48.474] [I] [core] [MQTT-16] ----------------- undefined [2019-02-03 16:56:48.474] [I] [core] [MQTT-16] +++++++++++++++++ {"first_start_up":"2018-12-02T10:07:40.798Z","count_of_reconnects":28,"emailInitialActivated":true,"firstaccess":false}

Does this help to reproduce the problem ?

Edubits commented 5 years ago

@alwalz, are you sure you’re running the latest version? The latest stable is 1.4.1.

alwalz commented 5 years ago

@Edubits: interesting point. I thought it was the latest version, because I've downloaded it through the web-application, but apparently it wasn't. Thank's for the hint. Meanwhile I've downloaded the version 1.4.1 manually (git clone) and after I while, I got it accepted and started by z-way-server. Now the app shows version 1.4.1. Unfortunately the same problem exists, see below. Another thing I tried, was starting mosquitto on the same server as z-way, but that also did not help.

[2019-02-04 17:20:01.253] [I] [core] Notification: device-info (device-OnOff): {"dev":"Door/Window (#6)","l":"off","location":1} [2019-02-04 17:20:01.304] [I] [core] [MQTT-16] Socket connection closed. [2019-02-04 17:20:01.308] [I] [core] [MQTT_16] Error: Disconnected, will retry to connect... at MQTT.BaseModule.error (automation/userModules/BaseModule/index.js:122:17) at MQTT.onDisconnect (automation/userModules/MQTT/index.js:173:7) at MQTTClient._disconnectCallback (automation/userModules/MQTT/index.js:110:46) at MQTTClient._onClose (automation/userModules/MQTT/lib/mqtt.js:303:10) at tcp._connection.onclose (automation/userModules/MQTT/lib/mqtt.js:173:10) [2019-02-04 17:20:01.309] [I] [core] [BaseModule-15] Set lastLevel to off for ZWayVDev_zway_6-0-113-6-Door-A (was on) [2019-02-04 17:20:01.355] [I] [core] [MQTT-16] Trying to reconnect (0) [2019-02-04 17:20:01.363] [I] [core] [MQTT-16] Reconnect attempt finished [2019-02-04 17:20:02.296] [I] [core] [MQTT-16] Socket connection opened. [2019-02-04 17:20:02.298] [I] [core] [MQTT-16] Connected to base as zway

PoltoS commented 5 years ago

The disconnect happens only in even from the sensor? May be it is a keep alive problem?

Can it be also reproduced using test.mosquitto.org? So we don't have to install the server ourselves

pastukhov commented 4 years ago

In my case this happen when device name conatin an #

Alex895 commented 4 years ago

In my case this happen when device name conatin an #

Thanks for hint !! It really is, have same problem

If # in device name - mqtt disconnects, after rename - works fine

PoltoS commented 4 years ago

Looks like # is a wildcard symbol - should be removed from device names.

thexperiments commented 4 years ago

Any progress here? I have the same issue as soon as a fibaro motion sensor triggers. I thought it also might be a naming issue as I have an umlaut in the name but after changin ü for ue the problem persists.

[2020-07-25 17:03:46.364] [I] [core] [MQTT-11] Socket connection closed.
[2020-07-25 17:03:46.396] [I] [core] [MQTT_11] Error: Disconnected, will retry to connect...
    at MQTT.BaseModule.error (automation/userModules/BaseModule/index.js:122:17)
    at MQTT.onDisconnect (automation/userModules/MQTT/index.js:177:7)
    at MQTTClient._disconnectCallback (automation/userModules/MQTT/index.js:114:46)
    at MQTTClient._onClose (automation/userModules/MQTT/lib/mqtt.js:303:10)
    at tcp._connection.onclose (automation/userModules/MQTT/lib/mqtt.js:173:10)

One thing I found out is that the disconnect happens even if mqtt app is not enabled for the fibaro motion sensor... Maybe it is a timeout as some other z-wave task is blocking the thread to long?

thexperiments commented 4 years ago

Ok it WAS the same issue, I found that it was als sending out the "temper" of the motion sensor which was automatically called "temper #2". The assumption that it happens also without any mqtt interaction above is false --> I thought it would be enough to restart the app from the webserver but it seems that a full stop/start cycle is required to get rid of previously configured interactions.

hartmark commented 3 years ago

I get this error too and after some digging I found this issue, I have some devices containing name with #

The code is outside my competence but there should be a way to escape # so it would work with MQTT

hartmark commented 3 years ago

After som digging I found that my broker used TLS and apparently it's not supported as stated in #2