Automation doesn't trigger from keyfob, but does from developer tools events

I am trying to create an automation that will trigger when I press a key on a Fibaro 601 keyfob and turn on a reading light switch.

When I use the keyfob I see entries in the log for the “zwave.scene_activated” event (suffix is [L]) but the automation does not execute. If I enter the event into the developer tools events page, then I see the log entry for “zwave.scene_activated” event (suffix is [R]), and in that case the automation executes.

The logs are as follows, first when pressing the keyfob button:

2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] notif_callback : new notification
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] notif_callback : Notification type : 2, nodeId : 4
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] addValueId : ValueID : 72057594110722067
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] addValueId : GetCommandClassId : 91, GetType : 3
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] addValueId : Notification : {'notificationType': 'ValueChanged', 'homeId': 3445027483, 'nodeId': 4, 'valueId': {'homeId': 3445027483, 'nodeId': 4, 'commandClass': 'COMMAND_CLASS_CENTRAL_SCENE', 'instance': 1, 'index': 1, 'id': 72057594110722067, 'genre': 'User', 'type': 'Int', 'value': 7680, 'label': 'Square', 'units': '', 'readOnly': False}}
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] notif_callback : call callback context
2018-08-30 11:47:55 DEBUG (Dummy-3) [openzwave] zwcallback args=[{'notificationType': 'ValueChanged', 'homeId': 3445027483, 'nodeId': 4, 'valueId': {'homeId': 3445027483, 'nodeId': 4, 'commandClass': 'COMMAND_CLASS_CENTRAL_SCENE', 'instance': 1, 'index': 1, 'id': 72057594110722067, 'genre': 'User', 'type': 'Int', 'value': 7680, 'label': 'Square', 'units': '', 'readOnly': False}}]
2018-08-30 11:47:55 DEBUG (Dummy-3) [openzwave] Z-Wave Notification ValueChanged : {'notificationType': 'ValueChanged', 'homeId': 3445027483, 'nodeId': 4, 'valueId': {'homeId': 3445027483, 'nodeId': 4, 'commandClass': 'COMMAND_CLASS_CENTRAL_SCENE', 'instance': 1, 'index': 1, 'id': 72057594110722067, 'genre': 'User', 'type': 'Int', 'value': 7680, 'label': 'Square', 'units': '', 'readOnly': False}}
2018-08-30 11:47:55 DEBUG (Dummy-3) [libopenzwave] notif_callback : end
2018-08-30 11:47:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event zwave.scene_activated[L]: entity_id=zwave.fibaro_system_fgkf601_keyfob, node_id=4, scene_id=1, scene_data=7680>
2018-08-30 11:47:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=zwave.fibaro_system_fgkf601_keyfob, old_state=<state zwave.fibaro_system_fgkf601_keyfob=initializing; node_id=4, node_name=FIBARO System FGKF601 Keyfob, manufacturer_name=FIBARO System, product_name=FGKF601 Keyfob, query_stage=CacheLoad, is_awake=False, is_ready=False, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=True, capabilities={'zwave_plus', 'beaming', 'routing'}, sentCnt=1, sentFailed=1, retries=0, receivedCnt=0, receivedDups=0, receivedUnsolicited=0, sentTS=2018-08-30 11:47:04:321 , receivedTS=2018-08-30 11:47:04:043 , lastRequestRTT=0, averageRequestRTT=0, lastResponseRTT=0, averageResponseRTT=0, battery_level=37, wake_up_interval=0, friendly_name=FIBARO System FGKF601 Keyfob @ 2018-08-30T10:47:04.250003+00:00>, new_state=<state zwave.fibaro_system_fgkf601_keyfob=initializing; node_id=4, node_name=FIBARO System FGKF601 Keyfob, manufacturer_name=FIBARO System, product_name=FGKF601 Keyfob, query_stage=CacheLoad, is_awake=False, is_ready=False, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=True, capabilities={'zwave_plus', 'beaming', 'routing'}, sentCnt=1, sentFailed=1, retries=0, receivedCnt=1, receivedDups=0, receivedUnsolicited=1, sentTS=2018-08-30 11:47:04:321 , receivedTS=2018-08-30 11:47:55:761 , lastRequestRTT=0, averageRequestRTT=0, lastResponseRTT=0, averageResponseRTT=0, battery_level=37, wake_up_interval=0, friendly_name=FIBARO System FGKF601 Keyfob @ 2018-08-30T10:47:04.250003+00:00>>
2018-08-30 11:47:55 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140692596228280: Sending {'id': 2, 'type': 'event', 'event': {'event_type': 'state_changed', 'data': {'entity_id': 'zwave.fibaro_system_fgkf601_keyfob', 'old_state': <state zwave.fibaro_system_fgkf601_keyfob=initializing; node_id=4, node_name=FIBARO System FGKF601 Keyfob, manufacturer_name=FIBARO System, product_name=FGKF601 Keyfob, query_stage=CacheLoad, is_awake=False, is_ready=False, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=True, capabilities={'zwave_plus', 'beaming', 'routing'}, sentCnt=1, sentFailed=1, retries=0, receivedCnt=0, receivedDups=0, receivedUnsolicited=0, sentTS=2018-08-30 11:47:04:321 , receivedTS=2018-08-30 11:47:04:043 , lastRequestRTT=0, averageRequestRTT=0, lastResponseRTT=0, averageResponseRTT=0, battery_level=37, wake_up_interval=0, friendly_name=FIBARO System FGKF601 Keyfob @ 2018-08-30T10:47:04.250003+00:00>, 'new_state': <state zwave.fibaro_system_fgkf601_keyfob=initializing; node_id=4, node_name=FIBARO System FGKF601 Keyfob, manufacturer_name=FIBARO System, product_name=FGKF601 Keyfob, query_stage=CacheLoad, is_awake=False, is_ready=False, is_failed=False, is_info_received=True, max_baud_rate=40000, is_zwave_plus=True, capabilities={'zwave_plus', 'beaming', 'routing'}, sentCnt=1, sentFailed=1, retries=0, receivedCnt=1, receivedDups=0, receivedUnsolicited=1, sentTS=2018-08-30 11:47:04:321 , receivedTS=2018-08-30 11:47:55:761 , lastRequestRTT=0, averageRequestRTT=0, lastResponseRTT=0, averageResponseRTT=0, battery_level=37, wake_up_interval=0, friendly_name=FIBARO System FGKF601 Keyfob @ 2018-08-30T10:47:04.250003+00:00>}, 'origin': 'LOCAL', 'time_fired': datetime.datetime(2018, 8, 30, 10, 47, 55, 867554, tzinfo=<UTC>), 'context': {'id': 'c6c6af7eb4a84247a9d85cdbb6429f99', 'user_id': None}}}

