Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
genestealer opened this issue Dec 15, 2023 · 19 comments · Fixed by #83
Labels
done Issue fixed in develop branch
Milestone

Comments

@genestealer
Copy link
Contributor

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
Copy link
Contributor Author

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 #60

@Achronite
Copy link
Owner

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

@genestealer
Copy link
Contributor Author

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

@genestealer
Copy link
Contributor Author

genestealer commented Dec 15, 2023

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

Ref: mqttjs/MQTT.js#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
Copy link
Contributor Author

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
Copy link
Contributor Author

Found issue was with systemd service, PR raised: #63

@Achronite Achronite added this to the v0.7.0 milestone Dec 16, 2023
@Achronite Achronite added the done Issue fixed in develop branch label Jan 12, 2024
@robertsLando
Copy link

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
Copy link
Owner

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

@robertsLando
Copy link

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

@genestealer
Copy link
Contributor Author

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
Copy link
Owner

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
Copy link
Contributor Author

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
Copy link

@genestealer Still not working?

@genestealer
Copy link
Contributor Author

@genestealer Still not working?

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

@robertsLando
Copy link

Thanks for your feedback 🙏🏼

Achronite added a commit that referenced this issue Feb 6, 2024
@Achronite
Copy link
Owner

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

@genestealer
Copy link
Contributor Author

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

@Achronite
Copy link
Owner

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

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

@robertsLando
Copy link

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

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

@Achronite Achronite mentioned this issue Feb 21, 2024
@Achronite Achronite linked a pull request Feb 21, 2024 that will close this issue
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
done Issue fixed in develop branch
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants