search

home-assistant-libs / python-matter-server

Python server to interact with Matter
Apache License 2.0
519 stars 79 forks source link

TrueNAS container install: Address already in use, but 5580 is not in use #982

Open Fuergrissa1 opened 2 days ago

Fuergrissa1 commented 2 days ago

I've been trying to work through this issue on the HA discord and have run out of ideas. No matter what I have tried, launching the container always produces this error.

2024-11-30 17:46:19.853 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Logging...
2024-11-30 17:46:19.853 (MainThread) INFO [matter_server.server.stack] Initializing CHIP/Matter Controller Stack...
[1732988779.865749][1:1] CHIP:CTL: Setting attestation nonce to random value
[1732988779.865897][1:1] CHIP:CTL: Setting CSR nonce to random value
[1732988779.866513][1:1] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1732988779.866683][1:1] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_factory.ini
[1732988779.866771][1:1] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_config.ini
[1732988779.866785][1:1] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /data/chip_counters.ini
[1732988779.866911][1:1] CHIP:DL: writing settings to file (/data/chip_counters.ini-hJdIe3)
[1732988779.866978][1:1] CHIP:DL: renamed tmp file to file (/data/chip_counters.ini)
[1732988779.866980][1:1] CHIP:DL: NVS set: chip-counters/reboot-count = 1064 (0x428)
[1732988779.867268][1:1] CHIP:DL: Got Ethernet interface: enp88s0
[1732988779.867406][1:1] CHIP:DL: Found the primary Ethernet interface:enp88s0
[1732988779.867675][1:1] CHIP:DL: Failed to get WiFi interface
[1732988779.867678][1:1] CHIP:DL: Failed to reset WiFi statistic counts
2024-11-30 17:46:19.867 (MainThread) INFO [chip.storage] Initializing persistent storage from file: /root/.matter_server/chip.json
2024-11-30 17:46:19.868 (MainThread) INFO [chip.storage] Loading configuration from /root/.matter_server/chip.json...
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] UDP::Init bind&listen port=0
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] UDP::Init bound to port=42921
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] UDP::Init bind&listen port=0
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] UDP::Init bound to port=51383
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] BLEBase::Init - setting/overriding transport
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.IN] TransportMgr initialized
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.FP] Initializing FabricTable from persistent storage
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = g/lkgt, Value = 0x7ffe839f4b40 (18)
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] Key Found 8

2024-11-30 17:46:19.868 (MainThread) CHIP_PROGRESS [chip.native.TS] Last Known Good Time: 2023-10-14T01:16:48
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = g/fidx, Value = 0x7ffe839f4d10 (44)
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] Key Not Found

2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = g/fs/c, Value = 0x7ffe839f4bb0 (36)
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] Key Not Found

2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = g/gcc, Value = 0x7ffe839f4c4c (4)
2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] Key Found 4

2024-11-30 17:46:19.868 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::GetKeyValue: Key = g/gdc, Value = 0x7ffe839f4c4c (4)
2024-11-30 17:46:19.869 (MainThread) CHIP_DETAIL [chip.native.CTL] Key Found 4

2024-11-30 17:46:19.869 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::SetKeyValue: Key = g/gcc, Value = 0x7ffe839f4c4c (4)
2024-11-30 17:46:19.869 (MainThread) CHIP_DETAIL [chip.native.CTL] StorageAdapter::SetKeyValue: Key = g/gdc, Value = 0x7ffe839f4c4c (4)
2024-11-30 17:46:19.869 (MainThread) CHIP_PROGRESS [chip.native.ZCL] Using ZAP configuration...
2024-11-30 17:46:19.869 (MainThread) ERROR [root] Uncaught exception
Traceback (most recent call last):
  File "/usr/local/bin/matter-server", line 8, in <module>
    sys.exit(main())
             ^^^^^^
  File "/usr/local/lib/python3.12/site-packages/matter_server/server/__main__.py", line 220, in main
    server = MatterServer(
             ^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/matter_server/server/server.py", line 138, in __init__
    self.stack = MatterStack(self, bluetooth_adapter_id, enable_server_interactions)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/matter_server/server/stack.py", line 120, in __init__
    self._chip_stack = ChipStack(
                       ^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/chip/ChipStack.py", line 60, in wrapper
    instance[0] = cls(*args, **kwargs)
                  ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/chip/ChipStack.py", line 172, in __init__
    res.raise_on_error()
  File "/usr/local/lib/python3.12/site-packages/chip/native/__init__.py", line 87, in raise_on_error
    raise self.to_exception()
chip.exceptions.ChipStackError: src/inet/UDPEndPointImplSockets.cpp:144: OS Error 0x02000062: Address already in use

I have used netstat -tuln | grep udp to check ports in use but 5580, and the random ports that appear in the log (42921 and 51383 in this instance, but it changes each time) never appear to have conflicts with any other services.

The logs also always show that the interface enp88s0 is selcted as the default, but this was not the interface that I have been using. No commands (--primary-interface enp89s0) added to the docker compose yaml, or attempting to launch using docker commands from the command line will change that enp88s0 always appears in the logs. So I gave up and switched to using enp88s0, but I still get the address in use error.

Here is the yaml for launching the container

services:
  python-matter-server:
    command:
      - '--log-level-sdk'
      - detail
      - '--port'
      - '5580'
      - '--primary-interface'
      - enp89s0
    container_name: matter-server
    environment:
      - LOG_LEVEL=DEBUG
    image: ghcr.io/home-assistant-libs/python-matter-server:stable
    network_mode: host
    restart: unless-stopped
    security_opt:
      - apparmor=unconfined
    volumes:
      - /mnt/store_nvme/app_data/homeassistant/matter_server:/data
      - /run/dbus:/run/dbus:ro
aj2012 commented 2 days ago

Literally working on the exact same issue with truenas scale right now, tried various versions all the way down to v5, and also verifed 5580 is not in use.