search

Achronite / mqtt-energenie-ener314rt

MQTT interface for Energenie ENER314-RT add-on board for the Raspberry Pi, designed for use by Home Assistant.
MIT License
13 stars 5 forks source link

Failed to start Energenie ener314rt MQTT client - If ERR! MQTT code: 'ECONNREFUSED', after 7 attempts #62

Closed genestealer closed 7 months ago

genestealer commented 9 months ago

I note, if the MQTT server is unavailable, such as it's rebooting or temporarily offline, then the mqtt-energenie-ener314rt.service will exit after trying to connect 7 times and must be restarted.

Can we: extended this to 100, make it infinite, or logarithmically increase the time between retries after the first 7 or so tries? 

Dec 14 22:06:12 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:12 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 3.130s CPU time.
Dec 14 22:06:13 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 2.
Dec 14 22:06:13 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:13 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 3.130s CPU time.
Dec 14 22:06:13 raspberrypi systemd[1]: Started Energenie ener314rt MQTT client.
Dec 14 22:06:13 raspberrypi node[4924]: mqtt-energenie-ener314rt version 0.6.0: starting
Dec 14 22:06:13 raspberrypi node[4924]: mqtt-ener314rt info MQTT connecting to broker mqtt://192.168.10.21
Dec 14 22:06:13 raspberrypi node[4924]: mqtt-ener314rt info monitor starting monitoring of FSK devices...
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT Error: connect ECONNREFUSED 192.168.10.21:1883
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT  ERROR %j connecting to MQTT broker: %j Error: connect ECONN>
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT   errno: -111,
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT   code: 'ECONNREFUSED',
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT   syscall: 'connect',
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT   address: '192.168.10.21',
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT   port: 1883
Dec 14 22:06:14 raspberrypi node[4924]: mqtt-ener314rt ERR! MQTT } mqtt://192.168.10.21
Dec 14 22:06:14 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 22:06:14 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:14 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.097s CPU time.
Dec 14 22:06:14 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 3.
Dec 14 22:06:14 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:14 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.097s CPU time.
Dec 14 22:06:14 raspberrypi systemd[1]: Started Energenie ener314rt MQTT client.
Dec 14 22:06:14 raspberrypi node[4941]: mqtt-energenie-ener314rt version 0.6.0: starting
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt info MQTT connecting to broker mqtt://192.168.10.21
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt info monitor starting monitoring of FSK devices...
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT Error: connect ECONNREFUSED 192.168.10.21:1883
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT  ERROR %j connecting to MQTT broker: %j Error: connect ECONN>
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT   errno: -111,
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT   code: 'ECONNREFUSED',
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT   syscall: 'connect',
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT   address: '192.168.10.21',
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT   port: 1883
Dec 14 22:06:15 raspberrypi node[4941]: mqtt-ener314rt ERR! MQTT } mqtt://192.168.10.21
Dec 14 22:06:15 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 22:06:15 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:15 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.049s CPU time.
Dec 14 22:06:15 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 4.
Dec 14 22:06:15 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:15 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.049s CPU time.
Dec 14 22:06:15 raspberrypi systemd[1]: Started Energenie ener314rt MQTT client.
Dec 14 22:06:15 raspberrypi node[4955]: mqtt-energenie-ener314rt version 0.6.0: starting
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt info MQTT connecting to broker mqtt://192.168.10.21
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt info monitor starting monitoring of FSK devices...
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT Error: connect ECONNREFUSED 192.168.10.21:1883
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT  ERROR %j connecting to MQTT broker: %j Error: connect ECONN>
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT   errno: -111,
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT   code: 'ECONNREFUSED',
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT   syscall: 'connect',
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT   address: '192.168.10.21',
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT   port: 1883
Dec 14 22:06:16 raspberrypi node[4955]: mqtt-ener314rt ERR! MQTT } mqtt://192.168.10.21
Dec 14 22:06:16 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 22:06:16 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:16 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.060s CPU time.
Dec 14 22:06:16 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 5.
Dec 14 22:06:16 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:16 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.060s CPU time.
Dec 14 22:06:16 raspberrypi systemd[1]: Started Energenie ener314rt MQTT client.
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-energenie-ener314rt version 0.6.0: starting
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt info MQTT connecting to broker mqtt://192.168.10.21
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt info monitor starting monitoring of FSK devices...
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT Error: connect ECONNREFUSED 192.168.10.21:1883
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT  ERROR %j connecting to MQTT broker: %j Error: connect ECONN>
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT   errno: -111,
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT   code: 'ECONNREFUSED',
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT   syscall: 'connect',
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT   address: '192.168.10.21',
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT   port: 1883
Dec 14 22:06:17 raspberrypi node[4972]: mqtt-ener314rt ERR! MQTT } mqtt://192.168.10.21
Dec 14 22:06:17 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 22:06:17 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:17 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.060s CPU time.
Dec 14 22:06:18 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 6.
Dec 14 22:06:18 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:18 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.060s CPU time.
Dec 14 22:06:18 raspberrypi systemd[1]: Started Energenie ener314rt MQTT client.
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-energenie-ener314rt version 0.6.0: starting
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt info MQTT connecting to broker mqtt://192.168.10.21
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt info monitor starting monitoring of FSK devices...
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT Error: connect ECONNREFUSED 192.168.10.21:1883
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT  ERROR %j connecting to MQTT broker: %j Error: connect ECONN>
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT     at TCPConnectWrap.afterConnect [as oncomplete] (node:net>
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT   errno: -111,
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT   code: 'ECONNREFUSED',
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT   syscall: 'connect',
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT   address: '192.168.10.21',
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT   port: 1883
Dec 14 22:06:18 raspberrypi node[4988]: mqtt-ener314rt ERR! MQTT } mqtt://192.168.10.21
Dec 14 22:06:18 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Main process exited, code=exited, status=1/FAILURE
Dec 14 22:06:18 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:18 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.049s CPU time.
Dec 14 22:06:19 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Scheduled restart job, restart counter is at 7.
Dec 14 22:06:19 raspberrypi systemd[1]: Stopped Energenie ener314rt MQTT client.
Dec 14 22:06:19 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Consumed 1.049s CPU time.
Dec 14 22:06:19 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Start request repeated too quickly.
Dec 14 22:06:19 raspberrypi systemd[1]: mqtt-energenie-ener314rt.service: Failed with result 'exit-code'.
Dec 14 22:06:19 raspberrypi systemd[1]: Failed to start Energenie ener314rt MQTT client.

