search

home-assistant / addons

:heavy_plus_sign: Docker add-ons for Home Assistant
https://home-assistant.io/hassio/
Apache License 2.0
1.55k stars 1.5k forks source link

ZHA-Multiprotocol ConnectionResetError #3459

Closed HaraldGithub closed 7 months ago

HaraldGithub commented 8 months ago

Describe the issue you are experiencing

Every 2-4 hours a ZHA-multiprotocol-rest-error occurs. Watchdog starts the add-on again and 2-4 hours later the same issue occurs. If i pair new ZHA-devices the error occurs more often, mostly some minutes after pairing a new device. This problem begann with updates after version 2.4.0 and with all HA-releases (2024.1.5 - 2024.2.1) and there are no changes on the hardware configuration for or after the updates. I'm using SkyConnect for multi-protocol

What type of installation are you running?

Home Assistant Supervised

Which operating system are you running on?

Home Assistant Operating System Home Assistant Core 2024.2.1 Supervisor 2024.01.1 Operating System 11.5 Frontend 20240207.1

Which add-on are you reporting an issue with?

Silicon Labs Multiprotocol

What is the version of the add-on?

2.4.4

Steps to reproduce the issue

After watchdog has restarted the add-on, it works for 2-4 hours

System Health information

no comment

Anything in the Supervisor logs that might be useful for us?

Logger: bellows.uart
Source: runner.py:188 
First occurred: 15:06:20 (1 occurrences) 
Last logged: 15:06:20
Lost serial connection: ConnectionResetError('Remote server closed connection')

Logger: bellows.ezsp
Source: runner.py:188 
First occurred: 15:06:20 (1 occurrences) 
Last logged: 15:06:20
NCP entered failed state. Requesting APP controller restart

Anything in the add-on logs that might be useful for us?

