Desperate....cannot get Zigbee2MQTT to start

I have been on this for days now, read and tried everything I can, but I cannot get Zigbee2MQTT to work.

I have following setup:

  • RPi4 with HASS installed
  • Sonoff USB 3.0 dongle
  • Flashed the latest coordinator firmware on the stick

Installed the Zigbee2MQTT addon with following configuration:

data_path: /config/zigbee2mqtt
socat:
  enabled: false
  master: pty,raw,echo=0,link=/tmp/ttyZ2M,mode=777
  slave: tcp-listen:8485,keepalive,nodelay,reuseaddr,keepidle=1,keepintvl=1,keepcnt=5
  options: '-d -d'
  log: false
mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://core-mosquitto:1883
  user: mqtt_user
  pass: mqtt_pass
serial:
  port: >-
    /dev/serial/by-id/usb-ITead_Sonoff_Zigbee_3.0_USB_Dongle_Plus_3aef3f34b0c9eb11ab838d4f1d69213e-if00-port0
homeassistant: true
frontend:
  port: 8099
zigbee_herdsman_debug: false
permit_join: true
experimental:
  new_api: true
advanced:
  log_level: warn
  pan_id: 6700
  channel: 15
  network_key:
    - 1
    - 3
    - 5
    - 7
    - 9
    - 11
    - 13
    - 15
    - 0
    - 2
    - 4
    - 6
    - 8
    - 10
    - 12
    - 13

Installed the MQTT broker addon with this configuration:

certfile: fullchain.pem
customize:
  active: false
  folder: mosquitto
keyfile: privkey.pem
logins:
  - username: mqtt_user
    password: mqtt_pass
require_certificate: false

Now when I try to start the addon I keep getting this log from Zigbee2MQTT:

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] socat.sh: executing... 
[18:35:42] INFO: Socat not enabled, marking service as down
[cont-init.d] socat.sh: exited 0.
[cont-init.d] zigbee2mqtt.sh: executing... 
[cont-init.d] zigbee2mqtt.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[18:35:44] INFO: Handing over control to Zigbee2mqtt Core ...
> [email protected] start
> node index.js
Zigbee2MQTT:error 2022-04-05 18:35:53: MQTT failed to connect: Connection refused: Not authorized
Zigbee2MQTT:error 2022-04-05 18:35:53: Exiting...
[18:36:04] INFO: Handing over control to Zigbee2mqtt Core ...
> [email protected] start
> node index.js
Zigbee2MQTT:error 2022-04-05 18:36:12: MQTT failed to connect: Connection refused: Not authorized
Zigbee2MQTT:error 2022-04-05 18:36:12: Exiting...

Combined with following error messages in the supervisor log:

22-04-05 18:36:08 ERROR (MainThread) [supervisor.api.ingress] Ingress error: Cannot connect to host 172.30.33.5:8099 ssl:default [Connect call failed ('172.30.33.5', 8099)]

If I turn on the zigbee_herdsman_debug option to true, I get following log from Zigbee2MQTT:

2022-04-05T16:46:16.135Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":170,"offset":0,"len":12}
2022-04-05T16:46:16.135Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,170,0,0,0,12,188]
2022-04-05T16:46:16.147Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.147Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.148Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.148Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.148Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.148Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":171}
2022-04-05T16:46:16.148Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,171,0,189]
2022-04-05T16:46:16.159Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.159Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.160Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.160Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.160Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.160Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":171,"offset":0,"len":12}
2022-04-05T16:46:16.161Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,171,0,0,0,12,189]
2022-04-05T16:46:16.172Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.173Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.173Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.173Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.173Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.173Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":172}
2022-04-05T16:46:16.174Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,172,0,186]
2022-04-05T16:46:16.184Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.184Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.185Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.185Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.185Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.185Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":172,"offset":0,"len":12}
2022-04-05T16:46:16.185Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,172,0,0,0,12,186]
2022-04-05T16:46:16.197Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.198Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.198Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.198Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.198Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.200Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":173}
2022-04-05T16:46:16.200Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,173,0,187]
2022-04-05T16:46:16.212Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.212Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.213Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.213Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.213Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.213Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":173,"offset":0,"len":12}
2022-04-05T16:46:16.214Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,173,0,0,0,12,187]
2022-04-05T16:46:16.226Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.226Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.226Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.226Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.226Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.227Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":174}
2022-04-05T16:46:16.227Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,174,0,184]
2022-04-05T16:46:16.238Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.238Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.238Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.238Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.238Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.239Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":174,"offset":0,"len":12}
2022-04-05T16:46:16.239Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,174,0,0,0,12,184]
2022-04-05T16:46:16.251Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.251Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.251Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.251Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.252Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.252Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":175}
2022-04-05T16:46:16.252Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,175,0,185]
2022-04-05T16:46:16.263Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.263Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.263Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.263Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.264Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.264Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":175,"offset":0,"len":12}
2022-04-05T16:46:16.264Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,175,0,0,0,12,185]
2022-04-05T16:46:16.276Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.276Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.276Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.277Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.277Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.277Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":176}
2022-04-05T16:46:16.277Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,176,0,166]
2022-04-05T16:46:16.287Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvRead - {"sysid":1,"itemid":1,"subid":176,"offset":0,"len":12}
2022-04-05T16:46:16.288Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,8,33,51,1,1,0,176,0,0,0,12,166]
2022-04-05T16:46:16.300Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.300Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,14,97,51,0,12,0,255,0,0,0,0,0,0,0,0,0,0,175]
2022-04-05T16:46:16.300Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 14 - 3 - 1 - 51 - [0,12,0,255,0,0,0,0,0,0,0,0,0,0] - 175
2022-04-05T16:46:16.300Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvRead - {"status":0,"len":12,"value":{"type":"Buffer","data":[0,255,0,0,0,0,0,0,0,0,0,0]}}
2022-04-05T16:46:16.301Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
2022-04-05T16:46:16.301Z zigbee-herdsman:adapter:zStack:znp:SREQ --> SYS - nvLength - {"sysid":1,"itemid":1,"subid":177}
2022-04-05T16:46:16.301Z zigbee-herdsman:adapter:zStack:unpi:writer --> frame [254,5,33,50,1,1,0,177,0,167]
2022-04-05T16:46:16.312Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.312Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext [254,4,97,50,12,0,0,0,91]
2022-04-05T16:46:16.312Z zigbee-herdsman:adapter:zStack:unpi:parser --> parsed 4 - 3 - 1 - 50 - [12,0,0,0] - 91
2022-04-05T16:46:16.312Z zigbee-herdsman:adapter:zStack:znp:SRSP <-- SYS - nvLength - {"len":12}
2022-04-05T16:46:16.312Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
[18:46:25] INFO: Zigbee Herdsman debug logging enabled
[18:46:29] INFO: Handing over control to Zigbee2mqtt Core ...