image image

genestealer commented 9 months ago

Note, this is why I thought the discovery messages were not being sent regularly. It was actually the service exiting after trying to connect. See https://github.com/Achronite/mqtt-energenie-ener314rt/issues/60

Achronite commented 9 months ago

That must be the default; if you want to change the behaviour you can modify your mqtt_options in your config.json file.

genestealer commented 9 months ago

I tried setting reconnectPeriod to 5 mins (120000) but cannot find anything to set infinite reconnections

genestealer commented 9 months ago

I note, you also have to set the connectTimeout to greater than reconnectPeriod. Else it fails.

Ref: https://github.com/mqttjs/MQTT.js/issues/419

E.G.

{
    "topic_stub": "energenie/",
    "mqtt_broker": "mqtt://192.168.10.21",
    "mqtt_options": {
        "username":"energenie",
        "password":"xxxxxx",
        "clean": true,
        "reconnectPeriod": "120000",
        "connectTimeout": "130000"
    },
    "monitoring": true,
    "discovery_prefix": "homeassistant/",
    "ook_xmits": 50,
    "fsk_xmits": 20,
    "log_level": "info
}
genestealer commented 9 months ago

I may be missing something but I'm struggling to see where in your .js application the exiting is occurring.

As from a simplistic point of view. I would look to try and remove the exit criteria, so as the .js application attempts to indefinitely reconnect.

genestealer commented 9 months ago

Found issue was with systemd service, PR raised: https://github.com/Achronite/mqtt-energenie-ener314rt/pull/63

robertsLando commented 8 months ago

The issue with the reconnect period and connect timeout should have been fixed now on mqttjs 5.3.5. Any feedback would be welcome

Achronite commented 8 months ago

https://github.com/mqttjs/MQTT.js/releases/tag/v5.3.5 @genestealer Are you OK to test if I bump the dependency?

robertsLando commented 8 months ago

I'm also working on a PR to add an error event on connack timeout: https://github.com/mqttjs/MQTT.js/pull/1781

genestealer commented 8 months ago

https://github.com/mqttjs/MQTT.js/releases/tag/v5.3.5 @genestealer Are you OK to test if I bump the dependency?

Happy to test, sorry been away from this for a few weeks and feel like I have forgotten things. Sorry to sound stupid, do I just need to edit "package.json" 'dependencies' and set MQTT to 5.3.5 and run npm install again?

image

Achronite commented 8 months ago

Happy to test, sorry been away from this for a few weeks and feel like I have forgotten things. Sorry to sound stupid, do I just need to edit "package.json" 'dependencies' and set MQTT to 5.3.5 and run npm install again?

Yes

genestealer commented 8 months ago

I'm also working on a PR to add an error event on connack timeout: mqttjs/MQTT.js#1781 @Achronite Tested, MQTT 5.3.5 is working great.

I'm also working on a PR to add an error event on connack timeout: mqttjs/MQTT.js#1781 @robertsLando Thank you, I have removed the connectTimeout & reconnectPeriod from my mqtt_options.json

image

robertsLando commented 8 months ago

@genestealer Still not working?

genestealer commented 8 months ago

@genestealer Still not working?

Tested, MQTT 5.3.5 is working great. Yes it's working.

robertsLando commented 8 months ago

Thanks for your feedback 🙏🏼

Achronite commented 8 months ago

@genestealer Do we still need your changes to the service?

genestealer commented 8 months ago

@Achronite No, MQTT 5.3.5 fixed the issue as far as I can tell.

Achronite commented 8 months ago

@robertsLando Does MQTT.js really require node.js v18.2+ ?

raspbian 9 doesn't support v18 (GLIBC_2.28 required)

robertsLando commented 7 months ago

@robertsLando Does MQTT.js really require node.js v18.2+ ?

Only tests require node 18+ but it works also with older nodejs versions