jason0x43 / hacs-hubitat

A Hubitat integration for Home Assistant
MIT License
203 stars 47 forks source link

Send device events with description text logging to HA #97

Open jeffchampagne opened 3 years ago

jeffchampagne commented 3 years ago

I have a Kwikset SmartCode 916 lock that is setup in Hubitat. When the lock is locked/unlocked, the details about how it was locked/unlocked (manually, keypad, via app, etc) and who performed the action (code user, manually, app) are logged as description text with the event.

I'd like to create routines in Node-RED based on the how and the who information from the event. A workaround does exist that involves creating a bunch of virtual switches in Hubitat to indicate what happened (https://community.hubitat.com/t/description-text-logging-actionable/17967/10) However, it seems fairly inefficient if I can just receive the details via a message payload in Node-RED and parse out what I need.

jason0x43 commented 3 years ago

The messages sent to HA for lock events include the description text. Hubitat events are of type hubitat_event. An example lock event looks like:

{
    "event_type": "hubitat_event",
    "data": {
        "device_id": "1234",
        "device_name": "Virtual Lock",
        "attribute": "code_name",
        "value": "Hubitat",
        "description": "Virtual Lock was unlocked by Hubitat",
        "type": null,
        "hub": "xxxxxxxx"
    },
    "origin": "LOCAL",
    "time_fired": "2021-01-04T02:01:24.791735+00:00",
    "context": {
        "id": "xxxxxxxx",
        "parent_id": null,
        "user_id": null
    }
}
jeffchampagne commented 3 years ago

Ah ok, I did setup a node to listen to the event type "hubitat_event", but didn't see anything come through via debug. I'll play around with it a bit more now and see if I can get it to work. Thanks!

jeffchampagne commented 3 years ago

I listened to all events coming through the bus and am not seeing any "hubitat_event" messages when I lock/unlock the door lock. I do however see "state_changed" messages for the lock status changing, but they don't include the description text.

The only time I see "hubitat_event" messages is when I use buttons that I have like my Aeotec WallMotes, those messages come through fine to HA.

jason0x43 commented 3 years ago

Hmmm...Just as a test, can you try creating an automation in HA that reacts to the lock? Use a "device" trigger, choose the lock, and choose a trigger like "Unlocked with code".

jeffchampagne commented 3 years ago

So I can define an automation rule in HA and the trigger condition can be "Unlocked with code ". However, the rule never actually triggers. I verified this by creating two rules, one that triggers on any unlock event, the other only triggers when I unlock with my code. The first rule triggers, but the 2nd never did.

jason0x43 commented 3 years ago

Ok, so one rule does trigger? That makes it seem like events are being emitted, but they may not include the unlock code. It's possible that the lock you're using doesn't report the code used to unlock (I don't have any locks, so I developed against Hubitat's simulated lock).

Try enabling debug logging for the integration, restarting HA, and then unlocking the lock. What hubitat-related log messages do you see during the unlock process?

jason0x43 commented 3 years ago

Any updates, or is this ok to close?

jeffchampagne commented 3 years ago

Not yet, I'll get the debug logs today

jeffchampagne commented 3 years ago

Ok, this is what I am seeing in the Hassio core log:

2021-01-25 14:40:41 DEBUG (MainThread) [hubitatmaker.hub] Sending command unlock() to 141 2021-01-25 14:40:41 DEBUG (MainThread) [custom_components.hubitat.device] sent unlock to 141 2021-01-25 14:40:46 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'unlocked', 'displayName': 'Living Room Door Lock', 'deviceId': '141', 'descriptionText': 'Living Room Door Lock was unlocked via command [digital]', 'unit': None, 'type': 'digital', 'data': None} 2021-01-25 14:40:46 DEBUG (MainThread) [hubitatmaker.hub] Updating lock of 141 to unlocked

The detail I want is in the descriptionText, however, if I listen to 'hubitat_event' on the Hassio message bus, I don't see any messages when I lock/unlock the lock.

jason0x43 commented 3 years ago

Ah, I think I see the issue. The only HA event that the integration emits for locks is for "lastCodeName" updates from Hubitat, which are emitted when a lock is unlocked with a code:

2021-02-04 20:08:51 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lastCodeName', 'value': 'Hubitat', 'displayName': 'Virtual Lock', 'deviceId': '191', 'descriptionText': 'Virtual Lock was unlocked by Hubitat', 'unit': None, 'type': None, 'data': None}
2021-02-04 20:08:51 DEBUG (MainThread) [custom_components.hubitat.device] Emitted event {'device_id': '191', 'device_name': 'Virtual Lock', 'attribute': 'code_name', 'value': 'Hubitat', 'description': 'Virtual Lock was unlocked by Hubitat', 'type': None, 'hub': '0fa4421e'}
2021-02-04 20:08:51 DEBUG (MainThread) [hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'unlocked', 'displayName': 'Virtual Lock', 'deviceId': '191', 'descriptionText': 'Virtual Lock was unlocked by Hubitat', 'unit': None, 'type': 'physical', 'data': '{"1":{"name":"Hubitat","code":"1234"}}'}