What am I missing, does anyone have an idea? I am going crazy and start being desperate, I think I have tried everything which I could read, but cannot get it to work.

1 Like

I have a problem which had issues with socat also. I read somewhere to set it to true from false. Changing the state enabled it and cleared that issue.

Tried it…no difference…

Either the address is wrong, or username
/password:

MQTT failed to connect: Connection refused: Not authorized

Where did you get your mqtt addres core-mosquitto from anyway??
yours:

mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://core-mosquitto:1883
  user: mqtt_user
  pass: mqtt_pass

mine:

mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://192.168.1.3
  user: <mqttuser>
  password: <mqttpw>

It also seems you need to use 8883, since tou seems to use SSL:

Depending on your configuration, the MQTT server config may need to include the port, typically 1883 or 8883 for SSL communications
But i guess you only use mqtt locally, so why bother using SSL??
ps: mqtt:// already implies 1883, no need to specify it (not even sure it is supported)

Thanks for those hints…user/pass are ok.

I tried it with the ipadress from my Homeassitant, but that didn’t work. Your comment about ssl makes me wonder. I have NGINX setup with a certifcate for ssl connection from outside, but does that impact this addon? At least…I don’t know where else I would have anything setup with ssl.

So I changed the config to:

mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://homeassitant_ip:8883
  user: mqtt_user
  pass: mqtt_pass

no, it doesn’t, keep in mind some people might use an mqtt broker on another machine or even a remote server :thinking:
If you have both zigbee2mqtt and mqtt broker as addon, skip the SSL :wink:

I use https (SSL) for remote web acess, but not for local mqtt.
Not much use to have it encrypted, besides my wife and daughter I’m the only one who would be able to do something with the data…

That is why I don’t understand my issue. I have both the zigbee2mqtt and the mqttbroker addon installed in HASS, so I don’t need ssl. But why does it try to do that?

Have you tried mqtt-explorer, so you’de know if everything on the broker side is ok??

require_certificate: false

it doesn’t (sorry i overlooked that line)

That seems to be ok

I do see these messages in the broker addon log:

1649184386: Socket error on client <unknown>, disconnecting.
1649184387: New connection from 172.30.32.1 on port 1883.

But I do not know what to do with them.

I found it…stupid thing. The config file should be:

mqtt:
  base_topic: zigbee2mqtt
  server: mqtt://core-mosquitto:1883
  user: mqtt_user
  password: mqtt_pass

Instead of “password”…the option I had in my config was “pass”…that does not work. Changed it and now everything is ok.

1 Like

Nice you found the error. Remember to change the network key before you install a lot of devices. The networek key is the standard, hence not secure.

Thank you. I did the same dumb thing.

Can you tell me what network key that should be changed? I’m afraid I’ve missed something here.

The network key in Zigbee2MQTT is always set to the standard, being 1,3,5,7…

You can of course leave it like this, and personally I do not see the zigbee network as a big security risk. However, as this is a standard key everybody can access your zigbee network if they know how. Be aware changing the key will require a re-pair of all devices.

In the old Z2M, with the long configuration file, the key was directly shown. If you search in the forum you can find a lot of examples on this. This have changed and the key is now configured under “Settings” - “Advanced”. You have to read the docs to figure out, I changed my key when it was still in the configuration file, hence have not tried in the GUI.

I solved this by creating a user in MQTT broker (instead of the user created in HA), updated z2m config and then everything started working. I don’t know why the HA user just stopped working but this solved the problem for me.