and now when synthethising the event in the Events tool:

2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event zwave.scene_activated[R]: entity_id=zwave.fibaro_system_fgkf601_keyfob, scene_id=1, scene_data=7680>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.components.automation] Executing Office Light
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event logbook_entry[L]: name=Office Light, message=has been triggered, domain=automation, entity_id=automation.office_light>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.helpers.script] Script Office Light: Running script
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.helpers.script] Script Office Light: Executing step call service
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=switch, service=turn_on, service_data=entity_id=switch.reading_lamp>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=mqtt, service=publish, service_data=topic=smartthings/outlet (reading light)/switch, qos=0, retain=True, payload=on>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]>
2018-08-30 11:49:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=automation.office_light, old_state=<state automation.office_light=on; last_triggered=None, id=1535621037915, friendly_name=Office Light @ 2018-08-30T10:49:26.113554+00:00>, new_state=<state automation.office_light=on; last_triggered=2018-08-30T10:49:48.512825+00:00, id=1535621037915, friendly_name=Office Light @ 2018-08-30T10:49:26.113554+00:00>>
2018-08-30 11:49:48 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on smartthings/outlet (reading light)/switch: b'on'

I have run out of ideas as to what to look at next to investigate why the keyfob event doesnt trigger the automation. The only obvious difference is the suffix on the event in the logs [L] versus [R], but I have no idea if that is significant or really what it means.

Any ideas on how to fix this would be appreciated.
–philip

what are you using as a trigger? I would expect the automation trigger to look like this:

- alias: my event trigger
  trigger:
    - platform: event
      event_type: zwave.scene_activated
      event_data:
        entity_id: zwave.fibaro_system_fgkf601_keyfob
        scene_id: 1

Petro, your expectation is basically correct, I currently have the following automation:

- id: '1535621037915'
  alias: Office Light
  trigger:
  - event_data:
      entity_id: zwave.fibaro_system_fgkf601_keyfob
      scene_data: '7680'
      scene_id: '1'
    event_type: zwave.scene_activated
    platform: event
  condition: []
  action:
  - data:
      entity_id: switch.reading_lamp
    service: switch.turn_on

try removing the quotes around your numbers. The data being output in the logs show them as numbers not strings. Not sure if that will solve the problem. Also, is the scene_data necessary?

Removing the quotes in the automation has fixed it. I guess I was looking for something deeper or more complex and had just missed that difference in the logs.

Many thanks for your prompt response.

1 Like