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

A lot of "Adapter disconnected, stopping" error after update 1.35 #21287

Closed
syntesys87 opened this issue Feb 7, 2024 · 37 comments
Closed

A lot of "Adapter disconnected, stopping" error after update 1.35 #21287

syntesys87 opened this issue Feb 7, 2024 · 37 comments
Labels
ezsp Issues related to deprecated ezsp driver problem Something isn't working

Comments

@syntesys87
Copy link

What happened?

When I launch an OTA update, I can see a lot of "Adapter disconnected, stopping" error followed by a "Zigbee2Mqtt has been restarted!"

Here attached a log file.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.35.3

Adapter firmware version

7.4.0.0 Build 0

Adapter

EZSP v12 SONOFF_Zigbee_3.0_USB_Dongle_Plus_V2

Setup

HAOS

Debug log

log.txt

@syntesys87 syntesys87 added the problem Something isn't working label Feb 7, 2024
@Kejserjorn
Copy link

Same thing happens to me now.

Zigbee2MQTT version 1.35.3

SonOff Dongle-E 7.3.1.0 firmware

@Koenkk Koenkk added the ezsp Issues related to deprecated ezsp driver label Feb 7, 2024
@derekoharrow
Copy link

I'm getting lots of errors now and devices not responding well since upgrading to 1.35.3 and latest-dev.

Reverting back to 1.35.2 seems to have fixed it for now

