zha-device-handlers: [BUG] XiaomiOpple2ButtonSwitchFace1 is no longer applied to Aquara lumi.switch.b2naus01

Bug description

I have a bunch of Aquara double rocker switches (and single rocker too, for that matter, but the single rocker never caused problems). The double rockers identify as lumi.switch.b2naus01, and in the past, the quirk zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace1 had been applied to them. After upgrading to HA 2023.12.1, the switches no longer worked and upon repairing them, the quirk is no longer applied. Log excerpt:

Checking quirks for LUMI lumi.switch.b2naus01 (mac redacted)
Considering <class 'zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace1'>
Fail because endpoint list mismatch: {1, 2, 41, 42, 242, 51, 21, 31} {1, 2, 242}

That issue had happened prior to 2023.12.1, too, and repairing them once or twice usually got the quirk applied. But now, even after retrying 10+ times, the quirk is never applied.

Steps to reproduce

Pair a lumi.switch.b2naus01 with HA.

Expected behavior

The quirk zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace1 is applied.

Screenshots/Video

Screenshots/Video

[Paste/upload your media here]

Device signature

Device signature
{
  "home_assistant": {
    "installation_type": "Home Assistant OS",
    "version": "2023.12.1",
    "dev": false,
    "hassio": true,
    "virtualenv": false,
    "python_version": "3.11.6",
    "docker": true,
    "arch": "x86_64",
    "timezone": "America/Los_Angeles",
    "os_name": "Linux",
    "os_version": "6.1.63-haos",
    "supervisor": "2023.11.6",
    "host_os": "Home Assistant OS 11.2",
    "docker_version": "24.0.7",
    "chassis": "embedded",
    "run_as_root": true
  },
  "custom_components": {
    "opensprinkler": {
      "version": "1.2.5",
      "requirements": [
        "pyopensprinkler==0.7.11"
      ]
    },
    "browser_mod": {
      "version": "2.3.0",
      "requirements": []
    },
    "hacs": {
      "version": "1.33.0",
      "requirements": [
        "aiogithubapi>=22.10.1"
      ]
    },
    "zha_toolkit": {
      "version": "v1.1.8",
      "requirements": [
        "pytz"
      ]
    }
  },
  "integration_manifest": {
    "domain": "zha",
    "name": "Zigbee Home Automation",
    "after_dependencies": [
      "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",
      "universal_silabs_flasher"
    ],
    "requirements": [
      "bellows==0.37.1",
      "pyserial==3.5",
      "pyserial-asyncio==0.6",
      "zha-quirks==0.0.107",
      "zigpy-deconz==0.22.0",
      "zigpy==0.60.0",
      "zigpy-xbee==0.20.0",
      "zigpy-zigate==0.12.0",
      "zigpy-znp==0.12.0",
      "universal-silabs-flasher==0.0.15",
      "pyserial-asyncio-fast==0.11"
    ],
    "usb": [
      {
        "vid": "10C4",
        "pid": "EA60",
        "description": "*2652*",
        "known_devices": [
          "slae.sh cc2652rb stick"
        ]
      },
      {
        "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*"
      }
    ],
    "is_built_in": true
  },
  "data": {
    "ieee": "**REDACTED**",
    "nwk": 14083,
    "manufacturer": "LUMI",
    "model": "lumi.switch.b2naus01",
    "name": "LUMI lumi.switch.b2naus01",
    "quirk_applied": false,
    "quirk_class": "zigpy.device.Device",
    "quirk_id": null,
    "manufacturer_code": 4447,
    "power_source": "Mains",
    "lqi": 156,
    "rssi": -61,
    "last_seen": "2023-12-09T11:56:01",
    "available": true,
    "device_type": "Router",
    "signature": {
      "node_descriptor": "NodeDescriptor(logical_type=<LogicalType.Router: 1>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True, *is_security_capable=False)",
      "endpoints": {
        "1": {
          "profile_id": "0x0104",
          "device_type": "0x0100",
          "input_clusters": [
            "0x0000",
            "0x0002",
            "0x0003",
            "0x0004",
            "0x0005",
            "0x0006",
            "0x0009",
            "0x0702",
            "0x0b04"
          ],
          "output_clusters": [
            "0x000a",
            "0x0019"
          ]
        },
        "2": {
          "profile_id": "0x0104",
          "device_type": "0x0100",
          "input_clusters": [
            "0x0000",
            "0x0003",
            "0x0004",
            "0x0005",
            "0x0006",
            "0x0012",
            "0xfcc0"
          ],
          "output_clusters": []
        },
        "242": {
          "profile_id": "0xa1e0",
          "device_type": "0x0061",
          "input_clusters": [],
          "output_clusters": [
            "0x0021"
          ]
        }
      },
      "manufacturer": "LUMI",
      "model": "lumi.switch.b2naus01"
    },
    "active_coordinator": false,
    "entities": [
      {
        "entity_id": "button.lumi_lumi_switch_b2naus01_identifizieren",
        "name": "LUMI lumi.switch.b2naus01"
      },
      {
        "entity_id": "light.lumi_lumi_switch_b2naus01_licht",
        "name": "LUMI lumi.switch.b2naus01"
      },
      {
        "entity_id": "light.lumi_lumi_switch_b2naus01_licht_2",
        "name": "LUMI lumi.switch.b2naus01"
      },
      {
        "entity_id": "sensor.lumi_lumi_switch_b2naus01_geratetemperatur",
        "name": "LUMI lumi.switch.b2naus01"
      },
      {
        "entity_id": "sensor.lumi_lumi_switch_b2naus01_leistung",
        "name": "LUMI lumi.switch.b2naus01"
      },
      {
        "entity_id": "sensor.lumi_lumi_switch_b2naus01_zusammenfassung_geliefert",
        "name": "LUMI lumi.switch.b2naus01"
      }
    ],
    "neighbors": [],
    "routes": [
      {
        "dest_nwk": "0xA92A",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0x0000",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x0000"
      },
      {
        "dest_nwk": "0xACD8",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xACD8"
      },
      {
        "dest_nwk": "0x9452",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xB795"
      },
      {
        "dest_nwk": "0x7387",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF2DC"
      },
      {
        "dest_nwk": "0xB795",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xB795"
      },
      {
        "dest_nwk": "0xF05A",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0x353A",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0x4F60",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0x0A1C",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0x8BCC",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x8BCC"
      },
      {
        "dest_nwk": "0xB52D",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xB52D"
      },
      {
        "dest_nwk": "0x6DE7",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x6DE7"
      },
      {
        "dest_nwk": "0x0F5E",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x0F5E"
      },
      {
        "dest_nwk": "0xE5E0",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xE5E0"
      },
      {
        "dest_nwk": "0xEE14",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xEE14"
      },
      {
        "dest_nwk": "0xCAEE",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0x93BA",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x93BA"
      },
      {
        "dest_nwk": "0x45CE",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x45CE"
      },
      {
        "dest_nwk": "0x2404",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x2404"
      },
      {
        "dest_nwk": "0xF2DC",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF2DC"
      },
      {
        "dest_nwk": "0xF311",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF311"
      },
      {
        "dest_nwk": "0xCBC1",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xCBC1"
      },
      {
        "dest_nwk": "0xB1D3",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xB1D3"
      },
      {
        "dest_nwk": "0x9583",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0x9583"
      },
      {
        "dest_nwk": "0x447A",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xF5BC",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xE14F",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0xCCF1",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xBCD2",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0xFCB1",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xDC15",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xDC15"
      },
      {
        "dest_nwk": "0xD3CE",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xB03A",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0xAC76",
        "route_status": "Validation_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xF5BC"
      },
      {
        "dest_nwk": "0x3D33",
        "route_status": "Active",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xDC15"
      },
      {
        "dest_nwk": "0x3DAB",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      },
      {
        "dest_nwk": "0x00B8",
        "route_status": "Discovery_Underway",
        "memory_constrained": false,
        "many_to_one": false,
        "route_record_required": false,
        "next_hop": "0xFFFE"
      }
    ],
    "endpoint_names": [
      {
        "name": "ON_OFF_LIGHT"
      },
      {
        "name": "ON_OFF_LIGHT"
      },
      {
        "name": "PROXY_BASIC"
      }
    ],
    "user_given_name": null,
    "device_reg_id": "011339d0bd211ea463aede4cba967d48",
    "area_id": null,
    "cluster_details": {
      "1": {
        "device_type": {
          "name": "ON_OFF_LIGHT",
          "id": 256
        },
        "profile_id": 260,
        "in_clusters": {
          "0x0000": {
            "endpoint_attribute": "basic",
            "attributes": {
              "0x0001": {
                "attribute_name": "app_version",
                "value": 25
              },
              "0x0004": {
                "attribute_name": "manufacturer",
                "value": "LUMI"
              },
              "0x0005": {
                "attribute_name": "model",
                "value": "lumi.switch.b2naus01"
              }
            },
            "unsupported_attributes": {}
          },
          "0x0002": {
            "endpoint_attribute": "device_temperature",
            "attributes": {
              "0x0000": {
                "attribute_name": "current_temperature",
                "value": 20
              }
            },
            "unsupported_attributes": {}
          },
          "0x0003": {
            "endpoint_attribute": "identify",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0004": {
            "endpoint_attribute": "groups",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0005": {
            "endpoint_attribute": "scenes",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0006": {
            "endpoint_attribute": "on_off",
            "attributes": {
              "0x0000": {
                "attribute_name": "on_off",
                "value": 0
              }
            },
            "unsupported_attributes": {
              "0x4003": {
                "attribute_name": "start_up_on_off"
              }
            }
          },
          "0x0009": {
            "endpoint_attribute": "alarms",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0702": {
            "endpoint_attribute": "smartenergy_metering",
            "attributes": {
              "0x0000": {
                "attribute_name": "current_summ_delivered",
                "value": 17525
              },
              "0x0304": {
                "attribute_name": "demand_formatting",
                "value": 0
              },
              "0x0302": {
                "attribute_name": "divisor",
                "value": 1000
              },
              "0x0306": {
                "attribute_name": "metering_device_type",
                "value": 0
              },
              "0x0301": {
                "attribute_name": "multiplier",
                "value": 1
              },
              "0x0200": {
                "attribute_name": "status",
                "value": 0
              },
              "0x0303": {
                "attribute_name": "summation_formatting",
                "value": 35
              },
              "0x0300": {
                "attribute_name": "unit_of_measure",
                "value": 0
              }
            },
            "unsupported_attributes": {
              "0x0400": {
                "attribute_name": "instantaneous_demand"
              },
              "0x0100": {
                "attribute_name": "current_tier1_summ_delivered"
              },
              "0x0102": {
                "attribute_name": "current_tier2_summ_delivered"
              },
              "0x0384": {},
              "0x0104": {
                "attribute_name": "current_tier3_summ_delivered"
              },
              "0x0106": {
                "attribute_name": "current_tier4_summ_delivered"
              },
              "0x0108": {
                "attribute_name": "current_tier5_summ_delivered"
              },
              "0x010a": {
                "attribute_name": "current_tier6_summ_delivered"
              }
            }
          },
          "0x0b04": {
            "endpoint_attribute": "electrical_measurement",
            "attributes": {
              "0x0605": {
                "attribute_name": "ac_power_divisor",
                "value": 10
              },
              "0x0604": {
                "attribute_name": "ac_power_multiplier",
                "value": 1
              },
              "0x050b": {
                "attribute_name": "active_power",
                "value": 0
              },
              "0x0000": {
                "attribute_name": "measurement_type",
                "value": 8
              }
            },
            "unsupported_attributes": {
              "0x0600": {
                "attribute_name": "ac_voltage_multiplier"
              },
              "0x0601": {
                "attribute_name": "ac_voltage_divisor"
              },
              "0x0602": {
                "attribute_name": "ac_current_multiplier"
              },
              "0x0603": {
                "attribute_name": "ac_current_divisor"
              },
              "0x0384": {},
              "0x0401": {
                "attribute_name": "ac_frequency_divisor"
              },
              "0x0400": {
                "attribute_name": "ac_frequency_multiplier"
              },
              "0x0403": {
                "attribute_name": "power_divisor"
              },
              "0x0402": {
                "attribute_name": "power_multiplier"
              },
              "0x0508": {
                "attribute_name": "rms_current"
              },
              "0x050d": {
                "attribute_name": "active_power_max"
              },
              "0x050a": {
                "attribute_name": "rms_current_max"
              },
              "0x050f": {
                "attribute_name": "apparent_power"
              },
              "0x0510": {
                "attribute_name": "power_factor"
              },
              "0x0300": {
                "attribute_name": "ac_frequency"
              },
              "0x0302": {
                "attribute_name": "ac_frequency_max"
              },
              "0x0505": {
                "attribute_name": "rms_voltage"
              },
              "0x0507": {
                "attribute_name": "rms_voltage_max"
              }
            }
          }
        },
        "out_clusters": {
          "0x000a": {
            "endpoint_attribute": "time",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0019": {
            "endpoint_attribute": "ota",
            "attributes": {},
            "unsupported_attributes": {}
          }
        }
      },
      "2": {
        "device_type": {
          "name": "ON_OFF_LIGHT",
          "id": 256
        },
        "profile_id": 260,
        "in_clusters": {
          "0x0000": {
            "endpoint_attribute": "basic",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0003": {
            "endpoint_attribute": "identify",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0004": {
            "endpoint_attribute": "groups",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0005": {
            "endpoint_attribute": "scenes",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0x0006": {
            "endpoint_attribute": "on_off",
            "attributes": {
              "0x0000": {
                "attribute_name": "on_off",
                "value": 0
              }
            },
            "unsupported_attributes": {
              "0x4003": {
                "attribute_name": "start_up_on_off"
              }
            }
          },
          "0x0012": {
            "endpoint_attribute": "multistate_input",
            "attributes": {},
            "unsupported_attributes": {}
          },
          "0xfcc0": {
            "endpoint_attribute": "manufacturer_specific",
            "attributes": {},
            "unsupported_attributes": {}
          }
        },
        "out_clusters": {}
      },
      "242": {
        "device_type": {
          "name": "PROXY_BASIC",
          "id": 97
        },
        "profile_id": 41440,
        "in_clusters": {},
        "out_clusters": {
          "0x0021": {
            "endpoint_attribute": "green_power",
            "attributes": {},
            "unsupported_attributes": {}
          }
        }
      }
    }
  }
}

Diagnostic information

Diagnostic information
[Paste the diagnostic information here]

Logs

Logs
Max concurrency (8) reached, delaying request (5 enqueued)
[0xB795:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0002]: async_initialize: retryable request #2 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 1.1s
Previously delayed request is now running, delayed by 1.65s
Previously delayed request is now running, delayed by 1.63s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 19, 162634, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x1B6C), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=80, profile_id=0, cluster_id=32820, data=Serialized[b'\xad\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
[0xB795:1:0x0b04]: failed to get attributes '['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0b04]: async_initialize: retryable request #2 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 1.2s
Previously delayed request is now running, delayed by 1.10s
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
Device 0x1b6c (04:cf:8c:df:3c:76:31:d6) left the network
[0xB795:1:0x0002]: initializing cluster handler: from_cache: False
[0xB795:1:0x0002]: initializing uncached cluster handler attributes: ['current_temperature'] - from cache[False]
[0xB795:1:0x0002]: Reading attributes in chunks: ['current_temperature']
[0xB795:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=182, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0002] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (3 enqueued)
[0xB795:1:0x0b04]: initializing cluster handler: from_cache: False
[0xB795:1:0x0b04]: initializing cached cluster handler attributes: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor', 'ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor', 'power_multiplier', 'power_factor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['power_multiplier', 'power_factor']
[0xB795:1:0x0b04]: initializing uncached cluster handler attributes: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max', 'rms_voltage', 'rms_voltage_max', 'ac_frequency', 'ac_frequency_max'] - from cache[False]
[0xB795:1:0x0b04]: Reading attributes in chunks: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']
[0xB795:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=183, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291, 1293, 1295, 1288, 1290])
Max concurrency (8) reached, delaying request (4 enqueued)
[0xAF40:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:1:0x0006]: async_initialize: retryable request #2 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 1.2s
Previously delayed request is now running, delayed by 2.32s
[0xAF40:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:2:0x0006]: async_initialize: retryable request #2 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 1.2s
Previously delayed request is now running, delayed by 2.18s
[0xACD8:1:0x0702]: failed to get attributes '['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']' on 'smartenergy_metering' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0702]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.0s
Previously delayed request is now running, delayed by 2.49s
Previously delayed request is now running, delayed by 1.02s
[0xAF40:2:0x0006]: initializing cluster handler: from_cache: False
[0xAF40:2:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xAF40:2:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xAF40:2:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xAF40:2:0x0006]: Reading attributes in chunks: ['on_off']
[0xAF40:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=188, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xAF40:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (1 enqueued)
[0xAF40:1:0x0006]: initializing cluster handler: from_cache: False
[0xAF40:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xAF40:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xAF40:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xAF40:1:0x0006]: Reading attributes in chunks: ['on_off']
[0xAF40:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=189, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xAF40:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (2 enqueued)
[0xACD8:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0002]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.3s
Previously delayed request is now running, delayed by 1.47s
[0xACD8:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0006]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.3s
Previously delayed request is now running, delayed by 0.30s
[0xACD8:1:0x0b04]: failed to get attributes '['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0b04]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 2.8s
Previously delayed request is now running, delayed by 0.30s
New device 0x3703 (04:cf:8c:df:3c:76:31:d6) joined the network
[0x3703] Scheduling initialization
Tries remaining: 5
[0x3703] Requesting 'Node Descriptor'
[0x3703] Extending timeout for 0xc1 request
Max concurrency (8) reached, delaying request (0 enqueued)
Device 0x3703 (04:cf:8c:df:3c:76:31:d6) joined the network
[0x3703] Scheduling initialization
[0x3703] Canceling old initialize call
Tries remaining: 5
[0x3703] Requesting 'Node Descriptor'
[0x3703] Extending timeout for 0xc2 request
Max concurrency (8) reached, delaying request (0 enqueued)
[0xBCD2:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xBCD2:1:0x0006]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.3s
Previously delayed request is now running, delayed by 0.03s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 11118, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), 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=6, profile_id=0, cluster_id=19, data=Serialized[b'\xd3\x037\xd61v<\xdf\x8c\xcf\x04\x8e'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
Device 0x3703 (04:cf:8c:df:3c:76:31:d6) joined the network
[0x3703] Scheduling initialization
[0x3703] Canceling old initialize call
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 19: Serialized[b'\xd3\x037\xd61v<\xdf\x8c\xcf\x04\x8e']
[0x3703:zdo] ZDO request ZDOCmd.Device_annce: [0x3703, 04:cf:8c:df:3c:76:31:d6, 142]
Tries remaining: 5
[0x3703] Requesting 'Node Descriptor'
[0x3703] Extending timeout for 0xc4 request
[0xBCD2:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xBCD2:1:0x0002]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.7s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 87741, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=7, profile_id=0, cluster_id=32770, data=Serialized[b'\xc2\x00\x037\x01@\x8e_\x11\x7fd\x00\x00,d\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32770: Serialized[b'\xc2\x00\x037\x01@\x8e_\x11\x7fd\x00\x00,d\x00\x00']
[0x3703:zdo] ZDO request ZDOCmd.Node_Desc_rsp: [<Status.SUCCESS: 0>, 0x3703, NodeDescriptor(logical_type=<LogicalType.Router: 1>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True, *is_security_capable=False)]
[0x3703:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_rsp([<Status.SUCCESS: 0>, 0x3703, NodeDescriptor(logical_type=<LogicalType.Router: 1>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True, *is_security_capable=False)])
[0xACD8:1:0x0702]: initializing cluster handler: from_cache: False
[0xACD8:1:0x0702]: initializing cached cluster handler attributes: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting', 'unit_of_measure']
[0xACD8:1:0x0702]: Reading attributes in chunks: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting']
[0xACD8:1:0x0702]: Reading attributes in chunks: ['unit_of_measure']
[0xACD8:1:0x0702]: initializing uncached cluster handler attributes: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered', 'current_tier4_summ_delivered', 'current_tier5_summ_delivered', 'current_tier6_summ_delivered', 'status'] - from cache[False]
[0xACD8:1:0x0702]: Reading attributes in chunks: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']
[0xACD8:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=198, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xACD8:1:0x0702] Sending request: Read_Attributes(attribute_ids=[1024, 0, 256, 258, 260])
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 322981, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=8, profile_id=0, cluster_id=32770, data=Serialized[b'\xc4\x00\x037\x01@\x8e_\x11\x7fd\x00\x00,d\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32770: Serialized[b'\xc4\x00\x037\x01@\x8e_\x11\x7fd\x00\x00,d\x00\x00']
[0x3703] Got Node Descriptor: NodeDescriptor(logical_type=<LogicalType.Router: 1>, complex_descriptor_available=0, user_descriptor_available=0, reserved=0, aps_flags=0, frequency_band=<FrequencyBand.Freq2400MHz: 8>, mac_capability_flags=<MACCapabilityFlags.FullFunctionDevice|MainsPowered|RxOnWhenIdle|AllocateAddress: 142>, manufacturer_code=4447, maximum_buffer_size=127, maximum_incoming_transfer_size=100, server_mask=11264, maximum_outgoing_transfer_size=100, descriptor_capability_field=<DescriptorCapability.NONE: 0>, *allocate_address=True, *is_alternate_pan_coordinator=False, *is_coordinator=False, *is_end_device=False, *is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True, *is_security_capable=False)
[0x3703] Discovering endpoints
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 331687, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=9, profile_id=0, cluster_id=2, data=Serialized[b'\xd4\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 2: Serialized[b'\xd4\x00\x00']
[0x3703:zdo] ZDO request ZDOCmd.Node_Desc_req: [0x0000]
[0x3703:zdo] No handler for ZDO request:ZDOCmd.Node_Desc_req([0x0000])
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 486208, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=11, profile_id=0, cluster_id=32773, data=Serialized[b'\xc8\x00\x037\x03\x01\x02\xf2'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32773: Serialized[b'\xc8\x00\x037\x03\x01\x02\xf2']
[0x3703] Discovered endpoints: [1, 2, 242]
[0x3703] Initializing endpoints [<Endpoint id=1 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=2 in=[] out=[] status=<Status.NEW: 0>>, <Endpoint id=242 in=[] out=[] status=<Status.NEW: 0>>]
[0x3703:1] Discovering endpoint information
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 598253, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=13, profile_id=0, cluster_id=32772, data=Serialized[b'\xca\x00\x037\x1e\x01\x04\x01\x00\x01\x01\t\x00\x00\x02\x00\x03\x00\x04\x00\x05\x00\x06\x00\t\x00\x02\x07\x04\x0b\x02\n\x00\x19\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32772: Serialized[b'\xca\x00\x037\x1e\x01\x04\x01\x00\x01\x01\t\x00\x00\x02\x00\x03\x00\x04\x00\x05\x00\x06\x00\t\x00\x02\x07\x04\x0b\x02\n\x00\x19\x00']
[0x3703:1] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=1, profile=260, device_type=256, device_version=1, input_clusters=[0, 2, 3, 4, 5, 6, 9, 1794, 2820], output_clusters=[10, 25])
[0x3703:2] Discovering endpoint information
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 668570, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=14, profile_id=0, cluster_id=32772, data=Serialized[b'\xcc\x00\x037\x16\x02\x04\x01\x00\x01\x01\x07\x00\x00\x03\x00\x04\x00\x05\x00\x06\x00\x12\x00\xc0\xfc\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32772: Serialized[b'\xcc\x00\x037\x16\x02\x04\x01\x00\x01\x01\x07\x00\x00\x03\x00\x04\x00\x05\x00\x06\x00\x12\x00\xc0\xfc\x00']
[0x3703:2] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=2, profile=260, device_type=256, device_version=1, input_clusters=[0, 3, 4, 5, 6, 18, 64704], output_clusters=[])
[0x3703:242] Discovering endpoint information
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 738220, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=15, profile_id=0, cluster_id=32772, data=Serialized[b'\xce\x00\x037\n\xf2\xe0\xa1a\x00\x00\x00\x01!\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
Received frame on uninitialized device <Device model=None manuf=None nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=False> from ep 0 to ep 0, cluster 32772: Serialized[b'\xce\x00\x037\n\xf2\xe0\xa1a\x00\x00\x00\x01!\x00']
[0x3703:242] Discovered endpoint information: SizePrefixedSimpleDescriptor(endpoint=242, profile=41440, device_type=97, device_version=0, input_clusters=[], output_clusters=[33])
[0x3703:1:0x0000] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=208, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0000] Sending request: Read_Attributes(attribute_ids=[4, 5])
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 821306, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=16, profile_id=260, cluster_id=0, data=Serialized[b'\x18\xd0\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x14lumi.switch.b2naus01'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
[0x3703:1:0x0000] Received ZCL frame: b'\x18\xd0\x01\x04\x00\x00B\x04LUMI\x05\x00\x00B\x14lumi.switch.b2naus01'
[0x3703:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=208, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0000] Decoded ZCL frame: Basic:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0004, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='LUMI')), ReadAttributeRecord(attrid=0x0005, status=<Status.SUCCESS: 0>, value=TypeValue(type=CharacterString, value='lumi.switch.b2naus01'))])
[0x3703] Read model 'lumi.switch.b2naus01' and manufacturer 'LUMI' from <Endpoint id=1 in=[basic:0x0000, device_temperature:0x0002, identify:0x0003, groups:0x0004, scenes:0x0005, on_off:0x0006, alarms:0x0009, smartenergy_metering:0x0702, electrical_measurement:0x0B04] out=[time:0x000A, ota:0x0019] status=<Status.ZDO_INIT: 1>>
[0x3703] Discovered basic device information for <Device model='lumi.switch.b2naus01' manuf='LUMI' nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=True>
Device is initialized <Device model='lumi.switch.b2naus01' manuf='LUMI' nwk=0x3703 ieee=04:cf:8c:df:3c:76:31:d6 is_initialized=True>
Checking quirks for LUMI lumi.switch.b2naus01 (04:cf:8c:df:3c:76:31:d6)
Considering <class 'zhaquirks.xiaomi.aqara.opple_switch.XiaomiOpple2ButtonSwitchFace1'>
Fail because endpoint list mismatch: {1, 2, 41, 42, 242, 51, 21, 31} {1, 2, 242}
Considering <class 'zhaquirks.xbee.xbee_io.XBeeSensor'>
Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
Considering <class 'zhaquirks.xbee.xbee3_io.XBee3Sensor'>
Fail because endpoint list mismatch: {232, 230} {1, 2, 242}
Considering <class 'zhaquirks.tuya.ts0201.MoesTemperatureHumidtySensorWithScreen'>
Fail because endpoint list mismatch: {1} {1, 2, 242}
Considering <class 'zhaquirks.smartthings.tag_v4.SmartThingsTagV4'>
Fail because endpoint list mismatch: {1} {1, 2, 242}
Considering <class 'zhaquirks.smartthings.multi.SmartthingsMultiPurposeSensor'>
Fail because endpoint list mismatch: {1} {1, 2, 242}
Considering <class 'zhaquirks.netvox.z308e3ed.Z308E3ED'>
Fail because endpoint list mismatch: {1} {1, 2, 242}
Considering <class 'zhaquirks.gledopto.soposhgu10.SoposhGU10'>
Fail because endpoint list mismatch: {11, 13} {1, 2, 242}
Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
Creating cluster handler for cluster id: 2 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.DeviceTemperature'>
Creating cluster handler for cluster id: 3 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Identify'>
Creating cluster handler for cluster id: 4 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Groups'>
Creating cluster handler for cluster id: 5 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Scenes'>
Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
Creating cluster handler for cluster id: 9 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Alarms'>
Creating cluster handler for cluster id: 1794 class: <class 'homeassistant.components.zha.core.cluster_handlers.smartenergy.Metering'>
Creating cluster handler for cluster id: 2820 class: <class 'homeassistant.components.zha.core.cluster_handlers.homeautomation.ElectricalMeasurementClusterHandler'>
Discovering entities for endpoint: 04:cf:8c:df:3c:76:31:d6-1
'button' component -> 'ZHAIdentifyButton' using ['identify']
'sensor' component -> 'ElectricalMeasurementApparentPower' using ['electrical_measurement']
'sensor' component -> 'ElectricalMeasurementRMSCurrent' using ['electrical_measurement']
'sensor' component -> 'ElectricalMeasurementRMSVoltage' using ['electrical_measurement']
'sensor' component -> 'ElectricalMeasurementFrequency' using ['electrical_measurement']
'sensor' component -> 'ElectricalMeasurementPowerFactor' using ['electrical_measurement']
'sensor' component -> 'DeviceTemperature' using ['device_temperature']
'sensor' component -> 'RSSISensor' using ['basic']
'sensor' component -> 'LQISensor' using ['basic']
'sensor' component -> 'PolledElectricalMeasurement' using ['electrical_measurement']
'sensor' component -> 'SmartEnergyMetering' using ['smartenergy_metering']
'sensor' component -> 'SmartEnergySummation' using ['smartenergy_metering']
'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off']
Creating cluster handler for cluster id: 0 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.BasicClusterHandler'>
Creating cluster handler for cluster id: 3 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Identify'>
Creating cluster handler for cluster id: 4 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Groups'>
Creating cluster handler for cluster id: 5 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.Scenes'>
Creating cluster handler for cluster id: 6 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.OnOffClusterHandler'>
Creating cluster handler for cluster id: 18 class: <class 'homeassistant.components.zha.core.cluster_handlers.general.MultistateInput'>
Creating cluster handler for cluster id: 64704 class: <class 'homeassistant.components.zha.core.cluster_handlers.manufacturerspecific.OppleRemote'>
Discovering entities for endpoint: 04:cf:8c:df:3c:76:31:d6-2
'button' component -> 'ZHAIdentifyButton' using ['identify']
'sensor' component -> 'RSSISensor' using ['basic']
'sensor' component -> 'LQISensor' using ['basic']
'select' component -> 'ZHAStartupOnOffSelectEntity' using ['on_off']
Discovering entities for endpoint: 04:cf:8c:df:3c:76:31:d6-242
device - 0x3703:04:cf:8c:df:3c:76:31:d6 entering async_device_initialized - is_new_join: True
device - 0x3703:04:cf:8c:df:3c:76:31:d6 has joined the ZHA zigbee network
[0x3703](lumi.switch.b2naus01): started configuration
[0x3703:ZDO](lumi.switch.b2naus01): 'async_configure' stage succeeded
Error handling '_save_attribute' event with (04:cf:8c:df:3c:76:31:d6, 1, 0, 4, 'LUMI', datetime.datetime(2023, 12, 9, 19, 49, 24, 825386, tzinfo=datetime.timezone.utc)) params: FOREIGN KEY constraint failed
[0x3703:1:0x0006]: Performing cluster binding
[0x3703:1:0x0003]: Configuring cluster attribute reporting
[0x3703:1:0x0003]: finished cluster handler configuration
[0x3703:1:0x0000]: Configuring cluster attribute reporting
[0x3703:1:0x0000]: finished cluster handler configuration
[0x3703:1:0x0b04]: Performing cluster binding
Max concurrency (8) reached, delaying request (0 enqueued)
[0x3703:1:0x0702]: Performing cluster binding
Max concurrency (8) reached, delaying request (1 enqueued)
[0x3703:1:0x0002]: Performing cluster binding
Max concurrency (8) reached, delaying request (2 enqueued)
[0x3703:1:0x0019]: finished cluster handler configuration
[0x3703:2:0x0006]: Performing cluster binding
Max concurrency (8) reached, delaying request (3 enqueued)
[0x3703:2:0x0003]: Configuring cluster attribute reporting
[0x3703:2:0x0003]: finished cluster handler configuration
[0x3703:2:0x0000]: Configuring cluster attribute reporting
[0x3703:2:0x0000]: finished cluster handler configuration
[0x3703:2:0xfcc0]: Performing cluster binding
Max concurrency (8) reached, delaying request (4 enqueued)
[0xACD8:1:0x0b04]: initializing cluster handler: from_cache: False
[0xACD8:1:0x0b04]: initializing cached cluster handler attributes: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor', 'ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor', 'power_multiplier', 'power_factor']
[0xACD8:1:0x0b04]: Reading attributes in chunks: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor']
[0xACD8:1:0x0b04]: Reading attributes in chunks: ['ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor']
[0xACD8:1:0x0b04]: Reading attributes in chunks: ['power_multiplier', 'power_factor']
[0xACD8:1:0x0b04]: initializing uncached cluster handler attributes: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max', 'rms_voltage', 'rms_voltage_max', 'ac_frequency', 'ac_frequency_max'] - from cache[False]
[0xACD8:1:0x0b04]: Reading attributes in chunks: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']
[0xACD8:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=217, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xACD8:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291, 1293, 1295, 1288, 1290])
Max concurrency (8) reached, delaying request (5 enqueued)
Error handling '_save_attribute' event with (04:cf:8c:df:3c:76:31:d6, 1, 0, 5, 'lumi.switch.b2naus01', datetime.datetime(2023, 12, 9, 19, 49, 24, 825431, tzinfo=datetime.timezone.utc)) params: FOREIGN KEY constraint failed
Previously delayed request is now running, delayed by 0.03s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 903413, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=17, profile_id=0, cluster_id=32801, data=Serialized[b'\xd2\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0x3703:1:0x0006]: Configuring cluster attribute reporting
[0x3703:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=219, command_id=<GeneralCommand.Configure_Reporting: 6>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)])
Max concurrency (8) reached, delaying request (5 enqueued)
Previously delayed request is now running, delayed by 0.08s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 947795, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=18, profile_id=0, cluster_id=32801, data=Serialized[b'\xd4\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04]: bound 'electrical_measurement' cluster: Status.SUCCESS
[0x3703:1:0x0b04]: Configuring cluster attribute reporting
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=221, command_id=<GeneralCommand.Configure_Reporting: 6>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x050B, datatype=41, min_interval=5, max_interval=900, reportable_change=1), AttributeReportingConfig(direction=0, attrid=0x050D, datatype=41, min_interval=30, max_interval=900, reportable_change=1), AttributeReportingConfig(direction=0, attrid=0x050F, datatype=33, min_interval=5, max_interval=900, reportable_change=1)])
Max concurrency (8) reached, delaying request (5 enqueued)
Previously delayed request is now running, delayed by 0.12s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 24, 988002, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=19, profile_id=0, cluster_id=32801, data=Serialized[b'\xd5\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702]: bound 'smartenergy_metering' cluster: Status.SUCCESS
[0x3703:1:0x0702]: Configuring cluster attribute reporting
[0x3703:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=223, command_id=<GeneralCommand.Configure_Reporting: 6>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0702] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0400, datatype=42, min_interval=5, max_interval=900, reportable_change=1), AttributeReportingConfig(direction=0, attrid=0x0000, datatype=37, min_interval=30, max_interval=900, reportable_change=1), AttributeReportingConfig(direction=0, attrid=0x0100, datatype=37, min_interval=30, max_interval=900, reportable_change=1)])
Max concurrency (8) reached, delaying request (5 enqueued)
Previously delayed request is now running, delayed by 0.17s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 44828, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=20, profile_id=0, cluster_id=32801, data=Serialized[b'\xd6\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0002]: bound 'device_temperature' cluster: Status.SUCCESS
[0x3703:1:0x0002]: Configuring cluster attribute reporting
[0x3703:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=225, command_id=<GeneralCommand.Configure_Reporting: 6>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0002] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=41, min_interval=30, max_interval=900, reportable_change=50)])
Max concurrency (8) reached, delaying request (5 enqueued)
Previously delayed request is now running, delayed by 0.22s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 89053, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=21, profile_id=0, cluster_id=32801, data=Serialized[b'\xd7\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:2:0x0006]: bound 'on_off' cluster: Status.SUCCESS
[0x3703:2:0x0006]: Configuring cluster attribute reporting
[0x3703:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=227, command_id=<GeneralCommand.Configure_Reporting: 6>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:2:0x0006] Sending request: Configure_Reporting(config_records=[AttributeReportingConfig(direction=0, attrid=0x0000, datatype=16, min_interval=0, max_interval=900, reportable_change=1)])
Max concurrency (8) reached, delaying request (5 enqueued)
Previously delayed request is now running, delayed by 0.25s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 142310, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=0, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=0, source_route=None, extended_timeout=False, tsn=22, profile_id=0, cluster_id=32801, data=Serialized[b'\xd8\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:2:0xfcc0]: bound 'manufacturer_specific' cluster: Status.SUCCESS
[0x3703:2:0xfcc0]: Configuring cluster attribute reporting
[0x3703:2:0xfcc0]: finished cluster handler configuration
[0xACD8:1:0x0002]: initializing cluster handler: from_cache: False
[0xACD8:1:0x0002]: initializing uncached cluster handler attributes: ['current_temperature'] - from cache[False]
[0xACD8:1:0x0002]: Reading attributes in chunks: ['current_temperature']
[0xACD8:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=229, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xACD8:1:0x0002] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (5 enqueued)
[0xACD8:1:0x0006]: initializing cluster handler: from_cache: False
[0xACD8:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xACD8:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xACD8:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xACD8:1:0x0006]: Reading attributes in chunks: ['on_off']
[0xACD8:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=230, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xACD8:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (6 enqueued)
[0xB795:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0006]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 2.9s
Previously delayed request is now running, delayed by 0.39s
[0xB795:1:0x0702]: failed to get attributes '['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']' on 'smartenergy_metering' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0702]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.4s
Previously delayed request is now running, delayed by 0.36s
Previously delayed request is now running, delayed by 0.35s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 365970, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=23, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xdb\x07\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0006] Received ZCL frame: b'\x18\xdb\x07\x00'
[0x3703:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=219, command_id=7, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)])
[0x3703:1:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)]
[0x3703:1:0x0006]: finished cluster handler configuration
Previously delayed request is now running, delayed by 0.33s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 384027, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=24, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\xdd\x07\x8c\x00\x0b\x05\x86\x00\r\x05\x86\x00\x84\x03'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\xdd\x07\x8c\x00\x0b\x05\x86\x00\r\x05\x86\x00\x84\x03'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=221, command_id=7, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.UNREPORTABLE_ATTRIBUTE: 140>, direction=<ReportingDirection.SendReports: 0>, attrid=1291), ConfigureReportingResponseRecord(status=<Status.UNSUPPORTED_ATTRIBUTE: 134>, direction=<ReportingDirection.SendReports: 0>, attrid=1293), ConfigureReportingResponseRecord(status=<Status.UNSUPPORTED_ATTRIBUTE: 134>, direction=<ReportingDirection.SendReports: 0>, attrid=900)])
Previously delayed request is now running, delayed by 0.32s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 421340, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=25, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\xdf\x07\x86\x00\x00\x04\x86\x00\x84\x03\x8d\x00\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702] Received ZCL frame: b'\x18\xdf\x07\x86\x00\x00\x04\x86\x00\x84\x03\x8d\x00\x00\x00'
[0x3703:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=223, command_id=7, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0702] Decoded ZCL frame: Metering:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.UNSUPPORTED_ATTRIBUTE: 134>, direction=<ReportingDirection.SendReports: 0>, attrid=1024), ConfigureReportingResponseRecord(status=<Status.UNSUPPORTED_ATTRIBUTE: 134>, direction=<ReportingDirection.SendReports: 0>, attrid=900), ConfigureReportingResponseRecord(status=<Status.INVALID_DATA_TYPE: 141>, direction=<ReportingDirection.SendReports: 0>, attrid=0)])
Previously delayed request is now running, delayed by 0.24s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 440869, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=26, profile_id=260, cluster_id=2, data=Serialized[b'\x18\xe1\x07\x8c\x00\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0002] Received ZCL frame: b'\x18\xe1\x07\x8c\x00\x00\x00'
[0x3703:1:0x0002] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=225, command_id=7, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0002] Decoded ZCL frame: DeviceTemperature:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.UNREPORTABLE_ATTRIBUTE: 140>, direction=<ReportingDirection.SendReports: 0>, attrid=0)])
[0x3703:1:0x0002]: Successfully configured reporting for 'set()' on 'device_temperature' cluster
[0x3703:1:0x0002]: Failed to configure reporting for '['current_temperature']' on 'device_temperature' cluster: [ConfigureReportingResponseRecord(status=<Status.UNREPORTABLE_ATTRIBUTE: 140>, direction=<ReportingDirection.SendReports: 0>, attrid=0)]
[0x3703:1:0x0002]: finished cluster handler configuration
[0x3703:1:0x0006]: 'async_configure' stage succeeded
[0x3703:1:0x0003]: 'async_configure' stage succeeded
[0x3703:1:0x0000]: 'async_configure' stage succeeded
[0x3703:1:0x0b04]: 'async_configure' stage failed: 900
[0x3703:1:0x0702]: 'async_configure' stage failed: 900
[0x3703:1:0x0002]: 'async_configure' stage succeeded
[0x3703:1:0x0019]: 'async_configure' stage succeeded
Previously delayed request is now running, delayed by 0.18s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 477212, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=27, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xe3\x07\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=160, rssi=-60)
[0x3703:2:0x0006] Received ZCL frame: b'\x18\xe3\x07\x00'
[0x3703:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=227, command_id=7, *direction=<Direction.Client_to_Server: 1>)
[0x3703:2:0x0006] Decoded ZCL frame: OnOff:Configure_Reporting_rsp(status_records=[ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)])
[0x3703:2:0x0006]: Successfully configured reporting for '{'on_off': (0, 900, 1)}' on 'on_off' cluster: [ConfigureReportingResponseRecord(status=<Status.SUCCESS: 0>)]
[0x3703:2:0x0006]: finished cluster handler configuration
[0x3703:2:0x0006]: 'async_configure' stage succeeded
[0x3703:2:0x0003]: 'async_configure' stage succeeded
[0x3703:2:0x0000]: 'async_configure' stage succeeded
[0x3703:2:0xfcc0]: 'async_configure' stage succeeded
[0x3703](lumi.switch.b2naus01): completed configuration
Tries remaining: 3
[0x3703:1:0x0003] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=238, command_id=64, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0003] Sending request: trigger_effect(effect_id=<EffectIdentifier.Okay: 2>, effect_variant=<EffectVariant.Default: 0>)
Max concurrency (8) reached, delaying request (0 enqueued)
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 562183, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=28, profile_id=260, cluster_id=64704, data=Serialized[b"\x1c_\x11\x00\n\xf7\x00A=d\x10\x00e\x10\x00\x03(\x14\x989\x00\x00\x00\x00\x959\x954\x8cA\x969\x00\x80\x93D\x979\x00\x00\x00\x00\x05!\x01\x00\x9a \x10\x08!\x19\x01\x07'\x00\x00\x00\x00\x00\x00\x00\x00\t!\x00\t\x0b \x00"], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703] Ignoring message on unknown cluster 64704 for endpoint <Endpoint id=1 in=[basic:0x0000, device_temperature:0x0002, identify:0x0003, groups:0x0004, scenes:0x0005, on_off:0x0006, alarms:0x0009, smartenergy_metering:0x0702, electrical_measurement:0x0B04] out=[time:0x000A, ota:0x0019] status=<Status.ZDO_INIT: 1>>
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 25, 879802, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=29, profile_id=260, cluster_id=0, data=Serialized[b'\x18\x01\n\x05\x00B\x14lumi.switch.b2naus01\x01\x00 \x19'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0000] Received ZCL frame: b'\x18\x01\n\x05\x00B\x14lumi.switch.b2naus01\x01\x00 \x19'
[0x3703:1:0x0000] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=1, command_id=10, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0000] Decoded ZCL frame: Basic:Report_Attributes(attribute_reports=[Attribute(attrid=0x0005, value=TypeValue(type=CharacterString, value='lumi.switch.b2naus01')), Attribute(attrid=0x0001, value=TypeValue(type=uint8_t, value=25))])
[0x3703:1:0x0000] Received command 0x0A (TSN 1): Report_Attributes(attribute_reports=[Attribute(attrid=0x0005, value=TypeValue(type=CharacterString, value='lumi.switch.b2naus01')), Attribute(attrid=0x0001, value=TypeValue(type=uint8_t, value=25))])
[0x3703:1:0x0000] Attribute report received: model='lumi.switch.b2naus01', app_version=25
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 79554, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=30, profile_id=260, cluster_id=10, data=Serialized[b'\x10\x02\x00\x00\x00\x02\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x000a] Received ZCL frame: b'\x10\x02\x00\x00\x00\x02\x00'
[0x3703:1:0x000a] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Server_to_Client: 0>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=2, command_id=0, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x000a] Decoded ZCL frame: Time:Read_Attributes(attribute_ids=[0, 2])
[0x3703:1:0x000a] Received command 0x00 (TSN 2): Read_Attributes(attribute_ids=[0, 2])
[0x3703:1:0x000a] Sending reply header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=2, command_id=<GeneralCommand.Read_Attributes_rsp: 1>, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x000a] Sending reply: Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=UTCTime, value=755466566)), ReadAttributeRecord(attrid=0x0002, status=<Status.SUCCESS: 0>, value=TypeValue(type=int32s, value=-28800))])
Max concurrency (8) reached, delaying request (1 enqueued)
[0xB795:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0002]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.3s
Previously delayed request is now running, delayed by 0.61s
Previously delayed request is now running, delayed by 0.05s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 147724, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=31, profile_id=260, cluster_id=3, data=Serialized[b'\x18\xee\x0b@\x81'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0003] Received ZCL frame: b'\x18\xee\x0b@\x81'
[0x3703:1:0x0003] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=238, command_id=11, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0003] Decoded ZCL frame: Identify:Default_Response(command_id=64, status=<Status.UNSUP_CLUSTER_COMMAND: 129>)
[0x3703](lumi.switch.b2naus01): started initialization
[0x3703:ZDO](lumi.switch.b2naus01): 'async_initialize' stage succeeded
[0x3703:1:0x0006]: initializing cluster handler: from_cache: False
[0x3703:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0x3703:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0x3703:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=241, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0006] Sending request: Read_Attributes(attribute_ids=[16387])
Max concurrency (8) reached, delaying request (0 enqueued)
[0x3703:1:0x0003]: initializing cluster handler: from_cache: False
[0x3703:1:0x0003]: finished cluster handler initialization
[0x3703:1:0x0000]: initializing cluster handler: from_cache: False
[0x3703:1:0x0000]: finished cluster handler initialization
[0x3703:1:0x0b04]: initializing cluster handler: from_cache: False
[0x3703:1:0x0b04]: initializing cached cluster handler attributes: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor', 'ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor', 'power_multiplier', 'power_factor']
[0x3703:1:0x0b04]: Reading attributes in chunks: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=242, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1539, 1538, 1541, 1540, 1537])
Max concurrency (8) reached, delaying request (1 enqueued)
[0x3703:1:0x0702]: initializing cluster handler: from_cache: False
[0x3703:1:0x0702]: initializing cached cluster handler attributes: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting', 'unit_of_measure']
[0x3703:1:0x0702]: Reading attributes in chunks: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting']
[0x3703:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=243, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0702] Sending request: Read_Attributes(attribute_ids=[772, 770, 774, 769, 771])
Max concurrency (8) reached, delaying request (2 enqueued)
[0x3703:1:0x0002]: initializing cluster handler: from_cache: False
[0x3703:1:0x0002]: initializing uncached cluster handler attributes: ['current_temperature'] - from cache[False]
[0x3703:1:0x0002]: Reading attributes in chunks: ['current_temperature']
[0x3703:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=244, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0002] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (3 enqueued)
[0x3703:1:0x0019]: initializing cluster handler: from_cache: False
[0x3703:1:0x0019]: finished cluster handler initialization
[0x3703:2:0x0006]: initializing cluster handler: from_cache: False
[0x3703:2:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0x3703:2:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0x3703:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=245, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:2:0x0006] Sending request: Read_Attributes(attribute_ids=[16387])
Max concurrency (8) reached, delaying request (4 enqueued)
[0x3703:2:0x0003]: initializing cluster handler: from_cache: False
[0x3703:2:0x0003]: finished cluster handler initialization
[0x3703:2:0x0000]: initializing cluster handler: from_cache: False
[0x3703:2:0x0000]: finished cluster handler initialization
[0x3703:2:0xfcc0]: initializing cluster handler: from_cache: False
[0x3703:2:0xfcc0]: Performing cluster handler specific initialization: []
[0x3703:2:0xfcc0]: finished cluster handler initialization
Previously delayed request is now running, delayed by 0.02s
Previously delayed request is now running, delayed by 0.05s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 219802, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=32, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xf1\x01\x03@\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0006] Received ZCL frame: b'\x18\xf1\x01\x03@\x86'
[0x3703:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=241, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0x3703:1:0x0006]: Reading attributes in chunks: ['on_off']
[0x3703:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=248, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (3 enqueued)
Previously delayed request is now running, delayed by 0.08s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 269120, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=33, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\xf2\x01\x03\x06\x86\x02\x06\x86\x05\x06\x00!\n\x00\x04\x06\x00!\x01\x00\x01\x06\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\xf2\x01\x03\x06\x86\x02\x06\x86\x05\x06\x00!\n\x00\x04\x06\x00!\x01\x00\x01\x06\x86'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=242, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0603, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0602, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0605, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint16_t, value=10)), ReadAttributeRecord(attrid=0x0604, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint16_t, value=1)), ReadAttributeRecord(attrid=0x0601, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0b04]: Reading attributes in chunks: ['ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=250, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1536, 1025, 1024, 0, 1027])
Max concurrency (8) reached, delaying request (3 enqueued)
Previously delayed request is now running, delayed by 0.12s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 302157, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=34, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\xf3\x01\x04\x03\x00\x18\x00\x02\x03\x00"\xe8\x03\x00\x06\x03\x00\x18\x00\x01\x03\x00"\x01\x00\x00\x03\x03\x00\x18#'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702] Received ZCL frame: b'\x18\xf3\x01\x04\x03\x00\x18\x00\x02\x03\x00"\xe8\x03\x00\x06\x03\x00\x18\x00\x01\x03\x00"\x01\x00\x00\x03\x03\x00\x18#'
[0x3703:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=243, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0702] Decoded ZCL frame: Metering:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0304, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>)), ReadAttributeRecord(attrid=0x0302, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint24_t, value=1000)), ReadAttributeRecord(attrid=0x0306, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>)), ReadAttributeRecord(attrid=0x0301, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint24_t, value=1)), ReadAttributeRecord(attrid=0x0303, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 35>))])
[0x3703:1:0x0702]: Reading attributes in chunks: ['unit_of_measure']
[0x3703:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=252, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0702] Sending request: Read_Attributes(attribute_ids=[768])
Max concurrency (8) reached, delaying request (3 enqueued)
Previously delayed request is now running, delayed by 0.15s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 332331, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=35, profile_id=260, cluster_id=2, data=Serialized[b'\x18\xf4\x01\x00\x00\x00)\x14\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0002] Received ZCL frame: b'\x18\xf4\x01\x00\x00\x00)\x14\x00'
[0x3703:1:0x0002] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=244, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0002] Decoded ZCL frame: DeviceTemperature:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=20))])
[0x3703:1:0x0002]: finished cluster handler initialization
Previously delayed request is now running, delayed by 0.13s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 372073, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=36, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xf5\x01\x03@\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:2:0x0006] Received ZCL frame: b'\x18\xf5\x01\x03@\x86'
[0x3703:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=245, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x4003, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:2:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0x3703:2:0x0006]: Reading attributes in chunks: ['on_off']
[0x3703:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=255, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (2 enqueued)
Previously delayed request is now running, delayed by 0.13s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 414404, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=37, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xf8\x01\x00\x00\x00\x10\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0006] Received ZCL frame: b'\x18\xf8\x01\x00\x00\x00\x10\x00'
[0x3703:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=248, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=Bool, value=<Bool.false: 0>))])
[0x3703:1:0x0006]: finished cluster handler initialization
Previously delayed request is now running, delayed by 0.13s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 463352, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=38, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\xfa\x01\x00\x06\x86\x01\x04\x86\x00\x04\x86\x00\x00\x00\x1b\x08\x00\x00\x00\x03\x04\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\xfa\x01\x00\x06\x86\x01\x04\x86\x00\x04\x86\x00\x00\x00\x1b\x08\x00\x00\x00\x03\x04\x86'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=250, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0600, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0401, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0400, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap32, value=<bitmap32: 8>)), ReadAttributeRecord(attrid=0x0403, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0b04]: Reading attributes in chunks: ['power_multiplier', 'power_factor']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=2, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1026, 1296])
Max concurrency (8) reached, delaying request (1 enqueued)
Previously delayed request is now running, delayed by 0.11s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 497162, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=39, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\xfc\x01\x00\x03\x000\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702] Received ZCL frame: b'\x18\xfc\x01\x00\x03\x000\x00'
[0x3703:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=252, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0702] Decoded ZCL frame: Metering:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0300, status=<Status.SUCCESS: 0>, value=TypeValue(type=enum8, value=<enum8.undefined_0x00: 0>))])
[0x3703:1:0x0702]: initializing uncached cluster handler attributes: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered', 'current_tier4_summ_delivered', 'current_tier5_summ_delivered', 'current_tier6_summ_delivered', 'status'] - from cache[False]
[0x3703:1:0x0702]: Reading attributes in chunks: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']
[0x3703:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=4, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0702] Sending request: Read_Attributes(attribute_ids=[1024, 0, 256, 258, 260])
Max concurrency (8) reached, delaying request (1 enqueued)
Previously delayed request is now running, delayed by 0.05s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 530101, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=2, source_route=None, extended_timeout=False, tsn=40, profile_id=260, cluster_id=6, data=Serialized[b'\x18\xff\x01\x00\x00\x00\x10\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:2:0x0006] Received ZCL frame: b'\x18\xff\x01\x00\x00\x00\x10\x00'
[0x3703:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=255, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:2:0x0006] Decoded ZCL frame: OnOff:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=Bool, value=<Bool.false: 0>))])
[0x3703:2:0x0006]: finished cluster handler initialization
[0x3703:2:0x0006]: 'async_initialize' stage succeeded
[0x3703:2:0x0003]: 'async_initialize' stage succeeded
[0x3703:2:0x0000]: 'async_initialize' stage succeeded
[0x3703:2:0xfcc0]: 'async_initialize' stage succeeded
Previously delayed request is now running, delayed by 0.06s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 575753, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=41, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x02\x01\x02\x04\x86\x10\x05\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\x02\x01\x02\x04\x86\x10\x05\x86'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=2, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0402, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0510, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0b04]: initializing uncached cluster handler attributes: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max', 'rms_voltage', 'rms_voltage_max', 'ac_frequency', 'ac_frequency_max'] - from cache[False]
[0x3703:1:0x0b04]: Reading attributes in chunks: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=7, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291, 1293, 1295, 1288, 1290])
Max concurrency (8) reached, delaying request (0 enqueued)
Previously delayed request is now running, delayed by 0.03s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 624242, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=42, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\x04\x01\x00\x04\x86\x00\x00\x00%uD\x00\x00\x00\x00\x00\x01\x86\x02\x01\x86\x04\x01\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702] Received ZCL frame: b'\x18\x04\x01\x00\x04\x86\x00\x00\x00%uD\x00\x00\x00\x00\x00\x01\x86\x02\x01\x86\x04\x01\x86'
[0x3703:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=4, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0702] Decoded ZCL frame: Metering:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0400, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0000, status=<Status.SUCCESS: 0>, value=TypeValue(type=uint48_t, value=17525)), ReadAttributeRecord(attrid=0x0100, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0102, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0104, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0702]: Reading attributes in chunks: ['current_tier4_summ_delivered', 'current_tier5_summ_delivered', 'current_tier6_summ_delivered', 'status']
[0x3703:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=9, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0702] Sending request: Read_Attributes(attribute_ids=[262, 264, 266, 512])
Max concurrency (8) reached, delaying request (0 enqueued)
Previously delayed request is now running, delayed by 0.02s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 657897, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=43, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x07\x01\x0b\x05\x00)\x00\x00\r\x05\x86\x0f\x05\x86\x08\x05\x86\n\x05\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\x07\x01\x0b\x05\x00)\x00\x00\r\x05\x86\x0f\x05\x86\x08\x05\x86\n\x05\x86'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=7, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0)), ReadAttributeRecord(attrid=0x050D, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x050F, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0508, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x050A, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0b04]: Reading attributes in chunks: ['rms_voltage', 'rms_voltage_max', 'ac_frequency', 'ac_frequency_max']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=11, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1285, 1287, 768, 770])
Max concurrency (8) reached, delaying request (0 enqueued)
Previously delayed request is now running, delayed by 0.02s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 698869, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=44, profile_id=260, cluster_id=1794, data=Serialized[b'\x18\t\x01\x06\x01\x86\x08\x01\x86\n\x01\x86\x00\x02\x00\x18\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0702] Received ZCL frame: b'\x18\t\x01\x06\x01\x86\x08\x01\x86\n\x01\x86\x00\x02\x00\x18\x00'
[0x3703:1:0x0702] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=9, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0702] Decoded ZCL frame: Metering:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0106, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0108, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x010A, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0200, status=<Status.SUCCESS: 0>, value=TypeValue(type=bitmap8, value=<bitmap8: 0>))])
[0x3703:1:0x0702]: Performing cluster handler specific initialization: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered', 'current_tier4_summ_delivered', 'current_tier5_summ_delivered', 'current_tier6_summ_delivered', 'status']
[0x3703:1:0x0702]: finished cluster handler initialization
[0xB795:1:0x0b04]: failed to get attributes '['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0b04]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.4s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 26, 750290, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=45, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x0b\x01\x05\x05\x86\x07\x05\x86\x00\x03\x86\x02\x03\x86'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18\x0b\x01\x05\x05\x86\x07\x05\x86\x00\x03\x86\x02\x03\x86'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=11, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x0505, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0507, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0300, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>), ReadAttributeRecord(attrid=0x0302, status=<Status.UNSUPPORTED_ATTRIBUTE: 134>)])
[0x3703:1:0x0b04]: finished cluster handler initialization
[0x3703:1:0x0006]: 'async_initialize' stage succeeded
[0x3703:1:0x0003]: 'async_initialize' stage succeeded
[0x3703:1:0x0000]: 'async_initialize' stage succeeded
[0x3703:1:0x0b04]: 'async_initialize' stage succeeded
[0x3703:1:0x0702]: 'async_initialize' stage succeeded
[0x3703:1:0x0002]: 'async_initialize' stage succeeded
[0x3703:1:0x0019]: 'async_initialize' stage succeeded
[0x3703](lumi.switch.b2naus01): power source: Mains
[0x3703](lumi.switch.b2naus01): completed initialization
start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation
start_up_on_off is not supported - skipping ZHAStartupOnOffSelectEntity entity creation
[0xAF40:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:2:0x0006]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.1s
[0xAF40:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:1:0x0006]: async_initialize: retryable request #3 failed: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>. Retrying in 3.0s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 27, 200355, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=46, profile_id=260, cluster_id=64704, data=Serialized[b"\x1c_\x11\x03\n\xf7\x00A=d\x10\x00e\x10\x00\x03(\x14\x989\x00\x00\x00\x00\x959\x954\x8cA\x969\x00\x80\x93D\x979\x00\x00\x00\x00\x05!\x01\x00\x9a \x00\x08!\x19\x01\x07'\x00\x00\x00\x00\x00\x00\x00\x00\t!\x00\t\x0b \x00"], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703] Ignoring message on unknown cluster 64704 for endpoint <Endpoint id=1 in=[basic:0x0000, device_temperature:0x0002, identify:0x0003, groups:0x0004, scenes:0x0005, on_off:0x0006, alarms:0x0009, smartenergy_metering:0x0702, electrical_measurement:0x0B04] out=[time:0x000A, ota:0x0019] status=<Status.ZDO_INIT: 1>>
[0xBCD2:1:0x0006]: initializing cluster handler: from_cache: False
[0xBCD2:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xBCD2:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xBCD2:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xBCD2:1:0x0006]: Reading attributes in chunks: ['on_off']
[0xBCD2:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=13, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xBCD2:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
[0xBCD2:1:0x0002]: initializing cluster handler: from_cache: False
[0xBCD2:1:0x0002]: initializing uncached cluster handler attributes: ['current_temperature'] - from cache[False]
[0xBCD2:1:0x0002]: Reading attributes in chunks: ['current_temperature']
[0xBCD2:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=15, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xBCD2:1:0x0002] Sending request: Read_Attributes(attribute_ids=[0])
[0xB795:1:0x0006]: initializing cluster handler: from_cache: False
[0xB795:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xB795:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xB795:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xB795:1:0x0006]: Reading attributes in chunks: ['on_off']
[0xB795:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=17, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 28, 296169, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=47, profile_id=260, cluster_id=6, data=Serialized[b'\x18\x04\n\x00\x00\x10\x00\xf5\x00#\x00\xff\xff\x02'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0006] Received ZCL frame: b'\x18\x04\n\x00\x00\x10\x00\xf5\x00#\x00\xff\xff\x02'
[0x3703:1:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=4, command_id=10, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0006] Decoded ZCL frame: OnOff:Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=Bool, value=<Bool.false: 0>)), Attribute(attrid=0x00F5, value=TypeValue(type=uint32_t, value=50331392))])
[0x3703:1:0x0006] Received command 0x0A (TSN 4): Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=Bool, value=<Bool.false: 0>)), Attribute(attrid=0x00F5, value=TypeValue(type=uint32_t, value=50331392))])
[0x3703:1:0x0006] Attribute report received: on_off=<Bool.false: 0>, 0x00F5=50331392
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 28, 311679, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=2, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=48, profile_id=260, cluster_id=6, data=Serialized[b'\x18\x05\n\x00\x00\x10\x00\xf5\x00#\x00\xff\xff\x02'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:2:0x0006] Received ZCL frame: b'\x18\x05\n\x00\x00\x10\x00\xf5\x00#\x00\xff\xff\x02'
[0x3703:2:0x0006] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=5, command_id=10, *direction=<Direction.Client_to_Server: 1>)
[0x3703:2:0x0006] Decoded ZCL frame: OnOff:Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=Bool, value=<Bool.false: 0>)), Attribute(attrid=0x00F5, value=TypeValue(type=uint32_t, value=50331392))])
[0x3703:2:0x0006] Received command 0x0A (TSN 5): Report_Attributes(attribute_reports=[Attribute(attrid=0x0000, value=TypeValue(type=Bool, value=<Bool.false: 0>)), Attribute(attrid=0x00F5, value=TypeValue(type=uint32_t, value=50331392))])
[0x3703:2:0x0006] Attribute report received: on_off=<Bool.false: 0>, 0x00F5=50331392
[0xB795:1:0x0702]: initializing cluster handler: from_cache: False
[0xB795:1:0x0702]: initializing cached cluster handler attributes: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting', 'unit_of_measure']
[0xB795:1:0x0702]: Reading attributes in chunks: ['demand_formatting', 'divisor', 'metering_device_type', 'multiplier', 'summation_formatting']
[0xB795:1:0x0702]: Reading attributes in chunks: ['unit_of_measure']
[0xB795:1:0x0702]: initializing uncached cluster handler attributes: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered', 'current_tier4_summ_delivered', 'current_tier5_summ_delivered', 'current_tier6_summ_delivered', 'status'] - from cache[False]
[0xB795:1:0x0702]: Reading attributes in chunks: ['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']
[0xB795:1:0x0702] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=19, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0702] Sending request: Read_Attributes(attribute_ids=[1024, 0, 256, 258, 260])
[0xACD8:1:0x0702]: failed to get attributes '['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']' on 'smartenergy_metering' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0702]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xB795:1:0x0002]: initializing cluster handler: from_cache: False
[0xB795:1:0x0002]: initializing uncached cluster handler attributes: ['current_temperature'] - from cache[False]
[0xB795:1:0x0002]: Reading attributes in chunks: ['current_temperature']
[0xB795:1:0x0002] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=21, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0002] Sending request: Read_Attributes(attribute_ids=[0])
[0xAF40:1:0x0006]: initializing cluster handler: from_cache: False
[0xAF40:1:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xAF40:1:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xAF40:1:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xAF40:1:0x0006]: Reading attributes in chunks: ['on_off']
[0xAF40:1:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=23, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xAF40:1:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (0 enqueued)
[0xAF40:2:0x0006]: initializing cluster handler: from_cache: False
[0xAF40:2:0x0006]: initializing cached cluster handler attributes: ['start_up_on_off']
[0xAF40:2:0x0006]: Reading attributes in chunks: ['start_up_on_off']
[0xAF40:2:0x0006]: initializing uncached cluster handler attributes: ['on_off'] - from cache[False]
[0xAF40:2:0x0006]: Reading attributes in chunks: ['on_off']
[0xAF40:2:0x0006] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=24, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xAF40:2:0x0006] Sending request: Read_Attributes(attribute_ids=[0])
Max concurrency (8) reached, delaying request (1 enqueued)
[0xACD8:1:0x0b04]: failed to get attributes '['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0b04]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 0.08s
[0xB795:1:0x0b04]: initializing cluster handler: from_cache: False
[0xB795:1:0x0b04]: initializing cached cluster handler attributes: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor', 'ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor', 'power_multiplier', 'power_factor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['ac_current_divisor', 'ac_current_multiplier', 'ac_power_divisor', 'ac_power_multiplier', 'ac_voltage_divisor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['ac_voltage_multiplier', 'ac_frequency_divisor', 'ac_frequency_multiplier', 'measurement_type', 'power_divisor']
[0xB795:1:0x0b04]: Reading attributes in chunks: ['power_multiplier', 'power_factor']
[0xB795:1:0x0b04]: initializing uncached cluster handler attributes: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max', 'rms_voltage', 'rms_voltage_max', 'ac_frequency', 'ac_frequency_max'] - from cache[False]
[0xB795:1:0x0b04]: Reading attributes in chunks: ['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']
[0xB795:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=26, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291, 1293, 1295, 1288, 1290])
Max concurrency (8) reached, delaying request (1 enqueued)
[0xACD8:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0002]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 0.35s
[0xACD8:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xACD8:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 0.18s
[0xACD8:1:0x0006]: 'async_initialize' stage succeeded
[0xACD8:1:0x0002]: 'async_initialize' stage succeeded
[0xACD8:1:0x0b04]: 'async_initialize' stage succeeded
[0xACD8:1:0x0003]: 'async_initialize' stage succeeded
[0xACD8:1:0x0702]: 'async_initialize' stage succeeded
[0xACD8:1:0x0000]: 'async_initialize' stage succeeded
[0xACD8:1:0x0019]: 'async_initialize' stage succeeded
[0xACD8](lumi.switch.b1naus01): power source: Mains
[0xACD8](lumi.switch.b1naus01): completed initialization
[0x8BCC:1:0x0b04]: async_update
[0x8BCC:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x8BCC:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=29, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x8BCC:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (0 enqueued)
[0xACD8:1:0x0b04]: async_update
[0xACD8:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0xACD8:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=30, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xACD8:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (1 enqueued)
[0x3DAB:1:0x0b04]: async_update
[0x3DAB:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x3DAB:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=31, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3DAB:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (2 enqueued)
[0xB795:1:0x0b04]: async_update
[0xB795:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0xB795:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=32, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xB795:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (3 enqueued)
[0x0A1C:1:0x0b04]: async_update
[0x0A1C:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x0A1C:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=33, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x0A1C:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (4 enqueued)
[0xBCD2:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xBCD2:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 0.45s
Previously delayed request is now running, delayed by 0.49s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 32, 107665, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x8BCC), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=225, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x1d\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
[0x8BCC:1:0x0b04] Received ZCL frame: b'\x18\x1d\x01\x0b\x05\x00)\x00\x00'
[0x8BCC:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=29, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x8BCC:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
[0x7387:1:0x0b04]: async_update
[0x7387:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x7387:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=36, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x7387:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (3 enqueued)
[0xBCD2:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xBCD2:1:0x0002]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 0.96s
[0xBCD2:1:0x0006]: 'async_initialize' stage succeeded
[0xBCD2:1:0x0002]: 'async_initialize' stage succeeded
[0xBCD2:1:0x0003]: 'async_initialize' stage succeeded
[0xBCD2:1:0x0000]: 'async_initialize' stage succeeded
[0xBCD2:1:0xfcc0]: 'async_initialize' stage succeeded
[0xBCD2:1:0x0019]: 'async_initialize' stage succeeded
[0xBCD2](lumi.switch.b1naus01): power source: Mains
[0xBCD2](lumi.switch.b1naus01): completed initialization
Previously delayed request is now running, delayed by 1.10s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 32, 729514, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3DAB), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=53, profile_id=260, cluster_id=2820, data=Serialized[b'\x18\x1f\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=76, rssi=-81)
[0x3DAB:1:0x0b04] Received ZCL frame: b'\x18\x1f\x01\x0b\x05\x00)\x00\x00'
[0x3DAB:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=31, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3DAB:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
[0x00B8:1:0x0b04]: async_update
[0x00B8:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x00B8:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=39, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x00B8:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (2 enqueued)
[0xB795:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
Previously delayed request is now running, delayed by 1.39s
Previously delayed request is now running, delayed by 0.93s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 33, 61027, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0A1C), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=50, profile_id=260, cluster_id=2820, data=Serialized[b'\x18!\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=84, rssi=-79)
[0x0A1C:1:0x0b04] Received ZCL frame: b'\x18!\x01\x0b\x05\x00)\x00\x00'
[0x0A1C:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=33, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x0A1C:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
[0xAF40:1:0x0b04]: async_update
[0xAF40:1:0x0b04]: Reading attributes in chunks: ['active_power', 'rms_voltage']
[0xDC15:1:0x0b04]: async_update
[0xDC15:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0xDC15:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=42, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0xDC15:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (1 enqueued)
Previously delayed request is now running, delayed by 0.37s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 33, 126797, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x7387), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=152, profile_id=260, cluster_id=2820, data=Serialized[b'\x08$\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=148, rssi=-63)
[0x7387:1:0x0b04] Received ZCL frame: b'\x08$\x01\x0b\x05\x00)\x00\x00'
[0x7387:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=36, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x7387:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
[0xCDB5:1:0x0b04]: async_update
[0xCDB5:1:0x0b04]: Reading attributes in chunks: ['active_power', 'rms_voltage']
[0x3703:1:0x0b04]: async_update
[0x3703:1:0x0b04]: Reading attributes in chunks: ['active_power']
[0x3703:1:0x0b04] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, direction=<Direction.Server_to_Client: 0>, disable_default_response=0, reserved=0, *is_cluster=False, *is_general=True), tsn=44, command_id=<GeneralCommand.Read_Attributes: 0>, *direction=<Direction.Server_to_Client: 0>)
[0x3703:1:0x0b04] Sending request: Read_Attributes(attribute_ids=[1291])
Max concurrency (8) reached, delaying request (1 enqueued)
Previously delayed request is now running, delayed by 0.07s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 33, 170125, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x00B8), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=43, profile_id=260, cluster_id=2820, data=Serialized[b"\x18'\x01\x0b\x05\x00)\x00\x00"], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=120, rssi=-70)
[0x00B8:1:0x0b04] Received ZCL frame: b"\x18'\x01\x0b\x05\x00)\x00\x00"
[0x00B8:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=39, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x00B8:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
Previously delayed request is now running, delayed by 0.05s
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 33, 196164, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0xDC15), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=227, profile_id=260, cluster_id=2820, data=Serialized[b'\x18*\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=128, rssi=-68)
[0xDC15:1:0x0b04] Received ZCL frame: b'\x18*\x01\x0b\x05\x00)\x00\x00'
[0xDC15:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=42, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0xDC15:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
Received a packet: ZigbeePacket(timestamp=datetime.datetime(2023, 12, 9, 19, 49, 33, 239928, tzinfo=datetime.timezone.utc), src=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x3703), src_ep=1, dst=AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x0000), dst_ep=1, source_route=None, extended_timeout=False, tsn=49, profile_id=260, cluster_id=2820, data=Serialized[b'\x18,\x01\x0b\x05\x00)\x00\x00'], tx_options=<TransmitOptions.NONE: 0>, radius=0, non_member_radius=0, lqi=164, rssi=-59)
[0x3703:1:0x0b04] Received ZCL frame: b'\x18,\x01\x0b\x05\x00)\x00\x00'
[0x3703:1:0x0b04] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=0, direction=<Direction.Client_to_Server: 1>, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=44, command_id=1, *direction=<Direction.Client_to_Server: 1>)
[0x3703:1:0x0b04] Decoded ZCL frame: ElectricalMeasurement:Read_Attributes_rsp(status_records=[ReadAttributeRecord(attrid=0x050B, status=<Status.SUCCESS: 0>, value=TypeValue(type=int16s, value=0))])
[0xB795:1:0x0702]: failed to get attributes '['instantaneous_demand', 'current_summ_delivered', 'current_tier1_summ_delivered', 'current_tier2_summ_delivered', 'current_tier3_summ_delivered']' on 'smartenergy_metering' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0702]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xB795:1:0x0002]: failed to get attributes '['current_temperature']' on 'device_temperature' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0002]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xAF40:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xAF40:1:0x0002]: 'async_initialize' stage succeeded
[0xAF40:1:0x0003]: 'async_initialize' stage succeeded
[0xAF40:1:0x0000]: 'async_initialize' stage succeeded
[0xAF40:1:0x0702]: 'async_initialize' stage succeeded
[0xAF40:1:0x0b04]: 'async_initialize' stage succeeded
[0xAF40:1:0xfcc0]: 'async_initialize' stage succeeded
[0xAF40:1:0x0006]: 'async_initialize' stage succeeded
[0xAF40:1:0x0019]: 'async_initialize' stage succeeded
[0xAF40:2:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xAF40:2:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xAF40:2:0x0000]: 'async_initialize' stage succeeded
[0xAF40:2:0x0003]: 'async_initialize' stage succeeded
[0xAF40:2:0xfcc0]: 'async_initialize' stage succeeded
[0xAF40:2:0x0006]: 'async_initialize' stage succeeded
[0xAF40](lumi.switch.b2naus01): power source: Mains
[0xAF40](lumi.switch.b2naus01): completed initialization
[0xB795:1:0x0b04]: failed to get attributes '['active_power', 'active_power_max', 'apparent_power', 'rms_current', 'rms_current_max']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0b04]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>'), DeliveryError('Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>')]
[0xB795:1:0x0006]: 'async_initialize' stage succeeded
[0xB795:1:0x0000]: 'async_initialize' stage succeeded
[0xB795:1:0x0702]: 'async_initialize' stage succeeded
[0xB795:1:0x0003]: 'async_initialize' stage succeeded
[0xB795:1:0x0002]: 'async_initialize' stage succeeded
[0xB795:1:0x0b04]: 'async_initialize' stage succeeded
[0xB795:1:0x0019]: 'async_initialize' stage succeeded
[0xB795](lumi.switch.b1naus01): power source: Mains
[0xB795](lumi.switch.b1naus01): completed initialization
[0xACD8:1:0x0b04]: failed to get attributes '['active_power']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>
[0xB795:1:0x0b04]: failed to get attributes '['active_power']' on 'electrical_measurement' cluster: Failed to deliver message: <EmberStatus.DELIVERY_FAILED: 102>

Additional information

No response

About this issue

  • Original URL
  • State: closed
  • Created 7 months ago
  • Comments: 27

Most upvoted comments

Oh, yeah, after adding Switch4 to the quirks, I repaired the switch that didn’t have a quirk and it came back as another Switch3… fussy, these Aqara switches, aren’t they? 😉

I had tried removing and adding all of them one time, and all work with XiaomiOpple2ButtonSwitch3 except one, which uses XiaomiOpple2ButtonSwitch2. So looks like we’re good for now 😃

Thanks again for your help!

I think so. You can also try just reloading the ZHA integration using the integrations page and see if that works.

Ah, change that import in line 58 to from zhaquirks.xiaomi.aqara.opple_remote import MultistateInputCluster, OppleCluster