-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[15:06:24] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa.
[15:06:24] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0
2024-02-09 15:06:25.035 homeassistant universal_silabs_flasher.flash INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version='4.3.1', ezsp_version='7.3.1.0', ot_rcp_version='SL-OPENTHREAD/2.3.1.0_GitHub-e6df00dd6' (2.3.1.0), cpc_version='4.3.1-4f7f9e99-dirty-de58d93e' (4.3.1), fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>, baudrate=460800)
2024-02-09 15:06:25.035 homeassistant universal_silabs_flasher.flasher INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-02-09 15:06:27.042 homeassistant universal_silabs_flasher.flasher INFO Probing ApplicationType.CPC at 460800 baud
2024-02-09 15:06:27.059 homeassistant universal_silabs_flasher.flasher INFO Detected ApplicationType.CPC, version '4.3.1-4f7f9e99-dirty-de58d93e' (4.3.1) at 460800 baudrate (bootloader baudrate None)
2024-02-09 15:06:27.060 homeassistant universal_silabs_flasher.flash INFO Firmware version '4.3.1-4f7f9e99-dirty-de58d93e' (4.3.1) is flashed, not re-installing
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service cpcd-config: starting
[15:06:27] INFO: Using known baudrate of 460800 for cpcd!
[15:06:27] INFO: Generating cpcd configuration.
s6-rc: info: service cpcd-config successfully started
s6-rc: info: service cpcd: starting
[15:06:27] INFO: Starting cpcd...
WARNING in function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk.
s6-rc: info: service cpcd successfully started
s6-rc: info: service zigbeed: starting
s6-rc: info: service otbr-agent: starting
s6-rc: info: service zigbeed successfully started
[15:06:28] INFO: Starting zigbeed...
[15:06:28] INFO: Setup OTBR firewall...
[15:06:28] INFO: Starting otbr-agent...
otbr-agent[302]: [NOTE]-AGENT---: Running 0.3.0
otbr-agent[302]: [NOTE]-AGENT---: Thread version: 1.3.0
otbr-agent[302]: [NOTE]-AGENT---: Thread interface: wpan0
otbr-agent[302]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0
otbr-agent[302]: [NOTE]-ILS-----: Infra link selected: enp0s31f6
otbr-agent[302]: 53d.16:28:45.758 [C] Platform------: mCpcBusSpeed = 115200
[15:06:27:649101] Info : [CPCd v4.3.1.0] [Library API v3] [RCP Protocol v4]
[15:06:27:649132] Info : Git commit: 133b29678b3d0bc7578e098d2f46b4d5bcd2ebb4 / branch: 
[15:06:27:649133] Info : Sources hash: ff8300587e7e4ab1def7a89a272c0baef32f9eb3bff9b0ba06b94e655d652367
[15:06:27:649135] WARNING : In function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk.
[15:06:27:649143] Info : Reading cli arguments
[15:06:27:649145] Info : /usr/local/bin/cpcd 
[15:06:27:650281] Info : Reading configuration
[15:06:27:650284] Info :   file_path = /usr/local/etc/cpcd.conf
[15:06:27:650284] Info :   instance_name = cpcd_0
[15:06:27:650285] Info :   socket_folder = /dev/shm
[15:06:27:650285] Info :   operation_mode = MODE_NORMAL
[15:06:27:650286] Info :   use_encryption = false
[15:06:27:650286] Info :   binding_key_file = /etc/binding-key.key
[15:06:27:650287] Info :   stdout_tracing = false
[15:06:27:650287] Info :   file_tracing = false
[15:06:27:650288] Info :   lttng_tracing = false
[15:06:27:650288] Info :   enable_frame_trace = false
[15:06:27:650288] Info :   traces_folder = /dev/shm/cpcd-traces
[15:06:27:650289] Info :   bus = UART
[15:06:27:650289] Info :   uart_baudrate = 460800
[15:06:27:650290] Info :   uart_hardflow = true
[15:06:27:650290] Info :   uart_file = /dev/ttyUSB0
[15:06:27:650291] Info :   fu_recovery_pins_enabled = false
[15:06:27:650291] Info :   fu_connect_to_bootloader = false
[15:06:27:650292] Info :   fu_enter_bootloader = false
[15:06:27:650292] Info :   restart_cpcd = false
[15:06:27:650293] Info :   application_version_validation = false
[15:06:27:650293] Info :   print_secondary_versions_and_exit = false
[15:06:27:650294] Info :   use_noop_keep_alive = false
[15:06:27:650294] Info :   reset_sequence = true
[15:06:27:650294] Info :   stats_interval = 0
[15:06:27:650295] Info :   rlimit_nofile = 2000
[15:06:27:650295] Info : ENCRYPTION IS DISABLED 
[15:06:27:650296] Info : Starting daemon in normal mode
[15:06:27:661521] Info : Connecting to Secondary...
[15:06:27:734359] Info : RX capability is 256 bytes
[15:06:27:734376] Info : Connected to Secondary
[15:06:27:737722] Info : Secondary Protocol v4
[15:06:27:744856] Info : Secondary CPC v4.3.1
[15:06:27:748358] Info : Secondary bus bitrate is 460800
[15:06:27:755904] Info : Secondary APP v4.3.1-4f7f9e99-dirty-de58d93e
[15:06:27:756064] Info : Daemon startup was successful. Waiting for client connections
[15:06:28:286958] Info : New client connection using library v4.3.1.0
[15:06:28:290783] Info : Opened connection socket for ep#12
[15:06:28:290832] Info : Endpoint socket #12: Client connected. 1 connections
[15:06:29:104386] Info : New client connection using library v4.3.1.0
[15:06:29:108714] Info : Endpoint socket #12: Client connected. 2 connections
otbr-agent[302]: 00:00:00.114 [N] RoutingManager: BR ULA prefix: fd47:7bce:23bc::/48 (loaded)
otbr-agent[302]: 00:00:00.114 [N] RoutingManager: Local on-link prefix: fdc3:68f6:e05c:eca::/64
otbr-agent[302]: 00:00:00.164 [N] Mle-----------: Role disabled -> detached
otbr-agent[302]: 00:00:00.167 [N] Platform------: [netif] Changing interface state to up.
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
[15:06:30] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
Listening on port 9999 for connection...
Accepting connection.
Accepted connection 7.
otbr-agent[302]: 00:00:25.241 [N] Mle-----------: RLOC16 d400 -> fffe
otbr-agent[302]: 00:00:25.253 [W] Platform------: [netif] Failed to process request#5: Unknown error -95
otbr-agent[302]: 00:00:25.899 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[302]: 00:00:32.399 [N] RouterTable---: Allocate router id 53
otbr-agent[302]: 00:00:32.399 [N] Mle-----------: RLOC16 fffe -> d400
otbr-agent[302]: 00:00:32.403 [N] Mle-----------: Role detached -> leader
otbr-agent[302]: 00:00:32.403 [N] Mle-----------: Partition ID 0x55fde90c
otbr-agent[302]: 00:00:32.445 [W] Platform------: [netif] Failed to process request#6: Unknown error -17
otbr-agent[302]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!

Additional information

./.

RafBois commented 8 months ago