Zigbee2MQTT:warn  07-02-2024 20:11:11: Failed to ping 'Lauren's lamp' (attempt 2/2, Read 0x000b57fffe4061c1/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:error 07-02-2024 20:11:17: Publish 'set' 'state' to 'Lounge Floor Lamp' failed: 'Error: Command 0x588e81fffeca296f/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)'
Zigbee2MQTT:warn  07-02-2024 20:11:23: Failed to ping 'Lounge table lamp' (attempt 1/2, Read 0x14b457fffe3738cc/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:error 07-02-2024 20:11:29: Publish 'set' 'state' to 'Lounge Floor Lamp' failed: 'Error: Command 0x588e81fffeca296f/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms)'
Zigbee2MQTT:warn  07-02-2024 20:11:35: Failed to ping 'Lounge table lamp' (attempt 2/2, Read 0x14b457fffe3738cc/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:warn  07-02-2024 20:11:46: Failed to ping 'Landing lamp' (attempt 1/2, Read 0x001788010206628c/11 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:warn  07-02-2024 20:11:55: Failed to ping 'Landing lamp' (attempt 2/2, Read 0x001788010206628c/11 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:warn  07-02-2024 20:12:06: Failed to ping 'Snug lamp' (attempt 1/2, Read 0xccccccfffed6bd92/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:warn  07-02-2024 20:12:15: Failed to ping 'Snug lamp' (attempt 2/2, Read 0xccccccfffed6bd92/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))
Zigbee2MQTT:warn  07-02-2024 20:12:26: Failed to ping 'Snug TV lamp' (attempt 1/2, Read 0xec1bbdfffe3985fe/1 genBasic(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (SRSP - AF - dataRequest after 6000ms))

@DoubleZed
Copy link

I am having the same issues with a Conbee II adapter. All zigbee communication between the network and HA is broken. Reverting to 1.35.2 fixed the issues.

buroa added a commit to buroa/k8s-gitops that referenced this issue Feb 7, 2024
@asan84
Copy link

asan84 commented Feb 8, 2024

After update 1.35.2 to 1.35.3 ZigBee2MQTT (Addon HASS) Started and next 15-30 second Stopped :(((
EZSP v7 firmware 6.6.5.0 build 204

In Log:

/app/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:264
var er = new ERR_STREAM_WRITE_AFTER_END();
^
Error: write after end
at writeAfterEnd (/app/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:264:12)
at File.Writable.write (/app/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:300:21)
at DerivedLogger.ondata (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:629:20)
at DerivedLogger.emit (node:events:517:28)
at DerivedLogger.Readable.read (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:451:26)
at flow (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:858:34)
at File.pipeOnDrainFunctionResult (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_readable.js:690:7)
at File.emit (node:events:517:28)
at onwriteDrain (/app/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:453:12)
at afterWrite (/app/node_modules/winston-transport/node_modules/readable-stream/lib/_stream_writable.js:441:18)

@tm8
Copy link

tm8 commented Feb 8, 2024

I am having the same issues with a Conbee II adapter. All zigbee communication between the network and HA is broken. Reverting to 1.35.2 fixed the issues.

How can I go back to 1.35.2 without importing a backup?
Thank You.

@DoubleZed
Copy link

I am having the same issues with a Conbee II adapter. All zigbee communication between the network and HA is broken. Reverting to 1.35.2 fixed the issues.

How can I go back to 1.35.2 without importing a backup? Thank You.

If you do not have a partial backup from any of your previous updates of zigbee2mqtt (even older than 1.35.2) then there is no officially supported way of doing it. However, there is a potential workaround to rollback the docker container version of the add-on to a previous version. However it is not recommended to do it that way as it can break your system so do it at your own risk.

@tm8
Copy link

tm8 commented Feb 8, 2024

I am having the same issues with a Conbee II adapter. All zigbee communication between the network and HA is broken. Reverting to 1.35.2 fixed the issues.

How can I go back to 1.35.2 without importing a backup? Thank You.

If you do not have a partial backup from any of your previous updates of zigbee2mqtt (even older than 1.35.2) then there is no officially supported way of doing it. However, there is a potential workaround to rollback the docker container version of the add-on to a previous version. However it is not recommended to do it that way as it can break your system so do it at your own risk.

Thank you very much, thought you could just jump back. I have backed up HA in Proxmox as a VM. That is not a problem. Many thanks for the quick feedback.

@syntesys87
Copy link
Author

Downgraded to 1.35.2, but the problem persists...

@ThorstenDtk
Copy link

Downgraded to 1.35.2, but the problem persists...

I have the same problem with 1.35.2.

@tm8
Copy link

tm8 commented Feb 15, 2024

Hello, I am back to version 1.35.1 which works without any problems.
Version 1.35.2 and 1.35.3 do not work, here the addon restarts every 3-4 minutes.

@fnordpojk
Copy link

On 1.35.3, while my network works fine, OTA updates crash Z2M around the 40% mark, and OTA update state goes into eternal spinner mode requiring hand editing of state.json.

@myoung34
Copy link

seeing this recently with a tubezb on latest zigbee2mqtt when launching OTA

Zigbee2MQTT:error 2024-02-14 03:07:53: Adapter disconnected, stopping
Zigbee2MQTT:debug 2024-02-14 03:07:53: Saving state to file /data/state.json
Zigbee2MQTT:info  2024-02-14 03:07:53: MQTT publish: topic 'zigbee2mqtt-upstairs/bridge/state', payload 'offline'
Zigbee2MQTT:info  2024-02-14 03:07:53: Disconnecting from MQTT server
Zigbee2MQTT:info  2024-02-14 03:07:53: Stopping zigbee-herdsman...
Zigbee2MQTT:error 2024-02-14 03:07:54: Failed to stop Zigbee2MQTT

@kerowog
Copy link

kerowog commented Feb 24, 2024

I also have problems after updating to 1.35.3-1
zigbemqtt addon keeps restarting.
The log ends with something like this and then restart:

/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264
var er = new ERR_STREAM_WRITE_AFTER_END();
^
Error: write after end
at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12)
at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21)
at DerivedLogger. [as debug] (/app/node_modules/winston/lib/winston/create-logger.js:81:14)
at Object.debug (/app/lib/util/logger.ts:193:12)
at MQTT.onMessage (/app/lib/mqtt.ts:140:20)
at MqttClient.emit (node:events:517:28)
at handlePublish (/app/node_modules/mqtt/src/lib/handlers/publish.ts:172:11)
at handle (/app/node_modules/mqtt/src/lib/handlers/index.ts:29:17)
at work (/app/node_modules/mqtt/src/lib/client.ts:726:17)
at Writable.writable._write (/app/node_modules/mqtt/src/lib/client.ts:750:4)

I had to restore the backup to version 1.32.2-1
I don't know if other versions above this one cause this error. I only tried 1.35.3-1.

It seems to me that the problem started when I wanted to add one of the IKEA TRADFRI bulb E27 WS globe 1055lm bulbs, but it may be a coincidence.

@Koenkk
Copy link
Owner

Koenkk commented Feb 25, 2024

@kerowog can you check what is the latest working version?

@djereg
Copy link

djereg commented Feb 25, 2024

I first noticed with version 1.35.3 that it restarted during an OTA update. Rolled back to 1.35.2 and the update has succeeded. It was a week ago.

I few days ago I tried to add a new end device and when the device tried to join the network the addon has restarted every time. Rolled back to 1.35.0 and now everything works well.

@kerowog
Copy link

kerowog commented Feb 25, 2024

I'll check it this week.
But my problem is more or less the same as @djereg . I was able to upgrade to 1.35.3, added some devices, made a backup in this state. I tried to do an OTA update and it caused reboots. Another time when I wanted to add a device that was not visible in the list of devices but was once on my network, it resulted in a lot of messages saying that the device had left the network. And then the restart loop. Returning to the backup made for 1.35.3 did not help. I had to find the version I wrote about earlier. Last time, even if I didn't change anything in the devices, the update itself caused restart loops.

@syntesys87
Copy link
Author

Seems the same problem I found in issue #21454

After that, I installed edge version (commit Feb 22): the device has paired, but I'm unable to end OTA update with BTicino devices and had restarts.

@kerowog
Copy link

kerowog commented Feb 27, 2024

@kerowog can you check what is the latest working version?

Unfortunately, apart from version 1.32.2, I only have a snapshot with version 1.34.0. I checked both.
I manage to go back to both versions. In both versions, IKEA bulbs are unsupported (TRADFRI bulb E27 WS globe 1055lm). I managed to determine that I need to remove these unsupported devices before upgrading to 1.35.3. Otherwise version 1.35.3 ends with a restart loop. I have 1.35.3 installed, but when I add missing devices that were previously on the network, I get an avalanche of messages that the device has left the network. Sometimes restarts start at this point and sometimes when I enable devices to be connected.
Additionally, I checked once and it seems to me that the problem also concerns adding an old device (supported for a long time) that was also once on the network.
I made many tests. I'm wondering whether to change the channel and add all the devices again because I have no idea how to add them now.

@adynis
Copy link

adynis commented Feb 28, 2024

It might be that what @kerowog wrote is related to the topic: #21118
In my last #21118 (comment) I had something very similar. In my tests after 1....10 trials it finally works ...

@djereg
Copy link

djereg commented Feb 29, 2024

Yes, my situation was the same with the device mentioned earlier. First I added it successfully in the room at my PC, but after when I tried to re join it on it's final place (in other room), Z2M started displaying a lot messages that the device has left the network and has stopped right after.

@kerowog
Copy link

kerowog commented Feb 29, 2024

I uninstalled the zigbe2mqtt add-on, deleted the config\zigbee2mqtt folder, even deleted the repository. I installed everything again, changed the channel and added all the devices. Everything was OK until two IKEA bulbs (connected to one power source) disconnected. I accidentally put them into pairing mode. Both bulbs disappeared from the list of devices in Z2M. So I turned them back on (2 at the same time) to pairing mode and allowed devices to connect. Then there were a lot of messages about disconnecting devices, but one of them managed to connect. Unfortunately, when I tried to add one that had not been added earlier, there were again messages about leaving the network, but this time the adapter restarted. Z2M also but it got stuck in restarts. I noticed that this one bulb is not on the list in Z2M, but it is in the config\zigbee2mqtt\configuration.yaml file. I don't know if I can remove it from it. I don't know if this is still a problem from this thread or if it relates to some other case.

@fnordpojk
Copy link

On 1.35.3, while my network works fine, OTA updates crash Z2M around the 40% mark, and OTA update state goes into eternal spinner mode requiring hand editing of state.json.

After upgrading to 1.36, this problem is now gone.

@aschmere
Copy link

aschmere commented Mar 8, 2024

On 1.35.3, while my network works fine, OTA updates crash Z2M around the 40% mark, and OTA update state goes into eternal spinner mode requiring hand editing of state.json.

After upgrading to 1.36, this problem is now gone.
If you refer to the "Adapter disconnected" issue, this problem at least for me remains with 1.36:

Zigbee2MQTT:error 2024-03-08 08:27:49: Adapter disconnected, stopping
Zigbee2MQTT:info 2024-03-08 08:27:49: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
Zigbee2MQTT:info 2024-03-08 08:27:49: Disconnecting from MQTT server
Zigbee2MQTT:info 2024-03-08 08:27:49: Stopping zigbee-herdsman...

I am running latest home assistant 2024.3 and Zigbee2Mqtt 1.36.0-1.

@ripnet
Copy link

ripnet commented Mar 16, 2024

Did anyone solve this? Upgrading to 1.36 did not work for me, nor did downgrading to 1.35.2.

@syntesys87
Copy link
Author

I had also this problem with 1.36.0

@aschmere
Copy link

I must admit, that suddenly the issue seems to have disappeared for me. Maybe just after a few updates (not even a Zigbee2Mqtt update) I have not experienced this issue anymore - so far at least.

@jaxuk
Copy link

jaxuk commented Mar 27, 2024

I am still having the same issue on 1.36.1

Zigbee2MQTT:info  2024-03-27 16:36:52: Started frontend on port 8099
Zigbee2MQTT:error 2024-03-27 16:36:52: Adapter disconnected, stopping
Zigbee2MQTT:debug 2024-03-27 16:36:52: Saving state to file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2024-03-27 16:36:52: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'offline'
Zigbee2MQTT:info  2024-03-27 16:36:52: Disconnecting from MQTT server
Zigbee2MQTT:info  2024-03-27 16:36:52: Stopping zigbee-herdsman...
Zigbee2MQTT:error 2024-03-27 16:36:52: Failed to stop Zigbee2MQTT

/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264
  var er = new ERR_STREAM_WRITE_AFTER_END();
           ^
Error: write after end
    at writeAfterEnd (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:264:12)
    at DerivedLogger.Writable.write (/app/node_modules/winston/node_modules/readable-stream/lib/_stream_writable.js:300:21)
    at DerivedLogger.<computed> [as error] (/app/node_modules/winston/lib/winston/create-logger.js:81:14)
    at Object.error (/app/lib/util/logger.ts:197:12)
    at Controller.callExtensions (/app/lib/controller.ts:340:24)
    at Controller.start (/app/lib/controller.ts:161:9)
    at start (/app/index.js:107:5)

Using the: usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff adapter

Issues started about 6 weeks ago, restarted worked for a while - but not anymore!

Going to try and downgrades, I have lots of backups of pervious versions.

@Koenkk
Copy link
Owner

Koenkk commented Mar 28, 2024

@jaxuk could you share your configuration.yaml?

@jaxuk
Copy link

jaxuk commented Apr 5, 2024

@jaxuk could you share your configuration.yaml?

Sure:

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:
  server: mqtt://core-mosquitto:1883
  user: user
  password: ###########
serial:
  port: >-
    /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_0B_00_00_93_00_00-if00-port0
external_converters: []
devices: devices.yaml
groups: groups.yaml
homeassistant: true
permit_join: false
advanced:
  log_level: warn
  pan_id: 6754
  channel: 11
  network_key:
    - 1
    - 3
    - 5
    - 7
    - 9
    - 11
    - 13
    - 15
    - 0
    - 2
    - 4
    - 6
    - 8
    - 10
    - 12
    - 13
  availability_blocklist: []
  availability_passlist: []
device_options: {}
blocklist: []
passlist: []
queue: {}
frontend:
  port: 8099
experimental: {}
zigbee_herdsman_debug: true

@jaxuk
Copy link

jaxuk commented Apr 5, 2024

downgrading made it a little less flaky, but didn't fix it. Currently running 1.36.1-1 again and the issue persists.

@DennisKuhn
Copy link

Hello,
I am getting the error with version 1.36.1-1 using the ZigStar LAN Gateway Zigbee. I have no problems with the Zigstar Stick v4. In both cases I used one device, a temperature, humdity, voc, Co2, Formaldehyd, PM2 sensor. The sensor does send quite a few updates. It lasts 30 - 45 seconds:

[19:54:12] INFO: Preparing to start...
[19:54:12] INFO: Socat not enabled
[19:54:14] INFO: Starting Zigbee2MQTT...
Zigbee2MQTT:error 2024-04-06 19:54:57: Adapter disconnected, stopping
Zigbee2MQTT:error 2024-04-06 19:54:57: Failed to stop Zigbee2MQTT

I am using the latest HA. My configuration is:

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: {}
serial:
  port: tcp://192.168.87.10:6638
advanced:
  log_level: debug

The Zigstar LAN Gateway is connected directly using an ethernet cable. A long ping did show some loss:

13777 packets transmitted, 13771 received, 0.0435508% packet loss, time 14104016ms
rtt min/avg/max/mdev = 0.252/0.324/0.793/0.051 ms

Is there anything I could try or change? Cheers :-)

@Koenkk
Copy link
Owner

Koenkk commented Apr 6, 2024

@jaxuk could you provide the herdsman debug logs? It looks that your network connection is not stable.

See this on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

@DennisKuhn
Copy link

DennisKuhn commented Apr 6, 2024

I get nothing more with the debug:

[20:38:30] INFO: Preparing to start...
[20:38:30] INFO: Socat not enabled
[20:38:32] INFO: Starting Zigbee2MQTT...
Zigbee2MQTT:info  2024-04-06 20:38:38: Logging to console and directory: '/config/zigbee2mqtt_lan/log/2024-04-06.20-38-38' filename: log.txt
Zigbee2MQTT:info  2024-04-06 20:38:38: Starting Zigbee2MQTT version 1.36.1 (commit #unknown)
Zigbee2MQTT:info  2024-04-06 20:38:38: Starting zigbee-herdsman (0.40.3)
Zigbee2MQTT:info  2024-04-06 20:38:40: zigbee-herdsman started (resumed)
Zigbee2MQTT:info  2024-04-06 20:38:40: Coordinator firmware version: '{"meta":{"maintrel":1,"majorrel":2,"minorrel":7,"product":1,"revision":20220219,"transportrev":2},"type":"zStack3x0"}'
Zigbee2MQTT:info  2024-04-06 20:38:40: Currently 1 devices are joined:
Zigbee2MQTT:info  2024-04-06 20:38:40: 0xa4c1380d5334d34d (0xa4c1380d5334d34d): TS0601_smart_air_house_keeper - TuYa Smart air house keeper (Router)
Zigbee2MQTT:info  2024-04-06 20:38:40: Zigbee: disabling joining new devices.
Zigbee2MQTT:info  2024-04-06 20:38:40: Connecting to MQTT server at mqtt://core-mosquitto:1883
Zigbee2MQTT:info  2024-04-06 20:38:40: Connected to MQTT server
Zigbee2MQTT:info  2024-04-06 20:38:40: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"online"}'
Zigbee2MQTT:info  2024-04-06 20:38:40: Started frontend on port 8099
Zigbee2MQTT:info  2024-04-06 20:38:40: MQTT publish: topic 
<Lots of bridge stuff ...>
Zigbee2MQTT:info  2024-04-06 20:38:40: MQTT publish: topic 
<Sensor description ...>
Zigbee2MQTT:info  2024-04-06 20:38:40: MQTT publish: topic 'zigbee2mqtt/0xa4c1380d5334d34d', payload '{"co2":362,"formaldehyd":3,"humidity":75.7,"linkquality":174,"pm25":4,"temperature":22.1,"voc":20}'
Zigbee2MQTT:info  2024-04-06 20:38:40: Zigbee2MQTT started!
Zigbee2MQTT:info  2024-04-06 20:38:40: MQTT publish: topic 'zigbee2mqtt/0xa4c1380d5334d34d', payload '{"co2":362,"formaldehyd":3,"humidity":75.7,"linkquality":174,"pm25":6,"temperature":22.1,"voc":20}'
...
Zigbee2MQTT:info  2024-04-06 20:38:58: MQTT publish: topic 'zigbee2mqtt/0xa4c1380d5334d34d', payload '{"co2":362,"formaldehyd":5,"humidity":74.1,"linkquality":171,"pm25":6,"temperature":21.9,"voc":16}'
Zigbee2MQTT:error 2024-04-06 20:39:13: Adapter disconnected, stopping
Zigbee2MQTT:info  2024-04-06 20:39:13: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
Zigbee2MQTT:info  2024-04-06 20:39:13: Disconnecting from MQTT server
Zigbee2MQTT:info  2024-04-06 20:39:13: Stopping zigbee-herdsman...
Zigbee2MQTT:error 2024-04-06 20:39:13: Failed to stop Zigbee2MQTT

I am a bit confused about the timestamps though, there seems to be a big gap between the last sensor reading and the shutdown. It doesn't stop if I connect no devices.

@jaxuk
Copy link

jaxuk commented Apr 6, 2024

@Koenkk here you are, I get different errors in the logs...

From one boot:

[09:43:10] INFO: Preparing to start...
[09:43:11] INFO: Socat not enabled
[09:43:11] INFO: Zigbee Herdsman debug logging enabled
[09:43:13] INFO: Starting Zigbee2MQTT...
Zigbee2MQTT:debug 2024-04-06 09:43:19: Loaded state from file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2024-04-06 09:43:19: Logging to console and directory: '/config/zigbee2mqtt/log/2024-04-06.09-43-19' filename: log.txt
Zigbee2MQTT:debug 2024-04-06 09:43:19: Removing old log directory '/config/zigbee2mqtt/log/2024-04-06.09-40-00'
Zigbee2MQTT:info  2024-04-06 09:43:19: Starting Zigbee2MQTT version 1.36.1 (commit #unknown)
Zigbee2MQTT:info  2024-04-06 09:43:19: Starting zigbee-herdsman (0.40.3)
Zigbee2MQTT:debug 2024-04-06 09:43:19: Using zigbee-herdsman with settings: '{"adapter":{"concurrent":null,"delay":null,"disableLED":false},"backupPath":"/config/zigbee2mqtt/coordinator_backup.json","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","databasePath":"/config/zigbee2mqtt/database.db","network":{"channelList":[11],"extendedPanID":[221,221,221,221,221,221,221,221],"networkKey":"HIDDEN","panID":6754},"serialPort":{"path":"/dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_23_93_30_D5-if00-port0"}}'
2024-04-06T08:43:20.363Z zigbee-herdsman:adapter:zStack:znp:error Failed to determine if path is valid: 'Error: ENOENT: no such file or directory, lstat '/dev/serial''
2024-04-06T08:43:20.380Z zigbee-herdsman:adapter Failed to validate path: 'Error: spawn udevadm ENOENT'
2024-04-06T08:43:20.383Z 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/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_23_93_30_D5-if00-port0"},"databasePath":"/config/zigbee2mqtt/database.db","databaseBackupPath":"/config/zigbee2mqtt/database.db.backup","backupPath":"/config/zigbee2mqtt/coordinator_backup.json","adapter":{"disableLED":false,"concurrent":null,"delay":null}}'
2024-04-06T08:43:20.385Z zigbee-herdsman:adapter:zStack:znp:log Opening SerialPort with {"path":"/dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_23_93_30_D5-if00-port0","baudRate":115200,"rtscts":false,"autoOpen":false}
Zigbee2MQTT:error 2024-04-06 09:43:20: Error while starting zigbee-herdsman
Zigbee2MQTT:error 2024-04-06 09:43:20: Failed to start zigbee
Zigbee2MQTT:error 2024-04-06 09:43:20: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
Zigbee2MQTT:error 2024-04-06 09:43:20: Exiting...
Zigbee2MQTT:error 2024-04-06 09:43:20: Error: Error: No such file or directory, cannot open /dev/serial/by-id/usb-Silicon_Labs_slae.sh_cc2652rb_stick_-_slaesh_s_iot_stuff_00_12_4B_00_23_93_30_D5-if00-port0

End of next boot attempt:

2024-04-06T08:41:41.883Z zigbee-herdsman:adapter:zStack:znp:log Port closed
2024-04-06T08:41:41.884Z zigbee-herdsman:controller:log Adapter disconnected'
2024-04-06T08:41:41.885Z zigbee-herdsman:adapter:zStack:znp:log closing
Zigbee2MQTT:error 2024-04-06 09:41:41: Adapter disconnected, stopping
Zigbee2MQTT:debug 2024-04-06 09:41:41: Saving state to file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2024-04-06 09:41:41: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'offline'
Zigbee2MQTT:info  2024-04-06 09:41:41: Disconnecting from MQTT server
Zigbee2MQTT:info  2024-04-06 09:41:41: Stopping zigbee-herdsman...
2024-04-06T08:41:41.907Z zigbee-herdsman:controller:database:log Writing database to '/config/zigbee2mqtt/database.db'
2024-04-06T08:41:41.928Z zigbee-herdsman:controller:log Disable joining
2024-04-06T08:41:41.931Z zigbee-herdsman:controller:error Failed to disable join on stop: Error: Cannot request when znp has not been initialized yet
2024-04-06T08:41:41.933Z zigbee-herdsman:controller:database:log Writing database to '/config/zigbee2mqtt/database.db'
2024-04-06T08:41:41.946Z zigbee-herdsman:controller:log Creating coordinator backup
2024-04-06T08:41:41.948Z zigbee-herdsman:adapter:zStack:startup:backup creating backup
Zigbee2MQTT:error 2024-04-06 09:41:41: Failed to stop Zigbee2MQTT

@jaxuk
Copy link

jaxuk commented Apr 6, 2024

end of another boot attempt:

Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device 'door bell' was last seen '1360.52' hours ago.
2024-04-06T08:49:36.590Z zigbee-herdsman:adapter:zStack:znp:log Port closed
2024-04-06T08:49:36.591Z zigbee-herdsman:controller:log Adapter disconnected'
2024-04-06T08:49:36.592Z zigbee-herdsman:adapter:zStack:znp:log closing
2024-04-06T08:49:36.614Z zigbee-herdsman:controller:database:log Writing database to '/config/zigbee2mqtt/database.db'
2024-04-06T08:49:36.630Z zigbee-herdsman:controller:log Disable joining
2024-04-06T08:49:36.633Z zigbee-herdsman:controller:error Failed to disable join on stop: Error: Cannot request when znp has not been initialized yet
2024-04-06T08:49:36.634Z zigbee-herdsman:controller:database:log Writing database to '/config/zigbee2mqtt/database.db'
2024-04-06T08:49:36.665Z zigbee-herdsman:controller:log Creating coordinator backup
2024-04-06T08:49:36.670Z zigbee-herdsman:adapter:zStack:startup:backup creating backup
Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device 'Temp and Humidity - Beatrix Room' was last seen '1360.16' hours ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device 'kitchen sensor' was last seen '1360.03' hours ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device 'Office Sensor' was last seen '1359.96' hours ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Active device 'Garden lights' was last seen '12446.01' minutes ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device 'Water sensor garage' was last seen '1360.66' hours ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Active device 'Air Purifier' was last seen '5281.39' minutes ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Active device 'Solar PV' was last seen '6636.71' minutes ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Active device 'office climate sensor' was last seen '5278.80' minutes ago.
Zigbee2MQTT:debug 2024-04-06 09:49:36: Passive device '4 gang switch - office' was last seen '209.21' hours ago.
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/4 gang switch - Living room', payload '{"action":null,"battery":69,"linkquality":9,"voltage":2800}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temp and Humidity - Living room', payload '{"battery":70,"humidity":70.5,"linkquality":141,"power_outage_count":288,"temperature":18.89,"voltage":2955}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/4 gang switch - kitchen', payload '{"action":null,"battery":69,"linkquality":60,"voltage":2800}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temp and Humidity - Master Bedroom', payload '{"battery":50,"humidity":70.79,"linkquality":36,"power_outage_count":29743,"temperature":22.34,"voltage":2925}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temp and Humidity - Sonny's room', payload '{"battery":83,"humidity":60.48,"linkquality":45,"power_outage_count":25677,"temperature":25.51,"voltage":2975}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Garage door sensor', payload '{"battery":100,"battery_low":false,"contact":true,"linkquality":129,"tamper":false}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Garage motion', payload '{"battery":100,"battery_low":false,"linkquality":9,"occupancy":false,"tamper":false,"voltage":3000}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/4 gang switch upstairs', payload '{"action":null,"battery":100,"linkquality":12,"voltage":3000}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temp and Humidity - Garage', payload '{"battery":61,"humidity":60.41,"linkquality":60,"temperature":21.29,"voltage":2800}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temperature and Humidity- Dinning room', payload '{"battery":48,"humidity":62.33,"linkquality":60,"temperature":18.67,"voltage":2700}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/door bell', payload '{"action":null,"battery":100,"click":null,"linkquality":57,"power_outage_count":29,"voltage":3012}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Temp and Humidity - Beatrix Room', payload '{"battery":52,"humidity":63.52,"linkquality":48,"temperature":18.47,"voltage":2700}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/kitchen sensor', payload '{"battery":100,"device_temperature":26,"illuminance":15,"illuminance_lux":15,"linkquality":48,"occupancy":false,"power_outage_count":31,"voltage":3005}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Office Sensor', payload '{"battery":100,"device_temperature":28,"illuminance":96,"illuminance_lux":96,"linkquality":48,"occupancy":true,"power_outage_count":26,"temperature":26,"voltage":3005}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Garden lights', payload '{"linkquality":72,"power_on_behavior":null,"state":"ON"}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Water sensor garage', payload '{"battery":100,"battery_low":false,"device_temperature":21,"linkquality":42,"power_outage_count":5,"tamper":false,"trigger_count":null,"voltage":3005,"water_leak":false}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Air Purifier', payload '{"air_quality":"good","child_lock":"LOCK","fan_mode":"auto","fan_speed":1,"fan_state":"ON","filter_age":158627,"led_enable":true,"linkquality":57,"pm25":16,"replace_filter":false,"update":{"installed_version":69633,"latest_version":69633,"state":"idle"},"update_available":false}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/Solar PV', payload '{"current":0.32,"energy":1612.17,"linkquality":15,"power":75.6,"state":"ON","voltage":240.6}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/office climate sensor', payload '{"humidity":66,"linkquality":15,"pm25":4,"temperature":20,"update":{"installed_version":16777233,"latest_version":16777233,"state":"idle"},"update_available":false,"voc_index":32}'
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/4 gang switch - office', payload '{"action":null,"battery":100,"linkquality":9,"voltage":3000}'
Zigbee2MQTT:info  2024-04-06 09:49:36: Zigbee2MQTT started!
Zigbee2MQTT:error 2024-04-06 09:49:36: Adapter disconnected, stopping
Zigbee2MQTT:debug 2024-04-06 09:49:36: Saving state to file /config/zigbee2mqtt/state.json
Zigbee2MQTT:info  2024-04-06 09:49:36: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'offline'
Zigbee2MQTT:info  2024-04-06 09:49:36: Disconnecting from MQTT server
Zigbee2MQTT:info  2024-04-06 09:49:36: Stopping zigbee-herdsman...
Zigbee2MQTT:error 2024-04-06 09:49:36: Failed to stop Zigbee2MQTT

@jaxuk
Copy link

jaxuk commented Apr 6, 2024

I have now reflashed the usb stick which didn't seem to help. I am going to try a different zigbee stick and see if it starts with that.

@jaxuk
Copy link

jaxuk commented Apr 7, 2024

OK just got a new psy for the PI, the official one, and everything seems to be stable. the last psu was an Ankar one of the same output, but perhaps it has burnt out or maybe it just didn't do what it said on the tin. For anyone else with the same issue, if your zigbee adapter has lights on it and the flash off and them back on while zigbee2mqtt is starting, then you are probably losing power to the usb port.

I don't know if it's a psu issue, or perhaps changes in the software that pushes the hardware harder and increases usb power demand. but the new pus has solved the issue. Will report back on stability.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
ezsp Issues related to deprecated ezsp driver problem Something isn't working
Projects
None yet
Development

No branches or pull requests