Socket error on client

[Isaksson]

Hello. I have been running this Module on my raspberry and it is working but now I have moved to Z-Way for Windows instead and now I cant get your module running. I hope you have some solution to this because this app is very critical in my installation, i use it for all logic, rules and control of all my z-wave devices.

This is what i get in the z-way log (not much)

[2017-01-01 23:46:18.051] [I] [core] --- Starting module MQTT [2017-01-01 23:46:18.058] [I] [core] Executing script: /* Buffer ***** ... [2017-01-01 23:46:18.061] [I] [core] Executing script: /* MQTTClient **** ...

And this is from my mosquitto brokers log file

1483310778: New connection from 10.0.0.6 on port 1883. 1483310779: Socket error on client , disconnecting.

I see that this is not much helpful information from the logs but maybe you have some idea what could cause this, i am running your latest version 1.1

[zerolith]

Same here (Mosquito Server on Ubuntu - No authentication )

[Isaksson]

Do you run Z-Way server on Windows?

[zerolith]

No, latest Rasbian on a Raspberry. Got it running with this: https://github.com/goodfield/zway-mqtt

[Edubits]

From the log it seems the module is just starting up, but not able to make an initial connection. It could be related to authentication, could you try to change index.js line 62 to the following:

self.client  = new MQTTClient(self.config.host, parseInt(self.config.port), {client_id: self.config.clientId});

(aka remove the options for username and password)

[Isaksson]

I have tried that but still same error.

[Edubits]

@Isaksson Ok, and no additional logging in your z-way-server.log?

[Isaksson]

No, unfortunately not. But my guess is that there is some compatibility issue with the mqtt.js when executed on windows.

I have had some more issues with other modules when i switched from rpi to to a windows server, so right now I think i have to move back to a rpi to have all up and running again.

[Edubits]

That's unfortunate indeed. I don't think my changes will solve your issue, but I've just pushed some changes to the 1.2 branch, might be worth a try.

[Isaksson]

It did not work. I have now moved from windows and back to rpi and now everything is back to normal.

[adingeldein]

I have the same socket error issue. The module tries to continuously reconnect.

Mosquitto broker is running on a slackware machine on my LAN that is receiving and publishing other MQTT data. There is no authentication enabled on the server.

ZWay version 2.3 on Raspian MQTT Module version 1.2

Here is some log info that I get from the zway log:

[2017-03-25 13:05:23.078] [I] [core] [MQTT_43] Error: Error: Please connect to server first at MQTT.BaseModule.error (automation/userModules/BaseModule/index.js:122:17) at null._errorCallback (automation/userModules/MQTT/index.js:114:8) at MQTTClient._onError (automation/userModules/MQTT/lib/mqtt.js:411:10) at MQTTClient.ping (automation/userModules/MQTT/lib/mqtt.js:528:10) at Function. (automation/userModules/MQTT/lib/mqtt.js:218:12)

[Edubits]

Thanks for sharing the log @adingeldein, it seems to be a similar issue as I had last weekend (first time the reconnect issue happened for myself). The MQTT library seems to try to send messages (in your case a ping, in my case it was a publish message), even when there is no connection yet. This triggers an error and an error triggers a reconnect. In the end this causes a loop. I'll add additional checks for this in version 1.3. As I'm currently in the middle of a move to a new house, it might take some though! Sorry for that!

[adingeldein]

No worries, good luck on your move!

[zyxxel]

It seems that the reconnect_timer can try a new connect even if the device has just connected. It checks the isConnecting flag and notices that there are no ongoing new connect and then calls initMQTTClient().

But it doesn't look at "connected" to see if there is already a connection.

This can lead to the following infinite loop of constant reconnects:

[2018-02-07 00:25:46.269] [I] [core] [MQTT-16] Socket connection opened.
[2018-02-07 00:25:46.269] [I] [core] [MQTT-16] Connected to localhost <= connect ok
[2018-02-07 00:25:47.263] [I] [core] [MQTT-16] Trying to reconnect (0) <= reconnect timer fumbles
[2018-02-07 00:25:47.286] [I] [core] [MQTT-16] Socket connection closed. <= kills the brand new connect
[2018-02-07 00:25:47.289] [I] [core] [MQTT_16] Error: Disconnected, will retry to connect...
[2018-02-07 00:25:47.290] [I] [core] [MQTT-16] Socket connection opened. <= manages a new
[2018-02-07 00:25:47.290] [I] [core] [MQTT-16] Connected to localhost
[2018-02-07 00:25:48.294] [I] [core] [MQTT-16] Trying to reconnect (0) <= and directly fumbles again
[2018-02-07 00:25:48.317] [I] [core] [MQTT-16] Socket connection closed.
[2018-02-07 00:25:48.321] [I] [core] [MQTT_16] Error: Disconnected, will retry to connect...

[Edubits]

Good catch @zyxxel, thanks! I've just pushed a fix for this and some other minor improvements. I'll submit this to the app store as version 1.3.1 soon.