I have an identical error with [Sonoff ZBDongle E]

` Add-on version: 2.4.4 You are running the latest version of this add-on. System: Home Assistant OS 11.5 (aarch64 / raspberrypi4-64) Home Assistant Core: 2024.2.1 Home Assistant Supervisor: 2024.01.1

Please, share the above information when looking for help or support in, e.g., GitHub, forums or the Discord chat.

s6-rc: info: service banner successfully started s6-rc: info: service universal-silabs-flasher: starting [13:04:01] INFO: Flashing firmware is disabled s6-rc: info: service universal-silabs-flasher successfully started s6-rc: info: service cpcd-config: starting [13:04:03] INFO: Generating cpcd configuration. s6-rc: info: service cpcd-config successfully started s6-rc: info: service cpcd: starting [13:04:03] INFO: Starting cpcd... WARNING in function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk. s6-rc: info: service cpcd successfully started s6-rc: info: service zigbeed: starting s6-rc: info: service otbr-agent: starting s6-rc: info: service zigbeed successfully started [13:04:04] INFO: Starting zigbeed... [13:04:03:859841] Info : [CPCd v4.3.1.0] [Library API v3] [RCP Protocol v4] [13:04:03:859990] Info : Git commit: 133b29678b3d0bc7578e098d2f46b4d5bcd2ebb4 / branch: [13:04:03:859994] Info : Sources hash: ff8300587e7e4ab1def7a89a272c0baef32f9eb3bff9b0ba06b94e655d652367 [13:04:03:860000] WARNING : In function 'main' in file /usr/src/cpc-daemon/main.c at line #186 : Running CPCd as 'root' is not recommended. Proceed at your own risk. [13:04:03:860216] Info : Reading cli arguments [13:04:03:860230] Info : /usr/local/bin/cpcd [13:04:03:862844] Info : Reading configuration [13:04:03:862859] Info : file_path = /usr/local/etc/cpcd.conf [13:04:03:862861] Info : instance_name = cpcd_0 [13:04:03:862864] Info : socket_folder = /dev/shm [13:04:03:862866] Info : operation_mode = MODE_NORMAL [13:04:03:862867] Info : use_encryption = false [13:04:03:862869] Info : binding_key_file = /etc/binding-key.key [13:04:03:862871] Info : stdout_tracing = false [13:04:03:862873] Info : file_tracing = false [13:04:03:862875] Info : lttng_tracing = false [13:04:03:862877] Info : enable_frame_trace = false [13:04:03:862879] Info : traces_folder = /dev/shm/cpcd-traces [13:04:03:862881] Info : bus = UART [13:04:03:862882] Info : uart_baudrate = 460800 [13:04:03:862885] Info : uart_hardflow = false [13:04:03:862887] Info : uart_file = /dev/ttyACM0 [13:04:03:862889] Info : fu_recovery_pins_enabled = false [13:04:03:862892] Info : fu_connect_to_bootloader = false [13:04:03:862893] Info : fu_enter_bootloader = false [13:04:03:862895] Info : restart_cpcd = false [13:04:03:862897] Info : application_version_validation = false [13:04:03:862899] Info : print_secondary_versions_and_exit = false [13:04:03:862901] Info : use_noop_keep_alive = false [13:04:03:862903] Info : reset_sequence = true [13:04:03:862904] Info : stats_interval = 0 [13:04:03:862907] Info : rlimit_nofile = 2000 [13:04:03:862909] Info : ENCRYPTION IS DISABLED [13:04:03:862911] Info : Starting daemon in normal mode [13:04:03:878456] Info : Connecting to Secondary... [13:04:03:945914] Info : RX capability is 256 bytes [13:04:03:945955] Info : Connected to Secondary [13:04:03:947522] Info : Secondary Protocol v4 [13:04:03:951074] Info : Secondary CPC v4.3.1 [13:04:03:952797] Info : Secondary bus bitrate is 460800 [13:04:03:956180] Info : Secondary APP vUNDEFINED [13:04:03:956470] Info : Daemon startup was successful. Waiting for client connections [13:04:05] INFO: Setup OTBR firewall... [13:04:05] INFO: Starting otbr-agent... otbr-agent[305]: [NOTE]-AGENT---: Running 0.3.0 otbr-agent[305]: [NOTE]-AGENT---: Thread version: 1.3.0 otbr-agent[305]: [NOTE]-AGENT---: Thread interface: wpan0 otbr-agent[305]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0 otbr-agent[305]: [NOTE]-ILS-----: Infra link selected: end0 otbr-agent[305]: 49d.17:59:04.357 [C] Platform------: mCpcBusSpeed = 115200 [13:04:05:315553] Info : New client connection using library v4.3.1.0 [13:04:05:318040] Info : Opened connection socket for ep#12 [13:04:05:318333] Info : Endpoint socket #12: Client connected. 1 connections [13:04:05:665560] Info : New client connection using library v4.3.1.0 [13:04:05:669235] Info : Endpoint socket #12: Client connected. 2 connections otbr-agent[305]: 00:00:00.063 [N] RoutingManager: BR ULA prefix: fd72:7324:c381::/48 (loaded) otbr-agent[305]: 00:00:00.064 [N] RoutingManager: Local on-link prefix: fd67:315b:6890:7e34::/64 otbr-agent[305]: 00:00:00.107 [N] Mle-----------: Role disabled -> detached otbr-agent[305]: 00:00:00.133 [N] Platform------: [netif] Changing interface state to up. s6-rc: info: service otbr-agent successfully started s6-rc: info: service otbr-agent-rest-discovery: starting [13:04:08] INFO: Successfully sent discovery information to Home Assistant. s6-rc: info: service otbr-agent-rest-discovery successfully started s6-rc: info: service legacy-services: starting s6-rc: info: service legacy-services successfully started Listening on port 9999 for connection... Accepting connection. otbr-agent[305]: 00:00:26.959 [N] Mle-----------: RLOC16 0c00 -> fffe otbr-agent[305]: 00:00:26.962 [W] Platform------: [netif] Failed to process request#5: Unknown error -95 otbr-agent[305]: 00:00:27.446 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset otbr-agent[305]: 00:00:33.950 [N] RouterTable---: Allocate router id 3 otbr-agent[305]: 00:00:33.951 [N] Mle-----------: RLOC16 fffe -> 0c00 otbr-agent[305]: 00:00:33.953 [N] Mle-----------: Role detached -> leader otbr-agent[305]: 00:00:33.955 [N] Mle-----------: Partition ID 0x58b4b846 otbr-agent[305]: 00:00:34.000 [W] Platform------: [netif] Failed to process request#6: Unknown error -17 otbr-agent[305]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!`