The reasoning behind the current behavior is that a simple unlock event is redundant -- you can tell when a lock is unlocked or locked by seeing its state change. The only reason an event is used for unlock-with-code is to allow for automations to trigger on code-specific unlocks (you can already trigger on general unlocks via the lock state).

jeffchampagne commented 3 years ago

Ah, makes sense. I also want to write automations that trigger when a door is locked/unlocked manually, by code, or by the app. For example, if the door is locked via the keypad from outside, I'd do something different than if the door is locked by the knob inside.

jason0x43 commented 3 years ago

Hmmm... tricky.

What do the events look like from Hubitat when you do those things?

1) Lock manually 2) Unlock manually 3) Lock with code (is that possible?) 4) Unlock with code 5) Lock with app 6) Unlock with app

I only have a virtual lock to test, so I'm not sure what information you get from each of those. The main question is whether there's enough information to be able to differentiate the various situations.

quinnjudge commented 1 month ago

@jason0x43 Sorry to resurrect an old issue, but I just ran into this exact issue with a new installation of Home Assistant and your Hubitat integration. I have a Schlage and Yale lock (both Z-Wave, if it matters?) directly connected to Hubitat, and I'm hoping to get method/user of lock/unlock events in Home Assistant for different automations...can I provide anything that will help resolve this?

jason0x43 commented 1 month ago

Wow, it's been a while since I looked at this one 😄 I think I still need the same info I mentioned in my last comment. Basically, enable debug logging, then try locking and unlocking the lock in various ways and post the events that are being sent to Home Assistant.

quinnjudge commented 1 month ago

Thanks for such a quick response! Here is what I was able to gather from my Yale lock:

Unlocked using thumbturn:

2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'unlocked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was manually unlocked [physical]', 'unit': None, 'type': 'physical', 'data': None} 2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to unlocked (None) 2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 08:23:00.772 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

Locked using thumbturn:

2024-10-24 08:23:08.393 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'locked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was manually locked [physical]', 'unit': None, 'type': 'physical', 'data': None} 2024-10-24 08:23:08.393 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to locked (None) 2024-10-24 08:23:08.394 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 08:23:08.394 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 08:23:08.394 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 08:23:08.394 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

Unlocked using keypad:

2024-10-24 08:27:47.619 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lastCodeName', 'value': 'Quinn', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was unlocked by Quinn', 'unit': None, 'type': None, 'data': None} 2024-10-24 08:27:47.619 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lastCodeName of 1884 to Quinn (None) 2024-10-24 08:27:47.619 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 08:27:47.619 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 08:27:47.620 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 08:27:47.620 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>) 2024-10-24 08:27:47.620 DEBUG (MainThread) [custom_components.hubitat.hub] Emitted event {'device_id': '1884', 'device_name': 'Front Door Lock', 'attribute': <EventName.CODE_NAME: 'code_name'>, 'value': 'Quinn', 'unit': None, 'description': 'Front Door Lock was unlocked by Quinn', 'type': None, 'hub': '9d2dd5aa', 'ha_device_id': '053dee4e2db7dd00e8f09970e57d41044f98b630427890782f3f0b4682d2d407::1884'} 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'unlocked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was unlocked by Quinn', 'unit': None, 'type': 'physical', 'data': '{"6":{"name":"Quinn","code":"XXXX"}}'} 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to unlocked (None) 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 08:27:47.633 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

Locked using keypad:

2024-10-24 08:27:55.025 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'locked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was manually locked [physical]', 'unit': None, 'type': 'physical', 'data': None} 2024-10-24 08:27:55.026 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to locked (None) 2024-10-24 08:27:55.026 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 08:27:55.026 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 08:27:55.026 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 08:27:55.026 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

Unlocked using Hubitat:

2024-10-24 09:12:37.908 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'unlocked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was unlocked via command [digital]', 'unit': None, 'type': 'digital', 'data': None} 2024-10-24 09:12:37.908 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to unlocked (None) 2024-10-24 09:12:37.909 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 09:12:37.909 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 09:12:37.909 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 09:12:37.909 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

Locked using Hubitat:

2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Received event: {'name': 'lock', 'value': 'locked', 'displayName': 'Front Door Lock', 'deviceId': '1884', 'descriptionText': 'Front Door Lock was locked via command [digital]', 'unit': None, 'type': 'digital', 'data': None} 2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.hubitatmaker.hub] Updating lock of 1884 to locked (None) 2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock, <class 'custom_components.hubitat.lock.HubitatLock'>) 2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Last Update Time, <class 'custom_components.hubitat.sensor.HubitatUpdateSensor'>) 2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Battery, <class 'custom_components.hubitat.sensor.HubitatBatterySensor'>) 2024-10-24 09:12:42.300 DEBUG (MainThread) [custom_components.hubitat.device] handling event for (Front Door Lock Code Changed, <class 'custom_components.hubitat.sensor.HubitatSensor'>)

I'm not sure if the Schlage lock will be the same or different; I can do the same for that lock as well if it is helpful. Let me know if there's anything else I can provide!