Zigbee2mqtt hangs during startup

I have HA 2021.12.10 on a pi4
I have a conbee2 plugged into usb port
I have installed zigbee2mqtt 1.22.2-1

In the config I have added mqtt broker ip, user and password (which is on a separate machine and works for other purposes)
Added this…

serial:
  port: /dev/ttyACM0
  adapter: deconz

I’ve made no other changes to the config.

The log shows:

[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:22:01] INFO: Socat not enabled, marking service as down
[cont-init.d] socat.sh: exited 0.
[cont-init.d] zigbee2mqtt.sh: executing... 
[18:22:02] INFO: MQTT available, fetching server detail ...
[18:22:02] INFO: Previous config file found, checking backup
[18:22:02] INFO: Creating backup config in '/config/zigbee2mqtt/.configuration.yaml.bk'
[18:22:03] INFO: Adjusting Zigbee2mqtt core yaml config with add-on quirks ...
[cont-init.d] zigbee2mqtt.sh: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
[18:22:04] INFO: Handing over control to Zigbee2mqtt Core ...
> [email protected] start
> node index.js
CREATED DECONZ ADAPTER

Anyone any idea what I need to do to get it to work.??

With herdsman debug enabled…

> node index.js
2022-01-30T07:49:24.976Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT'
2022-01-30T07:49:24.985Z zigbee-herdsman:deconz:driver Set delay to 0
CREATED DECONZ ADAPTER
2022-01-30T07:49:24.989Z zigbee-herdsman:controller:log Starting with options '{"network":{"networkKeyDistribute":false,"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13],"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11]},"serialPort":{"path":"/dev/ttyACM0","adapter":"deconz"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2022-01-30T07:49:24.990Z zigbee-herdsman:deconz:driver Opening with /dev/ttyACM0
2022-01-30T07:49:25.008Z zigbee-herdsman:deconz:driver Serialport opened
2022-01-30T07:49:25.011Z zigbee-herdsman:controller:log Started with result 'resumed'
2022-01-30T07:49:25.012Z zigbee-herdsman:controller:log Injected database: true, adapter: true
2022-01-30T07:49:25.033Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 1 paramId: 1
2022-01-30T07:49:25.051Z zigbee-herdsman:deconz:frameParser MAC: 0x00212effff07d4c5
2022-01-30T07:49:25.053Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 2 paramId: 7
2022-01-30T07:49:25.056Z zigbee-herdsman:deconz:frameParser NWKADDR: 0
2022-01-30T07:49:25.063Z zigbee-herdsman:deconz:driver send read firmware version request from queue. seqNr: 3
2022-01-30T07:49:25.066Z zigbee-herdsman:deconz:frameParser read firmware version response - version: 0,7,88,38
2022-01-30T07:49:25.070Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 4 paramId: 5
2022-01-30T07:49:25.071Z zigbee-herdsman:deconz:frameParser PANID: 1a62
2022-01-30T07:49:25.075Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 5 paramId: 11
2022-01-30T07:49:25.077Z zigbee-herdsman:deconz:frameParser APS_EXT_PANID: 0xdddddddddddddddd
2022-01-30T07:49:25.080Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 6 paramId: 28
2022-01-30T07:49:25.082Z zigbee-herdsman:deconz:frameParser CHANNEL: 11
2022-01-30T07:49:25.085Z zigbee-herdsman:deconz:driver send read parameter request from queue. seqNr: 7 paramId: 24
2022-01-30T07:49:25.088Z zigbee-herdsman:deconz:frameParser NETWORK_KEY: hidden
2022-01-30T07:49:25.094Z zigbee-herdsman:controller:log Disable joining
2022-01-30T07:49:25.101Z zigbee-herdsman:deconz:adapter zclFrame to all - zclFrame.payload:
2022-01-30T07:49:25.109Z zigbee-herdsman:deconz:adapter { options: 11, commisioningWindow: 0 }
2022-01-30T07:49:25.109Z zigbee-herdsman:deconz:adapter sendZclFrameToAll - message send
2022-01-30T07:49:25.111Z zigbee-herdsman:deconz:driver DATA_REQUEST - destAddr: 0xfffd EP:242 SeqNr. 8 request id: 1
2022-01-30T07:49:25.115Z zigbee-herdsman:deconz:frameParser DATA_REQUEST RESPONSE - request id: 1 status: 0
2022-01-30T07:49:25.116Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.116Z zigbee-herdsman:deconz:frameParser DEVICE_STATE changed: 10100110
2022-01-30T07:49:25.117Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 1 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.118Z zigbee-herdsman:deconz:driver query aps data confirm
2022-01-30T07:49:25.123Z zigbee-herdsman:deconz:driver DATA_CONFIRM - sending data state request - SeqNr. 9
2022-01-30T07:49:25.127Z zigbee-herdsman:deconz:frameParser DATA_CONFIRM RESPONSE - destAddr: 0xfffd request id: 1 confirm status: 0
2022-01-30T07:49:25.127Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.129Z zigbee-herdsman:deconz:driver DATA_REQUEST - destAddr: 0xfffc EP:0 SeqNr. 10 request id: 2
2022-01-30T07:49:25.132Z zigbee-herdsman:deconz:frameParser DATA_REQUEST RESPONSE - request id: 2 status: 0
2022-01-30T07:49:25.133Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.783Z zigbee-herdsman:deconz:frameParser DEVICE_STATE changed: 10100110
2022-01-30T07:49:25.784Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 1 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.785Z zigbee-herdsman:deconz:driver query aps data confirm
2022-01-30T07:49:25.788Z zigbee-herdsman:deconz:driver DATA_CONFIRM - sending data state request - SeqNr. 11
2022-01-30T07:49:25.791Z zigbee-herdsman:deconz:frameParser DATA_CONFIRM RESPONSE - destAddr: 0xfffc request id: 2 confirm status: 0
2022-01-30T07:49:25.791Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:25.793Z zigbee-herdsman:deconz:adapter PERMIT_JOIN - 0 seconds
2022-01-30T07:49:25.907Z zigbee-herdsman:deconz:driver send write parameter request from queue. seqNr: 12 paramId: 33 param: 0
2022-01-30T07:49:25.911Z zigbee-herdsman:deconz:frameParser write parameter response - parameter id: 33 - status: 0
2022-01-30T07:49:27.990Z zigbee-herdsman:deconz:adapter checking coordinator simple descriptor
2022-01-30T07:49:27.995Z zigbee-herdsman:deconz:driver DATA_REQUEST - destAddr: 0x0 EP:0 SeqNr. 13 request id: 3
2022-01-30T07:49:27.999Z zigbee-herdsman:deconz:frameParser DATA_REQUEST RESPONSE - request id: 3 status: 0
2022-01-30T07:49:27.999Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:28.001Z zigbee-herdsman:deconz:frameParser DEVICE_STATE changed: 10101110
2022-01-30T07:49:28.002Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 1 apsDataIndication: 1 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:28.006Z zigbee-herdsman:deconz:driver query aps data confirm
2022-01-30T07:49:28.008Z zigbee-herdsman:deconz:driver DATA_CONFIRM - sending data state request - SeqNr. 14
2022-01-30T07:49:28.011Z zigbee-herdsman:deconz:driver query aps data indication
2022-01-30T07:49:28.013Z zigbee-herdsman:deconz:frameParser DATA_CONFIRM RESPONSE - destAddr: 0x0 request id: 3 confirm status: 0
2022-01-30T07:49:28.013Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 1 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:28.014Z zigbee-herdsman:deconz:driver query aps data indication
2022-01-30T07:49:28.016Z zigbee-herdsman:deconz:driver DATA_INDICATION - sending read data request - SeqNr. 15
2022-01-30T07:49:28.020Z zigbee-herdsman:deconz:frameParser DATA_INDICATION RESPONSE - seqNr. 15 srcAddr: 0x0 destAddr: 0x0 profile id: 0x0 cluster id: 0x8004 lqi: 17
2022-01-30T07:49:28.021Z zigbee-herdsman:deconz:frameParser response payload: 3,0,0,0,20,1,4,1,5,0,1,3,0,0,10,0,25,0,3,1,0,32,0,0,5
2022-01-30T07:49:28.021Z zigbee-herdsman:deconz:adapter resolve data request without a transSeq Nr.
2022-01-30T07:49:28.022Z zigbee-herdsman:deconz:driver networkstate: 2 apsDataConfirm: 0 apsDataIndication: 0 configChanged: 0 apsRequestFreeSlots: 1
2022-01-30T07:49:28.023Z zigbee-herdsman:deconz:adapter RECEIVING SIMPLE_DESCRIPTOR - addr: 0x0 EP:1 inClusters: 0,10,25 outClusters: 1,32,1280
2022-01-30T07:49:28.023Z zigbee-herdsman:deconz:adapter EP: 1
2022-01-30T07:49:28.023Z zigbee-herdsman:deconz:adapter profile ID: 260
2022-01-30T07:49:28.024Z zigbee-herdsman:deconz:adapter device ID: 5
2022-01-30T07:49:28.024Z zigbee-herdsman:deconz:adapter input cluster: 0x0
2022-01-30T07:49:28.024Z zigbee-herdsman:deconz:adapter input cluster: 0xa
2022-01-30T07:49:28.024Z zigbee-herdsman:deconz:adapter input cluster: 0x19
2022-01-30T07:49:28.024Z zigbee-herdsman:deconz:adapter output cluster: 0x1
2022-01-30T07:49:28.025Z zigbee-herdsman:deconz:adapter output cluster: 0x20
2022-01-30T07:49:28.025Z zigbee-herdsman:deconz:adapter output cluster: 0x500
2022-01-30T07:49:28.025Z zigbee-herdsman:deconz:driver DATA_INDICATION - sending read data request - SeqNr. 16