eikaramba commented 8 months ago

same here too, currently running the sonoff or the skyconnect stick with Multiprotocol seems to be a hot mess. i have given up on matter for the foreseeable future. Hopefully it will resolve at some point.

fbonelle commented 8 months ago

same problem for me also

HaraldGithub commented 8 months ago

I‘ve solved the problem by disable multiprotocol and switch back to ZigBee-ZHA online. In the HA-release party video to 2024.2.0 they told, that at moment no more development on multiprotocol will take place. So i decided to switch back.

djdubd commented 8 months ago

I've had this same issue, I have operated SkyConnect in multiprotocol mode since I got it because of promises with Matter. It worked fine until ZHA last night. I understand the fix is to reconfigure the radio and change from multiprotocol. When following up on the repair note I found a post that says a firmware flash is required, is this correct?

If so this is rather inconvenient as this has happened on a remote site, but I would like to know before I travel to the site. Thanks!

HaraldGithub commented 8 months ago

The only thing you have to do, is to disable multiprotocol in HA/hardware. HA will reconfigure and flash your skyconnect automatically. All your zigbee-devices will work as before and the siliconlabs-addon will be removed frommyour HA.

djdubd commented 8 months ago

The only thing you have to do, is to disable multiprotocol in HA/hardware. HA will reconfigure and flash your skyconnect automatically. All your zigbee-devices will work as before and the siliconlabs-addon will be removed frommyour HA.

I must have something else going on then, because when I switch from multiprotocol:

Screenshot 2024-02-12 163248

I get a message:

Your device is running the wrong firmware and cannot be used with ZHA until the correct firmware is installed. A repair has been created with more information and instructions for how to fix this.

The note on the "Repair" says:

Your Zigbee radio was previously used with multiprotocol (Zigbee and Thread) and still has multiprotocol firmware installed: (CPC). To run your radio exclusively with ZHA, you need to install Zigbee firmware. Follow your Zigbee radio manufacturer's instructions for how to do this.

When I access the SkyConnect page about updating firmware (https://skyconnect.home-assistant.io/firmware-update/) it wants me to connect directly to the device to flash firmware.

I'm hoping that I can get it fixed without having to do so. But if not it isn't a huge deal to travel to the site, just not able to for a couple of days.

github-actions[bot] commented 7 months ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.