search

home-assistant-libs / python-matter-server

Python server to interact with Matter
Apache License 2.0
495 stars 77 forks source link

Python Matter Server doesn't show up over LAN via macvlan network. #347

Closed S0ulf3re closed 1 year ago

S0ulf3re commented 1 year ago

I've been discussing this in the HA Discord. But I'm just gonna write it here so it can get a bit more attention by others. I've been trying to commission a TP-Link Tapo P125M Wi-Fi Smart Plug to my Home Assistant Container instance running the docker image for the Python Matter Server exposed to my LAN over a macvlan network alongside a few other things on it. However, whenever I view all exisitng mDNS entries on my network, the Matter Server doesn't show up as a _matter._tcp. entry. And any attempts to commission the device fail with the Python Matter Server complaining about timing out with mDNS resolution.

2023-06-30 12:05:43 matter-server chip.CTL[1] DEBUG Key Found 97
2023-06-30 12:05:43 matter-server chip.CTL[1] DEBUG StorageAdapter::SetKeyValue: Key = f/1/k/0, Value = 0x7f11537fca30 (97)
2023-06-30 12:05:43 matter-server PersistentStorage[1] INFO SetSdkKey: f/1/k/0 = b'\x15$\x01\x00$\x02\x016\x03\x15$\x04\x00%\x05\x80\x070\x06\x10\xf2\x1b\xe1\xd8\x8c\xe3\xce\x18fH\x94O\xbe}m\x92\x18\x15$\x04\x00$\x05\x000\x06\x10\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18\x15$\x04\x00$\x05\x000\x06\x10\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x18\x18%\x07\xff\xff\x18'
2023-06-30 12:05:43 matter-server PersistentStorage[1] INFO Committing...
2023-06-30 12:05:43 matter-server matter_server.server.device_controller[1] DEBUG CHIP Device Controller Initialized
2023-06-30 12:05:43 matter-server matter_server.server.storage[1] DEBUG Loading persistent settings from /data/3126079813310142521.json
2023-06-30 12:05:43 matter-server matter_server.server.storage[1] DEBUG Started.
2023-06-30 12:05:43 matter-server matter_server.server.device_controller[1] DEBUG Loaded 0 nodes
2023-06-30 12:05:43 matter-server matter_server.server.vendor_info[1] INFO Loading vendor info from storage.
2023-06-30 12:05:43 matter-server matter_server.server.vendor_info[1] INFO Loaded 81 vendors from storage.
2023-06-30 12:05:43 matter-server matter_server.server.vendor_info[1] INFO Fetching the latest vendor info from DCL.
2023-06-30 12:05:44 matter-server matter_server.server.vendor_info[1] INFO Fetched 81 vendors from DCL.
2023-06-30 12:05:44 matter-server matter_server.server.vendor_info[1] INFO Saving vendor info to storage.
2023-06-30 12:05:44 matter-server matter_server.server.server[1] DEBUG Webserver initialized.
2023-06-30 12:05:45 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Connected from 192.168.1.2
2023-06-30 12:05:45 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Received: {
  "message_id": "4ede87e77e4547c08ea93ccbaf271016",
  "command": "start_listening",
  "args": null
}
2023-06-30 12:05:45 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Received CommandMessage(message_id='4ede87e77e4547c08ea93ccbaf271016', command='start_listening', args=None)
2023-06-30 12:05:45 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Handling command start_listening
2023-06-30 12:06:59 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Received: {
  "message_id": "a412eea54196475798b185b14796e63b",
  "command": "commission_with_code",
  "args": {
    "code": "10232554859"
  }
}
2023-06-30 12:06:59 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Received CommandMessage(message_id='a412eea54196475798b185b14796e63b', command='commission_with_code', args={'code': '10232554859'})
2023-06-30 12:06:59 matter-server matter_server.server.client_handler[1] DEBUG [139712493335184] Handling command commission_with_code
2023-06-30 12:06:59 matter-server matter_server.server.helpers.paa_certificates[1] INFO Fetching the latest PAA root certificates from DCL.
2023-06-30 12:07:00 matter-server matter_server.server.helpers.paa_certificates[1] INFO Fetched 0 PAA root certificates from DCL.
2023-06-30 12:07:00 matter-server matter_server.server.helpers.paa_certificates[1] INFO Fetching the latest PAA root certificates from Git.
2023-06-30 12:07:00 matter-server matter_server.server.helpers.paa_certificates[1] INFO Fetched 0 PAA root certificates from Git.
2023-06-30 12:07:00 matter-server chip.CTL[1] INFO Setting attestation nonce to random value
2023-06-30 12:07:00 matter-server chip.CTL[1] INFO Setting CSR nonce to random value
2023-06-30 12:07:00 matter-server chip.CTL[1] DEBUG Stopping commissioning discovery over DNS-SD
2023-06-30 12:07:00 matter-server chip.CTL[1] INFO Starting commissioning discovery over BLE
2023-06-30 12:07:00 matter-server chip.CTL[1] INFO Starting commissioning discovery over DNS-SD
2023-06-30 12:07:00 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth0:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:00 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth1:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address

