search

home-assistant / addons

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

Skyconnect disconnects and software issues #3440

Closed HFeenstra closed 7 months ago

HFeenstra commented 8 months ago

Describe the issue you are experiencing

added or tweaked. Running an Home Assistant Blue, 2024.1.3 with Skyconnect, 2.4.2 Sillicon lab firmware, looks like it started when upgrading to 2.4.4 (firmware as of 26-1-2024). Have ZHA integration and was working perfectly until this interruption.

What did I do: Restore backup before this issue, then reboot the whole system including hardware, then it works for 15 min and gives these issues in logbook.

Odd it disconnects and starts a new session..? ZHA doesn’t give an error. All entities I see, try to switch a light, gives a failed send request error in RED.

Restored from backup now twice no success thus far. Who has more info, steps to resolve??

What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Silicon Labs Multiprotocol

What is the version of the add-on?

2.4.2

Steps to reproduce the issue

  1. See all information in description

  3. ...

System Health information

System Information

version core-2024.1.5
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.11.6
os_name Linux
os_version 6.1.71-haos
arch aarch64
timezone Europe/Amsterdam
config_dir /config
Home Assistant Community Store GitHub API | ok -- | -- GitHub Content | ok GitHub Web | ok GitHub API Calls Remaining | 4996 Installed Version | 1.34.0 Stage | running Available Repositories | 1381 Downloaded Repositories | 51
Home Assistant Cloud logged_in | false -- | -- can_reach_cert_server | ok can_reach_cloud_auth | ok can_reach_cloud | ok
Home Assistant Supervisor host_os | Home Assistant OS 11.4 -- | -- update_channel | stable supervisor_version | supervisor-2023.12.1 agent_version | 1.6.0 docker_version | 24.0.7 disk_total | 113.9 GB disk_used | 20.2 GB healthy | true supported | true board | odroid-n2 supervisor_api | ok version_api | ok installed_addons | AdGuard Home (5.0.2), Node-RED (17.0.3), Genie (3.0.0), Samba share (12.2.0), Mosquitto broker (6.4.0), AirSonos (4.2.0), Studio Code Server (5.15.0), Advanced SSH & Web Terminal (17.0.4), TasmoAdmin (0.29.1), Grocy (0.21.0), ESPHome (2023.12.9), Silicon Labs Multiprotocol (2.4.2), Matter Server (5.0.4), Piper (1.4.0), Whisper (1.0.2), Simple Scheduler (2.2.1), Home Assistant Google Drive Backup (0.112.1), openWakeWord (1.8.2), Z-Wave JS (0.4.3), Cloudflared (5.1.1)
Dashboards dashboards | 9 -- | -- resources | 36 views | 22 mode | storage
Recorder oldest_recorder_run | 18 januari 2024 om 05:04 -- | -- current_recorder_run | 28 januari 2024 om 17:34 estimated_db_size | 400.93 MiB database_engine | sqlite database_version | 3.41.2
Spotify api_endpoint_reachable | ok -- | --

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

24-01-28 17:34:47 INFO (MainThread) [supervisor.homeassistant.core] Wait until Home Assistant is ready
24-01-28 17:34:52 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state freeze
24-01-28 17:34:52 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
24-01-28 17:34:53 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to NOT_RUNNING
24-01-28 17:34:53 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
24-01-28 17:34:53 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/jakowenko/double-take-hassio-addons repository
24-01-28 17:34:53 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/arthurdent75/SimpleScheduler repository
24-01-28 17:34:53 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/zigbee2mqtt/hassio-zigbee2mqtt repository
24-01-28 17:34:53 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/brenner-tobias/ha-addons repository
24-01-28 17:34:54 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/esphome/home-assistant-addon repository
24-01-28 17:34:54 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/sabeechen/hassio-google-drive-backup repository
24-01-28 17:34:54 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/hassio-addons/repository repository
24-01-28 17:34:54 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/home-assistant/addons repository
24-01-28 17:34:56 INFO (MainThread) [supervisor.store] Loading add-ons from store: 90 all - 0 new - 0 remove
24-01-28 17:34:56 INFO (MainThread) [supervisor.store] Loading add-ons from store: 90 all - 0 new - 0 remove
24-01-28 17:35:11 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'MQTT'
24-01-28 17:35:13 INFO (MainThread) [supervisor.auth] Home Assistant not running, checking cache
24-01-28 17:38:46 WARNING (MainThread) [supervisor.jobs] 'BackupManager.do_backup_partial' blocked from execution, system is not running - freeze
24-01-28 17:40:47 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to STARTING
24-01-28 17:40:53 WARNING (MainThread) [supervisor.jobs] 'BackupManager.do_backup_partial' blocked from execution, system is not running - freeze
24-01-28 17:41:03 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
24-01-28 17:41:03 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant Core state changed to RUNNING
24-01-28 17:41:03 INFO (MainThread) [supervisor.homeassistant.core] Detect a running Home Assistant instance
24-01-28 17:41:03 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
24-01-28 17:41:03 INFO (MainThread) [supervisor.backups.manager] Full-Restore 10906f8d done
24-01-28 17:41:03 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Backup 4e341213 starting stage addon_repositories
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Backup 4e341213 starting stage docker_config
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Creating new partial backup with slug 4e341213
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Backup 4e341213 starting stage addons
24-01-28 17:45:49 INFO (MainThread) [supervisor.addons.addon] Building backup for add-on 9074a9fa_cloudflared
24-01-28 17:45:49 INFO (MainThread) [supervisor.addons.addon] Finish backup for addon 9074a9fa_cloudflared
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Backup 4e341213 starting stage finishing_file
24-01-28 17:45:49 INFO (MainThread) [supervisor.backups.manager] Creating partial backup with slug 4e341213 completed
24-01-28 17:45:49 INFO (MainThread) [supervisor.docker.addon] Updating image ghcr.io/brenner-tobias/cloudflared/aarch64:5.1.0 to ghcr.io/brenner-tobias/cloudflared/aarch64:5.1.1
24-01-28 17:45:49 INFO (MainThread) [supervisor.docker.interface] Downloading docker image ghcr.io/brenner-tobias/cloudflared/aarch64 with tag 5.1.1.
24-01-28 17:45:52 INFO (SyncWorker_1) [supervisor.docker.manager] Stopping addon_9074a9fa_cloudflared application
24-01-28 17:45:56 INFO (SyncWorker_1) [supervisor.docker.manager] Cleaning addon_9074a9fa_cloudflared application
24-01-28 17:45:56 INFO (MainThread) [supervisor.addons.addon] Add-on '9074a9fa_cloudflared' successfully updated
24-01-28 17:45:56 INFO (SyncWorker_9) [supervisor.docker.manager] Cleanup images: ['ghcr.io/brenner-tobias/cloudflared/aarch64:5.1.0', 'ghcr.io/brenner-tobias/cloudflared/aarch64:latest']
24-01-28 17:45:57 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ghcr.io/brenner-tobias/cloudflared/aarch64 with version 5.1.1
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /core/info access from 9074a9fa_cloudflared
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /supervisor/info access from cebe7a76_hassio_google_drive_backup
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /backups access from cebe7a76_hassio_google_drive_backup
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /backups/4e341213/info access from cebe7a76_hassio_google_drive_backup
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /supervisor/info access from cebe7a76_hassio_google_drive_backup
24-01-28 17:45:59 INFO (MainThread) [supervisor.api.middleware.security] /backups access from cebe7a76_hassio_google_drive_backup
24-01-28 17:47:57 WARNING (MainThread) [supervisor.addons.addon] Timeout while waiting for addon Cloudflared to start, took more than 120 seconds
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/jakowenko/double-take-hassio-addons repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/arthurdent75/SimpleScheduler repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/zigbee2mqtt/hassio-zigbee2mqtt repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/brenner-tobias/ha-addons repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/esphome/home-assistant-addon repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/sabeechen/hassio-google-drive-backup repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/hassio-addons/repository repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.store.git] Update add-on https://github.com/home-assistant/addons repository
24-01-28 17:47:57 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
24-01-28 17:47:59 INFO (MainThread) [supervisor.store] Loading add-ons from store: 90 all - 0 new - 0 remove
24-01-28 17:47:59 INFO (MainThread) [supervisor.store] Loading add-ons from store: 90 all - 0 new - 0 remove
24-01-28 17:53:00 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'mqtt'
24-01-28 17:53:00 INFO (MainThread) [supervisor.auth] Successful login for 'mqtt'
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.check] System checks complete
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
24-01-28 17:53:05 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
24-01-28 17:54:26 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
24-01-28 17:58:11 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'mqtt'
24-01-28 17:58:11 INFO (MainThread) [supervisor.auth] Successful login for 'mqtt'
24-01-28 18:24:29 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token
24-01-28 18:37:13 INFO (MainThread) [supervisor.auth] Auth request from 'core_mosquitto' for 'mqtt'
24-01-28 18:37:13 INFO (MainThread) [supervisor.auth] Successful login for 'mqtt'
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.check] System checks complete
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
24-01-28 18:53:05 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
24-01-28 18:54:32 INFO (MainThread) [supervisor.homeassistant.api] Updated Home Assistant API token

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

