Duplicate events fired

[dahlb]

I seem to be seeing duplicate HA events fired for each hubitat event; below are two sets of home-assistant logs where a single received event causes two to be emitted. This makes automations using modes other then single very difficult. I checked the hubitat logs and it doesn't appear that maker api is duplicating rather they appear to be duplicating in the hubitat integration. Happy to provide further debugging, anything that is helpful.

root@data:/primary/docker/homeassistant# tail -f home-assistant.log | grep hubitat
2021-04-12 14:47:09 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'battery', 'value': '100', 'displayName': 'Utilities sensor', 'deviceId': '55', 'descriptionText': 'Utilities sensor battery level is 100%', 'unit': '%', 'type': None, 'data': None}
2021-04-12 14:47:09 DEBUG (MainThread) [hubitatmaker.hub] Updating battery of 55 to 100
2021-04-12 14:47:32 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lastActivity', 'value': '2021 Apr 12 Mon 2:47:33 PM', 'displayName': 'Laundry Light Switch', 'deviceId': '357', 'descriptionText': None, 'unit': None, 'type': None, 'data': None}
2021-04-12 14:47:32 DEBUG (MainThread) [hubitatmaker.hub] Updating lastActivity of 357 to 2021 Apr 12 Mon 2:47:33 PM
2021-04-12 14:47:40 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lastActivity', 'value': '2021 Apr 12 Mon 2:47:41 PM', 'displayName': 'Sage light switch', 'deviceId': '484', 'descriptionText': None, 'unit': None, 'type': None, 'data': None}
2021-04-12 14:47:40 DEBUG (MainThread) [hubitatmaker.hub] Updating lastActivity of 484 to 2021 Apr 12 Mon 2:47:41 PM
2021-04-12 14:47:41 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'energy', 'value': '2.462', 'displayName': 'Sage light switch', 'deviceId': '484', 'descriptionText': None, 'unit': 'kWh', 'type': None, 'data': None}
2021-04-12 14:47:41 DEBUG (MainThread) [hubitatmaker.hub] Updating energy of 484 to 2.462
2021-04-12 14:47:46 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'pushed', 'value': '2', 'displayName': "Sage's buttons", 'deviceId': '34', 'descriptionText': "Sage's buttons button 2 was pushed", 'unit': None, 'type': 'physical', 'data': None}
2021-04-12 14:47:46 DEBUG (MainThread) [hubitatmaker.hub] Updating pushed of 34 to 2
2021-04-12 14:47:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '34', 'device_name': "Sage's buttons", 'attribute': 'pushed', 'value': '2', 'description': "Sage's buttons button 2 was pushed", 'type': 'physical', 'hub': 'd8f9ed05'}
2021-04-12 14:47:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '34', 'device_name': "Sage's buttons", 'attribute': 'pushed', 'value': '2', 'description': "Sage's buttons button 2 was pushed", 'type': 'physical', 'hub': 'd8f9ed05'}
^C
root@data:/primary/docker/homeassistant# tail -f home-assistant.log | grep hubitat
2021-04-12 15:14:09 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'battery', 'value': '100', 'displayName': 'Utilities sensor', 'deviceId': '55', 'descriptionText': 'Utilities sensor battery level is 100%', 'unit': '%', 'type': None, 'data': None}
2021-04-12 15:14:09 DEBUG (MainThread) [hubitatmaker.hub] Updating battery of 55 to 100
2021-04-12 15:14:23 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lastActivity', 'value': '2021 Apr 12 Mon 3:14:24 PM', 'displayName': 'Laundry Light Switch', 'deviceId': '357', 'descriptionText': None, 'unit': None, 'type': None, 'data': None}
2021-04-12 15:14:23 DEBUG (MainThread) [hubitatmaker.hub] Updating lastActivity of 357 to 2021 Apr 12 Mon 3:14:24 PM
2021-04-12 15:14:50 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'pushed', 'value': '2', 'displayName': "Sage's buttons", 'deviceId': '34', 'descriptionText': "Sage's buttons button 2 was pushed", 'unit': None, 'type': 'physical', 'data': None}
2021-04-12 15:14:50 DEBUG (MainThread) [hubitatmaker.hub] Updating pushed of 34 to 2
2021-04-12 15:14:50 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '34', 'device_name': "Sage's buttons", 'attribute': 'pushed', 'value': '2', 'description': "Sage's buttons button 2 was pushed", 'type': 'physical', 'hub': 'd8f9ed05'}
2021-04-12 15:14:50 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '34', 'device_name': "Sage's buttons", 'attribute': 'pushed', 'value': '2', 'description': "Sage's buttons button 2 was pushed", 'type': 'physical', 'hub': 'd8f9ed05'}

[justindthomas]

I'm seeing the same. Here is a single scene event on one of my Inovelli switches (a triple-tap). The number of extra events is the same regardless of the event (e.g., a double tap also results in 4 events).

