Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SYMFONISK sound remote gen2 - sporadically no commands can be sent - await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) #131387

Open
Matze89x opened this issue Nov 23, 2024 · 8 comments

Comments

@Matze89x
Copy link

Matze89x commented Nov 23, 2024

The problem

Hello to you,

I just posted this on Zigpy... I think it was a bit inappropriate there. That's why I've made up for it here. zigpy/zigpy#1506

I've had a serious problem since a few updates (unfortunately I can't remember exactly when).

I can't use the remote control all the time. Every 30 minutes it seems to lose the connection for 10 minutes and then it can be reached again normally and the commands are sent to Skyconnect again. However, if I do the identification test, it works in Home Assistant.

I would also like to say that I have owned the remote control for several months and it has always worked reliably. We've had less time in the last few weeks and therefore haven't used it as regularly. Now in the cold season it has been used more frequently and the function has failed again and again.

image image
It concerns the remote control from Ikea.
SYMFONISK sound remote gen2
from IKEA of Sweden
Installed version - 0x01000035
IEEE: 1c:34:f1:ff:fe:a2:7a:6e
Nwk: 0xcd1c
Device Type: EndDevice
LQI: 196
RSSI: -62

Connected via:
SkyConnect v1.0
from Nabu Casa
Firmware: 7.4.4.0 build 0

I have already tried the following:

  • Removed all devices (sockets) that also pair with the remote control.
  • Reset the remote control and re-paired it several times.
  • I have already moved the Skyconnect stick to another location using extension cables.
  • Paired the remote control via another system as a test
  • Already changed channel 25 to 18 for the entire network
  • No WLAN interference in the network - everything is OK - other devices (35) work perfectly.
  • Also tested a migration from SkyConnect to SONOFF Dongle-E - same problems.
  • I have already changed the batteries twice.
  • I paired the remote control on my Linux system with Zigbee2MQTT as a test and used it to forward some commands over the course of a day - no problems. I wanted to know whether the remote control might be faulty.

Here is the protocol that is constantly forming during the day... over 60x

Logger: zigpy.zcl
Quelle: runner.py:189
Erstmals aufgetreten: 13:46:54 (10 Vorkommnisse)
Zuletzt protokolliert: 18:22:03

[0xCD1C:1:0x0020] Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 270, in request return await self.device.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 378, in request await send_request() File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 825, in request await self.send_packet( File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 824, in send_packet raise zigpy.exceptions.DeliveryError( zigpy.exceptions.DeliveryError: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074> The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/general.py", line 630, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 84, in wrapper with wrap_zigpy_exceptions(): File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__ self.gen.throw(value) File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 76, in wrap_zigpy_exceptions raise ZHAException(message) from exc zha.exceptions.ZHAException: Failed to send request: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074>
[0xCD1C:1:0x0020] Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 381, in request return await req.result ^^^^^^^^^^^^^^^^ asyncio.exceptions.CancelledError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 375, in request return await self._endpoint.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 270, in request return await self.device.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 380, in request async with asyncio_timeout(timeout): File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__ raise TimeoutError from exc_val TimeoutError The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/general.py", line 630, in check_in_response await self.checkin_response(True, self.CHECKIN_FAST_POLL_TIMEOUT, tsn=tsn) File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 84, in wrapper with wrap_zigpy_exceptions(): File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__ self.gen.throw(value) File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 69, in wrap_zigpy_exceptions raise ZHAException("Failed to send request: device did not respond") from exc zha.exceptions.ZHAException: Failed to send request: device did not respond
[0xCD1C:1:0x0020] Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 270, in request return await self.device.request( ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 378, in request await send_request() File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 825, in request await self.send_packet( File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 824, in send_packet raise zigpy.exceptions.DeliveryError( zigpy.exceptions.DeliveryError: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074> The above exception was the direct cause of the following exception: Traceback (most recent call last): File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/general.py", line 633, in check_in_response await self.fast_poll_stop() File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 84, in wrapper with wrap_zigpy_exceptions(): File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__ self.gen.throw(value) File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 76, in wrap_zigpy_exceptions raise ZHAException(message) from exc zha.exceptions.ZHAException: Failed to send request: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074>

image

I would really appreciate your help. I'm really at a loss as to what's going on here. I'm also watching the visualisation - everything is OK and connects to other sockets in the household from time to time. TS011F
from _TZ3000_u5u4cakc

What version of Home Assistant Core has the issue?

core-2024.11.3

What was the last working version of Home Assistant Core?

core-2024.10

What type of installation are you running?

Home Assistant OS

Integration causing the issue

ZHA

Link to integration documentation on our website

No response

Diagnostics information

{
  "home_assistant": {
    "installation_type": "Home Assistant OS",
    "version": "2024.11.3",
    "dev": false,
    "hassio": true,
    "virtualenv": false,
    "python_version": "3.12.4",
    "docker": true,
    "arch": "aarch64",
    "timezone": "Europe/Berlin",
    "os_name": "Linux",
    "os_version": "6.6.31-haos-raspi",
    "supervisor": "2024.11.4",
    "host_os": "Home Assistant OS 13.2",
    "docker_version": "27.2.0",
    "chassis": "embedded",
    "run_as_root": true
  },
  "custom_components": {
    "home_connect_alt": {
      "documentation": "https://github.com/ekutner/home-connect-hass",
      "version": "1.1.9",
      "requirements": [
        "home-connect-async==0.8.0"
      ]
    },
    "alexa_media": {
      "documentation": "https://github.com/alandtse/alexa_media_player/wiki",
      "version": "4.13.8",
      "requirements": [
        "alexapy==1.29.4",
        "packaging>=20.3",
        "wrapt>=1.14.0"
      ]
    },
    "powercalc": {
      "documentation": "https://docs.powercalc.nl",
      "version": "v1.15.4",
      "requirements": [
        "numpy>=1.21.1"
      ]
    },
    "hacs": {
      "documentation": "https://hacs.xyz/docs/configuration/start",
      "version": "2.0.1",
      "requirements": [
        "aiogithubapi>=22.10.1"
      ]
    },
    "hyperhdr": {
      "documentation": "https://github.com/awawa-dev/HyperHDR#readme",
      "version": "0.0.7",
      "requirements": [
        "hyperhdr-py==0.0.3"
      ]
    },
    "bosch_shc": {
      "documentation": "https://github.com/tschamm/boschshc-hass/blob/master/README.md",
      "version": "0.4.92",
      "requirements": [
        "boschshcpy==0.2.95"
      ]
    },
    "delete": {
      "documentation": "https://github.com/chomupashchuk/delete-file-home-assistant",
      "version": "1.9",
      "requirements": []
    }
  },
  "integration_manifest": {
    "domain": "zha",
    "name": "Zigbee Home Automation",
    "after_dependencies": [
      "hassio",
      "onboarding",
      "usb"
    ],
    "codeowners": [
      "dmulcahey",
      "adminiuga",
      "puddly",
      "TheJulianJES"
    ],
    "config_flow": true,
    "dependencies": [
      "file_upload"
    ],
    "documentation": "https://www.home-assistant.io/integrations/zha",
    "iot_class": "local_polling",
    "loggers": [
      "aiosqlite",
      "bellows",
      "crccheck",
      "pure_pcapy3",
      "zhaquirks",
      "zigpy",
      "zigpy_deconz",
      "zigpy_xbee",
      "zigpy_zigate",
      "zigpy_znp",
      "zha",
      "universal_silabs_flasher"
    ],
    "requirements": [
      "universal-silabs-flasher==0.0.25",
      "zha==0.0.39"
    ],
    "usb": [
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*2652*",
        "known_devices": [
          "slae.sh cc2652rb stick"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*slzb-07*",
        "known_devices": [
          "smlight slzb-07"
        ]
      },
      {
        "vid": "1A86",
        "pid": "55D4",
        "description": "*sonoff*plus*",
        "known_devices": [
          "sonoff zigbee dongle plus v2"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*sonoff*plus*",
        "known_devices": [
          "sonoff zigbee dongle plus"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*tubeszb*",
        "known_devices": [
          "TubesZB Coordinator"
        ]
      },
      {
        "vid": "1A86",
        "pid": "7523",
        "description": "*tubeszb*",
        "known_devices": [
          "TubesZB Coordinator"
        ]
      },
      {
        "vid": "1A86",
        "pid": "7523",
        "description": "*zigstar*",
        "known_devices": [
          "ZigStar Coordinators"
        ]
      },
      {
        "vid": "1CF1",
        "pid": "0030",
        "description": "*conbee*",
        "known_devices": [
          "Conbee II"
        ]
      },
      {
        "vid": "0403",
        "pid": "6015",
        "description": "*conbee*",
        "known_devices": [
          "Conbee III"
        ]
      },
      {
        "vid": "10C4",
        "pid": "8A2A",
        "description": "*zigbee*",
        "known_devices": [
          "Nortek HUSBZB-1"
        ]
      },
      {
        "vid": "0403",
        "pid": "6015",
        "description": "*zigate*",
        "known_devices": [
          "ZiGate+"
        ]
      },
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*zigate*",
        "known_devices": [
          "ZiGate"
        ]
      },
      {
        "vid": "10C4",
        "pid": "8B34",
        "description": "*bv 2010/10*",
        "known_devices": [
          "Bitron Video AV2010/10"
        ]
      }
    ],
    "zeroconf": [
      {
        "type": "_esphomelib._tcp.local.",
        "name": "tube*"
      },
      {
        "type": "_zigate-zigbee-gateway._tcp.local.",
        "name": "*zigate*"
      },
      {
        "type": "_zigstar_gw._tcp.local.",
        "name": "*zigstar*"
      },
      {
        "type": "_uzg-01._tcp.local.",
        "name": "uzg-01*"
      },
      {
        "type": "_slzb-06._tcp.local.",
        "name": "slzb-06*"
      },
      {
        "type": "_xzg._tcp.local.",
        "name": "xzg*"
      },
      {
        "type": "_czc._tcp.local.",
        "name": "czc*"
      }
    ],
    "is_built_in": true,
    "overwrites_built_in": false
  },
  "setup_times": {
    "null": {
      "setup": 0.00014273599998659847
    },
    "c2dc01141cbd11c527bc02aa1f7d887a": {
      "wait_import_platforms": -0.0749319329999878,
      "wait_base_component": -0.002764165999991519,
      "config_entry_setup": 23.01430604699999
    }
  },
  "data": {
    "config": {
      "zigpy_config": {
        "ota": {
          "otau_directory": "/config/zigpy_ota",
          "extra_providers": [
            {
              "type": "ikea"
            },
            {
              "type": "inovelli"
            },
            {
              "type": "ledvance"
            },
            {
              "type": "salus"
            },
            {
              "type": "sonoff"
            },
            {
              "type": "thirdreality"
            }
          ]
        }
      },
      "enable_quirks": true,
      "custom_quirks_path": "/config/zhaquirks",
      "device_config": {
        "a4:c1:38:34:04:f7:ae:5a-1": {
          "type": "switch"
        },
        "a4:c1:38:cc:78:20:c0:f8-1": {
          "type": "switch"
        }
      }
    },
    "config_entry": {
      "created_at": "1970-01-01T00:00:00+00:00",
      "data": {
        "device": {
          "baudrate": 115200,
          "flow_control": null,
          "path": "/dev/serial/by-id/usb-Nabu_Casa_SkyConnect_v1.0_8eacad668c18ec11945bee9a47486eb0-if00-port0"
        },
        "radio_type": "ezsp"
      },
      "discovery_keys": {},
      "disabled_by": null,
      "domain": "zha",
      "entry_id": "c2dc01141cbd11c527bc02aa1f7d887a",
      "minor_version": 1,
      "modified_at": "2024-11-23T08:53:14.180849+00:00",
      "options": {},
      "pref_disable_new_entities": false,
      "pref_disable_polling": false,
      "source": "usb",
      "title": "Home Assistant ZHA",
      "unique_id": "**REDACTED**",
      "version": 4
    },
    "application_state": {
      "node_info": {
        "nwk": 0,
        "ieee": "**REDACTED**",
        "logical_type": 0,
        "model": "SkyConnect v1.0",
        "manufacturer": "Nabu Casa",
        "version": "7.4.4.0 build 0"
      },
      "network_info": {
        "extended_pan_id": "**REDACTED**",
        "pan_id": 12789,
        "nwk_update_id": 0,
        "nwk_manager_id": 0,
        "channel": 18,
        "channel_mask": 134215680,
        "security_level": 5,
        "network_key": "**REDACTED**",
        "tc_link_key": {
          "key": [
            90,
            105,
            103,
            66,
            101,
            101,
            65,
            108,
            108,
            105,
            97,
            110,
            99,
            101,
            48,
            57
          ],
          "tx_counter": 0,
          "rx_counter": 0,
          "seq": 0,
          "partner_ieee": "**REDACTED**"
        },
        "key_table": [],
        "children": [],
        "nwk_addresses": {},
        "stack_specific": {
          "ezsp": {
            "hashed_tclk": "009ed9e623ba42f33a6f019b5440a7a5"
          }
        },
        "metadata": {
          "ezsp": {
            "stack_version": 13,
            "can_burn_userdata_custom_eui64": true,
            "can_rewrite_custom_eui64": true
          }
        },
        "source": "[email protected]"
      },
      "counters": {
        "ezsp_counters": {
          "MAC_RX_BROADCAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_RX_BROADCAST', _raw_value=3146, reset_count=16, _last_reset_value=66997)"
          },
          "MAC_TX_BROADCAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_TX_BROADCAST', _raw_value=1328, reset_count=16, _last_reset_value=18642)"
          },
          "MAC_RX_UNICAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_RX_UNICAST', _raw_value=2545, reset_count=16, _last_reset_value=81605)"
          },
          "MAC_TX_UNICAST_SUCCESS": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_TX_UNICAST_SUCCESS', _raw_value=1768, reset_count=16, _last_reset_value=54403)"
          },
          "MAC_TX_UNICAST_RETRY": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_TX_UNICAST_RETRY', _raw_value=81, reset_count=16, _last_reset_value=18313)"
          },
          "MAC_TX_UNICAST_FAILED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='MAC_TX_UNICAST_FAILED', _raw_value=5, reset_count=16, _last_reset_value=3562)"
          },
          "APS_DATA_RX_BROADCAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_RX_BROADCAST', _raw_value=3, reset_count=16, _last_reset_value=935)"
          },
          "APS_DATA_TX_BROADCAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_TX_BROADCAST', _raw_value=3, reset_count=16, _last_reset_value=935)"
          },
          "APS_DATA_RX_UNICAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_RX_UNICAST', _raw_value=1466, reset_count=16, _last_reset_value=45447)"
          },
          "APS_DATA_TX_UNICAST_SUCCESS": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_TX_UNICAST_SUCCESS', _raw_value=927, reset_count=16, _last_reset_value=27503)"
          },
          "APS_DATA_TX_UNICAST_RETRY": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_TX_UNICAST_RETRY', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "APS_DATA_TX_UNICAST_FAILED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DATA_TX_UNICAST_FAILED', _raw_value=86, reset_count=16, _last_reset_value=2293)"
          },
          "ROUTE_DISCOVERY_INITIATED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ROUTE_DISCOVERY_INITIATED', _raw_value=12, reset_count=16, _last_reset_value=758)"
          },
          "NEIGHBOR_ADDED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='NEIGHBOR_ADDED', _raw_value=86, reset_count=16, _last_reset_value=2739)"
          },
          "NEIGHBOR_REMOVED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='NEIGHBOR_REMOVED', _raw_value=86, reset_count=16, _last_reset_value=2723)"
          },
          "NEIGHBOR_STALE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='NEIGHBOR_STALE', _raw_value=83, reset_count=16, _last_reset_value=3103)"
          },
          "JOIN_INDICATION": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='JOIN_INDICATION', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "CHILD_REMOVED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='CHILD_REMOVED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "ASH_OVERFLOW_ERROR": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ASH_OVERFLOW_ERROR', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "ASH_FRAMING_ERROR": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ASH_FRAMING_ERROR', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "ASH_OVERRUN_ERROR": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ASH_OVERRUN_ERROR', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "NWK_FRAME_COUNTER_FAILURE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='NWK_FRAME_COUNTER_FAILURE', _raw_value=21, reset_count=16, _last_reset_value=2738)"
          },
          "APS_FRAME_COUNTER_FAILURE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_FRAME_COUNTER_FAILURE', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "UTILITY": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='UTILITY', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "APS_LINK_KEY_NOT_AUTHORIZED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_LINK_KEY_NOT_AUTHORIZED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "NWK_DECRYPTION_FAILURE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='NWK_DECRYPTION_FAILURE', _raw_value=320, reset_count=16, _last_reset_value=4720)"
          },
          "APS_DECRYPTION_FAILURE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='APS_DECRYPTION_FAILURE', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "ALLOCATE_PACKET_BUFFER_FAILURE": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ALLOCATE_PACKET_BUFFER_FAILURE', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "RELAYED_UNICAST": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='RELAYED_UNICAST', _raw_value=0, reset_count=16, _last_reset_value=9)"
          },
          "PHY_TO_MAC_QUEUE_LIMIT_REACHED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PHY_TO_MAC_QUEUE_LIMIT_REACHED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PACKET_VALIDATE_LIBRARY_DROPPED_COUNT": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PACKET_VALIDATE_LIBRARY_DROPPED_COUNT', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "TYPE_NWK_RETRY_OVERFLOW": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='TYPE_NWK_RETRY_OVERFLOW', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PHY_CCA_FAIL_COUNT": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PHY_CCA_FAIL_COUNT', _raw_value=8, reset_count=16, _last_reset_value=139)"
          },
          "BROADCAST_TABLE_FULL": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='BROADCAST_TABLE_FULL', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_LO_PRI_REQUESTED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_LO_PRI_REQUESTED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_HI_PRI_REQUESTED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_HI_PRI_REQUESTED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_LO_PRI_DENIED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_LO_PRI_DENIED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_HI_PRI_DENIED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_HI_PRI_DENIED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_LO_PRI_TX_ABORTED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_LO_PRI_TX_ABORTED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "PTA_HI_PRI_TX_ABORTED": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='PTA_HI_PRI_TX_ABORTED', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "ADDRESS_CONFLICT_SENT": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='ADDRESS_CONFLICT_SENT', _raw_value=0, reset_count=16, _last_reset_value=0)"
          },
          "EZSP_FREE_BUFFERS": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='EZSP_FREE_BUFFERS', _raw_value=250, reset_count=16, _last_reset_value=0)"
          }
        },
        "controller_app_counters": {
          "unicast_rx": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='unicast_rx', _raw_value=46917, reset_count=0, _last_reset_value=0)"
          },
          "unicast_tx_success": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='unicast_tx_success', _raw_value=28431, reset_count=0, _last_reset_value=0)"
          },
          "broadcast_tx_success_unexpected": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='broadcast_tx_success_unexpected', _raw_value=938, reset_count=0, _last_reset_value=0)"
          },
          "unicast_tx_failure": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='unicast_tx_failure', _raw_value=2374, reset_count=0, _last_reset_value=0)"
          },
          "broadcast_rx": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='broadcast_rx', _raw_value=916, reset_count=0, _last_reset_value=0)"
          },
          "unicast_tx_failure_unexpected": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='unicast_tx_failure_unexpected', _raw_value=5, reset_count=0, _last_reset_value=0)"
          },
          "unicast_tx_success_unexpected": {
            "__type": "<class 'zigpy.state.Counter'>",
            "repr": "Counter(name='unicast_tx_success_unexpected', _raw_value=1, reset_count=0, _last_reset_value=0)"
          }
        }
      },
      "broadcast_counters": {},
      "device_counters": {},
      "group_counters": {}
    },
    "energy_scan": {
      "11": 52.75969252664325,
      "12": 49.512515447068886,
      "13": 49.512515447068886,
      "14": 33.860880820104335,
      "15": 25.74050169409602,
      "16": 6.011489450827149,
      "17": 10.914542804728702,
      "18": 25.74050169409602,
      "19": 5.317630506738386,
      "20": 12.244260188723507,
      "21": 59.15797905332195,
      "22": 7.659755505061292,
      "23": 1.5075412082833717,
      "24": 6.789392891308996,
      "25": 3.2311094587038967,
      "26": 97.7033852118351
    },
    "versions": {
      "bellows": "0.42.0",
      "zigpy": "0.72.0",
      "zigpy_deconz": "0.24.1",
      "zigpy_xbee": "0.21.0",
      "zigpy_znp": "0.13.1",
      "zigpy_zigate": "0.13.2",
      "zhaquirks": "0.0.124",
      "zha": "0.0.39"
    },
    "devices": [
      {
        "manufacturer": "Nabu Casa",
        "model": "SkyConnect v1.0",
        "logical_type": "Coordinator"
      },
      {
        "manufacturer": "_TZ3000_u5u4cakc",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_g5xawfcq",
        "model": "TS0121",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_u5u4cakc",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_g5xawfcq",
        "model": "TS0121",
        "logical_type": "Router"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.sensor_magnet.aq2",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.weather",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.vibration.aq1",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.sensor_magnet.aq2",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.sensor_magnet.aq2",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "_TZ3000_hdopuwv6",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZE204_nklqjk62",
        "model": "TS0601",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_u5u4cakc",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_mkhkxx1p",
        "model": "TS0001",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_46t1rvdu",
        "model": "TS0001",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_dowj6gyi",
        "model": "TS0201",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "_TZ3000_okaz9tjs",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_fukaa7nc",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_fukaa7nc",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_cjrngdr3",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.sensor_magnet.aq2",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "LUMI",
        "model": "lumi.weather",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "_TZ3000_5f43h46b",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_5f43h46b",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZE204_myd45weu",
        "model": "TS0601",
        "logical_type": "EndDevice"
      },
      {
        "manufacturer": "_TZ3000_5f43h46b",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_5f43h46b",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_hdopuwv6",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZE204_yojqa8xn",
        "model": "TS0601",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_okaz9tjs",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_okaz9tjs",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_tvuarksa",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "_TZ3000_okaz9tjs",
        "model": "TS011F",
        "logical_type": "Router"
      },
      {
        "manufacturer": "IKEA of Sweden",
        "model": "SYMFONISK sound remote gen2",
        "logical_type": "EndDevice"
      }
    ]
  }
}

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

@home-assistant
Copy link

Hey there @dmulcahey, @Adminiuga, @puddly, @TheJulianJES, mind taking a look at this issue as it has been labeled with an integration (zha) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of zha can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign zha Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


zha documentation
zha source
(message by IssueLinks)

@puddly
Copy link
Contributor

puddly commented Nov 23, 2024

I can't use the remote control all the time. Every 30 minutes it seems to lose the connection for 10 minutes and then it can be reached again normally and the commands are sent to Skyconnect again. However, if I do the identification test, it works in Home Assistant.

Do you mean that clicking buttons on the remote does not work reliably, but you can send commands to the remote?

Have you tried changing its battery?

@Matze89x
Copy link
Author

@puddly
That's right, I didn't even mention it. Yes, I have already changed the batteries twice. However, re-pairing also works (press 4 times).

Yes, pressing does not work reliably. However, I can initiate this identification in Home Assistant, which triggers a contact. This even changes the LQI and RSSI values.

@puddly
Copy link
Contributor

puddly commented Nov 23, 2024

When it stops working again, can you enable ZHA debug logging and try to click some buttons on the remote? Make sure to send an Identify command in the same debug log as well.

Thanks!

@Matze89x
Copy link
Author

Matze89x commented Nov 23, 2024

Here I show the real thing in use, which has just happened again. It's actually totally crazy that it happens like this.