[17:32:33:057007] Info :   uart_hardflow = true
[17:32:33:057009] Info :   uart_file = /dev/ttyUSB0
[17:32:33:057011] Info :   fu_recovery_pins_enabled = false
[17:32:33:057013] Info :   fu_connect_to_bootloader = false
[17:32:33:057014] Info :   fu_enter_bootloader = false
[17:32:33:057016] Info :   restart_cpcd = false
[17:32:33:057018] Info :   application_version_validation = false
[17:32:33:057020] Info :   print_secondary_versions_and_exit = false
[17:32:33:057021] Info :   use_noop_keep_alive = false
[17:32:33:057023] Info :   reset_sequence = true
[17:32:33:057024] Info :   stats_interval = 0
[17:32:33:057026] Info :   rlimit_nofile = 2000
[17:32:33:057028] Info : ENCRYPTION IS DISABLED 
[17:32:33:057029] Info : Starting daemon in normal mode
[17:32:33:068543] Info : Connecting to Secondary...
[17:32:33:146855] Info : RX capability is 256 bytes
[17:32:33:146885] Info : Connected to Secondary
[17:32:33:149964] Info : Secondary Protocol v4
[17:32:33:156545] Info : Secondary CPC v4.3.1
[17:32:33:159739] Info : Secondary bus bitrate is 460800
[17:32:33:166758] Info : Secondary APP v4.3.1-4f7f9e99-dirty-de58d93e
[17:32:33:167012] Info : Daemon startup was successful. Waiting for client connections
[17:32:34] INFO: Setup OTBR firewall...
[17:32:34] INFO: Starting otbr-agent...
[17:32:34:856599] Info : New client connection using library v4.3.1.0
[17:32:34:860495] Info : Opened connection socket for ep#12
[17:32:34:860684] Info : Endpoint socket #12: Client connected. 1 connections
otbr-agent[324]: [NOTE]-AGENT---: Running 0.3.0
otbr-agent[324]: [NOTE]-AGENT---: Thread version: 1.3.0
otbr-agent[324]: [NOTE]-AGENT---: Thread interface: wpan0
otbr-agent[324]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0
otbr-agent[324]: [NOTE]-ILS-----: Infra link selected: end0
otbr-agent[324]: 49d.17:42:49.935 [C] Platform------: mCpcBusSpeed = 115200
[17:32:35:243598] Info : New client connection using library v4.3.1.0
[17:32:35:247368] Info : Endpoint socket #12: Client connected. 2 connections
otbr-agent[324]: 00:00:00.120 [N] RoutingManager: BR ULA prefix: fd2d:c636:28fb::/48 (loaded)
otbr-agent[324]: 00:00:00.121 [N] RoutingManager: Local on-link prefix: fd50:c023:1930:580c::/64
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::acff:33ff:fead:10ea/vetha78f8d7/58
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
otbr-agent[324]: 00:00:00.264 [N] Mle-----------: Role disabled -> detached
otbr-agent[324]: 00:00:00.282 [N] Platform------: [netif] Changing interface state to up.
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::acff:33ff:fead:10ea/vetha78f8d7/58
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::acff:33ff:fead:10ea/vetha78f8d7/58
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::acff:33ff:fead:10ea/vetha78f8d7/58
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::88e2:feff:fe78:e7c8/vetha5b2346/63
Listening on port 9999 for connection...
Accepting connection.
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::1c:37ff:fe2b:a8b2/vethbd4606f/60
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::88e2:feff:fe78:e7c8/vetha5b2346/63
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::88e2:feff:fe78:e7c8/vetha5b2346/63
[17:32:38] 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
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::88e2:feff:fe78:e7c8/vetha5b2346/63
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::88e2:feff:fe78:e7c8/vetha5b2346/63
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9c1d:2ff:febf:aa16/veth9b68b27/65
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::404:86ff:fe05:cc18/vetha5a6c7e/67
otbr-agent[324]: 00:00:27.117 [N] Mle-----------: RLOC16 2c00 -> fffe
otbr-agent[324]: 00:00:27.121 [W] Platform------: [netif] Failed to process request#5: Unknown error -95
otbr-agent[324]: 00:00:27.659 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[324]: 00:00:34.159 [N] RouterTable---: Allocate router id 11
otbr-agent[324]: 00:00:34.159 [N] Mle-----------: RLOC16 fffe -> 2c00
otbr-agent[324]: 00:00:34.162 [N] Mle-----------: Role detached -> leader
otbr-agent[324]: 00:00:34.162 [N] Mle-----------: Partition ID 0x3f3010f5
otbr-agent[324]: 00:00:34.288 [W] Platform------: [netif] Failed to process request#6: Unknown error -17
otbr-agent[324]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
Accepted connection 7.
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c4c:38ff:feb2:fca2/veth137d550/69
Socket connection has been closed, restarting...
Listening on port 9999 for connection...
Accepting connection.
Accepted connection 7.
Restarting
[17:46:53:865568] Info : Endpoint socket #12: Client disconnected. 1 connections
[17:46:53:865631] Info : Client disconnected
[17:46:54:869883] Info : New client connection using library v4.3.1.0
[17:46:54:873434] Info : Endpoint socket #12: Client connected. 2 connections
Reusing socket from previous instance.

Additional information

Everything is in description

HFeenstra commented 8 months ago

Extra input: log file after restoring backup from 10 days ago: (see also: #108927 of general issues)

18:43:20:265404] Info : uart_hardflow = true [18:43:20:265406] Info : uart_file = /dev/ttyUSB0 [18:43:20:265408] Info : fu_recovery_pins_enabled = false [18:43:20:265410] Info : fu_connect_to_bootloader = false [18:43:20:265412] Info : fu_enter_bootloader = false [18:43:20:265414] Info : restart_cpcd = false [18:43:20:265415] Info : application_version_validation = false [18:43:20:265417] Info : print_secondary_versions_and_exit = false [18:43:20:265418] Info : use_noop_keep_alive = false [18:43:20:265420] Info : reset_sequence = true [18:43:20:265421] Info : stats_interval = 0 [18:43:20:265423] Info : rlimit_nofile = 2000 [18:43:20:265425] Info : ENCRYPTION IS DISABLED [18:43:20:265427] Info : Starting daemon in normal mode [18:43:20:276993] Info : Connecting to Secondary... [18:43:20:355303] Info : RX capability is 256 bytes [18:43:20:355342] Info : Connected to Secondary [18:43:20:358581] Info : Secondary Protocol v4 [18:43:20:365426] Info : Secondary CPC v4.3.1 [18:43:20:368663] Info : Secondary bus bitrate is 460800 [18:43:20:375782] Info : Secondary APP v4.3.1-4f7f9e99-dirty-de58d93e [18:43:20:375914] Info : Daemon startup was successful. Waiting for client connections [18:43:21] INFO: Setup OTBR firewall... [18:43:21] INFO: Starting otbr-agent... otbr-agent[313]: [NOTE]-AGENT---: Running 0.3.0 otbr-agent[313]: [NOTE]-AGENT---: Thread version: 1.3.0 otbr-agent[313]: [NOTE]-AGENT---: Thread interface: wpan0 otbr-agent[313]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0 otbr-agent[313]: [NOTE]-ILS-----: Infra link selected: end0 otbr-agent[313]: 51d.18:53:27.982 [C] Platform------: mCpcBusSpeed = 115200 [18:43:22:046127] Info : New client connection using library v4.3.1.0 [18:43:22:049971] Info : Opened connection socket for ep#12 [18:43:22:050065] Info : Endpoint socket #12: Client connected. 1 connections [18:43:22:166739] Info : New client connection using library v4.3.1.0 [18:43:22:170697] Info : Endpoint socket #12: Client connected. 2 connections otbr-agent[313]: 00:00:00.114 [N] RoutingManager: BR ULA prefix: fd2d:c636:28fb::/48 (loaded) otbr-agent[313]: 00:00:00.114 [N] RoutingManager: Local on-link prefix: fd50:c023:1930:580c::/64 otbr-agent[313]: 00:00:00.202 [N] Mle-----------: Role disabled -> detached otbr-agent[313]: 00:00:00.219 [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 Listening on port 9999 for connection... Accepting connection. [18:43:25] 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 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c1f:95ff:fe23:ef42/veth798ffb3/84 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9849:75ff:fec8:120f/veth632547c/82 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c1f:95ff:fe23:ef42/veth798ffb3/84 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c1f:95ff:fe23:ef42/veth798ffb3/84 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c1f:95ff:fe23:ef42/veth798ffb3/84 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c1f:95ff:fe23:ef42/veth798ffb3/84 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9406:83ff:fe40:ae63/veth3ccf3be/88 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::c0f8:baff:fe08:bac9/vethcbbff60/86 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9406:83ff:fe40:ae63/veth3ccf3be/88 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9406:83ff:fe40:ae63/veth3ccf3be/88 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9406:83ff:fe40:ae63/veth3ccf3be/88 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::9406:83ff:fe40:ae63/veth3ccf3be/88 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::540b:86ff:fe82:5db/vethf0de868/90 otbr-agent[313]: 00:00:28.207 [N] Mle-----------: RLOC16 2c00 -> fffe otbr-agent[313]: 00:00:28.211 [W] Platform------: [netif] Failed to process request#5: Unknown error -95 otbr-agent[313]: 00:00:28.409 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::f03c:68ff:fe4f:d806/veth707b170/92 otbr-agent[313]: 00:00:34.910 [N] RouterTable---: Allocate router id 11 otbr-agent[313]: 00:00:34.911 [N] Mle-----------: RLOC16 fffe -> 2c00 otbr-agent[313]: 00:00:34.916 [N] Mle-----------: Role detached -> leader otbr-agent[313]: 00:00:34.917 [N] Mle-----------: Partition ID 0xc68edcf otbr-agent[313]: 00:00:35.015 [W] Platform------: [netif] Failed to process request#6: Unknown error -17 otbr-agent[313]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary! Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::a4b7:cfff:fed4:ec01/vethe19fe5c/94 Accepted connection 7. otbr-agent[313]: 01:08:57.527 [W] Platform------: Error processing result: InvalidState otbr-agent[313]: 01:08:57.533 [W] Platform------: Error waiting response: InvalidState otbr-agent[313]: 01:08:57.533 [W] SubMac--------: RadioReceive() failed, error: InvalidState

HFeenstra commented 8 months ago

Update/Work around: As mentioned in other tickets regarding SkyConnect and Multiprotocol I have now turned off Multiprotocol and had to completely setup again all the devices, some of them came up again, but overall I had to reconnect/readd them. This has just been 1.5 hours up till now and still all devices are working properly. Hope devs will figure out what makes that SkyConnect is losing connection/Multiprotocol is some what interferring?

Read in other tickets this seems to have been reported as of 2023.12.x

Jordenjj commented 8 months ago

Rolling back to 2.4.2 seemed to fix it for now. Looks like somethings wrong in the latest vesion

HFeenstra commented 8 months ago

Thanks for the reply. I ended up disabling the Multiprotocol of the Skyconnect and reconfigure the whole ZHA interface and devices.

szimszon commented 8 months ago

Same issue here. Seems restore to 2.4.2 and complete reboot (shutdown, power off, power on) fix the issue of 2.4.4 :( for now.

marbon87 commented 8 months ago

How can I install version 2.4.2? I don't find a link where I can download older versions.

szimszon commented 8 months ago

Typically if you upgrade a backup is created and you can revert back to the backup.

Unfortunately - a have to say - for me after the 2.4.4 version reverting back to 2.4.2 didn't do the trick 100%. After a while it started to fail. Maybe there was also a fw update with 2.4.4, I don't know. I decided to try 2.4.4 again and my light switches disappeared (I just didn't realized it first) and I wasn't able to reconfigure it. :(

I ended up to disable the OpenThread Border Router and firewall as I don't have any Matter device.

Now Zigbee seems to work...

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.