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

Many devices don't work anymore after updating to v.1.39.0-1. Some fatal errors. #23302

Open
Krzysztonek opened this issue Jul 8, 2024 · 21 comments
Labels
problem Something isn't working

Comments

@Krzysztonek
Copy link

Krzysztonek commented Jul 8, 2024

What happened?

Some devices disappear or they are being disconnected from the network randomly for a long time. Then only part of them appears back again.
One of the most problematic devices are the roller drivers AM43-0.45_40-ES-EB, which are out of the network since last update. After repairing they remain in the zigbee network for a while, then become randomly disconnected.

What did you expect to happen?

No response

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.39.0-1

Adapter firmware version

7.4.2

Adapter

SkyConnect

Setup

x86

Debug log

[00:19:29] INFO: Preparing to start...
[00:19:30] INFO: Socat not enabled
[00:19:30] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-07-09 00:19:34] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-07-09 00:19:34] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-07-09 00:19:34] error: 	zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-07-09 00:19:35] warning: 	zh:ember: [EzspConfigId] Failed to SET "ADDRESS_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:19:35] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:19:35] warning: 	zh:ember: [EzspConfigId] Failed to SET "NEIGHBOR_TABLE_SIZE" TO "26" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:19:35] warning: 	zh:ember: [EzspConfigId] Failed to SET "SOURCE_ROUTE_TABLE_SIZE" TO "200" with status=ERROR_INVALID_VALUE. Firmware value will be used instead.
[2024-07-09 00:19:35] warning: 	zh:ember: [EzspConfigId] Failed to SET "MULTICAST_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:20:07] warning: 	z2m: Failed to ping 'Roleta Iga Okno D' (attempt 1/1, ZCL command 0x048727fffe557123/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":113}))
[2024-07-09 00:20:15] warning: 	z2m: Failed to ping 'Roleta Sypialnia Okno L' (attempt 1/1, ZCL command 0x3410f4fffee3b19f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":115}))
[2024-07-09 00:20:24] error: 	z2m: Failed to configure 'Energia AC Gab_Iga', attempt 1 (Error: ZCL command 0xa4c138bcff9500c7/1 genBasic.read(["manufacturerName","zclVersion","appVersion","modelId","powerSource",65534], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":118})
    at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:96:31)
    at EmberAdapter.onMessageSent (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:607:34)
    at Ezsp.emit (node:events:517:28)
    at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:3953:14)
    at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:792:18)
    at Ezsp.tick (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:446:22)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7))
[2024-07-09 00:15:08] warning: 	z2m: Failed to ping 'Roleta Salon Okno PL' (attempt 1/1, ZCL command 0xcc86ecfffeb010ff/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":255}))
[2024-07-09 00:15:45] warning: 	z2m: Failed to ping 'Roleta Salon Okno LP' (attempt 1/1, ZCL command 0xcc86ecfffea1f7ca/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":31}))
[2024-07-09 00:15:52] warning: 	z2m: Failed to ping 'Roleta Salon Okno LL' (attempt 1/1, ZCL command 0x3410f4fffee9ef9f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":41}))

And here is the most frequently repeatable list of errors:

[00:51:56] INFO: Preparing to start...
[00:51:56] INFO: Socat not enabled
[00:51:57] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-07-09 00:52:01] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-07-09 00:52:01] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-07-09 00:52:01] error: 	zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-07-09 00:52:02] warning: 	zh:ember: [EzspConfigId] Failed to SET "ADDRESS_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:52:02] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:52:02] warning: 	zh:ember: [EzspConfigId] Failed to SET "NEIGHBOR_TABLE_SIZE" TO "26" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-09 00:52:02] warning: 	zh:ember: [EzspConfigId] Failed to SET "SOURCE_ROUTE_TABLE_SIZE" TO "200" with status=ERROR_INVALID_VALUE. Firmware value will be used instead.
[2024-07-09 00:52:02] warning: 	zh:ember: [EzspConfigId] Failed to SET "MULTICAST_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.

Here is my config:

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: zigbee
  password: zigbee
serial:
  port: >-
    /dev/serial/by-id/usb-Nabu_Casa_SkyConnect_v1.0_30c07efc368xxxxxxxxxxxxxxxxxx-if00-port0
  adapter: ember
  rtscts: true
homeassistant: true
advanced:
  homeassistant_legacy_entity_attributes: false
  legacy_api: false
  legacy_availability_payload: false
  channel: 25
  last_seen: ISO_8601_local
frontend:
  port: 8099
device_options:
  legacy: true
availability: true
@Krzysztonek Krzysztonek added the problem Something isn't working label Jul 8, 2024
@Krzysztonek Krzysztonek changed the title Many devices don't work anymore after updating to v.1.39.0-1. Too many fatal errors. Many devices don't work anymore after updating to v.1.39.0-1. Some fatal errors. Jul 9, 2024
@Nerivec
Copy link
Collaborator

Nerivec commented Jul 9, 2024

Those fatal errors happen during the startup sequence but there is a retry mechanism in place to bypass them (due to hardware flow control issues, Silabs is aware). In short, it's a problem, but it's bypassed for now, and doesn't prevent Z2M from starting; it should not be related to your troubles here.

Seems devices are failing to ping though. Any chance you have a fuller debug log file I can take a look at?

Did you try clearing the NVM3 on your adapter (backup/clear/restore)? Seems some configs are failing to set that really shouldn't, could be the adapter is having some troubles.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 9, 2024

Did you try clearing the NVM3 on your adapter (backup/clear/restore)?

No, I'm not aware of any method clearing the NVM on my SkyConnect adapter.
Would you please give me any hints? guidance? commands? procedures?

I rebooted my HA server several times. Unfortunately, it doesn't help/change/repair anything. Still the same set of error messages appears:

[00:47:00] INFO: Preparing to start...
[00:47:00] INFO: Socat not enabled
[00:47:00] INFO: Enabled Zigbee2MQTT watchdog with value 'default'
[00:47:01] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT with watchdog (60000,300000,900000,1800000,3600000).
[2024-07-10 00:47:04] warning: 	zh:ember: [EzspConfigId] Failed to SET "ADDRESS_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-10 00:47:05] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-10 00:47:05] warning: 	zh:ember: [EzspConfigId] Failed to SET "NEIGHBOR_TABLE_SIZE" TO "26" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-10 00:47:05] warning: 	zh:ember: [EzspConfigId] Failed to SET "SOURCE_ROUTE_TABLE_SIZE" TO "200" with status=ERROR_INVALID_VALUE. Firmware value will be used instead.
[2024-07-10 00:47:05] warning: 	zh:ember: [EzspConfigId] Failed to SET "MULTICAST_TABLE_SIZE" TO "16" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-10 00:47:40] warning: 	z2m: Failed to ping 'Energia AC Gab_Iga' (attempt 1/1, ZCL command 0xa4c138bcff9500c7/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":247}))
[2024-07-10 00:47:47] error: 	z2m: Publish 'set' 'state' to 'Gniazdo Iga' failed: 'Error: ZCL command 0x540f57fffe78b292/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":251})'
[2024-07-10 00:47:52] warning: 	z2m: Failed to ping 'Oświetlenie Łazienka Sufit' (attempt 1/1, ZCL command 0xa4c13802912ea5f0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":252}))
[2024-07-10 00:47:58] warning: 	z2m: Failed to ping 'Gniazdo Salon Kominek' (attempt 1/1, ZCL command 0xa4c138726c8fed7f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":2}))
[2024-07-10 00:48:05] error: 	z2m: Publish 'set' 'state' to 'Gniazdo Koc Krzyś' failed: 'Error: ZCL command 0xa4c138b489a67b2c/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":3})'
[2024-07-10 00:48:10] error: 	z2m: Publish 'set' 'state' to 'Gniazdo Koc Aga' failed: 'Error: ZCL command 0xa4c1386b6e9c24f1/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":4})'
[2024-07-10 00:48:15] warning: 	z2m: Failed to ping 'Roleta Gabinet Okno D' (attempt 1/1, ZCL command 0x2c1165fffeea778c/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":5}))
[2024-07-10 00:48:37] warning: 	z2m: Failed to ping 'Roleta Iga Okno D' (attempt 1/1, ZCL command 0x048727fffe557123/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":33}))
[2024-07-10 00:48:43] error: 	z2m: Publish 'set' 'state' to 'Zawór Gazowy' failed: 'Error: ZCL command 0xa4c138648462125a/1 genOnOff.off({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":36})'
[2024-07-10 00:49:00] warning: 	z2m: Failed to ping 'Oświetlenie Kuchnia' (attempt 1/1, ZCL command 0xa4c138247b91408c/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":63}))
[2024-07-10 00:49:07] warning: 	z2m: Failed to ping 'Oświetlenie Iga Sufit' (attempt 1/1, ZCL command 0xa4c138afaa2eefa0/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":66}))
[2024-07-10 00:49:14] warning: 	z2m: Failed to ping 'Oświetlenie Gabinet Sufit' (attempt 1/1, ZCL command 0xa4c13851a4420b95/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":68}))
[2024-07-10 00:49:21] warning: 	z2m: Failed to ping 'Oświetlenie Jadalnia' (attempt 1/1, ZCL command 0xa4c138e2b911d4a8/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":73}))
[2024-07-10 00:49:30] warning: 	z2m: Failed to ping 'Gniazdo Koc Aga' (attempt 1/1, ZCL command 0xa4c1386b6e9c24f1/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":89}))
[2024-07-10 00:49:38] error: 	z2m: Failed to read state of 'Oświetlenie Gabinet Sufit' after reconnect (ZCL command 0xa4c13851a4420b95/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":103}))
[2024-07-10 00:49:42] warning: 	z2m: Failed to ping 'Roleta Salon Okno PP' (attempt 1/1, ZCL command 0x048727fffe4eaafa/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":104}))
[2024-07-10 00:49:52] error: 	z2m: Failed to read state of 'Oświetlenie Iga Sufit' after reconnect (ZCL command 0xa4c138afaa2eefa0/1 genOnOff.read(["onOff"], {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":6,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":110}))
[2024-07-10 00:49:53] error: 	zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":6,"sourceEndpoint":0,"destinationEndpoint":0,"options":256,"groupId":0,"sequence":150} messageTag=255]
[2024-07-10 00:49:57] warning: 	z2m: Failed to ping 'Roleta Salon Okno PL' (attempt 1/1, ZCL command 0xcc86ecfffeb010ff/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":114}))
[2024-07-10 00:50:07] warning: 	z2m: Failed to ping 'Roleta Salon Okno LP' (attempt 1/1, ZCL command 0xcc86ecfffea1f7ca/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":125}))
[2024-07-10 00:50:14] warning: 	z2m: Failed to ping 'Roleta Salon Okno LL' (attempt 1/1, ZCL command 0x3410f4fffee9ef9f/1 genBasic.read(["zclVersion"], {"timeout":10000,"disableResponse":false,"disableRecovery":true,"disableDefaultResponse":true,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (Delivery failed for {"profileId":260,"clusterId":0,"sourceEndpoint":1,"destinationEndpoint":1,"options":4160,"groupId":0,"sequence":130}))

I'm even not able to get into UI:
obraz

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 9, 2024

The failed pings on startup are likely preventing the frontend from showing up in a timely manner. Current dev/edge has some improvements in that domain.

For the NVM3, you can try using the new ember-zli: https://github.com/Nerivec/ember-zli (check the Wiki)
or universal-silabs-flasher + bellows: procedure details
The overall process is the same in both: backup, clear the NVM3, restore.
Note: the backup/restore process is the same executed when you stop/start Z2M (when applicable).

You can DM me from zigbee2mqtt server on Discord if needed.

@Krzysztonek
Copy link
Author

I tried to do backup of my skyconnect configuration following the linked procedure.
When executing the following command:

➜  ~ bellows -d /dev/ttyUSB0 -b 115200 backup | tee bellow.backup.json 

I got the following log:

Traceback (most recent call last):
  File "/usr/bin/bellows", line 8, in <module>
    sys.exit(main())
             ^^^^^^
  File "/usr/lib/python3.12/site-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
         ^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bellows/cli/util.py", line 39, in inner
    loop.run_until_complete(f(*args, **kwargs))
  File "/usr/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bellows/cli/backup.py", line 80, in backup
    await _backup(ezsp)
  File "/usr/lib/python3.12/site-packages/bellows/cli/backup.py", line 114, in _backup
    (status, key) = await ezsp.getKey(key_type)
                          ^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bellows/ezsp/__init__.py", line 300, in __getattr__
    return getattr(self._protocol, name)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/bellows/ezsp/protocol.py", line 148, in __getattr__
    raise AttributeError(f"{name} not found in COMMANDS")
AttributeError: getKey not found in COMMANDS

So, I've followed again this video to upgrade my SkyConnect dongle to 7.4.3.0 from this repo.

And I failed again:

[14:37:59] INFO: Preparing to start...
[14:37:59] INFO: Socat not enabled
[14:37:59] INFO: Enabled Zigbee2MQTT watchdog with value 'default'
[14:38:00] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT with watchdog (60000,300000,900000,1800000,3600000).
[2024-07-13 14:38:04] error: 	zh:ember:uart:ash: Received ERROR from NCP while connecting, with code=RESET_WATCHDOG.
[2024-07-13 14:38:04] error: 	zh:ember:uart:ash: ASH disconnected | NCP status: ASH_NCP_FATAL_ERROR
[2024-07-13 14:38:04] error: 	zh:ember:uart:ash: Error while parsing received frame, status=ASH_NCP_FATAL_ERROR.
[2024-07-13 14:38:06] warning: 	zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e]
[2024-07-13 14:38:06] error: 	zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE.
[2024-07-13 14:38:06] error: 	zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR
[2024-07-13 14:38:06] error: 	zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR.
[2024-07-13 14:38:06] error: 	zh:ember: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!!
[2024-07-13 14:38:06] error: 	zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR.
[2024-07-13 14:38:08] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.
[2024-07-13 14:40:34] warning: 	zh:ember:uart:ash: Frame(s) in progress cancelled in [1ac1020b0a527e]
[2024-07-13 14:40:34] error: 	zh:ember:uart:ash: Received unexpected reset from NCP, with reason=RESET_SOFTWARE.
[2024-07-13 14:40:34] error: 	zh:ember:uart:ash: ASH disconnected: ASH_ERROR_NCP_RESET | NCP status: ASH_NCP_FATAL_ERROR
[2024-07-13 14:40:34] error: 	zh:ember:uart:ash: Error while parsing received frame, status=HOST_FATAL_ERROR.
[2024-07-13 14:40:34] error: 	zh:ember: !!! NCP FATAL ERROR reason=HOST_FATAL_ERROR. ATTEMPTING RESET... !!!
[2024-07-13 14:40:39] warning: 	zh:ember: [EzspConfigId] Failed to SET "APS_UNICAST_MESSAGE_COUNT" TO "32" with status=ERROR_OUT_OF_MEMORY. Firmware value will be used instead.

I'm stuck again, really don't understand what is going wrong in there.

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 13, 2024

Try this:

Since you have a proper coordinator backup created by Z2M, it should detect that the adapter was reset, and reform the network using that backup. If all goes well, this should clear the NVM3 and restore your backup from Z2M.
Note that step 2 is important, as the process described here relies on that backup file to be correct, if not you may end up having to re-pair all devices.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 14, 2024

Yesterday I did the backup:

{
  "metadata": {
    "format": "zigpy/open-coordinator-backup",
    "version": 1,
    "source": "zigbee-herdsman@0.50.1",
    "internal": {
      "date": "2024-07-13T11:00:21.474Z",
      "ezspVersion": 13
    }
  },
  "stack_specific": {
    "ezsp": {
      "hashed_tclk": "7c257da8ae16c70d6ffececad90cfaf8"
    }
  },
...

I already updated my SkyConnect dongle firmware to EMBER. So, my first concern is, why is this dongle still visible as ezsp, not as ember.

Today I launched ember-zli bootloader command and got the following:

[2024-07-14 11:05:21.861] info:         cli: Data folder: C:\Users\Krzysztof\ember-zli.
? Adapter connection type Serial
? Adapter firmware baudrate 115200
? Serial port Silicon Labs Silicon Labs CP210x USB to UART Bridge (COM4)
USB\VID_10C4&PID_EA60\30C07EFC368DEC119AFC69E883C5466D (COM4)
? Flow control Software Flow Control (rtscts=false)
? Adapter model Home Assistant SkyConnect
[2024-07-14 11:05:21.499] info:         gecko: Connecting to bootloader...
[2024-07-14 11:05:21.573] info:         gecko: Serial port opened
[2024-07-14 11:05:21.585] info:         gecko: Closing serial connection...
[2024-07-14 11:05:21.588] info:         gecko: Port closed.
[2024-07-14 11:05:21.589] info:         gecko: Unable to enter bootloader.
[2024-07-14 11:05:21.591] info:         zh:ember:ezsp: ======== EZSP starting ========
[2024-07-14 11:05:21.592] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-14 11:05:21.593] info:         zh:ember:uart:ash: RTS/CTS config is off, enabling software flow control.
[2024-07-14 11:05:21.604] info:         zh:ember:uart:ash: Serial port opened
[2024-07-14 11:05:21.605] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-14 11:05:21.134] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-14 11:05:21.135] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-14 11:05:21.138] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-14 11:05:21.644] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-14 11:05:21.645] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-14 11:05:21.647] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-14 11:05:21.166] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-14 11:05:21.167] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-14 11:05:21.170] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-14 11:05:21.779] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-14 11:05:21.780] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-14 11:05:21.782] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-14 11:05:21.290] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
    Error: Failed to start EZSP layer with status=33.

Still EZSP, not EMBER.. Is that OK?

Then I tried to run Clear NVM3, getting this:

? Menu Clear NVM3
? Confirm NVM3 clearing? (Cannot be undone.) yes
[2024-07-14 11:34:42.456] error:        gecko: Firmware upload aborted.

In the next step I executed:

? Menu Get info
[2024-07-14 11:34:42.492] info:         gecko: Gecko Bootloader v2.01.01.
? Menu Update firmware
? Firmware Source Use pre-defined firmware (recommended or latest based on your adapter)
? Firmware version Latest (7.4.3.0)
[2024-07-14 11:34:42.985] info:         gecko: Firmware file metadata: SDK version: 4.4.3, EZSP version: 7.4.3.0, baudrate: 115200, type: ncp-uart-hw
? Version: 7.4.3.0, Baudrate: 115200. Proceed with this firmware? yes
[2024-07-14 11:34:42.126] info:         gecko: Firmware upload completed.
? Menu Clear NVM3
? Confirm NVM3 clearing? (Cannot be undone.) yes
[2024-07-14 11:34:42.455] error:        gecko: Firmware upload aborted.
? Menu Exit bootloader
[2024-07-14 11:34:42.606] info:         gecko: Closing serial connection...
[2024-07-14 11:34:42.608] info:         gecko: Port closed.

At the end I connected my dongle back to HA server and started Z2M again with the following result:

[11:49:39] INFO: Preparing to start...
[11:49:39] INFO: Socat not enabled
[11:49:40] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-07-14 11:49:55] error: 	z2m: Error while starting zigbee-herdsman
[2024-07-14 11:49:55] error: 	z2m: Failed to start zigbee
[2024-07-14 11:49:55] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-07-14 11:49:55] error: 	z2m: Exiting...
[2024-07-14 11:49:55] error: 	z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR.
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:889:19)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2722:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:129:29)
    at Zigbee.start (/app/lib/zigbee.ts:63:27)
    at Controller.start (/app/lib/controller.ts:139:27)
    at start (/app/index.js:154:5)
[11:50:26] INFO: Preparing to start...
[11:50:26] INFO: Socat not enabled
[11:50:27] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-07-14 11:50:42] error: 	z2m: Error while starting zigbee-herdsman
[2024-07-14 11:50:42] error: 	z2m: Failed to start zigbee
[2024-07-14 11:50:42] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-07-14 11:50:42] error: 	z2m: Exiting...
[2024-07-14 11:50:42] error: 	z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR.
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:889:19)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2722:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:129:29)
    at Zigbee.start (/app/lib/zigbee.ts:63:27)
    at Controller.start (/app/lib/controller.ts:139:27)
    at start (/app/index.js:154:5)

Looks, I've not been succeeded :/

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 14, 2024

EZSP is the name of the "middle-man" in the EmberZNet stack (EmberZNet Serial Protocol = EZSP) so it's still there in some names, just the Z2M driver itself is named ember, as opposed to the old driver, named ezsp.
Your backup appears correct, and according to your logs, you are using the ember driver properly.

Can you go into the data folder for ember-zli and retrieve the log file with the failed NVM3 clearing?
Also, can you enable debug log for your next Z2M logs, so I can see where the error is exactly.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 14, 2024

Here is my ember-zli data folder content:
logs.zip

And this is my Z2M log folder content:
z2m_log.zip

I'm not able to start Z2M at all, therefore I can't get into UI to enable debug log for my next Z2M logs.

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 17, 2024

Alright, let's try another method:

Same as before, make sure your coordinator_backup.json from Z2M is proper so it will restore when you start it again.

PS: you can enable debug in logs from the configuration.yaml file directly.

advanced:
  log_level: debug

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 17, 2024

I launched ember-zli stack command with the SkyConnect dongle plugged into my PC USB port, getting this:

[2024-07-17 20:21:31.136] info:         cli: Data folder: C:\Users\Krzysztof\ember-zli.
? Path: COM4, Baudrate: 115200, RTS/CTS: true. Use this config? yes
[2024-07-17 20:21:31.638] info:         zh:ember:ezsp: ======== EZSP starting ========
[2024-07-17 20:21:31.639] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-17 20:21:31.651] info:         zh:ember:uart:ash: Serial port opened
[2024-07-17 20:21:31.655] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-17 20:21:31.194] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-17 20:21:31.195] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-17 20:21:31.197] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-17 20:21:31.731] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-17 20:21:31.732] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-17 20:21:31.738] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-17 20:21:31.261] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-17 20:21:31.262] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-17 20:21:31.265] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-17 20:21:31.802] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
[2024-07-17 20:21:31.803] info:         zh:ember:uart:ash: ======== ASH Adapter reset ========
[2024-07-17 20:21:31.806] info:         zh:ember:uart:ash: ======== ASH starting ========
[2024-07-17 20:21:31.343] error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
    Error: Failed to start EZSP layer with status=33.

Since some errors appeared, I launched the below set of commands: first ember-zli bootloader and then ember-zli stack:

obraz

As you can see, during first atempt the Clear NVM3 command failed with errors. During second atempt I was not able even to launch this command due to Error: Failed to start EZSP layer with status=33. appearance, which finally stopped the whole process.

I don't understand what is wrong with this damn adapter. The only I can say, seems it's not damaged.

I would also bring your attention to one more point (please, see the below screen with Update Firmware Menu):
obraz

From what I see, the recommended version of the firmware is 7.4.1.0 while I already updated the adapter to version 7.4.3.0. As per your advise I didn't downgrade it to recommended, still keeping the latest 7.4.3.0.

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 17, 2024

Since you flashed latest before, make sure you use these settings: port: COM4, baudrate: 115200, rtscts: false.
In the first screenshot, did you unplug the adapter before launching ember-zli stack again? It's likely stuck in bootloader since you Force close (instead of Exit bootloader).
Unplug the adapter for a few seconds, then try using ember-zli stack directly after re-plugging it.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 18, 2024

I did exactly what you've suggested:

Launch ember-zli stack command with the adapter plugged into the machine
Answer the prompt's questions
Go to Reset NVM3 tokens menu https://github.com/Nerivec/ember-zli/wiki/Stack#reset-nvm3-tokens
Confirm
Exit
Go back to Z2M, and start it again

This time Reset NVM3 tokens was executed successfully! Indeed, when launching ember-zli stack directly right after re-pluging the dongle, it works fine.

However, seems this method still doesn't bring any success, since the same errors appear again:

[08:26:04] INFO: Preparing to start...
[08:26:04] INFO: Socat not enabled
[08:26:05] INFO: Starting Zigbee2MQTT...
Starting Zigbee2MQTT without watchdog.
[2024-07-18 08:26:20] error: 	z2m: Error while starting zigbee-herdsman
[2024-07-18 08:26:20] error: 	z2m: Failed to start zigbee
[2024-07-18 08:26:20] error: 	z2m: Check https://www.zigbee2mqtt.io/guide/installation/20_zigbee2mqtt-fails-to-start.html for possible solutions
[2024-07-18 08:26:20] error: 	z2m: Exiting...
[2024-07-18 08:26:20] error: 	z2m: Error: Failed to start EZSP layer with status=HOST_FATAL_ERROR.
    at EmberAdapter.initEzsp (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:889:19)
    at EmberAdapter.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:2722:24)
    at Controller.start (/app/node_modules/zigbee-herdsman/src/controller/controller.ts:129:29)
    at Zigbee.start (/app/lib/zigbee.ts:63:27)
    at Controller.start (/app/lib/controller.ts:139:27)
    at start (/app/index.js:154:5)

I also enabled debug for Z2M, but it changed nothing in the logs. Seems I even didn't manage to reach Z2M, being stopped by the incorrect setup of my dongle.

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 18, 2024

I seem to remember you had some past troubles with your configuration.yaml file being duplicated in different folders and the file you were editing wasn't the one actually used by Z2M. Can you double-check that it didn't happen again?

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 18, 2024

