search

zigpy / zha-device-handlers

ZHA device handlers bridge the functionality gap created when manufacturers deviate from the ZCL specification, handling deviations and exceptions by parsing custom messages to and from Zigbee devices.
Apache License 2.0
752 stars 691 forks source link

[Device Support Request] Moes dimmer switches _TZE200_ip2akl4w & _TZE200_fjjbhx9d #1302

Closed Daandeve closed 2 years ago

Daandeve commented 2 years ago

This is a Tuya device that has no entities and/or controls in home assistant and its a simple Zigbee Tuya dimmer. It should be very similar to many other devices like this.

1 Gang _TZE200_ip2akl4w

{
  "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=4417, maximum_buffer_size=66, maximum_incoming_transfer_size=66, server_mask=10752, maximum_outgoing_transfer_size=66, 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": "0x0051",
      "in_clusters": [
        "0x0000",
        "0x0004",
        "0x0005",
        "0xef00"
      ],
      "out_clusters": [
        "0x000a",
        "0x0019"
      ]
    },
    "242": {
      "profile_id": 41440,
      "device_type": "0x0061",
      "in_clusters": [],
      "out_clusters": [
        "0x0021"
      ]
    }
  },
  "manufacturer": "_TZE200_ip2akl4w",
  "model": "TS0601",
  "class": "zigpy.device.Device"
}

2 Gang _TZE200_fjjbhx9d

{
  "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=4417, maximum_buffer_size=66, maximum_incoming_transfer_size=66, server_mask=10752, maximum_outgoing_transfer_size=66, 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": "0x0051",
      "in_clusters": [
        "0x0000",
        "0x0004",
        "0x0005",
        "0xef00"
      ],
      "out_clusters": [
        "0x000a",
        "0x0019"
      ]
    },
    "242": {
      "profile_id": 41440,
      "device_type": "0x0061",
      "in_clusters": [],
      "out_clusters": [
        "0x0021"
      ]
    }
  },
  "manufacturer": "_TZE200_fjjbhx9d",
  "model": "TS0601",
  "class": "zigpy.device.Device"
}

Thanks in advance for the support.

javicalle commented 2 years ago

Could it be something encoding/decoding related? Maybe the firmware on my dimmer is newer/older than your switch?

For these values I don't think so. The simplest case 'BOOLEAN' does not present much of an encoding problem.

My suspicion is that the problem is with the transaction ID tsn. In most implementations it is not taken into account, but I suspect that in this case it must be managed correctly, but for that it is necessary to know 'how' it must be managed.

Tropaion commented 2 years ago

Could you attach the traces when doing the same from HA?

@javicalle Do you mean me? What do you mean with "attaching traces"? How do I do that? Sorry, it's my first time doing this and I'm pretty new to HA so I sometimes need guidance 😃

javicalle commented 2 years ago

Sorry, yes @Tropaion the message was for you. Just the same thing you've done before with the logs whem playing with the physical device, but this time from Home Assistant. Although we know that the device does not react, I am interested in seeing the raw values of the messages that are generated.

Tropaion commented 2 years ago

@javicalle How do I do that? These are the logs from HA: I set this in configuration.yaml:

logger:
  default: info
  logs:
    homeassistant.core: debug
    homeassistant.components.zha: debug
    bellows.zigbee.application: debug
    bellows.ezsp: debug
    zigpy: debug
    zigpy_deconz.zigbee.application: debug
    zigpy_deconz.api: debug
    zigpy_xbee.zigbee.application: debug
    zigpy_xbee.api: debug
    zigpy_zigate: debug
    zigpy_znp: debug
    zhaquirks: debug

BTW if it's easier, i can also give you temporary access to my installation or with a live video with teams.

javicalle commented 2 years ago

The same files you get here:

Those logs are the ones that are generated when you interact with the physical device.

Interacting through HA, logs will also be generated in the same file. It's the same thing you've already done, but from HA. Because you have the device also in HA right?

Tropaion commented 2 years ago

Those logs are the ones that are generated when you interact with the physical device.

No, these logs aren't from physical interaction, these are from HA. I tried turning on the light via ZHA in devices, it sends something, the command is not denied from the device and the state resets back to off.

Interacting through HA, logs will also be generated in the same file. It's the same thing you've already done, but from HA. Because you have the device also in HA right?

Yes, the device is in HA and I tried interacting it via HA, so the logs are generated without touching the device.

image

This is from physical turning it off:

2022-01-28 17:55:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=10333306, TSN=0, Data=b'\x09\x0B\x01\x00\x23\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 17:55:40 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=11 command_id=1>
2022-01-28 17:55:40 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=35, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>))]
2022-01-28 17:55:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.esszimmer_deckenlicht_level_on_off, old_state=<state light.esszimmer_deckenlicht_level_on_off=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=65, off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T17:20:56.386832+01:00>, new_state=<state light.esszimmer_deckenlicht_level_on_off=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T17:55:40.662336+01:00>>
2022-01-28 17:55:40 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=11, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x0B\x0B\x01\x00')
2022-01-28 17:55:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 17:55:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=10358374, TSN=0, Data=b'\x09\x0B\x01\x00\x23\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 17:55:41 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=11 command_id=1>
2022-01-28 17:55:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=11)
javicalle commented 2 years ago

Ahhhh, sorry. My fault.

If you want i can try getting the logs from physical interaction too.

Yes please, I want to compare both of them.

Tropaion commented 2 years ago

@javicalle np, happens, thanks for your help :D

Physical turning on:

2022-01-28 17:57:24 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=21, SecurityUse=<Bool.false: 0>, TimeStamp=1087626, TSN=0, Data=b'\x09\x0D\x01\x00\x24\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 17:57:24 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=13 command_id=1>
2022-01-28 17:57:24 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=36, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>))]
2022-01-28 17:57:24 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.esszimmer_deckenlicht_level_on_off, old_state=<state light.esszimmer_deckenlicht_level_on_off=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T17:55:40.662336+01:00>, new_state=<state light.esszimmer_deckenlicht_level_on_off=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=65, off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T17:57:24.379753+01:00>>
2022-01-28 17:57:24 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=13, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x0D\x0B\x01\x00')
2022-01-28 17:57:24 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 17:57:24 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=13)

Turning off via HA:

2022-01-28 17:59:59 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=entity_id=light.esszimmer_deckenlicht_level_on_off>
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0006] Sending Tuya Cluster Command... Cluster Command is 0, Arguments are ()
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] tuya_mcu_command: cluster_data=TuyaClusterData(endpoint_id=1, cluster_attr='on_off', attr_value=0)
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] get_dp_mapping --> found DP: 1
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb: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-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ztype: Bool.false
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] from_value: [1, 0]
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] raw: b'\x00'
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] tuya_command: TuyaCommand(status=0, tsn=8, dp=1, data=TuyaData(dp_type=<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>))
2022-01-28 17:59:59 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2DCB:1:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: Status.SUCCESS
2022-01-28 17:59:59 DEBUG (MainThread) [homeassistant.components.zha.entity] light.esszimmer_deckenlicht_level_on_off: turned off: Status.SUCCESS
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=9, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x05\x41\x11\x09\x00\x00\x08\x01\x01\x00\x01\x00')
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=9)
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=25, SecurityUse=<Bool.false: 0>, TimeStamp=10795613, TSN=0, Data=b'\x18\x09\x0B\x00\x83', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 17:59:59 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=9 command_id=Command.Default_Response>
Tropaion commented 2 years ago

@javicalle Did this help to get some insights or should i try something else (sniffing)?

javicalle commented 2 years ago

If you can, there are some random tests.

In your local quirk /custom_zha_quirks/ts0601_dimmer.py file add this class just above TuyaSingleSwitchDimmerGP:

class TestManufCluster(TuyaManufacturerLevelControl):

    set_time_offset = 1970

Also, replace the TuyaSingleSwitchDimmerGP class for this one:

class TuyaSingleSwitchDimmerGP(TuyaDimmerSwitch):
    """Tuya touch switch device."""

    signature = {

        MODELS_INFO: [
            ("_TZE200_3p5ydos3", "TS0601"),
            ("_TZE200_ip2akl4w", "TS0601"),
        ],
        ENDPOINTS: {
            1: {
                PROFILE_ID: zha.PROFILE_ID,
                DEVICE_TYPE: zha.DeviceType.SMART_PLUG,
                INPUT_CLUSTERS: [
                    Basic.cluster_id,
                    Groups.cluster_id,
                    Scenes.cluster_id,
                    TuyaManufCluster.cluster_id,
                ],
                OUTPUT_CLUSTERS: [Time.cluster_id, Ota.cluster_id],
            },
            242: {
                PROFILE_ID: 41440,
                DEVICE_TYPE: 97,
                INPUT_CLUSTERS: [],
                OUTPUT_CLUSTERS: [GreenPowerProxy.cluster_id],
            },
        },
    }

    replacement = {
        ENDPOINTS: {
            1: {
                DEVICE_TYPE: zha.DeviceType.ON_OFF_LIGHT,
                INPUT_CLUSTERS: [
                    Basic.cluster_id,
                    Groups.cluster_id,
                    Scenes.cluster_id,
                    LevelControl.cluster_id,
                    TestManufCluster,
                    TuyaOnOff,
                    TuyaLevelControl,
                ],
                OUTPUT_CLUSTERS: [Time.cluster_id, Ota.cluster_id],
            },
            242: {
                PROFILE_ID: 41440,
                DEVICE_TYPE: 97,
                INPUT_CLUSTERS: [],
                OUTPUT_CLUSTERS: [GreenPowerProxy.cluster_id],
            },
        },
    }

Delete pycache, restart and test. Logs from HA and physical device are welcomed.

I really don't know where the problem could be and they are tests to try random things and see if there is any result.

Tropaion commented 2 years ago

Ok, here are the logs

Turning on via HA:

2022-01-28 21:51:21 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_on, service_data=entity_id=light.esszimmer_deckenlicht_level_on_off>
2022-01-28 21:51:21 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2DCB:1:0x0006]: executed 'on' command with args: '()' kwargs: '{}' result: Status.SUCCESS
2022-01-28 21:51:21 DEBUG (MainThread) [homeassistant.components.zha.entity] light.esszimmer_deckenlicht_level_on_off: turned on: {'on_off': <Status.SUCCESS: 0>}
2022-01-28 21:51:21 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=17, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x05\x41\x11\x11\x00\x00\x00\x01\x01\x00\x01\x01')
2022-01-28 21:51:21 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 21:51:21 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=43, SecurityUse=<Bool.false: 0>, TimeStamp=11598042, TSN=0, Data=b'\x18\x11\x0B\x00\x83', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:51:21 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=17 command_id=Command.Default_Response>
2022-01-28 21:51:22 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=17)
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=0, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=43, SecurityUse=<Bool.false: 0>, TimeStamp=11829177, TSN=0, Data=b'\x08\x7B\x0A\x01\x00\x20\x40\xE2\xFF\x20\x20\xE4\xFF\x20\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=123 command_id=Command.Report_Attributes>
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] ZCL request 0x000a: [[Attribute(attrid=1, value=<TypeValue type=uint8_t, value=64>), Attribute(attrid=65506, value=<TypeValue type=uint8_t, value=32>), Attribute(attrid=65508, value=<TypeValue type=uint8_t, value=0>)]]
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] Attribute report received: app_version=64, 65506=32, 65508=0
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=0, TSN=123, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK: 32>, Radius=30, Data=b'\x18\x7B\x0B\x0A\x00')
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=0, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=40, SecurityUse=<Bool.false: 0>, TimeStamp=11855750, TSN=0, Data=b'\x08\x7B\x0A\x01\x00\x20\x40\xE2\xFF\x20\x20\xE4\xFF\x20\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:51:25 DEBUG (MainThread) [zigpy.util] Duplicate 123 TSN
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=0, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=11866779, TSN=0, Data=b'\x08\x7B\x0A\x01\x00\x20\x40\xE2\xFF\x20\x20\xE4\xFF\x20\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=123 command_id=Command.Report_Attributes>
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] ZCL request 0x000a: [[Attribute(attrid=1, value=<TypeValue type=uint8_t, value=64>), Attribute(attrid=65506, value=<TypeValue type=uint8_t, value=32>), Attribute(attrid=65508, value=<TypeValue type=uint8_t, value=0>)]]
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0x0000] Attribute report received: app_version=64, 65506=32, 65508=0
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy.util] Duplicate 123 TSN
2022-01-28 21:51:26 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=123)

Turning on physically:

2022-01-28 21:52:39 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=58, SecurityUse=<Bool.false: 0>, TimeStamp=752924, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:39 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=124 command_id=1>
2022-01-28 21:52:39 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=58, command_id=257, function=0, data=[1, 1])]
2022-01-28 21:52:39 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 58, Command: 257, Function: 0, Data: [1, 1]]
2022-01-28 21:52:39 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 1
2022-01-28 21:52:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.esszimmer_deckenlicht_level_on_off, old_state=<state light.esszimmer_deckenlicht_level_on_off=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T21:44:46.772686+01:00>, new_state=<state light.esszimmer_deckenlicht_level_on_off=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=87, off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T21:52:39.884054+01:00>>
2022-01-28 21:52:39 DEBUG (MainThread) [zigpy_znp.api] Sending request: SYS.Ping.Req()
2022-01-28 21:52:39 DEBUG (MainThread) [zigpy_znp.api] Received command: SYS.Ping.Rsp(Capabilities=<MTCapabilities.APP_CNF|GP|UTIL|ZDO|AF|SYS: 1625>)
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=54, SecurityUse=<Bool.false: 0>, TimeStamp=777990, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=124 command_id=1>
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=58, command_id=257, function=0, data=[1, 1])]
2022-01-28 21:52:40 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 58, Command: 257, Function: 0, Data: [1, 1]]
2022-01-28 21:52:40 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 1
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=54, SecurityUse=<Bool.false: 0>, TimeStamp=790537, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=43, SecurityUse=<Bool.false: 0>, TimeStamp=803083, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:40 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=36, SecurityUse=<Bool.false: 0>, TimeStamp=816126, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=43, SecurityUse=<Bool.false: 0>, TimeStamp=828174, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=124 command_id=1>
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=58, command_id=257, function=0, data=[1, 1])]
2022-01-28 21:52:41 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 58, Command: 257, Function: 0, Data: [1, 1]]
2022-01-28 21:52:41 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 1
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=840720, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=853265, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=54, SecurityUse=<Bool.false: 0>, TimeStamp=865812, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:52:41 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=878358, TSN=0, Data=b'\x09\x7C\x01\x00\x3A\x01\x01\x00\x01\x01', MacSrcAddr=0x2DCB, MsgResultRadius=29)

Turning off via HA:

2022-01-28 21:54:18 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service=turn_off, service_data=entity_id=light.esszimmer_deckenlicht_level_on_off>
2022-01-28 21:54:18 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x2DCB:1:0x0006]: executed 'off' command with args: '()' kwargs: '{}' result: Status.SUCCESS
2022-01-28 21:54:18 DEBUG (MainThread) [homeassistant.components.zha.entity] light.esszimmer_deckenlicht_level_on_off: turned off: Status.SUCCESS
2022-01-28 21:54:18 DEBUG (MainThread) [zigpy_znp.api] Sending request: AF.DataRequestExt.Req(DstAddrModeAddress=AddrModeAddress(mode=<AddrMode.NWK: 2>, address=0x2DCB), DstEndpoint=1, DstPanId=0x0000, SrcEndpoint=1, ClusterId=61184, TSN=19, Options=<TransmitOptions.SUPPRESS_ROUTE_DISC_NETWORK|ACK_REQUEST: 48>, Radius=30, Data=b'\x05\x41\x11\x13\x00\x00\x00\x01\x01\x00\x01\x00')
2022-01-28 21:54:18 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataRequestExt.Rsp(Status=<Status.SUCCESS: 0>)
2022-01-28 21:54:18 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.DataConfirm.Callback(Status=<Status.SUCCESS: 0>, Endpoint=1, TSN=19)
2022-01-28 21:54:18 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=6919834, TSN=0, Data=b'\x18\x13\x0B\x00\x83', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:54:18 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=True> manufacturer=None tsn=19 command_id=Command.Default_Response>

Turning off physically:

2022-01-28 21:55:42 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=43, SecurityUse=<Bool.false: 0>, TimeStamp=12151444, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:42 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=127 command_id=1>
2022-01-28 21:55:42 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=59, command_id=257, function=0, data=[1, 0])]
2022-01-28 21:55:42 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 59, Command: 257, Function: 0, Data: [1, 0]]
2022-01-28 21:55:42 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 0
2022-01-28 21:55:42 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=light.esszimmer_deckenlicht_level_on_off, old_state=<state light.esszimmer_deckenlicht_level_on_off=on; supported_color_modes=['brightness'], color_mode=brightness, brightness=87, off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T21:52:39.884054+01:00>, new_state=<state light.esszimmer_deckenlicht_level_on_off=off; supported_color_modes=['brightness'], off_brightness=None, friendly_name=Esszimmer_ Deckenlicht level, on_off, supported_features=33 @ 2022-01-28T21:55:42.247776+01:00>>
2022-01-28 21:55:42 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=12176511, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:42 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=58, SecurityUse=<Bool.false: 0>, TimeStamp=12189554, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=12201605, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=127 command_id=1>
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=59, command_id=257, function=0, data=[1, 0])]
2022-01-28 21:55:43 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 59, Command: 257, Function: 0, Data: [1, 0]]
2022-01-28 21:55:43 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 0
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=40, SecurityUse=<Bool.false: 0>, TimeStamp=12214152, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=40, SecurityUse=<Bool.false: 0>, TimeStamp=12226699, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=12239245, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:43 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=12251790, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:44 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=47, SecurityUse=<Bool.false: 0>, TimeStamp=12264335, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)
2022-01-28 21:55:44 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=127 command_id=1>
2022-01-28 21:55:44 DEBUG (MainThread) [zigpy.zcl] [0x2dcb:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=59, command_id=257, function=0, data=[1, 0])]
2022-01-28 21:55:44 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 Received Attribute Report. Command is 1, Tuya Paylod values[Status : 0, TSN: 59, Command: 257, Function: 0, Data: [1, 0]]
2022-01-28 21:55:44 DEBUG (MainThread) [zhaquirks.tuya] a4:c1:38:a3:68:a2:5f:32 - Received switch event message, channel: 1, state: 0
2022-01-28 21:55:44 DEBUG (MainThread) [zigpy_znp.api] Received command: AF.IncomingMsg.Callback(GroupId=0x0000, ClusterId=61184, SrcAddr=0x2DCB, SrcEndpoint=1, DstEndpoint=1, WasBroadcast=<Bool.false: 0>, LQI=51, SecurityUse=<Bool.false: 0>, TimeStamp=12276881, TSN=0, Data=b'\x09\x7F\x01\x00\x3B\x01\x01\x00\x01\x00', MacSrcAddr=0x2DCB, MsgResultRadius=29)

BTW I don't know why, but my ZHA never generates a pycache file :D

javicalle commented 2 years ago

Hi @Tropaion I'm trying to see if there is a pattern or something in your logs that gives me a clue, but maybe you can see something else.

I have doubts if the timestamp of the messages can be related to the problem. A common security measure in messaging is that responses to messages happen in a close amount of time. If the both systems have different datetime values, it could be that the MCU discards the messages.

The last proposed change implements one of the internal set_time_request MCU commands. I insist that I am not sure if it is related, but it is something that I wanted to try.

The fact is that reviewing the messaging, I have focused in the TimeStamp field that is included in some messages.

That TimeStamp is clearly a value that increases little by little in each block of messages. I am also sure that the units of measurement are not seconds (there are several messages in the same second with different TimeStamp). It can be microseconds or anything else. But what I would expect is that it would always be incremental.

But in the blocks you include, these values seem to change more or less randomly. Sometimes they are greater and sometimes smaller.

Most likely it's nothing, but can you check if in your traces you see a pattern or something that seems remarkable to you?

Tropaion commented 2 years ago

@javicalle I already suggested this but maybe I should really try sniffing the communication with a Tuya Gateway?

Daandeve commented 2 years ago

If you can, there are some random tests.

In your local quirk /custom_zha_quirks/ts0601_dimmer.py file add this class just above TuyaSingleSwitchDimmerGP:

class TestManufCluster(TuyaManufacturerLevelControl):

    set_time_offset = 1970

Also, replace the TuyaSingleSwitchDimmerGP class for this one:

class TuyaSingleSwitchDimmerGP(TuyaDimmerSwitch):
    """Tuya touch switch device."""

    signature = {

        MODELS_INFO: [
            ("_TZE200_3p5ydos3", "TS0601"),
            ("_TZE200_ip2akl4w", "TS0601"),
        ],
        ENDPOINTS: {
            1: {
                PROFILE_ID: zha.PROFILE_ID,
                DEVICE_TYPE: zha.DeviceType.SMART_PLUG,
                INPUT_CLUSTERS: [
                    Basic.cluster_id,
                    Groups.cluster_id,
                    Scenes.cluster_id,
                    TuyaManufCluster.cluster_id,
                ],
                OUTPUT_CLUSTERS: [Time.cluster_id, Ota.cluster_id],
            },
            242: {
                PROFILE_ID: 41440,
                DEVICE_TYPE: 97,
                INPUT_CLUSTERS: [],
                OUTPUT_CLUSTERS: [GreenPowerProxy.cluster_id],
            },
        },
    }

    replacement = {
        ENDPOINTS: {
            1: {
                DEVICE_TYPE: zha.DeviceType.ON_OFF_LIGHT,
                INPUT_CLUSTERS: [
                    Basic.cluster_id,
                    Groups.cluster_id,
                    Scenes.cluster_id,
                    LevelControl.cluster_id,
                    TestManufCluster,
                    TuyaOnOff,
                    TuyaLevelControl,
                ],
                OUTPUT_CLUSTERS: [Time.cluster_id, Ota.cluster_id],
            },
            242: {
                PROFILE_ID: 41440,
                DEVICE_TYPE: 97,
                INPUT_CLUSTERS: [],
                OUTPUT_CLUSTERS: [GreenPowerProxy.cluster_id],
            },
        },
    }

Delete pycache, restart and test. Logs from HA and physical device are welcomed.

I really don't know where the problem could be and they are tests to try random things and see if there is any result.

Just tried this, the switch is now offline (But that is usual I think). Initializing logs:

2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0000] Attribute id: 4 value: _TZE200_ip2akl4w
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0000] Attribute id: 5 value: TS0601
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0000] Attribute id: 4 value: _TZE200_ip2akl4w
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0000] Attribute id: 5 value: TS0601
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0008] Attribute id: 61185 value: 2
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0008] Attribute id: 61186 value: 0
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0008] Attribute id: 0 value: 94
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0000] Attribute id: 65503 value: �N�)iFa�)i
2022-01-28 23:34:33 DEBUG (MainThread) [zigpy.appdb] [0xf51b:1:0x0006] Attribute id: 0 value: 1
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.device] [0xF51B](TS0601): started initialization
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:ZDO](TS0601): 'async_initialize' stage succeeded
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: initializing channel: from_cache: False
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: initializing channel: from_cache: False
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0000]: initializing channel: from_cache: False
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0000]: finished channel initialization
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0019]: initializing channel: from_cache: False
2022-01-28 23:34:49 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0019]: finished channel initialization
2022-01-28 23:34:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster:
2022-01-28 23:34:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: async_initialize: retryable request #1 failed: . Retrying in 0.8s
2022-01-28 23:34:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster:
2022-01-28 23:34:57 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: async_initialize: retryable request #1 failed: . Retrying in 1.0s
2022-01-28 23:34:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: initializing channel: from_cache: False
2022-01-28 23:34:58 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: initializing channel: from_cache: False
2022-01-28 23:35:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: failed to get attributes '['on_off']' on 'on_off' cluster:
2022-01-28 23:35:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: async_initialize: retryable request #2 failed: . Retrying in 0.9s
2022-01-28 23:35:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: failed to get attributes '['current_level']' on 'level' cluster:
2022-01-28 23:35:05 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: async_initialize: retryable request #2 failed: . Retrying in 0.9s
2022-01-28 23:35:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0006]: initializing channel: from_cache: False
2022-01-28 23:35:06 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0xF51B:1:0x0008]: initializing channel: from_cache: False

Off (These two lines but 10x)

2022-01-28 23:38:24 DEBUG (MainThread) [zigpy.zcl] [0xf51b:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=144 command_id=1>
2022-01-28 23:38:24 DEBUG (MainThread) [zigpy.zcl] [0xf51b:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=78, command_id=257, function=0, data=[1, 0])]

On (These two lines but 10x)

2022-01-28 23:38:22 DEBUG (MainThread) [zigpy.zcl] [0xf51b:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=144 command_id=1>
2022-01-28 23:38:26 DEBUG (MainThread) [zigpy.zcl] [0xf51b:1:0xef00] ZCL request 0x0001: [Command(status=0, tsn=79, command_id=257, function=0, data=[1, 1])]

With these Moes dimmers I get Duplicate 143 TSN and Duplicate 107 TSN but I don't get these messages from other working zigbee devices

Tropaion commented 2 years ago

@javicalle Now I'm NaN for a week, tried to install sniffer firmware on my ZHA Stick and bricked it...have to buy cJTAG debugger 😢

javicalle commented 2 years ago

Now I'm NaN for a week, tried to install sniffer firmware on my ZHA Stick and bricked it...have to buy cJTAG debugger 😢

Upssss, sorry to ear. I hope it doesn't cause you too much trouble.

MattWestb commented 2 years ago

@Tropaion You can flashing it with one RPi and dont need waiting for the cJTAG debugger but the pins its little "tight" but working. Instruction is / was on Z2M pages.

javicalle commented 2 years ago

I already suggested this but maybe I should really try sniffing the communication with a Tuya Gateway?

I think that would give us the Zigbee protocol messaging between a gateway and the device (which would be very good).

But I don't think it would be much different from what we already have. I may be wrong, but I think the problem may be in the values of some of the messaging attributes that we don't pay much attention to: _transactionid, timestamp, etc. I think that these devices may have some kind of extra control that has not been taken into account until now.

In the end, the raw data can give an idea, but it is necessary to perform exhaustive tests to understand the operation of the values and what it supports/fails in messaging.

MattWestb commented 2 years ago

"Decoding Zigbee sniffs" is little tricky then its many layer that is doing hand shaking but if having one command to tracking and looking how tuya is doing it in the "tuya way" it can good with sniffs but its not guarantee to finding the "Tuya magic".

Mostly tuya is doing special configurations than start talking with the device for getting them in one different "mode". The tuya DPs is only tunneled as APS commands and only being passed to the host system from the network layer but it can bing that they is doing some "extra setting" for this device.

@Tropaion If you is posting one sniff with pairing one device its also have your (encrypted) network key for the system its being sniffed and can being decrypted of all that downloading it with right knowledge. For test system its no problem but not recommended doing for production system (if you is writing the PLZ and haus number of your home ;-))).

