zigbee2mqtt icon indicating copy to clipboard operation
zigbee2mqtt copied to clipboard

After upgrading to 1.37.0 zigbee2mqtt can't connect via IPv6

Open ytimenkov opened this issue 9 months ago • 22 comments

What happened?

After updating docker image to 1.37.0 zigbee2mqtt exits after start with:

May 02 05:05:17 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:17+02:00] info:         z2m: Connecting to MQTT server at mqtt://[fd9b:9838:3fd5:2e::1]:1883
May 02 05:05:17 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:17+02:00] error:         z2m: MQTT error: connect ECONNREFUSED /
May 02 05:05:17 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:17+02:00] error:         z2m: MQTT failed to connect, exiting...
May 02 05:05:17 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:17+02:00] info:         z2m: Stopping zigbee-herdsman...
May 02 05:05:18 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:18+02:00] error:         z2m: MQTT error: connect ECONNREFUSED /
May 02 05:05:19 heimdall systemd-zigbee[13674]: [2024-05-02T05:05:19+02:00] error:         z2m: MQTT error: connect ECONNREFUSED /

After switching to ipv4 address, the daemon started.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.37.0 (commit #46f34c8)

Adapter firmware version

not applicable

Adapter

not applicable

Setup

Podman with netavark stack

Debug log

May 02 05:06:42 heimdall systemd-zigbee[13996]: [2024-05-02T05:06:42+02:00] info:         z2m: Connecting to MQTT server at mqtt://[fd9b:9838:3fd5:2e::1]:1883
May 02 05:06:42 heimdall systemd-zigbee[13996]: [2024-05-02T05:06:42+02:00] debug:         z2m: Using MQTT anonymous login
May 02 05:06:42 heimdall systemd-zigbee[13996]: [2024-05-02T05:06:42+02:00] error:         z2m: MQTT error: connect ECONNREFUSED /
May 02 05:06:42 heimdall systemd-zigbee[13996]: [2024-05-02T05:06:42+02:00] error:         z2m: MQTT failed to connect, exiting...

ytimenkov avatar May 02 '24 03:05 ytimenkov

same symptoms for me as well but using IPv4

klevin92 avatar May 05 '24 15:05 klevin92

Hi, I have the same Problem

[2024-05-05 23:05:09] info: z2m: Connecting to MQTT server at http://192.168.2.144:1883 [2024-05-05 23:05:09] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:09] error: z2m: MQTT failed to connect, exiting... [2024-05-05 23:05:09] info: z2m: Stopping zigbee-herdsman... [2024-05-05 23:05:10] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:11] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:12] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:13] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:14] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:15] error: z2m: MQTT error: connect ECONNREFUSED / [2024-05-05 23:05:16] error: z2m: MQTT error: connect ECONNREFUSED /

SoSv73 avatar May 05 '24 21:05 SoSv73

@SoSv73 you shouldn't use http://, use mqtt://192.168.2.144:1883

Koenkk avatar May 06 '24 18:05 Koenkk

Thanks Koenkk, that was very usefull. Now it works like a charm. Thank you very much

SoSv73 avatar May 06 '24 20:05 SoSv73

I guess docker networking defaults to IPv6 as I'm having the same issue with the following server url: mqtt://mosquitto:1883

zigbee2mqtt  | [2024-05-07 22:11:05] info:      z2m: Connecting to MQTT server at http://mosquitto:1883/
zigbee2mqtt  | [2024-05-07 22:11:05] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:05] error:     z2m: MQTT failed to connect, exiting...
zigbee2mqtt  | [2024-05-07 22:11:05] info:      z2m: Stopping zigbee-herdsman...
zigbee2mqtt  | [2024-05-07 22:11:07] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:08] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:09] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:10] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:11] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:12] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:13] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:14] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:15] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:16] error:     z2m: MQTT error: connect ECONNREFUSED /
zigbee2mqtt  | [2024-05-07 22:11:17] error:     z2m: MQTT error: connect ECONNREFUSED /

After exposing 1883 to 0.0.0.0 and switching the server url to local_ipv4:1883 it works again.

Astu04 avatar May 07 '24 20:05 Astu04

Can you check with the latest dev branch?dev branch

Koenkk avatar May 07 '24 20:05 Koenkk

I've just tested the image koenkk/zigbee2mqtt:latest-dev and it works as expected :)

zigbee2mqtt  | [2024-05-07 22:31:22] info:      z2m: Connecting to MQTT server at mqtt://mosquitto:1883/
mosquitto    | 1715113882: New connection from 172.31.0.2:44940 on port 1883.
mosquitto    | 1715113882: New client connected from 172.31.0.2:44940 as zigbee (p2, c1, k60, u'z2m_qtt').
zigbee2mqtt  | [2024-05-07 22:31:22] info:      z2m: Connected to MQTT server

Wonderful, thank you!

Astu04 avatar May 07 '24 20:05 Astu04

So something broke with a recent version of MQTT.js, can you do:

docker exec -it zigbee2mqtt CONTAINER_NAME sh
npm install [email protected]
exit
docker restart CONTAINER_NAME

See if it still works, then bump the mqtt version until it breaks.

Koenkk avatar May 07 '24 20:05 Koenkk

I had to apk add npm to the alpine image even when it's on the Dockerfile Testing with main image, not latest. 5.5.3 worked, 5.5.4 didn't.

Astu04 avatar May 07 '24 21:05 Astu04

5.5.5 works with a caveat server: 'mqtt://mosquitto:1883/' still gets a connection refused but 'mqtt://mosquitto:1883' works as expected.

Connection error: Error: connect ECONNREFUSED /
    at PipeConnectWrap.afterConnect [as oncomplete] (node:net:1555:16) {
  errno: -111,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '/'
}

Given that I haven't seen documentation with the trailing slash, I think it's a just me issue.

I used this tiny script that may be handy for someone else:

const mqtt = require("mqtt");

// MQTT broker URL
// const brokerUrl = "mqtt://mosquitto:1883/";
const brokerUrl = "mqtt://mosquitto:1883";
// MQTT broker username and password
const options = {
  username: "z2m_qtt",
  password: "password"
};

// Connect to the MQTT broker
const client = mqtt.connect(brokerUrl, options);

client.on("connect", () => {
  // Subscribe to a topic
  client.subscribe("presence", (err) => {
    if (!err) {
      // Publish a message after successful subscription
      client.publish("presence", "Hello mqtt");
    } else {
      console.error("Subscription error:", err);
    }
  });
});

client.on("message", (topic, message) => {
  // Display received message
  console.log(message.toString());
  // Close the client connection
  client.end();
});

// Handle connection errors
client.on("error", (error) => {
  console.error("Connection error:", error);
});

Edit. I'm closing the PR, I've just noticed the regression from 5.5.5 to 5.5.0 and I'm not aware of why but you must know something I don't.

Astu04 avatar May 08 '24 08:05 Astu04

So it starts to break from 5.5.4?

Koenkk avatar May 08 '24 20:05 Koenkk

Sorry for late reply.

I tried latest-dev tag and can confirm that it fixes the problem (zigbee2mqtt connects to mosquitto via IPv6)

/app # grep version node_modules/mqtt/package.json 
  "version": "5.5.0",

ytimenkov avatar May 09 '24 06:05 ytimenkov

I wonder if it is related to https://github.com/mqttjs/MQTT.js/pull/1852 (or corresponding issue?) (based on fuzzy gpt-style text searching for most probable location 😁).

Digging a bit more I saw that you've downgraded mqtt.js version in dev. Then it makes more sense (I didn't pay attention to the versions and thought that you've bumped to the latest 5.5.5).

ytimenkov avatar May 09 '24 06:05 ytimenkov

I wonder if it is related to mqttjs/MQTT.js#1852 (or corresponding issue?) (based on fuzzy gpt-style text searching for most probable location 😁).

Given that my error is slightly different it's clearly related, and thinks the address is a socket path or something silly:

z2m: Starting Zigbee2MQTT version 1.37.0 (commit #unknown) z2m: Starting zigbee-herdsman (0.45.0) ... z2m: Connecting to MQTT server at mqtt://[fd0c::4c]:1883 z2m: MQTT error: connect EAFNOSUPPORT / z2m: MQTT failed to connect, exiting...

(EAFNOSUPPORT presumably occurs when it's hardened under systemd to only allow RestrictAddressFamilies=AF_INET6)

arcnmx avatar May 09 '24 15:05 arcnmx

@ytimenkov does 5.5.5 work for you?

Koenkk avatar May 10 '24 19:05 Koenkk

@Koenkk No, it doesn't:

/app # apk add npm
fetch https://dl-cdn.alpinelinux.org/alpine/v3.18/main/aarch64/APKINDEX.tar.gz
fetch https://dl-cdn.alpinelinux.org/alpine/v3.18/community/aarch64/APKINDEX.tar.gz
(1/1) Installing npm (9.6.6-r0)
Executing busybox-1.36.1-r2.trigger
OK: 77 MiB in 34 packages
/app # ls data/
configuration.yaml       coordinator_backup.json  database.db
/app # npm install [email protected]

changed 1 package, and audited 209 packages in 1m

30 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
/app # node index.js 
[2024-05-12T06:02:26+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-12T06:02:26+00:00] error:      z2m: MQTT failed to connect, exiting...
[2024-05-12T06:02:27+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-12T06:02:28+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /

The latest 1.37.1 works though. Release notes mention it as #605.

ytimenkov avatar May 12 '24 06:05 ytimenkov

  • Is your url: mqtt://[fd9b:9838:3fd5:2e::1]:1883?
  • what is the last working version? Start from 5.5.0 and update until it breaks

Koenkk avatar May 13 '24 18:05 Koenkk

Sorry for late reply. Was busy with day job and life during the week...

what is the last working version? Start from 5.5.0 and update until it breaks

It breaks at 5.5.4.

/app # npm install [email protected]

changed 1 package, and audited 209 packages in 15s

30 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
/app # node index.js

/// Runs here silently, I can see socket connected via ss

/app # npm install [email protected]

changed 1 package, and audited 209 packages in 15s

30 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
/app # node index.js
[2024-05-18T11:33:20+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:20+00:00] error:      z2m: MQTT failed to connect, exiting...
[2024-05-18T11:33:21+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:22+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:23+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:24+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:25+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:26+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:27+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:28+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:29+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:30+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:31+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-18T11:33:32+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /

Is your url: mqtt://[fd9b:9838:3fd5:2e::1]:1883?

Yes. (It is a standard way to write ipv6 addresses, as I understand).

/app # grep mqtt data/configuration.yaml 
mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://[fd9b:9838:3fd5:2e::1]:1883

ytimenkov avatar May 18 '24 11:05 ytimenkov

They've released MQTT 5.6.1 now, can you check if that works?

Koenkk avatar May 19 '24 14:05 Koenkk

No, same here.

/app # npm install [email protected]

changed 1 package, and audited 209 packages in 1m

30 packages are looking for funding
  run `npm fund` for details

found 0 vulnerabilities
/app # node index.js 
[2024-05-20T18:09:49+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:09:49+00:00] error:      z2m: MQTT failed to connect, exiting...
[2024-05-20T18:09:50+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:09:51+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:09:52+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:09:53+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:09:54+00:00] error:    z2m: Not connected to MQTT server!

I added strace to the image and ran. This confirms that mqtt.js confuses ipv6 address with unix socket address:

/app # strace -e trace=%net node index.js
...
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 21
connect(21, {sa_family=AF_UNIX, sun_path="/"}, 110) = -1 ECONNREFUSED (Connection refused)
[2024-05-20T18:11:32+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /
[2024-05-20T18:11:32+00:00] error:      z2m: MQTT failed to connect, exiting...
socket(AF_UNIX, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 21
connect(21, {sa_family=AF_UNIX, sun_path="/"}, 110) = -1 ECONNREFUSED (Connection refused)
[2024-05-20T18:11:33+00:00] error:      z2m: MQTT error: connect ECONNREFUSED /

Downgrading back to 5.5.3 produces result as expected:

socket(AF_INET6, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP) = 21
connect(21, {sa_family=AF_INET6, sin6_port=htons(1883), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "fd9b:9838:3fd5:2e::1", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation in progress)
getsockopt(21, SOL_SOCKET, SO_ERROR, [0], [4]) = 0

More and more evidence that adding unix sockets broke ipv6 :) At least in the original format.

Honestly, I think wrapping ipv6 addresses into [] is required, because of colon used to separate address and port. Otherwise the grammar will be ambiguous. For example:

$ ping 2600::0:1
PING 2600::0:1 (2600::1) 56 data bytes
64 bytes from 2600::1: icmp_seq=1 ttl=47 time=23.3 ms
64 bytes from 2600::1: icmp_seq=2 ttl=47 time=23.8 ms

So is :1 a port or part of the address? (Obviously, ping doesn't accept port, so it dropped :0 and canonicalized the address. BTW, 2600:: is also a valid address which can be pinged.

ytimenkov avatar May 20 '24 18:05 ytimenkov

I'm not sure if you have the time to do so, but could you make a min example and submit a bug report in the MQTT.js repo? That would be greatly appreciated!

Koenkk avatar May 21 '24 18:05 Koenkk

I'll put this on my todo list. Shall find some time some time 🤣.

Making a smaller repro for mqtt.js doesn't require to take down whole home automation.

ytimenkov avatar May 22 '24 09:05 ytimenkov

Sorry for late reply. There were few rounds in MQTT.js to fix the issue.

I can confirm that 5.7.0 doesn't have this problem anymore.

@Koenkk you can update again to the latest and close this ticket.

ytimenkov avatar Jun 08 '24 06:06 ytimenkov

@ytimenkov latest dev uses 5.7.0, many thanks @ytimenkov !

Koenkk avatar Jun 08 '24 16:06 Koenkk