IMG_0080.mp4

And less than 10 minutes later...

IMG_0081.mp4

I think the identification is only listed in the log but not actually reported as received? Maybe you can't send a signal after all...

Logger: homeassistant.components.websocket_api.http.connection
Quelle: components/websocket_api/commands.py:245
Integration: Home Assistant WebSocket API (Dokumentation, Probleme)
Erstmals aufgetreten: 19:37:29 (1 Vorkommnisse)
Zuletzt protokolliert: 19:37:29

[547205361104] Unexpected exception
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 67, in wrap_zigpy_exceptions
    yield
  File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 85, in wrapper
    return await RETRYABLE_REQUEST_DECORATOR(func)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/zigpy/util.py", line 136, in retry
    return await func()
           ^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/zigpy/zcl/__init__.py", line 375, in request
    return await self._endpoint.request(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/zigpy/endpoint.py", line 270, in request
    return await self.device.request(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/zigpy/device.py", line 378, in request
    await send_request()
  File "/usr/local/lib/python3.12/site-packages/zigpy/application.py", line 825, in request
    await self.send_packet(
  File "/usr/local/lib/python3.12/site-packages/bellows/zigbee/application.py", line 824, in send_packet
    raise zigpy.exceptions.DeliveryError(
zigpy.exceptions.DeliveryError: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074>

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/zha/helpers.py", line 1335, in handler
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/zha/button.py", line 60, in async_press
    await self.entity_data.entity.async_press()
  File "/usr/local/lib/python3.12/site-packages/zha/application/platforms/button/__init__.py", line 107, in async_press
    await command(*arguments, **kwargs)
  File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 84, in wrapper
    with wrap_zigpy_exceptions():
  File "/usr/local/lib/python3.12/contextlib.py", line 158, in __exit__
    self.gen.throw(value)
  File "/usr/local/lib/python3.12/site-packages/zha/zigbee/cluster_handlers/__init__.py", line 76, in wrap_zigpy_exceptions
    raise ZHAException(message) from exc
zha.exceptions.ZHAException: Failed to send request: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074>

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/commands.py", line 245, in handle_call_service
    response = await hass.services.async_call(
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2802, in async_call
    response_data = await coro
                    ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/core.py", line 2845, in _execute_service
    return await target(service_call)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1007, in entity_service_call
    single_response = await _handle_entity_call(
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/service.py", line 1079, in _handle_entity_call
    result = await task
             ^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/components/button/__init__.py", line 132, in _async_press_action
    await self.async_press()
  File "/usr/src/homeassistant/homeassistant/components/zha/helpers.py", line 1337, in handler
    raise HomeAssistantError(err) from err
homeassistant.exceptions.HomeAssistantError: Failed to send request: Failed to deliver message: <sl_Status.ZIGBEE_DELIVERY_FAILED: 3074>

I'll provide a diagnostic log in a moment, where it worked before and then stopped working a few minutes later.

@Matze89x
Copy link
Author

Matze89x commented Nov 23, 2024

Here is the diagnosis... At first it went perfectly. Then it was unavailable again and then it worked again. You can see this in the identification commands.

home-assistant_zha_2024-11-23T18-51-01.153Z.log

2024-11-23 19:47:37.324 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:47:37.324 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:47:42.711 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11W\x05\x01\xff'}
2024-11-23 19:47:42.711 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 196, -62, 0xCD1C, 255, 4, b'\x11W\x05\x01\xff']
2024-11-23 19:47:42.712 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 42, 712596, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=74, profile_id=260, cluster_id=8, data=Serialized[b'\x11W\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:42.718 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11W\x05\x01\xff'
2024-11-23 19:47:42.719 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=87, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:42.720 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:42.721 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 87): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:42.721 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:43.318 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=75), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11X\x05\x01\xff'}
2024-11-23 19:47:43.319 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=75), 196, -62, 0xCD1C, 255, 4, b'\x11X\x05\x01\xff']
2024-11-23 19:47:43.320 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 43, 320426, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=75, profile_id=260, cluster_id=8, data=Serialized[b'\x11X\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:43.321 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11X\x05\x01\xff'
2024-11-23 19:47:43.322 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=88, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:43.324 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:43.324 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 88): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:43.324 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:44.015 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=76), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11Y\x05\x00\xff'}
2024-11-23 19:47:44.016 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=76), 196, -62, 0xCD1C, 255, 4, b'\x11Y\x05\x00\xff']
2024-11-23 19:47:44.017 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 44, 17018, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=76, profile_id=260, cluster_id=8, data=Serialized[b'\x11Y\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:44.019 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11Y\x05\x00\xff'
2024-11-23 19:47:44.020 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=89, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:44.022 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.022 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 89): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.022 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.556 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=77), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11Z\x05\x00\xff'}
2024-11-23 19:47:44.557 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=77), 196, -62, 0xCD1C, 255, 4, b'\x11Z\x05\x00\xff']
2024-11-23 19:47:44.557 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 44, 557586, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=77, profile_id=260, cluster_id=8, data=Serialized[b'\x11Z\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:44.559 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11Z\x05\x00\xff'
2024-11-23 19:47:44.561 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=90, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:44.563 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.563 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 90): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.564 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.712 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11W\x05\x01\xff'}
2024-11-23 19:47:44.713 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 196, -62, 0xCD1C, 255, 4, b'\x11W\x05\x01\xff']
2024-11-23 19:47:44.714 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 44, 714314, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=74, profile_id=260, cluster_id=8, data=Serialized[b'\x11W\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:44.715 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:44.949 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=78), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11[\x05\x00\xff'}
2024-11-23 19:47:44.950 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=78), 196, -62, 0xCD1C, 255, 4, b'\x11[\x05\x00\xff']
2024-11-23 19:47:44.951 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 44, 951088, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=78, profile_id=260, cluster_id=8, data=Serialized[b'\x11[\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:44.953 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11[\x05\x00\xff'
2024-11-23 19:47:44.954 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=91, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:44.957 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.958 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 91): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:44.958 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:46.068 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=75), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11X\x05\x01\xff'}
2024-11-23 19:47:46.070 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=75), 196, -62, 0xCD1C, 255, 4, b'\x11X\x05\x01\xff']
2024-11-23 19:47:46.071 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 46, 71011, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=75, profile_id=260, cluster_id=8, data=Serialized[b'\x11X\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:46.072 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:46.203 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=76), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11Y\x05\x00\xff'}
2024-11-23 19:47:46.204 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=76), 196, -62, 0xCD1C, 255, 4, b'\x11Y\x05\x00\xff']
2024-11-23 19:47:46.204 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 46, 204477, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=76, profile_id=260, cluster_id=8, data=Serialized[b'\x11Y\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:46.205 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:46.224 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=79), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\\\x05\x01\xff'}
2024-11-23 19:47:46.225 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=79), 196, -62, 0xCD1C, 255, 4, b'\x11\\\x05\x01\xff']
2024-11-23 19:47:46.225 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 46, 225857, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=79, profile_id=260, cluster_id=8, data=Serialized[b'\x11\\\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:46.227 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\\\x05\x01\xff'
2024-11-23 19:47:46.228 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=92, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:46.228 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:46.229 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 92): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:46.230 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:46.739 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11W\x05\x01\xff'}
2024-11-23 19:47:46.740 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=74), 196, -62, 0xCD1C, 255, 4, b'\x11W\x05\x01\xff']
2024-11-23 19:47:46.740 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 46, 740903, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=74, profile_id=260, cluster_id=8, data=Serialized[b'\x11W\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:46.742 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:46.746 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=80), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11]\x05\x01\xff'}
2024-11-23 19:47:46.747 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=80), 196, -62, 0xCD1C, 255, 4, b'\x11]\x05\x01\xff']
2024-11-23 19:47:46.748 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 46, 748151, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=80, profile_id=260, cluster_id=8, data=Serialized[b'\x11]\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:46.749 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11]\x05\x01\xff'
2024-11-23 19:47:46.750 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=93, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:46.751 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:46.752 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 93): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:46.752 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:47:47.406 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=77), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11Z\x05\x00\xff'}
2024-11-23 19:47:47.407 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=77), 196, -62, 0xCD1C, 255, 4, b'\x11Z\x05\x00\xff']
2024-11-23 19:47:47.408 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 47, 408217, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=77, profile_id=260, cluster_id=8, data=Serialized[b'\x11Z\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:47.409 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:47.592 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=78), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11[\x05\x00\xff'}
2024-11-23 19:47:47.593 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=78), 196, -62, 0xCD1C, 255, 4, b'\x11[\x05\x00\xff']
2024-11-23 19:47:47.593 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 47, 593623, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=78, profile_id=260, cluster_id=8, data=Serialized[b'\x11[\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:47.594 DEBUG (MainThread) [zigpy.device] [0xcd1c] Filtering duplicate packet
2024-11-23 19:47:47.608 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=81), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11^\x05\x00\xff'}
2024-11-23 19:47:47.608 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=81), 196, -62, 0xCD1C, 255, 4, b'\x11^\x05\x00\xff']
2024-11-23 19:47:47.609 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 47, 609107, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=81, profile_id=260, cluster_id=8, data=Serialized[b'\x11^\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:47.610 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11^\x05\x00\xff'
2024-11-23 19:47:47.611 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=94, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:47:47.612 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:47.612 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 94): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:47.613 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:47:49.523 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=82), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xb9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:47:49.523 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=82), 196, -62, 0xCD1C, 255, 4, b'\xb9\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:47:49.524 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 49, 524075, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=82, profile_id=0, cluster_id=0, data=Serialized[b'\xb9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:47:49.525 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:47:58.462 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 47, 58, 462635, tzinfo=datetime.timezone.utc), priority=<PacketPriority.LOW: -1>, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), dst_ep=0, source_route=None, extended_timeout=False, tsn=227, profile_id=0, cluster_id=<ZDOCmd.NWK_addr_rsp: 0x8000>, data=Serialized[b'\xe3\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-11-23 19:47:58.463 DEBUG (MainThread) [bellows.ezsp.protocol] Sending command  sendUnicast: () {'type': <EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 'indexOrDestination': 0xCD1C, 'apsFrame': EmberApsFrame(profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=227), 'messageTag': 25, 'messageContents': b'\xe3\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'}
2024-11-23 19:48:03.485 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=83), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xba\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:48:03.486 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=83), 196, -62, 0xCD1C, 255, 4, b'\xba\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:48:03.487 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 48, 3, 487135, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=83, profile_id=0, cluster_id=0, data=Serialized[b'\xba\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:48:03.488 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:48:05.520 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=84), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xbb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:48:05.521 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=84), 192, -63, 0xCD1C, 255, 4, b'\xbb\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:48:05.521 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 48, 5, 521505, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=84, profile_id=0, cluster_id=0, data=Serialized[b'\xbb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:48:05.523 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:48:09.339 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:48:09.339 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:48:26.223 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 48, 26, 223797, tzinfo=datetime.timezone.utc), priority=<PacketPriority.LOW: -1>, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), dst_ep=0, source_route=None, extended_timeout=False, tsn=228, profile_id=0, cluster_id=<ZDOCmd.NWK_addr_rsp: 0x8000>, data=Serialized[b'\xe4\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-11-23 19:48:26.224 DEBUG (MainThread) [bellows.ezsp.protocol] Sending command  sendUnicast: () {'type': <EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 'indexOrDestination': 0xCD1C, 'apsFrame': EmberApsFrame(profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=228), 'messageTag': 56, 'messageContents': b'\xe4\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'}
2024-11-23 19:48:41.357 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:48:41.358 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:48:53.994 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 48, 53, 994777, tzinfo=datetime.timezone.utc), priority=<PacketPriority.LOW: -1>, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), dst_ep=0, source_route=None, extended_timeout=False, tsn=229, profile_id=0, cluster_id=<ZDOCmd.NWK_addr_rsp: 0x8000>, data=Serialized[b'\xe5\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-11-23 19:48:53.996 DEBUG (MainThread) [bellows.ezsp.protocol] Sending command  sendUnicast: () {'type': <EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 'indexOrDestination': 0xCD1C, 'apsFrame': EmberApsFrame(profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=229), 'messageTag': 88, 'messageContents': b'\xe5\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'}
2024-11-23 19:49:11.063 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=89), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xbc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:11.064 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=89), 192, -63, 0xCD1C, 255, 4, b'\xbc\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:11.064 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 11, 64677, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=89, profile_id=0, cluster_id=0, data=Serialized[b'\xbc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:49:11.066 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:12.328 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=93), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xbd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:12.328 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=93), 196, -62, 0xCD1C, 255, 4, b'\xbd\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:12.329 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 12, 329217, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=93, profile_id=0, cluster_id=0, data=Serialized[b'\xbd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:12.330 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:13.328 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=97), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xbe\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:13.329 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=97), 196, -62, 0xCD1C, 255, 4, b'\xbe\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:13.329 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 13, 329942, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=97, profile_id=0, cluster_id=0, data=Serialized[b'\xbe\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:13.331 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:13.429 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:49:13.441 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:49:13.983 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=100), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xbf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:13.983 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=100), 192, -63, 0xCD1C, 255, 4, b'\xbf\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:13.984 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 13, 984318, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=100, profile_id=0, cluster_id=0, data=Serialized[b'\xbf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:49:13.985 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:14.232 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=102), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:14.233 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=102), 192, -63, 0xCD1C, 255, 4, b'\xc0\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:14.233 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 14, 233445, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=102, profile_id=0, cluster_id=0, data=Serialized[b'\xc0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:49:14.234 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:15.162 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=105), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:15.163 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=105), 192, -63, 0xCD1C, 255, 4, b'\xc1\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:15.163 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 15, 163798, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=105, profile_id=0, cluster_id=0, data=Serialized[b'\xc1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:49:15.165 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:15.405 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=107), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:15.406 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=107), 192, -63, 0xCD1C, 255, 4, b'\xc2\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:15.407 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 15, 407158, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=107, profile_id=0, cluster_id=0, data=Serialized[b'\xc2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:49:15.408 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:19.482 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=4, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:49:19.483 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request: identify(identify_time=5)
2024-11-23 19:49:19.486 DEBUG (MainThread) [zigpy.device] [0xcd1c] Extending timeout for 0x04 request
2024-11-23 19:49:21.763 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 21, 762964, tzinfo=datetime.timezone.utc), priority=<PacketPriority.NORMAL: 0>, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), dst_ep=1, source_route=None, extended_timeout=True, tsn=4, profile_id=260, cluster_id=3, data=Serialized[b'\x01\x04\x00\x05\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-11-23 19:49:21.777 DEBUG (MainThread) [bellows.ezsp.protocol] Sending command  sendUnicast: () {'type': <EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 'indexOrDestination': 0xCD1C, 'apsFrame': EmberApsFrame(profileId=260, clusterId=3, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=4), 'messageTag': 109, 'messageContents': b'\x01\x04\x00\x05\x00'}
2024-11-23 19:49:22.697 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=108), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:22.698 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=108), 196, -62, 0xCD1C, 255, 4, b'\xc3\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:22.698 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 22, 698363, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=108, profile_id=0, cluster_id=0, data=Serialized[b'\xc3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:22.699 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:23.278 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=109), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:23.279 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=109), 196, -62, 0xCD1C, 255, 4, b'\xc4\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:23.279 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 23, 279499, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=109, profile_id=0, cluster_id=0, data=Serialized[b'\xc4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:23.280 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:27.245 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=114), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc8\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:27.246 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=114), 196, -62, 0xCD1C, 255, 4, b'\xc8\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:27.247 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 27, 246968, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=114, profile_id=0, cluster_id=0, data=Serialized[b'\xc8\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:27.248 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:27.464 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=116), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xc9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:27.465 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=116), 196, -62, 0xCD1C, 255, 4, b'\xc9\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:27.465 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 27, 465776, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=116, profile_id=0, cluster_id=0, data=Serialized[b'\xc9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:27.467 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:30.076 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=121), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xca\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:30.077 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=121), 196, -62, 0xCD1C, 255, 4, b'\xca\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:30.077 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 30, 77900, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=121, profile_id=0, cluster_id=0, data=Serialized[b'\xca\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:30.079 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:36.658 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=122), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xcb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:36.659 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=122), 196, -62, 0xCD1C, 255, 4, b'\xcb\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:36.659 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 36, 659727, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=122, profile_id=0, cluster_id=0, data=Serialized[b'\xcb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:36.661 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:39.139 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=123), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xcc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:39.140 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=123), 196, -62, 0xCD1C, 255, 4, b'\xcc\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:39.140 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 39, 140810, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=123, profile_id=0, cluster_id=0, data=Serialized[b'\xcc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:39.142 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:39.329 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=124), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xcd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:39.330 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=124), 196, -62, 0xCD1C, 255, 4, b'\xcd\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:39.331 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 39, 331086, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=124, profile_id=0, cluster_id=0, data=Serialized[b'\xcd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:39.332 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:43.905 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=125), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xce\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:43.906 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=125), 196, -62, 0xCD1C, 255, 4, b'\xce\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:43.906 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 43, 906783, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=125, profile_id=0, cluster_id=0, data=Serialized[b'\xce\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:43.908 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:45.457 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:49:45.458 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:49:49.537 DEBUG (MainThread) [bellows.zigbee.application] Sending packet ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 49, 537638, tzinfo=datetime.timezone.utc), priority=<PacketPriority.LOW: -1>, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), dst_ep=0, source_route=None, extended_timeout=False, tsn=230, profile_id=0, cluster_id=<ZDOCmd.NWK_addr_rsp: 0x8000>, data=Serialized[b'\xe6\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'], tx_options=<TransmitOptions.ACK: 1>, radius=0, non_member_radius=0, lqi=None, rssi=None)
2024-11-23 19:49:49.539 DEBUG (MainThread) [bellows.ezsp.protocol] Sending command  sendUnicast: () {'type': <EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 'indexOrDestination': 0xCD1C, 'apsFrame': EmberApsFrame(profileId=0, clusterId=32768, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=230), 'messageTag': 143, 'messageContents': b'\xe6\x00\x9cUR\xfe\xff\xa3e\x8c\x00\x00\x00\x00'}
2024-11-23 19:49:49.639 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=5, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:49:49.640 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request: identify(identify_time=5)
2024-11-23 19:49:49.641 DEBUG (MainThread) [zigpy.device] [0xcd1c] Extending timeout for 0x05 request
2024-11-23 19:49:50.630 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=134), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xcf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:50.631 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=134), 196, -62, 0xCD1C, 255, 4, b'\xcf\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:50.640 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 50, 639959, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=134, profile_id=0, cluster_id=0, data=Serialized[b'\xcf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:50.642 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:54.070 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=135), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:54.070 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=135), 196, -62, 0xCD1C, 255, 4, b'\xd0\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:54.071 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 54, 71025, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=135, profile_id=0, cluster_id=0, data=Serialized[b'\xd0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:54.072 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:54.160 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=136), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:54.161 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=136), 196, -62, 0xCD1C, 255, 4, b'\xd1\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:54.162 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 54, 162119, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=136, profile_id=0, cluster_id=0, data=Serialized[b'\xd1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:54.163 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:54.341 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=137), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:54.342 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=137), 196, -62, 0xCD1C, 255, 4, b'\xd2\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:54.343 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 54, 342942, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=137, profile_id=0, cluster_id=0, data=Serialized[b'\xd2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:54.344 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:55.882 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=138), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:55.883 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=138), 196, -62, 0xCD1C, 255, 4, b'\xd3\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:55.883 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 55, 883712, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=138, profile_id=0, cluster_id=0, data=Serialized[b'\xd3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:55.885 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:57.604 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=139), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:57.605 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=139), 196, -62, 0xCD1C, 255, 4, b'\xd4\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:57.605 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 57, 605674, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=139, profile_id=0, cluster_id=0, data=Serialized[b'\xd4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:57.607 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:49:59.868 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=140), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd5\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:49:59.869 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=140), 196, -62, 0xCD1C, 255, 4, b'\xd5\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:49:59.869 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 49, 59, 869597, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=140, profile_id=0, cluster_id=0, data=Serialized[b'\xd5\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:49:59.871 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:02.867 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=141), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd6\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:02.867 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=141), 196, -62, 0xCD1C, 255, 4, b'\xd6\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:02.867 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 2, 867949, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=141, profile_id=0, cluster_id=0, data=Serialized[b'\xd6\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:02.869 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:05.855 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=142), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd7\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:05.856 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=142), 192, -63, 0xCD1C, 255, 4, b'\xd7\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:05.856 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 5, 856781, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=142, profile_id=0, cluster_id=0, data=Serialized[b'\xd7\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:50:05.858 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:08.845 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=143), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd8\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:08.846 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=143), 196, -62, 0xCD1C, 255, 4, b'\xd8\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:08.846 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 8, 846770, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=143, profile_id=0, cluster_id=0, data=Serialized[b'\xd8\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:08.847 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:11.840 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=144), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xd9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:11.841 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=144), 192, -63, 0xCD1C, 255, 4, b'\xd9\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:11.842 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 11, 841974, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=144, profile_id=0, cluster_id=0, data=Serialized[b'\xd9\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:50:11.843 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:14.832 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=145), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xda\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:14.833 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=145), 196, -62, 0xCD1C, 255, 4, b'\xda\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:14.833 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 14, 833885, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=145, profile_id=0, cluster_id=0, data=Serialized[b'\xda\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:14.835 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:17.480 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:50:17.480 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:50:17.829 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=146), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xdb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:17.829 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=146), 196, -62, 0xCD1C, 255, 4, b'\xdb\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:17.830 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 17, 830265, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=146, profile_id=0, cluster_id=0, data=Serialized[b'\xdb\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:17.832 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:20.820 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=147), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xdc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:20.821 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=147), 196, -62, 0xCD1C, 255, 4, b'\xdc\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:20.821 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 20, 821764, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=147, profile_id=0, cluster_id=0, data=Serialized[b'\xdc\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:20.823 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:23.815 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=148), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xdd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:23.816 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=148), 196, -62, 0xCD1C, 255, 4, b'\xdd\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:23.816 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 23, 816640, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=148, profile_id=0, cluster_id=0, data=Serialized[b'\xdd\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:23.817 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:26.813 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=149), 'lastHopLqi': 172, 'lastHopRssi': -68, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xde\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:26.814 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=149), 172, -68, 0xCD1C, 255, 4, b'\xde\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:26.814 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 26, 814764, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=149, profile_id=0, cluster_id=0, data=Serialized[b'\xde\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=172, rssi=-68)
2024-11-23 19:50:26.815 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:29.796 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=150), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xdf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:29.797 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=150), 196, -62, 0xCD1C, 255, 4, b'\xdf\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:29.797 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 29, 797775, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=150, profile_id=0, cluster_id=0, data=Serialized[b'\xdf\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:29.799 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:32.786 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=151), 'lastHopLqi': 192, 'lastHopRssi': -63, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xe0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:32.787 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=151), 192, -63, 0xCD1C, 255, 4, b'\xe0\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:32.788 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 32, 787970, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=151, profile_id=0, cluster_id=0, data=Serialized[b'\xe0\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=192, rssi=-63)
2024-11-23 19:50:32.790 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:35.777 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=152), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xe1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:35.778 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=152), 196, -62, 0xCD1C, 255, 4, b'\xe1\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:35.778 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 35, 778491, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=152, profile_id=0, cluster_id=0, data=Serialized[b'\xe1\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:35.779 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:38.777 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=153), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xe2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:38.778 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=153), 196, -62, 0xCD1C, 255, 4, b'\xe2\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:38.778 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 38, 778526, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=153, profile_id=0, cluster_id=0, data=Serialized[b'\xe2\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:38.779 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:41.765 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=154), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xe3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:41.765 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=154), 196, -62, 0xCD1C, 255, 4, b'\xe3\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:41.766 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 41, 766301, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=154, profile_id=0, cluster_id=0, data=Serialized[b'\xe3\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:41.767 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:44.764 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_BROADCAST: 4>, 'apsFrame': EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=155), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\xe4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'}
2024-11-23 19:50:44.765 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_BROADCAST: 4>, EmberApsFrame(profileId=0, clusterId=0, sourceEndpoint=0, destinationEndpoint=0, options=<EmberApsOption.APS_OPTION_SOURCE_EUI64: 1024>, groupId=0, sequence=155), 196, -62, 0xCD1C, 255, 4, b'\xe4\x9cUR\xfe\xff\xa3e\x8c\x00\x00']
2024-11-23 19:50:44.765 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 44, 765622, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.Broadcast: 15>, address=<BroadcastAddress.ALL_ROUTERS_AND_COORDINATOR: 65532>), dst_ep=0, source_route=None, extended_timeout=False, tsn=155, profile_id=0, cluster_id=0, data=Serialized[b'\xe4\x9cUR\xfe\xff\xa3e\x8c\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:44.766 DEBUG (MainThread) [zigpy.zdo] [0xcd1c:zdo] ZDO request ZDOCmd.NWK_addr_req: [8c:65:a3:ff:fe:52:55:9c, <AddrRequestType.Single: 0>, 0]
2024-11-23 19:50:47.285 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=156), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11}\x05\x00\xff'}
2024-11-23 19:50:47.286 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=156), 196, -62, 0xCD1C, 255, 4, b'\x11}\x05\x00\xff']
2024-11-23 19:50:47.286 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 47, 286816, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=156, profile_id=260, cluster_id=8, data=Serialized[b'\x11}\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:47.289 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11}\x05\x00\xff'
2024-11-23 19:50:47.291 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=125, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:47.294 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:47.295 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 125): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:47.296 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:47.817 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=157), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11~\x05\x00\xff'}
2024-11-23 19:50:47.818 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=157), 196, -62, 0xCD1C, 255, 4, b'\x11~\x05\x00\xff']
2024-11-23 19:50:47.818 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 47, 818752, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=157, profile_id=260, cluster_id=8, data=Serialized[b'\x11~\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:47.820 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11~\x05\x00\xff'
2024-11-23 19:50:47.821 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=126, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:47.822 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:47.823 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 126): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:47.823 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:48.683 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=158), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x7f\x05\x01\xff'}
2024-11-23 19:50:48.683 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=158), 196, -62, 0xCD1C, 255, 4, b'\x11\x7f\x05\x01\xff']
2024-11-23 19:50:48.684 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 48, 684130, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=158, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x7f\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:48.685 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x7f\x05\x01\xff'
2024-11-23 19:50:48.686 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=127, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:48.688 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:48.689 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 127): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:48.689 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:49.100 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=159), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x00\x05\x01\xff'}
2024-11-23 19:50:49.100 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=159), 196, -62, 0xCD1C, 255, 4, b'\x11\x00\x05\x01\xff']
2024-11-23 19:50:49.101 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 49, 101436, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=159, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x00\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:49.103 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x00\x05\x01\xff'
2024-11-23 19:50:49.107 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=0, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:49.109 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:49.110 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 0): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:49.111 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:49.496 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Device seen - marking the device available and resetting counter
2024-11-23 19:50:49.497 DEBUG (MainThread) [zha.zigbee.device] [0xCD1C](SYMFONISK sound remote gen2): Update device availability -  device available: True - new availability: True - changed: False
2024-11-23 19:50:49.716 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=160), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x01\x05\x00\xff'}
2024-11-23 19:50:49.717 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=160), 196, -62, 0xCD1C, 255, 4, b'\x11\x01\x05\x00\xff']
2024-11-23 19:50:49.718 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 49, 718059, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=160, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x01\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:49.719 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x01\x05\x00\xff'
2024-11-23 19:50:49.721 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=1, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:49.723 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:49.723 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 1): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:49.724 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:50.370 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=161), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x02\x05\x00\xff'}
2024-11-23 19:50:50.370 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=161), 196, -62, 0xCD1C, 255, 4, b'\x11\x02\x05\x00\xff']
2024-11-23 19:50:50.371 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 50, 371033, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=161, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x02\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:50.372 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x02\x05\x00\xff'
2024-11-23 19:50:50.373 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=2, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:50.374 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:50.375 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 2): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:50.375 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:51.031 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=162), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x03\x05\x01\xff'}
2024-11-23 19:50:51.032 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=162), 196, -62, 0xCD1C, 255, 4, b'\x11\x03\x05\x01\xff']
2024-11-23 19:50:51.032 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 51, 32848, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=162, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x03\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:51.035 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x03\x05\x01\xff'
2024-11-23 19:50:51.036 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=3, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:51.038 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.039 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 3): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.039 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.407 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=163), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x04\x05\x01\xff'}
2024-11-23 19:50:51.407 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=163), 196, -62, 0xCD1C, 255, 4, b'\x11\x04\x05\x01\xff']
2024-11-23 19:50:51.408 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 51, 408312, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=163, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x04\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:51.409 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x04\x05\x01\xff'
2024-11-23 19:50:51.410 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=4, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:51.411 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.411 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 4): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.412 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:51.914 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=164), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x05\x05\x00\xff'}
2024-11-23 19:50:51.915 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=164), 196, -62, 0xCD1C, 255, 4, b'\x11\x05\x05\x00\xff']
2024-11-23 19:50:51.916 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 51, 916050, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=164, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x05\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:51.918 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x05\x05\x00\xff'
2024-11-23 19:50:51.923 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=5, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:51.925 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:51.925 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 5): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:51.925 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:52.170 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=165), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x06\x05\x00\xff'}
2024-11-23 19:50:52.171 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=165), 196, -62, 0xCD1C, 255, 4, b'\x11\x06\x05\x00\xff']
2024-11-23 19:50:52.171 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 52, 171722, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=165, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x06\x05\x00\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:52.172 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x06\x05\x00\xff'
2024-11-23 19:50:52.173 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=6, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:52.174 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:52.175 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 6): move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:52.175 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Up: 0>, rate=255)
2024-11-23 19:50:52.584 DEBUG (MainThread) [bellows.ezsp.protocol] Received command incomingMessageHandler: {'type': <EmberIncomingMessageType.INCOMING_UNICAST: 0>, 'apsFrame': EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=166), 'lastHopLqi': 196, 'lastHopRssi': -62, 'sender': 0xCD1C, 'bindingIndex': 255, 'addressIndex': 4, 'messageContents': b'\x11\x07\x05\x01\xff'}
2024-11-23 19:50:52.584 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=8, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_RETRY|APS_OPTION_ENABLE_ROUTE_DISCOVERY: 320>, groupId=0, sequence=166), 196, -62, 0xCD1C, 255, 4, b'\x11\x07\x05\x01\xff']
2024-11-23 19:50:52.584 DEBUG (MainThread) [zigpy.application] Received a packet: ZigbeePacket(timestamp=datetime.datetime(2024, 11, 23, 18, 50, 52, 584927, tzinfo=datetime.timezone.utc), priority=0, src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xCD1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=166, profile_id=260, cluster_id=8, data=Serialized[b'\x11\x07\x05\x01\xff'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=196, rssi=-62)
2024-11-23 19:50:52.586 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received ZCL frame: b'\x11\x07\x05\x01\xff'
2024-11-23 19:50:52.587 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl<0x11>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 0>, disable_default_response=1, reserved=0, *is_cluster=True, *is_general=False), tsn=7, command_id=5, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:52.588 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Decoded ZCL frame: LevelControl:move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:52.589 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] Received command 0x05 (TSN 7): move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:52.589 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0008] No explicit handler for cluster command 0x05: move_with_on_off(move_mode=<MoveMode.Down: 1>, rate=255)
2024-11-23 19:50:53.734 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl<0x01>(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=6, command_id=0, *direction=<Direction.Client_to_Server: 0>)
2024-11-23 19:50:53.735 DEBUG (MainThread) [zigpy.zcl] [0xCD1C:1:0x0003] Sending request: identify(identify_time=5)
2024-11-23 19:50:53.741 DEBUG (MainThread) [zigpy.device] [0xcd1c] Extending timeout for 0x06 request