2023-06-30 12:07:00 matter-server matter_server.server.storage[1] DEBUG Saved data to persistent storage
2023-06-30 12:07:00 matter-server chip.DL[1] DEBUG TRACE: Bus acquired for name C-0001
2023-06-30 12:07:00 matter-server chip.DL[1] DEBUG PlatformBlueZInit init success
2023-06-30 12:07:00 matter-server chip.BLE[1] INFO BLE removing known devices.
2023-06-30 12:07:00 matter-server chip.BLE[1] INFO BLE initiating scan.
2023-06-30 12:07:00 matter-server chip.DL[1] ERROR Long dispatch time: 144 ms, for event type 2
2023-06-30 12:07:01 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:01 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth0:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:01 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth1:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:01 matter-server chip.DIS[1] DEBUG mDNS broadcast had only partial success: 2 successes and 2 failures.
2023-06-30 12:07:01 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:02 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:03 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:03 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth0:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:03 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth1:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:03 matter-server chip.DIS[1] DEBUG mDNS broadcast had only partial success: 2 successes and 2 failures.
2023-06-30 12:07:04 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:04 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:04 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:04 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:04 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:05 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:05 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:05 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:06 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:06 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:06 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:07 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:07 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:07 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth0:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:07 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth1:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:07 matter-server chip.DIS[1] DEBUG mDNS broadcast had only partial success: 2 successes and 2 failures.
2023-06-30 12:07:08 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:10 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:10 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:10 matter-server chip.BLE[1] DEBUG Device F8:A2:6D:D6:73:93 does not look like a CHIP device.
2023-06-30 12:07:10 matter-server chip.BLE[1] ERROR BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
2023-06-30 12:07:10 matter-server chip.BLE[1] INFO Scan complete. No matching device found.
2023-06-30 12:07:15 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth0:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:15 matter-server chip.DIS[1] DEBUG Warning: Attempt to mDNS broadcast failed on eth1:  src/inet/UDPEndPointImplSockets.cpp:411: OS Error 0x02000063: Cannot assign requested address
2023-06-30 12:07:15 matter-server chip.DIS[1] DEBUG mDNS broadcast had only partial success: 2 successes and 2 failures.
2023-06-30 12:07:30 matter-server chip.CTL[1] ERROR Discovery timed out
2023-06-30 12:07:30 matter-server chip.CTL[1] DEBUG Stopping commissioning discovery over BLE
2023-06-30 12:07:30 matter-server chip.BLE[1] ERROR BleConnectionDelegate::CancelConnection is not implemented.
2023-06-30 12:07:30 matter-server chip.-[1] ERROR src/platform/Linux/BLEManagerImpl.cpp:732: CHIP Error 0x0000002D: Not Implemented at src/controller/SetUpCodePairer.cpp:551
2023-06-30 12:07:30 matter-server chip.CTL[1] DEBUG Stopping commissioning discovery over DNS-SD
2023-06-30 12:07:30 matter-server chip.ZCL[1] ERROR Secure Pairing Failed
2023-06-30 12:07:30 matter-server matter_server.server.client_handler[1] ERROR [139712493335184] Error handling message: CommandMessage(message_id='a412eea54196475798b185b14796e63b', command='commission_with_code', args={'code': '10232554859'})
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/matter_server/server/client_handler.py", line 188, in _run_handler
    result = await result
             ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/matter_server/server/device_controller.py", line 172, in commission_with_code
    raise NodeCommissionFailed(
matter_server.common.errors.NodeCommissionFailed: Commission with code failed for node 10
2023-06-30 12:07:31 matter-server chip.DIS[1] ERROR Timeout waiting for mDNS resolution.

A few other things in these debug logs that concern me:

  1. The logs are claiming that there is an eth0 and an eth1, but at the moment. The only ethernet port on my host machine is an ethernet interface labeled enp2s0
  2. The logs are complaining about being unable to assign the requested address
  3. Another thing, mainly because it seems to have caught Marcelveldt's eye in the Discord matter channel as being a big offender 
    2023-06-30 12:07:00 matter-server chip.DIS[1] DEBUG mDNS broadcast had only partial success: 2 successes and 2 failures.

The smart plug is currently commissioned to Apple Home and Google Home without any issues. And both the Home Assistant Container instance and Python Matter Server are running on the same device, and are connected to the same LAN that the P125M is on.

My network is currently managed by a Pfsense firewall running version 2.6.0 that has the WAN set to DHCP/DHCP6 and the LAN set to a static ipv6/track interface of WAN for ipv6. Avahi is currently installed and enabled, and set to repeat packets across subnets for a few extra IoT devices on another network.

And here is my docker compose for the Matter server and macvlan:


networks:
  a-lan:
    driver: macvlan
    driver_opts:
      parent: enp2s0
    ipam:
      config:
        - subnet: 192.168.1.0/24
          gateway: 192.168.1.1
        - subnet: xxxx:xxxx:xxxx:948::/64
          gateway: fe80::xxxx:xxxx:fe70:c331

services:
  matter-server:
    hostname: matter-server
    mac_address: D2-C8-9C-B1-50-2A
    image: ghcr.io/home-assistant-libs/python-matter-server:stable
    container_name: matter-server
    command: "--log-level debug"
    restart: unless-stopped
    # Required for mDNS to work correctly
    security_opt:
      - apparmor:unconfined
    volumes:
      - /docker/home-assistant/python-matter-server/data:/data/
      - /run/dbus:/run/dbus:ro
    ports:
      - 5580:5580
    networks:
      homeassistant:
      a-lan:
        ipv4_address: 192.168.1.4
        ipv6_address: 'xxxx:xxxx:xxxx:948:1335:ad2d:8def:1b3f'
S0ulf3re commented 1 year ago

Ok, So I made sure to turn off mDNS repeating like the documentation says to within the Avahi package. But I am still not getting any different results

S0ulf3re commented 1 year ago

I was never able to fix this, so I just ended up switching to the raspberry pi. I apologize to anyone who might have found this via search engine :(