zha-device-handlers: [BUG]Unexpected interaction with New Dimmer quirk and Dimmer switch TS0601 _TZE200_1agwnems
Thanks to the great work by the contributors here I have full control of my dimmer switches. (dimmer switch TS0601 _TZE200_1agwnems)! Thank you very much! There is however a small problem, changing the brightness slider causes the light to momentarily turn off almost like a reset for a fraction of a second (time it takes to blink almost) and then from full brightness goes down to the selected brightness. Expected result would be for the dimmer to change from eg. 40% to 50% instead it goes from 40% to off(barely noticeable) to 100% and slowly dims to 50%.
To Reproduce Steps to reproduce the behavior:
- With the dimmer either on or off change the brightness value of dimmer using either automation or via the entity
- Become blinded for a time until the light slowly dims to the set value from its max value.
Expected behavior Sliding the brightness slider from eg. 0% to 40% should slowly step through the levels of brightness from 0 to 40% and sliding it bac from 40% to 0% should smoothly transition from 40% brightness to 0%
Device signature - this can be acquired by clicking on the "Zigbee Device Signature" button in the device settings
{
"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.AllocateAddress|RxOnWhenIdle|MainsPowered|FullFunctionDevice: 142>, manufacturer_code=4098, maximum_buffer_size=82, maximum_incoming_transfer_size=82, server_mask=11264, maximum_outgoing_transfer_size=82, 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": 260,
"device_type": "0x0100",
"in_clusters": [
"0x0000",
"0x0004",
"0x0005",
"0x0006",
"0x0008",
"0xef00"
],
"out_clusters": [
"0x000a",
"0x0019"
]
}
},
"manufacturer": "_TZE200_1agwnems",
"model": "TS0601",
"class": "zhaquirks.tuya.ts0601_dimmer.TuyaSingleSwitchDimmer"
}
Diagnostic information - this can be acquired by clicking on the "Download Diagnostics" button in the device settings
{
"home_assistant": {
"installation_type": "Home Assistant OS",
"version": "2022.5.2",
"dev": false,
"hassio": true,
"virtualenv": false,
"python_version": "3.9.9",
"docker": true,
"arch": "x86_64",
"timezone": "Australia/Sydney",
"os_name": "Linux",
"os_version": "5.10.108",
"supervisor": "2022.05.0",
"host_os": "Home Assistant OS 7.6",
"docker_version": "20.10.9",
"chassis": "vm",
"run_as_root": true
},
"custom_components": {
"xiaomi_miot_raw": {
"version": "v1.3.1",
"requirements": [
"construct",
"python-miio>=0.5.3"
]
},
"localtuya": {
"version": "3.2.1",
"requirements": []
},
"webrtc": {
"version": "v2.3.0",
"requirements": []
},
"meross_lan": {
"version": "2.5.8",
"requirements": []
},
"hacs": {
"version": "1.24.5",
"requirements": [
"aiogithubapi>=21.11.0"
]
},
"reolink_dev": {
"version": "0.52",
"requirements": [
"reolink==0.0.61"
]
},
"samsungtv_smart": {
"version": "0.6.1",
"requirements": [
"websocket-client>=0.58.0",
"wakeonlan>=2.0.0",
"aiofiles>=0.8.0"
]
}
},
"integration_manifest": {
"domain": "zha",
"name": "Zigbee Home Automation",
"config_flow": true,
"documentation": "https://www.home-assistant.io/integrations/zha",
"requirements": [
"bellows==0.29.0",
"pyserial==3.5",
"pyserial-asyncio==0.6",
"zha-quirks==0.0.73",
"zigpy-deconz==0.16.0",
"zigpy==0.45.1",
"zigpy-xbee==0.14.0",
"zigpy-zigate==0.7.4",
"zigpy-znp==0.7.0"
],
"usb": [
{
"vid": "10C4",
"pid": "EA60",
"description": "*2652*",
"known_devices": [
"slae.sh cc2652rb stick"
]
},
{
"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": "10C4",
"pid": "8A2A",
"description": "*zigbee*",
"known_devices": [
"Nortek HUSBZB-1"
]
},
{
"vid": "10C4",
"pid": "8B34",
"description": "*bv 2010/10*",
"known_devices": [
"Bitron Video AV2010/10"
]
}
],
"codeowners": [
"@dmulcahey",
"@adminiuga"
],
"zeroconf": [
{
"type": "_esphomelib._tcp.local.",
"name": "tube*"
}
],
"after_dependencies": [
"usb",
"zeroconf"
],
"iot_class": "local_polling",
"loggers": [
"aiosqlite",
"bellows",
"crccheck",
"pure_pcapy3",
"zhaquirks",
"zigpy",
"zigpy_deconz",
"zigpy_xbee",
"zigpy_zigate",
"zigpy_znp"
],
"is_built_in": true
},
"data": {
"ieee": "**REDACTED**",
"nwk": 65143,
"manufacturer": "_TZE200_1agwnems",
"model": "TS0601",
"name": "_TZE200_1agwnems TS0601",
"quirk_applied": true,
"quirk_class": "zhaquirks.tuya.ts0601_dimmer.TuyaSingleSwitchDimmer",
"manufacturer_code": 4098,
"power_source": "Mains",
"lqi": 255,
"rssi": -84,
"last_seen": "2022-05-09T02:07:28",
"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.AllocateAddress|RxOnWhenIdle|MainsPowered|FullFunctionDevice: 142>, manufacturer_code=4098, maximum_buffer_size=82, maximum_incoming_transfer_size=82, server_mask=11264, maximum_outgoing_transfer_size=82, 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": 260,
"device_type": "0x0100",
"in_clusters": [
"0x0000",
"0x0004",
"0x0005",
"0x0006",
"0x0008",
"0xef00"
],
"out_clusters": [
"0x000a",
"0x0019"
]
}
}
},
"entities": [
{
"entity_id": "light.youssefs_room_level_on_off",
"name": "_TZE200_1agwnems TS0601"
}
],
"neighbors": [
{
"device_type": "Coordinator",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x0000",
"permit_joining": "Unknown",
"depth": "0",
"lqi": "107"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x56EF",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "120"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x8073",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "89"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x83FA",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "190"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x88FE",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "117"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Parent",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0x9527",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "236"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0xB150",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "114"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0xB797",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "120"
},
{
"device_type": "Router",
"rx_on_when_idle": "On",
"relationship": "Sibling",
"extended_pan_id": "**REDACTED**",
"ieee": "**REDACTED**",
"nwk": "0xC54C",
"permit_joining": "Unknown",
"depth": "15",
"lqi": "102"
}
],
"endpoint_names": [
{
"name": "ON_OFF_LIGHT"
}
],
"user_given_name": "REDACTEDS's Room",
"device_reg_id": "1bac9fa15b21a8d52d1e563874e74754",
"area_id": null
}
}
Logs - Here are some logs I found during the time I Changed the brightness, I don't know how useful this would be, but if you have any information on where and how I can dig up more useful information to diagnose this please let me know!
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Received ZCL frame: b'\t.\x01\x00\x8c\x01\x01\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=46, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=140, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>)))
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'77fe69cbd1feffea3590ffc502fa834cc5'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100000bffc577feffff0a096d01005a010100010106'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=11), 255, -59, 0xfe77, 255, 255, b'\tm\x01\x00Z\x01\x01\x00\x01\x01']
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fcda0e9e300>)
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fcda0e9e300>) completed
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Received ZCL frame: b'\tm\x01\x00Z\x01\x01\x00\x01\x01'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=109, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=90, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Received command 0x01 (TSN 109): get_data(data=TuyaCommand(status=0, tsn=90, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>)))
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_attribute event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending reply header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=109, command_id=<GeneralCommand.Default_Response: 11>, *is_reply=True)
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'412ab1ed542e14b2b6954b25ab5592b469e5542b12316d82c2c763bbfd7f3fa6ebc9a9bd7e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending reply: Default_Response(command_id=1, status=<Status.SUCCESS: 0>)
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'512ab1f127aa7a0f886ab5cf9fc56de29db0afe2c57e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'612ab1f173bfdef68f6ab5cf9fc56de39db0aff9807e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2022-05-10 02:01:06 DEBUG (MainThread) [hass_nabucasa.google_report_state] Publishing message:
{'msgid': '5cb8a4fce42f465abb1beaec88216a6d',
'payload': {'devices': {'states': {'light.youssefs_room_level_on_off': {'brightness': 37,
'on': True,
'online': True}}}}}
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0x8073, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=56), 149, b'\x188\x0b\x01\x00')
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef010100010000fdf5ab7380ffff0a093f010032010100010004'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=253), 245, -85, 0x8073, 255, 255, b'\t?\x01\x002\x01\x01\x00\x01\x00']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Received ZCL frame: b'\t?\x01\x002\x01\x01\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'172b219c545995b65894a524ab1593499c76b2aef5f66c8afdfd877e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=63, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=50, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.device] [0x8073] Invalid state on future for 0x3f seq -- probably duplicate response
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'73806fbdd1feffea3590ffab01fe88'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x8073, 90:35:ea:ff:fe:d1:bd:6f, 255, -85, [0x88fe]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x8073, 90:35:ea:ff:fe:d1:bd:6f, 255, -85, [0x88fe])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'2795cb44d6feffea3590ffaa01fe88'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x9527, 90:35:ea:ff:fe:d6:44:cb, 255, -86, [0x88fe]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x9527, 90:35:ea:ff:fe:d6:44:cb, 255, -86, [0x88fe])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'712ab1f1bb7c897a886ab5cf9fc568ee9cfac27e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'012ab1f123d47c79886ab5cf9fc56d8c9eb4a4e7289baf7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'112ab1ed542e14b2b6954b25ab55923063e5003e12316d82d3c76305fd7f3fa6ebc913e07e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'222ba19c54df3d607e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2022-05-10 02:01:06 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/hassio_ingress/-vSDmX6Eydea08IgIZXQ8kjyb41sAks9CmmU5CJmpRw/ to 192.168.0.191 (auth: False)
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'ef569cc8d1feffea3590faa700'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x56ef, 90:35:ea:ff:fe:d1:c8:9c, 250, -89, []]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x56ef, 90:35:ea:ff:fe:d1:c8:9c, 250, -89, [])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'77fe69cbd1feffea3590ffc502fa834cc5'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef01010001000079ffab2795ffff0a092e01008c010100010004'
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fcda0e9e300>, 'UPDATE devices_v8 SET last_seen=? WHERE ieee=?', (datetime.datetime(2022, 5, 9, 15, 38, 9, 3618, tzinfo=datetime.timezone.utc), 90:35:ea:ff:fe:d1:cb:69))
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method execute of sqlite3.Connection object at 0x7fcda0e9e300>, 'UPDATE devices_v8 SET last_seen=? WHERE ieee=?', (datetime.datetime(2022, 5, 9, 15, 38, 9, 3618, tzinfo=datetime.timezone.utc), 90:35:ea:ff:fe:d1:cb:69)) completed
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=121), 255, -85, 0x9527, 255, 255, b'\t.\x01\x00\x8c\x01\x01\x00\x01\x00']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Received ZCL frame: b'\t.\x01\x00\x8c\x01\x01\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=46, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'322bb1f1c39dbd72886ab5cf9fc56d8c9eb4a4e72874f97e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'422bb1ed542e14b2b6954b25ab55920e63e8c8fd12316d82bfc763bcf87a3fa6ebcfa9ce7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x9527:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=140, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.device] [0x9527] Invalid state on future for 0x2e seq -- probably duplicate response
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 52 (sendUnicast) received: b'00f5'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'522bb1ed542e14b2b6954b25ab559245638b505512316d8290c763d3fd7f3fa6eacb3dcc7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'622bb1ed542e14b2b6954b25ab559202638bb01c12316d82ccc76306f87a3fa6ebcb388d7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'97b7a8c0d1feffea3590ffc502fa834cc5'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xb797, 90:35:ea:ff:fe:d1:c0:a8, 255, -59, [0x83fa, 0xc54c]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xb797, 90:35:ea:ff:fe:d1:c0:a8, 255, -59, [0x83fa, 0xc54c])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef01010001000047ffa6ef56ffff0a0942010035040400010002'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'722bb197545995b65894a524ab1593499cbbb2abed1a247e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=71), 255, -90, 0x56ef, 255, 255, b'\tB\x01\x005\x04\x04\x00\x01\x00']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Received ZCL frame: b'\tB\x01\x005\x04\x04\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=66, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=53, dp=4, data=TuyaData(dp_type=<TuyaDPType.ENUM: 4>, function=0, raw=b'\x00', *payload=<enum8.undefined_0x00: 0>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Received command 0x01 (TSN 66): get_data(data=TuyaCommand(status=0, tsn=53, dp=4, data=TuyaData(dp_type=<TuyaDPType.ENUM: 4>, function=0, raw=b'\x00', *payload=<enum8.undefined_0x00: 0>)))
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_attribute event
2022-05-10 02:01:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x56EF:1:0x0008]: received attribute: 61186 update with value: enum8.undefined_0x00
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Sending reply header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=66, command_id=<GeneralCommand.Default_Response: 11>, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x56EF:1:0xef00] Sending reply: Default_Response(command_id=1, status=<Status.SUCCESS: 0>)
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'022bb1ed542e14b2b6954b25ab5592b763e5542b12316d82c2c763bbfd7f3fa6ebc9bec67e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100000cffc577feffff0a096d01005a010100010106'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=12), 255, -59, 0xfe77, 255, 255, b'\tm\x01\x00Z\x01\x01\x00\x01\x01']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Received ZCL frame: b'\tm\x01\x00Z\x01\x01\x00\x01\x01'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=109, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=90, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>)))
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100004bffc597b7ffff0a093101008f040400010006'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=75), 255, -59, 0xb797, 255, 255, b'\t1\x01\x00\x8f\x04\x04\x00\x01\x00']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Received ZCL frame: b'\t1\x01\x00\x8f\x04\x04\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'122bb1f127aa7a0f886ab5cf9fc56de29db0afa1807e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=49, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=143, dp=4, data=TuyaData(dp_type=<TuyaDPType.ENUM: 4>, function=0, raw=b'\x00', *payload=<enum8.undefined_0x00: 0>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Received command 0x01 (TSN 49): get_data(data=TuyaCommand(status=0, tsn=143, dp=4, data=TuyaData(dp_type=<TuyaDPType.ENUM: 4>, function=0, raw=b'\x00', *payload=<enum8.undefined_0x00: 0>)))
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_attribute event
2022-05-10 02:01:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xB797:1:0x0008]: received attribute: 61186 update with value: enum8.undefined_0x00
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'222bb1f123d47c79886ab5cf9fc56d8c9eb4a4e728cd9c7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Sending reply header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.GLOBAL_COMMAND: 0>, is_manufacturer_specific=False, is_reply=1, disable_default_response=1, reserved=0, *is_cluster=False, *is_general=True), tsn=49, command_id=<GeneralCommand.Default_Response: 11>, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xB797:1:0xef00] Sending reply: Default_Response(command_id=1, status=<Status.SUCCESS: 0>)
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 63 (messageSentHandler) received: b'007380040100ef010140010000f5950000'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received messageSentHandler frame with [<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 32883, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=245), 149, <EmberStatus.SUCCESS: 0>, b'']
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'322bb1ed542e14b2b6954b25ab559244638b505512316d8290c763d3fd7f3fa6eacb18e47e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.util] Duplicate 200 TSN
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef010100010000feffab7380ffff0a093f010032010100010004'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=254), 255, -85, 0x8073, 255, 255, b'\t?\x01\x002\x01\x01\x00\x01\x00']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] executing functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fcda0e9e300>)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Received ZCL frame: b'\t?\x01\x002\x01\x01\x00\x01\x00'
2022-05-10 02:01:06 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7fcda0e9e300>) completed
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=63, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0x8073:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=50, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>)))
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'422bb1ed542e14b2b6954b25ab55923363e5003e12316d82d3c76305fd7f3fa6ebc956ce7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'522bb1f173bfdef68f6ab5cf9fc57de59db0af08957e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'622bb1f127aa7a0f886ab5cf9fc56de39db0af46a77e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'722bb1f127aa7a0f886ab5cf9fc56de29db0af004e7e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8070787e'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.device] [0x8073] Invalid state on future for 0x3f seq -- probably duplicate response
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'73806fbdd1feffea3590ffab01fe88'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x8073, 90:35:ea:ff:fe:d1:bd:6f, 255, -85, [0x88fe]]
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x8073, 90:35:ea:ff:fe:d1:bd:6f, 255, -85, [0x88fe])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'77fe69cbd1feffea3590ffc502fa834cc5'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c]]
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'022bb1ed542e14b2b6954b25ab5592b663e5542b12316d82c2c763bbfd7f3fa6ebc960d97e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8160597e'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0xfe77, 90:35:ea:ff:fe:d1:cb:69, 255, -59, [0x83fa, 0xc54c])
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_relays event
2022-05-10 02:01:06 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2022-05-10 02:01:06 DEBUG (MainThread) [zeroconf] Ignoring duplicate message received from '::ffff:192.168.0.133':5353 [socket 12 (('::', 5353, 0, 0))] (126 bytes) as [b'\x00\x00\x84\x00\x00\x00\x00\x01\x00\x00\x00\x01\x06iPhone\x07_rdlink\x04_tcp\x05local\x00\x00\x10\x80\x01\x00\x00\x11\x94\x008\x16rpBA=88:EC:9E:B8:47:14\x0erpVr=340.19.11\x11rpAD=7a2bf5330949\xc0\x0c\x00/\x80\x01\x00\x00\x11\x94\x00\t\xc0\x0c\x00\x05\x00\x00\x80\x00@']
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100000dffc577feffff0a096d01005a010100010106'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=13), 255, -59, 0xfe77, 255, 255, b'\tm\x01\x00Z\x01\x01\x00\x01\x01']
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Received ZCL frame: b'\tm\x01\x00Z\x01\x01\x00\x01\x01'
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=0, is_reply=1, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), tsn=109, command_id=1, *is_reply=True)
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Decoded ZCL frame: TuyaLevelControlManufCluster:get_data(data=TuyaCommand(status=0, tsn=90, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>)))
2022-05-10 02:01:06 DEBUG (MainThread) [zigpy.device] [0xfe77] Invalid state on future for 0x6d seq -- probably duplicate response
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100007affab2795ffff0a092e01008c010100010004'
2022-05-10 02:01:06 DEBUG (MainThread) [bellows.zigbee.application] Received incomingMessageHandler frame with [<EmberIncomingMessageType.INCOMING_UNICAST: 0>, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY: 256>, groupId=0, sequence=122), 255, -85, 0x9527, 255, 255, b'\t.\x01\x00\x8c\x01\x01\x00\x01\x00']
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'122bb1f173bfdef68f6ab5cf9fc56de29db0af9c967e'
2022-05-10 02:01:06 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'82503a7e'
2022-05-10 02:01:06 WARNING (MainThread) [zigpy.appdb] Discarding _save_device_last_seen event
Logs 2
2022-05-10 13:30:23 DEBUG (MainThread) [homeassistant.components.websocket_api.http.connection] [139696786098016] Received {'type': 'call_service', 'domain': 'light', 'service': 'turn_on', 'service_data': {'entity_id': 'light.youssefs_room_level_on_off', 'brightness_pct': 61}, 'id': 89}
2022-05-10 13:30:23 DEBUG (Recorder) [homeassistant.components.recorder] Processing task: EventTask(event=<Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.youssefs_room_level_on_off, brightness_pct=61>)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0x0008] Sending Tuya Cluster Command. Cluster Command is 4, Arguments are (156, 1)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] tuya_mcu_command: cluster_data=TuyaClusterData(endpoint_id=1, cluster_attr='on_off', attr_value=1, expect_reply=True)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] get_dp_mapping --> found DP: 1
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] from_cluster_data: 1, DPToAttributeMapping(ep_attribute='on_off', attribute_name='on_off', dp_type=<TuyaDPType.BOOL: 1>, converter=None, dp_converter=None, endpoint_id=None)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] ztype: Bool.true
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] from_value: [1, 1]
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] raw: b'\x01'
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] tuya_command: TuyaCommand(status=0, tsn=34, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>))
2022-05-10 13:30:23 DEBUG (Thread-3) [aiosqlite] operation functools.partial(<built-in method commit of sqlite3.Connection object at 0x7f0daf3d9e40>) completed
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4098, tsn=35, command_id=0, *is_reply=False)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending request: set_data(data=TuyaCommand(status=0, tsn=34, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>)))
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] tuya_mcu_command: cluster_data=TuyaClusterData(endpoint_id=1, cluster_attr='current_level', attr_value=156, expect_reply=True)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] get_dp_mapping --> found DP: 2
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] from_cluster_data: 2, DPToAttributeMapping(ep_attribute='level', attribute_name='current_level', dp_type=<TuyaDPType.VALUE: 2>, converter=<function TuyaLevelControlManufCluster.<lambda> at 0x7f0daf5f4ca0>, dp_converter=<function TuyaLevelControlManufCluster.<lambda> at 0x7f0daf5f4d30>, endpoint_id=None)
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] converted: 611
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] ztype: 611
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] from_value: [4, 0, 0, 2, 99]
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] raw: b'\x00\x00\x02c'
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] tuya_command: TuyaCommand(status=0, tsn=36, dp=2, data=TuyaData(dp_type=<TuyaDPType.VALUE: 2>, function=0, raw=b'\x00\x00\x02c', *payload=1661075456))
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending request header: ZCLHeader(frame_control=FrameControl(frame_type=<FrameType.CLUSTER_COMMAND: 1>, is_manufacturer_specific=True, is_reply=0, disable_default_response=0, reserved=0, *is_cluster=True, *is_general=False), manufacturer=4098, tsn=37, command_id=0, *is_reply=False)
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'200db1f1bb7c897a886ab5cf9fc56fef9c140f7e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'83401b7e'
2022-05-10 13:30:23 DEBUG (MainThread) [zigpy.zcl] [0xFE77:1:0xef00] Sending request: set_data(data=TuyaCommand(status=0, tsn=36, dp=2, data=TuyaData(dp_type=<TuyaDPType.VALUE: 2>, function=0, raw=b'\x00\x00\x02c', *payload=1661075456)))
2022-05-10 13:30:23 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xFE77:1:0x0008]: executed 'move_to_level_with_on_off' command with args: '(156, 1)' kwargs: '{}' result: Default_Response(command_id=4, status=<Status.SUCCESS: 0>)
2022-05-10 13:30:23 DEBUG (MainThread) [homeassistant.components.zha.entity] light.youssefs_room_level_on_off: turned on: {'move_to_level_with_on_off': Default_Response(command_id=4, status=<Status.SUCCESS: 0>)}
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'300db1ed542e14b2b6954b25ab55926363889de812316d82c2c763bbfd7f3fa6ebc9dd587e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8430fc7e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'400db1f1bb7c897a886ab5cf9fc56eef9c67397e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8520dd7e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'500db19754c543b65894a524ab1593499cd806abed7bb97e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'8610be7e'
2022-05-10 13:30:23 DEBUG (MainThread) [bellows.ezsp.protocol] Send command sendUnicast: (<EmberOutgoingMessageType.OUTGOING_DIRECT: 0>, 0xFE77, EmberApsFrame(profileId=260, clusterId=61184, sourceEndpoint=1, destinationEndpoint=1, options=<EmberApsOption.APS_OPTION_ENABLE_ROUTE_DISCOVERY|APS_OPTION_RETRY: 320>, groupId=0, sequence=35), 38, b'\x05\x02\x10#\x00\x00"\x01\x01\x00\x01\x01')
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'0612219c545debb65894a524ab1593499c6d01a7e8cc77a8fdc64188fd7d5e3ea61e1f7e'
2022-05-10 13:30:23 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 89 (incomingRouteRecordHandler) received: b'ef569cc8d1feffea3590fda600'
2022-05-10 13:30:23 DEBUG (MainThread) [bellows.zigbee.application] Received incomingRouteRecordHandler frame with [0x56ef, 90:35:ea:ff:fe:d1:c8:9c, 253, -90, []]
2022-05-10 13:30:23 DEBUG (MainThread) [bellows.zigbee.application] Processing route record request: (0x56ef, 90:35:ea:ff:fe:d1:c8:9c, 253, -90, [])
2022-05-10 13:30:23 DEBUG (MainThread) [homeassistant.components.homekit.accessories] New_state: <state light.youssefs_room_level_on_off=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=156, off_brightness=None, friendly_name=Youssef's Room level, on_off, supported_features=33 @ 2022-05-10T13:29:08.224809+10:00>
2022-05-10 13:30:23 DEBUG (MainThread) [pyhap.characteristic] set_value: On to 1
2022-05-10 13:30:23 DEBUG (MainThread) [pyhap.characteristic] set_value: Brightness to 61.0
2022-05-10 13:30:23 DEBUG (MainThread) [bellows.ezsp.protocol] Application frame 69 (incomingMessageHandler) received: b'00040100ef0101000100002affc6ba43ffff0a093f010032010100010004'
2022-05-10 13:30:23 DEBUG (Recorder) [homeassistant.components.recorder] Processing task: EventTask(event=<Event state_changed[L]: entity_id=light.youssefs_room_level_on_off, old_state=<state light.youssefs_room_level_on_off=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=53, off_brightness=None, friendly_name=Youssef's Room level, on_off, supported_features=33 @ 2022-05-10T13:29:08.224809+10:00>, new_state=<state light.youssefs_room_level_on_off=on; supported_color_modes=[<ColorMode.BRIGHTNESS: 'brightness'>], color_mode=brightness, brightness=156, off_brightness=None, friendly_name=Youssef's Room level, on_off, supported_features=33 @ 2022-05-10T13:29:08.224809+10:00>>)
2022-05-10 13:30:23 DEBUG (Recorder) [homeassistant.components.recorder.pool.RecorderPool] Connection <sqlite3.Connection object at 0x7f0db4d82e40> checked out from pool
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Data frame: b'600db1ed542e14b2b6954b25ab55929670e8c8fd12316a828cc76b8bff7c3fa3ebcdde6e8db4667e'
2022-05-10 13:30:23 DEBUG (bellows.thread_0) [bellows.uart] Sending: b'87009f7e'
Please let me know if there is any further information you require! Thank you!
About this issue
- Original URL
- State: closed
- Created 2 years ago
- Comments: 56 (9 by maintainers)
Here is a short video of how it behaves -
Thanks again for your help, I’ve just looked at my diagnostic info and it shows the version to be zha-quirks==0.0.82. I’ve also enabled the enhanced brightness slider and temperature transition from off-state options in the Zha configuration. Physically adjusting the brightness from the upper and lower buttons on the switch works as expected, stepping through the brightness levels. However, the same behaviour I explained at the beginning of the post is occurring when adjusting through HomeAssistant
Logs with reproduced behaviour
I can confirm that the dimmer function is broken and outputs random values or just maxes at 100. here are the logs:
Logs with reproduced behaviour
Well, let’s analyze it step by step.
If the device has a behavior when you operate it manually, the quirk won’t change it at all. The quirk acts as a translator between (for example) HA and the device, but cannot change the behavior of the physical device.
Recently a behavior has been ‘corrected’ in some of the quirks (including a few Tuya dimmers). HA sends a
move_to_level_with_on_offcommand when the dim bar is operated from the UI. With the corrected implementation, the quirk sends the correspondingon_offcommand and thedimcommand. This behavior is ‘normal’ in standard Zigbee devices and that is why it has been adapted in this way. Maybe it can be improved, but I’m not going to argue that the behavior has to be different on a particular device. If it is reviewed it will be for any implementation, not a device specific one.About point 2, you can imagine how it goes. Someone complains that their device won’t turn on when they move the dim bar. The reason is detected and corrected. Then someone complains that they have lost the ability to modify the value of dim without turning on the device and that this is a bug, and so on… That is why I am not going to look for a solution for 1 device. I’m only going to implement the solution that fits the ‘standard’ behavior. I hope you understand my reasons.
IMO the quirk is working (for your device) as expected. In your logs I don’t see anything unusual and, as you as said, its behavior is consistent with what is expected.
However I’m going to check what the dim behavior is in HA (sends always on/off command when the dim bar is moved?). I will also review what is ‘normal’ behavior when (for example) a Zigbee device that is already on receives an
oncommand. Maybe this point could be improved, but it adds complexity to the quirk and I’m not sure if there is an optimal solution. Give me some time to review it.Regards.
Hi @javicalle just wondering if this was still on your radar and whether there was anything I can do to help?
sure thing, thanks for looking into this again!
Logs , ctrl f "Youssef" to see the entity im using
This is the manufacturer provided device handler for SmartThings. I wonder if this can be translated over to ZHA.
https://drive.google.com/file/d/1eqLByV3P_9wEDrZV9bQvIWGg2MIT5ySB/view
Diagnostic information - I enabled debug logs for zhaquriks and others found on the zha debug page on homeassistant.io and found some of the "Sending Tuya Cluster Command" lines you were looking for, Please let me know if you need more info, I greatly appreciate your help
Also, regarding the dimmer itself, tapping the dimming buttons works as expected. However, if it was set at 40% brightness for example and I turn it off and back on again from the middle button, the lights go from 100% to 40%(The previous state it was in before turning it off) instead of a smooth transition from 0% to 40%.
This behaviour is the same thing I’m experiencing if I remotely access it, the quirk seems to be not just sending a brightness command but also a command to turn it on again (since it’s already on it flashes off and on really quick).
I’m not completely sure how the quirk functions but if its sending both brightness and on/off commands at the same time this would cause it to behave like this. A fix may be to send only brightness commands to the dimmer and off commands when they hit 0% brightness.
Have you enabled the debug logs for
zhaquirks? It is expected that you will have traces of the typeSending Tuya Cluster Command... Cluster Command is %x, Arguments are %swhen turn on/off the device or of the typeSending Tuya Cluster Command. Cluster Command is %x, Arguments are %swhen dimming the device.In addition there are traces of at least 5 different devices (the first value of the tuple
[0x8073:1:0xef00]defines the device). We need to get the correct info to be able to understand what is happening.I am aware that it is not an easy task if you are not used to it, but it is necessary for someone with the device to do this analysis in order to give a correct answer.
Sorry, I am having trouble finding the debug logs for the device, are you looking for the /config/homeassistant.log file? I’ve set the logger to debug in configuration.yaml but there is a ton of text so sift through do I need to filter it? and if so how? Your help is appreciated!
Edit: I’ve added some logs to the original comment