Tropaion commented 2 years ago

@MattWestb Do you have a link about how to do it with the RasPi? I searched for it but didn't find anything about cJTAG.

MattWestb commented 2 years ago

I was thinking you have one CC-2531 stick (I have 2 but is not using them then using IKEA Zigbee modules).

Z2M have deleting the old guides that i was using but our crazy UK friends have making one guide with video and its possible connecting the stick with normal 2.5 MM cables but its tricky. https://notenoughtech.com/home-automation/flashing-cc2531-without-cc-debugger/

I was having the thin cable and the adapter so it was easy for my but i think its no large problem getting it done with normal if not braking the PCB.

Tropaion commented 2 years ago

@MattWestb No, I have the ZZH-Stick with CC2652R Chip, which doesn't support JTAG (which I would have a few adapter) but only works with cJTAG, which I never heard of before and I found only one debugger, which I ordered now.

Upssss, sorry to ear. I hope it doesn't cause you too much trouble.

No it isn't, but it takes a week for the debugger to arrive, because there aren't many vendors for it. The positive side is, that it's easier to do experiements with it.

But I don't think it would be much different from what we already have. I may be wrong, but I think the problem may be in the values of some of the messaging attributes that we don't pay much attention to: _transactionid, timestamp, etc. I think that these devices may have some kind of extra control that has not been taken into account until now.

I don't have much knowledge about this area, but I hope you/we can find a solution because I have already bought and installed a few of these dimmer :D. Even though I'm also studying IT but my area is ASM/C/C++ (uCs) so I can't help much with this but do testing.

If you is posting one sniff with pairing one device its also have your (encrypted) network key for the system its being sniffed and can being decrypted of all that downloading it with right knowledge. For test system its no problem but not recommended doing for production system (if you is writing the PLZ and haus number of your home ;-))).

I know, thats also why a made/wanted to make a test network.

MattWestb commented 2 years ago

OK then its no RPi flashing on your stack but i hope you is getting the debugger fast !!

If you can soldering and you can always baying one IKEA device and using the Zigbee module but the old its possible flashing with RPi and ESP devices but the new one need one real J-Link for flashing.

One working sniffer and also coordinator for ZHA / Z2M named "IKEA Billy EZSP" for 7€ :-))))

The good with the community is the mix some great coders is here and some other with no coding knowledge but with electronic and telecommunication like my so in the end we can doing much that all is working together.

If you is getting sniffs i can heling looking on them. I have doing some hundred hours sniffing IKEA remotes (not the last firmware update but the generation before) and also some tuya like my current problem tuya TS004F that i and one Hubart dev was cracking the magic and Hi was implanting it but i cant o the coding but have the knowledge how it shall being made for getting the device working OK.

Tropaion commented 2 years ago

@MattWestb @javicalle I'm back, finally managed to setup the ZigBee Sniffer. Here are some sniffed packets between Tuya Gateway and Dimmer, I hope they are usefull (you have to remove .txt): DimmerON.pcapng.txt DImmerOFF.pcapng.txt DimmerON1.pcapng.txt DImmerOFF1.pcapng.txt

MattWestb commented 2 years ago

Looks great @Tropaion but we cant see any commands only the underlying network acks then all commands is cryptated and need the network key for see them.

Tropaion commented 2 years ago

@MattWestb I entered the network key, but looks like it didn't work...here is the key: 35:0A:9E:F7:F8:C3:43:A0:A2:7D:75:A1:8E:18:A0:EB. I extracted it while pairing a device because I didn't find another way with the tuya gateway.

MattWestb commented 2 years ago

The network key is saved in your local wireshark settings but its possible adding itas one comment in the fie header 👍

Tropaion commented 2 years ago

@MattWestb Is this key wrong? As far as I know the ZigBee Network Key doesn't have anything to do with WireShark since it isn't paired with the Gateway and the Gateway owns the key.

At least according this guide: https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html#_3-sniffing-traffic image

MattWestb commented 2 years ago

The key is working very well !! Is looking if i finding some manufacture coded frames or somthing strange.

MattWestb commented 2 years ago

@javicalle Is you using your new tuya MCU code here ? Then tuya ZBGW is sending one on command first the device is sending one APS ACK in the Zigbee layer. Then the device is sending the updated status to the tuya ZBGW and the ZBGW is sending one default response back to the device.

If the device is not getting one default response its repeating sending the last command until its timing out (depends of the firmware) if not getting the ACK.

For ZCL commands is the Zigbee stack doing all this but our cluster is not ZCL then its one manufactur cluster and then the application is responsibility doing all handshaking in the APS layer.

You can see the transaction number (tsn) is the same = resending the same message then no APS ACK (default response) is being returned.

I have not looking on the ACKs in the 802.15.4 layer but is normally no problems with that (its only one transport layer for the Zigbee frames.

I think the old implementation is here but i have not looking so well: https://github.com/zigpy/zha-device-handlers/blob/23a166902e50d5c32019e0d4d32a968715041bb6/zhaquirks/tuya/__init__.py#L394

MattWestb commented 2 years ago

In tuya INIT is 4 implementations for sending default response for "normal" Zigbee that using manufacture clusters for blind, OnOff switches and dimmers switches plus one or two for DP commands so little confusing if getting the wrong place.

MattWestb commented 2 years ago

tuya is "pulling" the device is one very strange way by sending:

ZigBee Network Layer Data, Dst: 0x7d4a, Src: 0x0000
ZigBee Application Support Layer Data, Dst Endpt: 1, Src Endpt: 1
ZigBee Cluster Library Frame, Command: Read Attributes, Seq: 44
    Frame Control Field: Profile-wide (0x10)
    Sequence Number: 44
    Command: Read Attributes (0x00)
    Attribute: Application Version (0x0001)

every 5 seconds !!

The Zigbee standard is configure reporting from data that shall being transmitted but Philips HUE is using polling of attributes instead but its very network intens and is not scaling good in large networks.

@Tropaion can you looking if tuya is also doing this if you closing the tuya app and letting the ZBGW being idle for some time ?

It can being that they is doing it only then "looking on the device" in the app for getting fast updates (looks like some TRVs is doing that).

If no latency problem is not recommended implanting somthing like this in ZHA only if its very needed for some devices.

Tropaion commented 2 years ago

@MattWestb I can do that, here is a full log for about half a minute: FullLog.pcapng.txt I did filter before, because I thought its easier.

Tropaion commented 2 years ago

@MattWestb Is this what you needed? Is it helpfull?

MattWestb commented 2 years ago

Looks like they is reading the attribute every 5 seconds if no other communication is made. I think its because getting the "pipe" open but if the firmware is OK it shall not being needed. From the suígnature:

*is_full_function_device=True, *is_mains_powered=True, *is_receiver_on_when_idle=True, *is_router=True,

so its not one sleeping end device or not sleeping end device is one normal router (if its the same as the first post).

Tropaion commented 2 years ago

@MattWestb Yeah, it's a dimmer with N-wire so it's a router and ZHA also detects it as a router. I don't know what this implied but is this the problem? :D

MattWestb commented 2 years ago

I think is no problem only that we dont knowing what tuya is doing. tuya is having 2 different Zigbee modules for "DP devices" the old one TYST11 and the new one TZE200 if reading the device Manufacturer Name. Both can having one router firmware = is not sleeping and is always online and the other is for sliping end device that is not router and is sleeping moer or less all the time (used in sensors and TRVs). How tuya is doing the configurations if them we dont knowing only that they is making some magic for getting it working in there system.

If the Zigbee module is working OK is it being used as one tunnel (for serial communication) for the MCU on the device to tuya coud. And we is trying getting the commands from the device MCU and using it in our way and getting all function we can in our devices.

@javicalle I dont have the knowledge looking in the DP commands and see is it OK or not. But if the default response is not working all traffic to and from the device is not working OK and very likely we are missing packages then its not working OK. If getting / having long delay between the time request and the response i think its very likely the MCU is not liking it.

I suggesting first fixing the default response and then looking how the time sync is working OK or not after that. Mixing more problems in one case is normally no working good and the "transport" problem must being fixed before hunting individual command problems.

MattWestb commented 2 years ago

By the way good sniffing done @Tropaion !!!

Tropaion commented 2 years ago

@MattWestb Thanks :D I hoped it helped to get it running.

javicalle commented 2 years ago

Hi there,

@javicalle Is you using your new tuya MCU code here ?

Yes, the first version was an extend form the version that nworbneb was running. The new device has the same signature but with the extra GPP endpoint.

After the first failed attempts, I have also offered versions that make use of the (let's call it) classic implementation. Also unsuccessful.

Sorry, but all the pcapng packages are far beyond my knowledge.

You can see the transaction number (tsn) is the same = resending the same message then no APS ACK (default response) is being returned.

The default response is implemented also in the 'new approach'. The nworbneb logs show that in his case there are no retries, so the default response is received by the device.

@javicalle I dont have the knowledge looking in the DP commands and see is it OK or not. But if the default response is not working all traffic to and from the device is not working OK and very likely we are missing packages then its not working OK.

At this point, my guess is that the default responses is indeed being sent, but for some reason the device doesn't like what's coming back and doesn't accept it as a valid response. Is it possible to trace and compare the request and response in both cases? In other words, analyze the response of the requests made by Tuya ZBGW and compare them with what is come from HA.

Tropaion commented 2 years ago

@javicalle I will try logging communication between dimmer and HA, shouldn't take long

MattWestb commented 2 years ago

In the last log i have seen form then receiving commnands from the device https://github.com/zigpy/zha-device-handlers/issues/1302#issuecomment-1024629142 is it many command frames with the same tsn and the frame is identical (only timestamp and LQI that coming from the coordinator) so in that case ZHA was not sending one default response. I dont knowing if the quirk system is logging it with debug but the TuyaSmartRemoteOnOffCluster quirk is logging its sending one default response then having debug enabled for quirks. https://github.com/zigpy/zha-device-handlers/blob/23a166902e50d5c32019e0d4d32a968715041bb6/zhaquirks/tuya/__init__.py#L814-L817

Tropaion commented 2 years ago

Did some sniffing between ZHA and Dimmer while sending one command to turn on, here is the result: SniffingZHA2Dimm.pcapng.txt The Zigbee Key is: 95:98:4E:A9:8D:58:DF:AA:20:6D:7B:93:DA:EC:CE:75

MattWestb commented 2 years ago

Then sending command to the device is the device very nicely sending one default response. 👍 How is it looking than you is doing something on the dimmer and its sending commands to ZHA ?

Tropaion commented 2 years ago

Log turning dimmer on physically: Dimmer2ZHA.pcapng.txt The Zigbee Key is: 95:98:4E:A9:8D:58:DF:AA:20:6D:7B:93:DA:EC:CE:75

MattWestb commented 2 years ago

So the device is sending the command with Seq 88 OK but 12 times then it not getting one default response. And the frame have the it setted:

ZigBee Cluster Library Frame
    Frame Control Field: Cluster-specific (0x09)
        .... ..01 = Frame Type: Cluster-specific (0x1)
        .... .0.. = Manufacturer Specific: False
        .... 1... = Direction: Server to Client
        ...0 .... = Disable Default Response: False
    Sequence Number: 88
    Command: Unknown (0x01)
Data (7 bytes)
    Data: 008e0101000101
    [Length: 7]

So the application shall sending one (its one no ZCL so the system must making it).

In the underlying 802.15.4 layer is the coordinator sending ACK for the frame OK but its in the network layer and the device have asking for one APP ACK and the quirk is not sending it.

As long the default response is not working nothing is working OK then the device is blocked for sending and receiving commands until its timing out (or the firmware is crashing).

@javicalle Can you debugging your tuya switch if its also "spamming" then sending commands from it ? It shall bing possible to see with little debug logging.

javicalle commented 2 years ago

@javicalle Can you debugging your tuya switch if its also "spamming" then sending commands from it ? It shall bing possible to see with little debug logging.

I am totally sure that in my system (and in the ones we have implemented so far) the default response message is processed correctly and no repetitions are received.

This is the message my device sends when I press a switch

2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer= None tsn=37 command_id=1>
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=109, dp=1, data=TuyaData(dp_type =<TuyaDPType.BOOL: 1>, function=0, raw=b'\x01', *payload=<Bool.true: 1>))]
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer= None tsn=38 command_id=1>
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=110, dp=2, data=TuyaData(dp_type =<TuyaDPType.BOOL: 1>, function=0, raw=b'\x00', *payload=<Bool.false: 0>))]
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer= None tsn=39 command_id=1>
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=111, dp=14, data=TuyaData(dp_type =<TuyaDPType.ENUM: 4>, function=0, raw=b'\x02', *payload=<enum8.undefined_0x02: 2>))]
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=CLUSTER_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer= None tsn=40 command_id=1>
2022-02-03 00:01:44 DEBUG (MainThread) [zigpy.zcl] [0xe6e3:1:0xef00] ZCL request 0x0001: [TuyaCommand(status=0, tsn=112, dp=15, data=TuyaData(dp_type =<TuyaDPType.ENUM: 4>, function=0, raw=b'\x01', *payload=<enum8.undefined_0x01: 1>))]

4 messages. 4 tsn. No repetitions 🤷🏻‍♂️

javicalle commented 2 years ago

tuya.zip

This is a tuya/__init__.py version with more logs. It must be unzipped in the custom_quirks folder.

I think it will not be necessary to modify the imports statements.

MattWestb commented 2 years ago

If the user is using one local quirk then the INIT must being placed in the HA contraire then local quirks is importing all functions from the container and cant getting the updated function from one nested local quirk. Its little sad but better then user alwys maust hacking the HA container.

javicalle commented 2 years ago

I agree that modifying the container is sure to apply the changes you make, but it's not always easy or accessible to all users.

For this people, the import statements can be tweaked to use the qustom_quirks classes as:

from custom_zha_quirks.tuya.mcu import (
    TuyaInWallLevelControl,
    TuyaLevelControlManufCluster,
    TuyaOnOff as TuyaOnOffMCU,
)

Also, a relative import can be used:

from .. import (
    ATTR_ON_OFF,
    TUYA_MCU_COMMAND,
    TUYA_MCU_VERSION_RSP,
    TUYA_SET_DATA,
    Data,
    TuyaCommand,
    TuyaData,
    TuyaLocalCluster,
    TuyaNewManufCluster,
)

But it is not always easy to understand the class hierarchy being applied, or whether another (untweaked) import is being applied elsewhere in the code, leading to unexpected results and more problems.

But, there is a case for every user...