Yes, you're right, I had some troubles in the past. It was caused by having two different Z2M instances installed on the same machine with two different Zigbee dongles connected to this machine, to ballance the zigbee network traffic ( those days I was facing huge lags in my zigbee network)..

But this is the past, few months ago I installed a fresh HA system from scratch with one Z2M add-on. Since then it worked fine until this huge failure, which I'm facing now.
Currently no other Z2M folders exist on my machine, just one. Here is my full configuration.yaml zip file uploaded directly from //192.168.1.20/config/zigbee2mqtt folder:

configuration.zip

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 18, 2024

  • Stop Z2M.
  • In that configuration.yaml, change rtscts: true to rtscts: false and log_level: warning to log_level: debug.
    • You can use file editor or studio code server add-on to edit the file directly.
  • Start Z2M.

See if you can at least get the logs to show as debug.
Good thing is, you were able to use ember-zli stack, so your adapter works fine (ember-zli uses the exact same code that Z2M uses), just need to figure out why your HA machine is not cooperating.

Note: August release will support concurrency, so you will probably want to remove adapter_concurrent: 1 too.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 18, 2024

I managed to enable log_level: debug and to change rtscts from true to false in the configuration.yaml file.
Here is my latest Z2M log.log file.
log.log

However, I also noticed, that regardless rtscts setting, zh controller starts with the following options:

...
debug: 	zh:controller: Starting with options
"serialPort":{"rtscts":true,"path":"/dev/serial/by-id/usb-Nabu_Casa_SkyConnect_v1.0_30c07efc368dxxxxxxxxxxxxxxxxxxxx-if00-port0","adapter":"ember"}
...

It means that rtscts value is always(?) set to true, regardless its setting in configuration.yaml....
Is it OK?

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 19, 2024

rtscts being true (with the firmware you have requiring false) is likely what's preventing Z2M from starting since I don't see anything else that would be an issue now.

@Koenkk You know the structure of the HA add-on better than me. Could something be cached and make a mess of the settings in configuration.yaml? Seems like something's not quite right here, it's not following what's in the file properly.

@Krzysztonek
Copy link
Author

Krzysztonek commented Jul 19, 2024

What a lovely Friday! I powered my HA server off for 2 hours, then powered on back. And my Z2M ...started working!
Looks that even the zigbee network has been rebuilt successfully (I still need to re-pair some of the devices). Thanks to you, this huge milestone has been achieved!
Here are my logs:

log.zip

Currently only the UI is still not reachable. When clicking Open UI button, I'm getting this:

obraz

Clicking RETRY doesn't change anything, still the same message appears..
Do you know how to get into UI screen?

@Nerivec
Copy link
Collaborator

Nerivec commented Jul 19, 2024

There are some improvements for the UI being slow to load on start for 1.39 in current dev branch/edge. If you want, you can try the Edge version of the add-on. You have to make sure to shutdown the regular add-on, and disable auto-start and watchdog for it. Also make sure to remove the line adapter_concurrent: 1 from your configuration.yaml. (You can switch back to regular, once August release is available.)

I am seeing a few repeating issues in your latest logs though:

[2024-07-19 12:41:06] error: 	z2m: MQTT error: client disconnecting
[2024-07-19 12:41:06] error: 	z2m: MQTT error: client disconnecting
[2024-07-19 12:41:06] error: 	z2m: MQTT error: client disconnecting
[2024-07-19 12:41:11] error: 	z2m: MQTT error: client disconnecting

This is happening right around the time the UI should become available.

@Koenkk
Copy link
Owner

Koenkk commented Jul 21, 2024

You have to put rtscts in the Z2M addon page configuration (under serial), not the z2m configuration.yaml itself.

@n-prat
Copy link

n-prat commented Aug 24, 2024

Hello,

I seemed to have a related issue (?) with the logs spammed of

zh:ember:uart:ash: ======== ASH starting ========
error:        zh:ember:uart:ash: ASH disconnected: ASH_ERROR_RESET_FAIL | Adapter status: NO_ERROR
info:         zh:ember:uart:ash: ======== ASH Adapter reset ========

and then Z2M refusing to start.

Reflashing + doing the Reset NVM3 tokens [all defaults/unselected] seemed to have done the trick. Thank you for that!

[not sure reflashing was needed but can't have hurt either]

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

No branches or pull requests

4 participants