search

home-assistant / addons

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

Ongoing otbr-agent error messages: "Failed to update ipsets: Failed" #3215

Closed kylev closed 9 months ago

kylev commented 1 year ago

Describe the issue you are experiencing

My thread network is unstable, and also produces a fair number of ipset and route problems. During the boot sequence of otbr-agent, I see a single ipset v7.10: The set with the given name does not exist message. This error continues in the logs over time, often paired with "unavailable" devices and routing errors.

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?

OpenThread Border Router

What is the version of the add-on?

2.3.2

Steps to reproduce the issue

  1. RP4 with SkyConnect Multiprotocol
  2. eero router, IPv4/6 with a real /64
  3. Boot, watch logs.

System Health information

System Information

version core-2023.9.2
installation_type Home Assistant OS
dev false
hassio true
docker true
user root
virtualenv false
python_version 3.11.5
os_name Linux
os_version 6.1.21-v8
arch aarch64
timezone America/Los_Angeles
config_dir /config
Home Assistant Community Store GitHub API | ok -- | -- GitHub Content | ok GitHub Web | ok GitHub API Calls Remaining | 4918 Installed Version | 1.32.1 Stage | running Available Repositories | 1285 Downloaded Repositories | 3
Home Assistant Cloud logged_in | true -- | -- subscription_expiration | October 7, 2023 at 5:00 PM relayer_connected | true relayer_region | us-east-1 remote_enabled | true remote_connected | true alexa_enabled | true google_enabled | false remote_server | us-east-1-8.ui.nabu.casa certificate_status | ready can_reach_cert_server | ok can_reach_cloud_auth | ok can_reach_cloud | ok
Home Assistant Supervisor host_os | Home Assistant OS 10.5 -- | -- update_channel | beta supervisor_version | supervisor-2023.09.2 agent_version | 1.5.1 docker_version | 23.0.6 disk_total | 458.4 GB disk_used | 6.5 GB healthy | true supported | true board | rpi4-64 supervisor_api | ok version_api | ok installed_addons | Terminal & SSH (9.7.1), File editor (5.6.0), AirSonos (3.6.0), Silicon Labs Multiprotocol (2.3.2), Matter Server (4.9.0)
Dashboards dashboards | 5 -- | -- resources | 0 views | 4 mode | storage
Recorder oldest_recorder_run | September 6, 2023 at 2:09 AM -- | -- current_recorder_run | September 14, 2023 at 11:36 AM estimated_db_size | 45.23 MiB database_engine | sqlite database_version | 3.41.2

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

No response

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

During boot:

Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:27] INFO: Starting otbr-agent...
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-AGENT---: Running 0.3.0
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-AGENT---: Thread version: 1.3.0
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-AGENT---: Thread interface: wpan0
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-AGENT---: Radio URL: spinel+cpc://cpcd_0?iid=2&iid-list=0
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-ILS-----: Infra link selected: eth0
Sep 14 20:36:27 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 54d.17:34:16.971 [C] Platform------: mCpcBusSpeed = 115200
Sep 14 20:36:28 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:27:900253] Info : New client connection using library v4.3.1.0
Sep 14 20:36:28 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:27:904609] Info : Opened connection socket for ep#12
Sep 14 20:36:28 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:27:904890] Info : Endpoint socket #12: Client connected. 1 connections
Sep 14 20:36:28 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:28:467836] Info : New client connection using library v4.3.1.0
Sep 14 20:36:28 homeassistant addon_core_silabs_multiprotocol[614]: [13:36:28:473891] Info : Endpoint socket #12: Client connected. 2 connections
Sep 14 20:36:30 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:00:00.112 [N] RoutingManager: BR ULA prefix: fd49:44c9:7890::/48 (loaded)
Sep 14 20:36:30 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:00:00.112 [N] RoutingManager: Local on-link prefix: fdd8:d149:30de:b674::/64
Sep 14 20:36:30 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 20:36:30 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:00:00.124 [W] Platform------: Failed to update ipsets: Failed
Sep 14 20:36:30 homeassistant addon_core_silabs_multiprotocol[614]: s6-rc: info: service otbr-agent successfully started

During a Thread mesh reconfiguration:

Sep 14 21:29:07 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:52:37.541 [N] Mle-----------: Attach attempt 0, BetterPartition 
Sep 14 21:29:38 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:08.434 [N] Mle-----------: Different partition (peer:48886013, local:1640488079)
Sep 14 21:29:38 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:08.436 [N] Mle-----------: Attach attempt 0, BetterPartition 
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.129 [N] Mle-----------: Different partition (peer:48886013, local:1640488079)
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.130 [N] Mle-----------: Attach attempt 0, BetterPartition 
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.919 [N] Mle-----------: Role leader -> detached
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.920 [N] Mle-----------: RLOC16 1c00 -> a402
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.925 [N] Mle-----------: Role detached -> child
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.943 [W] Platform------: Failed to update ipsets: Failed
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: [NOTE]-BBA-----: BackboneAgent: Backbone Router resigns Primary to Secondary!
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.977 [W] Platform------: [netif] Failed to process request#32: Unknown error -95
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.987 [W] Platform------: Failed to update ipsets: Failed
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.988 [W] Platform------: [netif] Failed to process request#33: Unknown error -95
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.989 [W] Platform------: [netif] Failed to process request#34: Unknown error -95
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.989 [W] Platform------: [netif] Failed to process request#36: Unknown error -95
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.990 [W] Platform------: [netif] Failed to process request#37: Unknown error -95
Sep 14 21:29:46 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:16.990 [W] Platform------: [netif] Failed to process request#38: Unknown error -95
Sep 14 21:29:48 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 21:29:48 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:18.151 [W] Platform------: Failed to update ipsets: Failed
Sep 14 21:29:48 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:18.153 [W] Platform------: [netif] Failed to process request#39: Unknown error -17
Sep 14 21:29:48 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:18.154 [W] Platform------: [netif] Failed to process request#40: Unknown error -17
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.266 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:96, src:0x2000, dst:0xa402, tag:62264, offset:312, dglen:784, sec:yes
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.311 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:96, src:0x2000, dst:0xa402, tag:62264, offset:408, dglen:784, sec:yes
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.379 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:96, src:0x2000, dst:0xa402, tag:62264, offset:504, dglen:784, sec:yes
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.396 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:96, src:0x2000, dst:0xa402, tag:62264, offset:600, dglen:784, sec:yes
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.436 [N] MeshForwarder-: Dropping rx frag frame, error:Drop, len:88, src:0x2000, dst:0xa402, tag:62264, offset:696, dglen:784, sec:yes
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.948 [N] MeshForwarder-: Dropping (reassembly queue) IPv6 UDP msg, len:784, chksum:0ede, ecn:no, sec:yes, error:ReassemblyTimeout, prio:
normal, rss:-43.0
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.948 [N] MeshForwarder-:     src:[fda3:66a8:9144:7dd4:2d50:7c75:af74:92a]:49155
Sep 14 21:29:51 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:53:21.949 [N] MeshForwarder-:     dst:[fda3:66a8:9144:7dd4:7210:c4f9:5888:98e5]:53542

Possibly during power off of a device:

Sep 14 21:30:57 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:54:27.790 [N] MeshForwarder-: Dropping IPv6 UDP msg, len:252, chksum:e938, ecn:no, sec:yes, error:Drop, prio:low
Sep 14 21:30:57 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:54:27.790 [N] MeshForwarder-:     src:[fd49:44c9:7890:1:9c1d:fd39:3963:368e]:47409
Sep 14 21:30:57 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:54:27.791 [N] MeshForwarder-:     dst:[fd49:44c9:7890:1:b732:b285:b412:6a19]:5540
Sep 14 21:32:17 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 21:32:17 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:55:47.966 [W] Platform------: Failed to update ipsets: Failed
Sep 14 21:35:20 homeassistant addon_core_silabs_multiprotocol[614]: ipset v7.10: The set with the given name does not exist
Sep 14 21:35:20 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:50.451 [W] Platform------: Failed to update ipsets: Failed
Sep 14 21:35:20 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:50.452 [W] Platform------: [netif] Failed to process request#41: Unknown error -95
Sep 14 21:35:20 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:50.453 [W] Platform------: [netif] Failed to process request#42: Unknown error -95
Sep 14 21:35:24 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:54.550 [N] Ip6-----------: Failed to find valid route for: fd49:44c9:7890:1:dbd2:1374:2923:311f
Sep 14 21:35:24 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:54.550 [N] Ip6-----------: Failed to find valid route for: fd49:44c9:7890:1:dbd2:1374:2923:311f
Sep 14 21:35:24 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:54.551 [N] Ip6-----------: Failed to find valid route for: fd49:44c9:7890:1:dbd2:1374:2923:311f
Sep 14 21:35:24 homeassistant addon_core_silabs_multiprotocol[614]: otbr-agent[305]: 00:58:54.551 [N] Ip6-----------: Failed to find valid route for: fd49:44c9:7890:1:dbd2:1374:2923:311f

Additional information

No response

fuomag9 commented 1 year ago

I have the same issue

otbr-agent[303]: 00:00:27.167 [N] Mle-----------: RLOC16 8000 -> fffe
otbr-agent[303]: 00:00:27.170 [W] Platform------: [netif] Failed to process request#5: Unknown error -95
otbr-agent[303]: 00:00:27.424 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[303]: 00:00:33.926 [N] RouterTable---: Allocate router id 32
otbr-agent[303]: 00:00:33.926 [N] Mle-----------: RLOC16 fffe -> 8000
otbr-agent[303]: 00:00:33.929 [N] Mle-----------: Role detached -> leader
otbr-agent[303]: 00:00:33.930 [N] Mle-----------: Partition ID 0xbd9a83a
ipset v7.10: The set with the given name does not exist
otbr-agent[303]: 00:00:33.946 [W] Platform------: Failed to update ipsets: Failed
otbr-agent[303]: 00:00:33.966 [W] Platform------: [netif] Failed to process request#6: Unknown error -17
ipset v7.10: The set with the given name does not exist
otbr-agent[303]: 00:00:34.373 [W] Platform------: Failed to update ipsets: Failed
ipset v7.10: The set with the given name does not exist
otbr-agent[303]: 00:00:34.686 [W] Platform------: Failed to update ipsets: Failed
otbr-agent[303]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
ipset v7.10: The set with the given name does not exist
otbr-agent[303]: 00:00:36.000 [W] Platform------: Failed to update ipsets: Failed
ipset v7.10: The set with the given name does not exist
otbr-agent[303]: 00:00:43.815 [W] Platform------: Failed to update ipsets: Failed
darkevilmac commented 11 months ago

Having the same issue here, not sure if this is a Home-Assistant setup issue or an issue with my router config. I'm running TP-Link Omada hardware and have home-assistant os running in a KVM with a physical network adapter passed through and setup as the default.

Logs look nearly identical:

s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
s6-rc: info: service otbr-web: starting
s6-rc: info: service otbr-web successfully started
[08:13:25] INFO: Starting otbr-web...
otbr-web[242]: [INFO]-WEB-----: Running 0.3.0-9e50efa-dirty
otbr-web[242]: [INFO]-WEB-----: Border router web started on wpan0
[08:13:26] 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
otbr-agent[180]: 00:00:25.119 [N] Mle-----------: RLOC16 a000 -> fffe
otbr-agent[180]: 00:00:25.122 [W] Platform------: [netif] Failed to process request#5: Operation not supported
otbr-agent[180]: 00:00:25.564 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
otbr-agent[180]: 00:00:32.067 [N] RouterTable---: Allocate router id 40
otbr-agent[180]: 00:00:32.069 [N] Mle-----------: RLOC16 fffe -> a000
otbr-agent[180]: 00:00:32.071 [N] Mle-----------: Role detached -> leader
otbr-agent[180]: 00:00:32.079 [N] Mle-----------: Partition ID 0x76776044
ipset v7.10: The set with the given name does not exist
otbr-agent[180]: 00:00:32.131 [W] Platform------: Failed to update ipsets: Failed
otbr-agent[180]: 00:00:32.147 [W] Platform------: [netif] Failed to process request#6: File exists
ipset v7.10: The set with the given name does not exist
otbr-agent[180]: 00:00:32.202 [W] Platform------: Failed to update ipsets: Failed
otbr-agent[180]: [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
ipset v7.10: The set with the given name does not exist
otbr-agent[180]: 00:00:34.452 [W] Platform------: Failed to update ipsets: Failed
ipset v7.10: The set with the given name does not exist
otbr-agent[180]: 00:00:35.997 [W] Platform------: Failed to update ipsets: Failed
ipset v7.10: The set with the given name does not exist
otbr-agent[180]: 00:00:44.635 [W] Platform------: Failed to update ipsets: Failed
github-actions[bot] commented 10 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.

Gillingham commented 10 months ago

have home-assistant os running in a KVM with a physical network adapter passed through and setup as the default.

Same thing here, same error message.

fischer404 commented 10 months ago

Is there any update? because I ran in the same error.

github-actions[bot] commented 9 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.

eiten commented 7 months ago

Same error messages on my system

QuentinCaldeira commented 7 months ago

Same here on raspberry pi 4 + HAOS + nrf52840 otbr

chriswoj commented 6 months ago

up

colinnewman2000 commented 6 months ago

This is still a problem at the moment.

MattWestb commented 4 months ago

If reading the error message: Failed to update ipsets: Failed ipset v7.10: The set with the given name does not exist is the system trying updating one IP-Set = OK if its already defined.

Then the system is starting the OS is not having custom IP-Sets loaded so first need adding the set it with the first use of it and after that using update all the time. So its looks some have making bad coding here (Silabs standard ?).

irayfuego commented 1 month ago

not stale