I might be missing something but log ends with adapter successfully created and zigbee2mqtt starting. What is the exact problem you are experiencing?

Well the webui just reports bad gateway error 502 so I am assuming startup is incomplete.

EDIT:
Found this error message in the main log which I guess is related but no idea what to do about it.

22-01-30 21:36:51 ERROR (MainThread) [supervisor.api.ingress] Ingress error: Cannot connect to host 172.30.33.7:8099 ssl:default [Connect call failed (‘172.30.33.7’, 8099)]

My proxy setting looks appropriate:

use_x_forwarded_for: true
  trusted_proxies:
    - 172.30.33.0/24
    - 192.168.0.50
    - 127.0.0.1
    - ::1

I have zero experience with reverse proxy. I use Nabu Casa for remote connections to the server. Is there a way to switch it off and test whether web ui works if it tries to contact 192.168.0.50 directly?

192.168.0.52 is the system with zigbee2mqtt installed, 192.168.0.50 is the mqtt broker machine, the 172.30.33.7 is some part of the underlying ‘container’ world upon which the HA sits. All that level is beyond me.

The reason I’m doing this is because I want two HA systems to have access to the zigbee devices and mqtt looked the solution.

Too complex for my knowledge of HA, but logs show that zigbee2mqtt is able to connect to MQTT server. If this is the case you could check on MQTT server end if anything is published in zigbee2mqtt topic.

I suspect it is web ui not being able to contact correct address / port, but I don’t know how to help, so I hope someone else will be able to do this.

You could also try to experiment with frontend configuration entries, as per below documentation. It seems, that you can specify frontend server in yaml.

https://www.zigbee2mqtt.io/guide/configuration/frontend.html#nginx-proxy-configuration

No mqtt traffic visible.

The frontend: bit is a mystery. You’d think the port specified would be to allow you to select which port to use, but changing it and restarting still reports it failing to connect to 172.30.33.3:8099.

Thanks for trying to help.

I also run a pi4 and have zigbee2mqtt installed on the same device as HA is installed on.

In my config, my USB dongle is configured as /dev/ttyUSB0 and not /dev/ttyACM0

I have the following in my zigbee2mqtt configuration as well.

frontend:
port: 8099

On your machine that has zigbee2mqtt installed, can you bring up the webui with a URL of 192.168.0.52:8099?

@BlackRose67 thanks for input.
If i try to use link in sidebar or link in addon page i get error 502 and a blank page. The system log then shows the error message…
.ERROR (MainThread) [supervisor.api.ingress] Ingress error: Cannot connect to host 172.30.33.7:8099 ssl:default [Connect call failed (‘172.30.33.7’, 8099)

192.168.0.52:8099 doesnt work, just timesout unable to connect.

Ive had huntsman debug enabled and it seems happy with dongle and mqtt connection.

Just the ui…

I finally solved it.
mqtt was the issue.
I used to have:

server: 192.168.0.50:1883

The solution was:

server: mqtt://192.168.0.50
1 Like