2021-04-25 16:17:46 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'pushed', 'value': '3', 'displayName': 'Office Dimmer', 'deviceId': '1059', 'descriptionText': None, 'unit': None, 'type': None, 'data': None}
2021-04-25 16:17:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '1059', 'device_name': 'Office Dimmer', 'attribute': 'pushed', 'value': '3', 'description': None, 'type': None, 'hub': '68a45f4a', 'ha_device_id': '798e4a165dba9252a4fd69cb33d165bb2967dbe31a5c55e9f5fa1e86e81db99a::1059'}
2021-04-25 16:17:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '1059', 'device_name': 'Office Dimmer', 'attribute': 'pushed', 'value': '3', 'description': None, 'type': None, 'hub': '68a45f4a', 'ha_device_id': '798e4a165dba9252a4fd69cb33d165bb2967dbe31a5c55e9f5fa1e86e81db99a::1059'}
2021-04-25 16:17:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '1059', 'device_name': 'Office Dimmer', 'attribute': 'pushed', 'value': '3', 'description': None, 'type': None, 'hub': '68a45f4a', 'ha_device_id': '798e4a165dba9252a4fd69cb33d165bb2967dbe31a5c55e9f5fa1e86e81db99a::1059'}
2021-04-25 16:17:46 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '1059', 'device_name': 'Office Dimmer', 'attribute': 'pushed', 'value': '3', 'description': None, 'type': None, 'hub': '68a45f4a', 'ha_device_id': '798e4a165dba9252a4fd69cb33d165bb2967dbe31a5c55e9f5fa1e86e81db99a::1059'}
2021-04-25 16:17:46 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lastActivity', 'value': '2021 Apr 25 Sun 4:17:46 PM', 'displayName': 'Office Dimmer', 'deviceId': '1059', 'descriptionText': None, 'unit': None, 'type': None, 'data': None}

I'm using version 0.6.6 of the Hubitat integration (the most current from what I can see).

[cgallred]

I'm also having this issue. I'm using version 0.6.8 of the Hubitat integration. I have an Aotec NanoMote, which is a Z-Wave device, running under HE. When I push a button on it I always get three closely spaced events in HA:

Event 14 fired 3:32 PM:
{
    "event_type": "hubitat_event",
    "data": {
        "device_id": "546",
        "device_name": "Test Control",
        "attribute": "pushed",
        "value": "4",
        "description": "Test Control Button 4 pushed",
        "type": "physical",
        "hub": "652267e9",
        "ha_device_id": "f8cf6ba6156f8ee9f1b6a0990ac2c37f2dd7a9951603bcc992a3d919398646b0::546"
    },
    "origin": "LOCAL",
    "time_fired": "2021-07-22T22:32:25.008657+00:00",
    "context": {
        "id": "fe955c14903b1239fd3f2c983882b7f1",
        "parent_id": null,
        "user_id": null
    }
}
Event 13 fired 3:32 PM:
{
    "event_type": "hubitat_event",
    "data": {
        "device_id": "546",
        "device_name": "Test Control",
        "attribute": "pushed",
        "value": "4",
        "description": "Test Control Button 4 pushed",
        "type": "physical",
        "hub": "652267e9",
        "ha_device_id": "f8cf6ba6156f8ee9f1b6a0990ac2c37f2dd7a9951603bcc992a3d919398646b0::546"
    },
    "origin": "LOCAL",
    "time_fired": "2021-07-22T22:32:25.008499+00:00",
    "context": {
        "id": "c01f2142261431ccb31871477fd8a342",
        "parent_id": null,
        "user_id": null
    }
}
Event 12 fired 3:32 PM:
{
    "event_type": "hubitat_event",
    "data": {
        "device_id": "546",
        "device_name": "Test Control",
        "attribute": "pushed",
        "value": "4",
        "description": "Test Control Button 4 pushed",
        "type": "physical",
        "hub": "652267e9",
        "ha_device_id": "f8cf6ba6156f8ee9f1b6a0990ac2c37f2dd7a9951603bcc992a3d919398646b0::546"
    },
    "origin": "LOCAL",
    "time_fired": "2021-07-22T22:32:25.008075+00:00",
    "context": {
        "id": "35c2390f20b460a1aecb63af9d7ec1f8",
        "parent_id": null,
        "user_id": null
    }
}

As with @dahlb, the Maker API log shows only one event on the HE side. The duplication appears to be happening in the integration.

I'm happy to provide anything that will help nail this down.

[jason0x43]

I'm pretty sure I see why this is happening now. Device-level events are being emitted by entities, and since many devices have multiple entities, there are typically multiple things emitting the same event. I should be able to get a fix out today.

[cgallred]

Thanks a lot, this indeed fixes the issue for my Aotec NanoMote!