@MattWestb
Copy link
Contributor

The bug have being around for nearly one year and seen it in both my production and test network (the last with 35 mostly IKEA controllers).
Always cluster 0x0020 and most of the time with self.CHECKIN_FAST_POLL_TIMEOUT.
My thinking its something is blocking the thread and the command is timing out before ZHA have responding on checking from the device so its going back to sleep then ZHA is sending it.
Sometime one end device have jumping or one router restarted but its coming nearly daily in my systems.

@Matze89x
Copy link
Author

Matze89x commented Nov 23, 2024

oh dear, that doesn't sound so good. But I really have to say that almost 2 months ago I was never able to use the remote control without a problem. The latest update 0x01000035 was installed directly from day 1 and was used with the Sonos Automation remote control.

I have had this remote control since 10.04 and it must have started to go extremely bad just 2 months ago (unfortunately too rarely used). By the way: No major changes in my constellation and no changes to the network.

Even if Ikea... unfortunately there are no other nice media controller remote controls that are so simple, cheap and actually top... grrr :-)

As a test, I even took out the batteries and restarted the identification, but now no value is recognised and the entities remain obsolete.

Batteries inserted and the link quality values appear again immediately. The buttons on the remote control are still not processed.

/edit:

I would like to apologise very much for ‘spamming’ so much here, but in fact I have now been able to narrow down the problem somewhat...

The connection from the adapter is then made to a socket that currently has no load connected, is set to off and has only logged the consumption. Now I just tried switching the socket on and off and immediately afterwards I was able to operate the remote control again!
image

Now I have activated the other logs by activating Voltage. This is permanently measured, even when the socket is not in use.

I am observing.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants