Here we go again SmartThings Delay

So once again I’m experiencing delays in a really simple routine.

Contact Sensor “Upstairs basement door” “efb0b54d-2253-47fc-8ea1-9db7e7160632” opens and triggers “Basement Stairway Lights” “e9bf2fde-393e-4f70-9a8f-635466228b13” to turn ON. Most of the time this is nearly instant. Over the last few days I’ve been having delays in this quite simple process of up to several minutes. Below are some CLI logs from a short delay. The time it took to turn on the light from the time the door opened, using a stop watch. (4.7 seconds). Is there anything in this log that jumps out as something to look at?

I also have a motion sensor that will turn these lights on if coming from the other side of the basement. Seems to be a similar delay there as well. (not in this log)

@Andreas_Roedl

2025-01-01T19:18:45.144984828Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> received Z-Wave command: {args={value=3}, cmd_class="BASIC", cmd_id="REPORT", dst_channels={}, encap="CRC16", payload="\x03", src_channel=0, version=1}
2025-01-01T19:18:45.347681471Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.360183175Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:18:45.417690116Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.445070544Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> emitting event: {"attribute_id":"level","capability_id":"switchLevel","component_id":"main","state":{"value":3}}
2025-01-01T19:18:45.452427822Z DEBUG Zigbee Contact  driver device thread event handled
2025-01-01T19:18:45.522389490Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.523481735Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.524526129Z WARN Z-Wave Switch  Attempted to generate event for e049fe95-649f-42a5-9a20-ed0e1eea6495.main but it does not support capability Contact Sensor
2025-01-01T19:18:45.526614626Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.527742854Z WARN Z-Wave Switch  Attempted to generate event for e049fe95-649f-42a5-9a20-ed0e1eea6495.main but it does not support capability Motion Sensor
2025-01-01T19:18:45.536239395Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:45.540655019Z WARN Z-Wave Switch  Attempted to generate event for e049fe95-649f-42a5-9a20-ed0e1eea6495.main but it does not support capability Water Sensor
2025-01-01T19:18:45.548796488Z DEBUG Z-Wave Switch  Master Bath Lights device thread event handled
2025-01-01T19:18:46.850692756Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:18:46.856383701Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> received Z-Wave command: {args={value=68}, cmd_class="SWITCH_MULTILEVEL", cmd_id="REPORT", dst_channels={}, encap="CRC16", payload="D", src_channel=0, version=1}
2025-01-01T19:18:46.908547856Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:46.909652428Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:18:46.924269116Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:46.925236049Z INFO Z-Wave Switch  <ZwaveDevice: e049fe95-649f-42a5-9a20-ed0e1eea6495 [C7] (Master Bath Lights)> emitting event: {"attribute_id":"level","capability_id":"switchLevel","component_id":"main","state":{"value":68}}
2025-01-01T19:18:46.945576832Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:46.946523650Z DEBUG Z-Wave Switch  Master Bath Lights device thread event handled
2025-01-01T19:18:48.871266006Z INFO Z-Wave Switch  hub handled command: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7:main:switch:off []
2025-01-01T19:18:48.873074018Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [00], src_channel: 0x0>
2025-01-01T19:18:48.890889648Z TRACE Z-Wave Switch  Z-Wave command(f4bfdaf1) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-01T19:18:49.214811981Z TRACE Z-Wave Switch  Z-Wave command(f4bfdaf1) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:18:49.573086379Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:18:49.619921908Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00", src_channel=0, version=1}
2025-01-01T19:18:50.004815031Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-01T19:18:50.103008702Z TRACE Z-Wave Switch  Z-Wave command(be9110d5) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-01T19:18:50.133120680Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:50.134291261Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-01T19:18:50.253207065Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:50.269959601Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-01T19:18:50.313499654Z TRACE Z-Wave Switch  Z-Wave command(be9110d5) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:18:50.375437128Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:18:50.390273164Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={current_value="OFF_DISABLE", duration=0, target_value="OFF_DISABLE", value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00", src_channel=0, version=2}
2025-01-01T19:18:50.452899211Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:50.460135966Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-01T19:18:50.485735284Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:18:50.486685226Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-01T19:18:53.757011120Z DEBUG Zigbee Switch  driver device thread event handled
2025-01-01T19:19:01.666827610Z INFO Z-Wave Switch  hub handled command: e9bf2fde-393e-4f70-9a8f-635466228b13:main:switch:off []
2025-01-01T19:19:01.668480200Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [00], src_channel: 0x0>
2025-01-01T19:19:01.693390280Z TRACE Z-Wave Switch  Z-Wave command(76c97f4b) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-01T19:19:01.875944124Z TRACE Z-Wave Switch  Z-Wave command(76c97f4b) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:01.910736344Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:01.913743132Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00", src_channel=0, version=1}
2025-01-01T19:19:01.952647586Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:01.956958763Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-01T19:19:01.980881754Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:01.981807749Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-01T19:19:02.700316399Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-01T19:19:02.725704406Z TRACE Z-Wave Switch  Z-Wave command(219b87ad) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-01T19:19:02.875822227Z TRACE Z-Wave Switch  Z-Wave command(219b87ad) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:02.910939076Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:02.914527448Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={current_value="OFF_DISABLE", duration=0, target_value="OFF_DISABLE", value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00", src_channel=0, version=2}
2025-01-01T19:19:02.950524773Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:02.958061212Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-01T19:19:02.976364097Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:02.977325616Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-01T19:19:09.807463881Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-01T19:19:09.957505323Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={alarm_level=0, alarm_type=0, event="WINDOW_DOOR_IS_OPEN", event_parameter="", notification_status="ON", notification_type="ACCESS_CONTROL", v1_alarm_level=0, v1_alarm_type=0, z_wave_alarm_event=22, z_wave_alarm_status="ON", z_wave_alarm_type="ACCESS_CONTROL", zensor_net_source_node_id=0}, cmd_class="NOTIFICATION", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00\xFF\x06\x16\x00", src_channel=0, version=3}
2025-01-01T19:19:10.265836539Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.271065298Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.277144215Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"open"}}
2025-01-01T19:19:10.351528630Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.352603842Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.353540332Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.354427055Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.390179919Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.403699948Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.409844207Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-01T19:19:10.414164671Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-01T19:19:10.435883931Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={sensor_type="DOOR_WINDOW", sensor_value="DETECTED_AN_EVENT"}, cmd_class="SENSOR_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\x0A", src_channel=0, version=2}
2025-01-01T19:19:10.546148812Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.550211447Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.587348286Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"open"}}
2025-01-01T19:19:10.617800927Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.618891506Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.623266734Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.624253782Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:10.625158788Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-01T19:19:12.299514066Z INFO Z-Wave Switch  hub handled command: e9bf2fde-393e-4f70-9a8f-635466228b13:main:switch:on []
2025-01-01T19:19:12.301168572Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [ff], src_channel: 0x0>
2025-01-01T19:19:12.325085691Z TRACE Z-Wave Switch  Z-Wave command(e2b420da) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-01T19:19:12.555977146Z TRACE Z-Wave Switch  Z-Wave command(e2b420da) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:12.600772945Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:12.601725177Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF", src_channel=0, version=1}
2025-01-01T19:19:12.633827451Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:12.637820829Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:19:12.662229451Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:12.663197800Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-01T19:19:13.329625587Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-01T19:19:13.355362004Z TRACE Z-Wave Switch  Z-Wave command(6f0389d9) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-01T19:19:13.438773444Z INFO Z-Wave Switch  hub handled command: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7:main:switch:on []
2025-01-01T19:19:13.440350197Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [ff], src_channel: 0x0>
2025-01-01T19:19:13.461323621Z TRACE Z-Wave Switch  Z-Wave command(ab22b044) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-01T19:19:13.566101123Z TRACE Z-Wave Switch  Z-Wave command(6f0389d9) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:13.608370186Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:13.619704599Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={current_value="ON_ENABLE", duration=0, target_value="ON_ENABLE", value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\xFF\x00", src_channel=0, version=2}
2025-01-01T19:19:13.652211671Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:13.656721332Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:19:13.673890785Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:13.674844766Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-01T19:19:13.836382540Z TRACE Z-Wave Switch  Z-Wave command(ab22b044) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:13.940972135Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:13.949911330Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF", src_channel=0, version=1}
2025-01-01T19:19:14.002105095Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:14.006064823Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:19:14.042907642Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:14.043873742Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-01T19:19:14.469922986Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-01T19:19:14.671092351Z TRACE Z-Wave Switch  Z-Wave command(c87b1c46) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-01T19:19:15.118800510Z TRACE Z-Wave Switch  Z-Wave command(c87b1c46) transmit status: TRANSMIT_COMPLETE_OK
2025-01-01T19:19:15.299122929Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-01T19:19:15.342330189Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={current_value="ON_ENABLE", duration=0, target_value="ON_ENABLE", value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\xFF\x00", src_channel=0, version=2}
2025-01-01T19:19:15.450542556Z DEBUG Zigbee Contact  driver device thread event handled
2025-01-01T19:19:15.621225089Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:15.623291638Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-01T19:19:15.624119849Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-01T19:19:15.667390828Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-01T19:19:15.679160357Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-01T19:19:15.795747076Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={alarm_level=0, alarm_type=0, event="WINDOW_DOOR_IS_CLOSED", event_parameter="", notification_status="ON", notification_type="ACCESS_CONTROL", v1_alarm_level=0, v1_alarm_type=0, z_wave_alarm_event=23, z_wave_alarm_status="ON", z_wave_alarm_type="ACCESS_CONTROL", zensor_net_source_node_id=0}, cmd_class="NOTIFICATION", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00\xFF\x06\x17\x00", src_channel=0, version=3}
2025-01-01T19:19:15.865608669Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.870882406Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.911461315Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"closed"}}
2025-01-01T19:19:15.941050513Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.942111982Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.943054302Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.943923409Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.960201016Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.961286057Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:15.963520980Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-01T19:19:15.964457220Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-01T19:19:15.980269019Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={sensor_type="DOOR_WINDOW", sensor_value="IDLE"}, cmd_class="SENSOR_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x0A", src_channel=0, version=2}
2025-01-01T19:19:15.999078359Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.000238446Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.001900781Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"closed"}}
2025-01-01T19:19:16.013452877Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.016190799Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.018864003Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.030319273Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-01T19:19:16.031248808Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled```

I can run the SmartThings CLI on my tablet. So what I would do is to keep the logcat running and open/close the door and see if there’s a delay.

Maybe the sensor itself is going to sleep and needs to wake up before it sends the message.

Do you have any other devices to trigger the routine, like maybe a button? You could also try a different bulb with a different transport protocol, like Zigbee or Thread in case your bulb is acting up.

And maybe it’s just the distance between the sensor and the hub. For testing purposes, remove the sensor from the app and the door, bring it closer to the hub and see if the latency goes down.

Z-Wave isn’t exactly known for its low latency…

And regarding the log: there seems to be a 2 seconds delay between the sensor and the switch. I have no experience with the Z-Wave sensor driver, but there are a lot of “Found ZwaveDispatcher handler in zwave_switch” lines…

That’s what the logs are above. I started the CLI and then opened the door. Using a stopwatch, it took 4.7 seconds to turn on the light. I should have been more clear, it’s not a bulb, it’s a Wall switch. “Basement Stairway Lights” “e9bf2fde-393e-4f70-9a8f-635466228b13” is a UltraPro Smart Switch. It can be controlled by the motion sensor I described above. There are delays using both ways of triggering the switch. The logs I provided was of the 4.7 second delay.

The sensor and the switch are 10 feet from the hub. Literally line of site.

It’s strange because sometimes it triggers nearly instantly and I have had times where I can open the door and sit and wait for several minutes for the light to come on. This was an issue a couple years ago and I granted SmartThings Support access and then after going back and forth a few times, they just gave up. It worked itself out after a few months. Now it’s back….

I’d just replace the Z-Wave contact sensor with a Zigbee sensor and call it a day.

I thought about that but that doesn’t/won’t solve the same delay with the ZOOZ ZSE18 motion sensor that has the same delay. I was hoping something definitive would jump out of the logs maybe indicating the UltraPro Switch was wonky. I think both sensors being bad would be unlikely.

What’s your ST hub?

Hub is a V3

1 Like

Pressing a button on the ST app turns them on instantly. So there has to be something going on with the devices or hub…

This was an issue a couple years ago and I granted SmartThings Support access and then after going back and forth a few times, they just gave up. It worked itself out after a few months. Now it’s back….

Replace the sensor with a Zigbee device and see what happens.

At 19:19:01.6 light is turned “Off”

In the logs you cannot see the time elapsed between when the sensor is physically opened and when the “open” command arrives at the driver.

The Sensor sends 2 commands in a row, separated by 0.6 sec, 19:19:09.98 and 19:19:10.6 and two “open” events are emitted immediately in both cases.

This causes the routine to be executed 2 times and one “On” command is received from routine at 19:19:12.3 and another at 19:19:13.3.

The “On” command is sent immediately by the Hub to switch, without going through the driver, two times.

The bulb answers 2 times reporting the “On” status at 19:19:12.6 and at 19:19:13.6 and 2 “On” events are emitted from the driver to platform.

Conclusion:
From the moment the “Open” command is received until the light bulb is turned on with the routine for the first time, 2.6 sec pass, according to the log.

Questions:
How long does it take for the “Open” command to reach the hub and driver from sensor?

Why does sensor send 2 Open commands, with different SensorBinary and Notification commands?

Hi Mariano. I don’t know how I would figure that out.

I’m not sure how to read those logs, that’s why I posted them. Using a stop watch, I open the door. It took 4.7 seconds for the UltraPro switch to turn on the light.

I just did it again (didn’t have CLI running). The door opened and the light did not come on for 18 minutes. I just sat there and waited for it.

I did not know it was doing that. Taking @Andreas_Roedl suggestion, I ordered a couple Zigbee contact sensors tonight. Maybe the sensor is goofy.

After thinking about this. I disabled the routine that turns on the switch to see if possibly there was another routine doing the same thing.

I have only 1 routine… [contact sensor opens] >>[UltraPro Switch] turns ON. I disabled the routine and the switch did not come on. I guess that rules out a routine that I didn’t remember running in parallel.

Start the logging with the SmartThings CLI command and select the Z-Wave sensor driver, then hit enter a few times to clear the screen a bit. Immediately after, open the contact sensor. You have to keep an eye on the log the whole time and count the seconds between opening the door and the first line in the log.

Just do that a couple of times: hit enter, open door, see if something shows up in the log.


Side note: the Z-Wave sensor driver is… I don’t know…

You’ve encountered this issue in early September 2023?

It is a Wink DW1 contact sensor 017F-0100-0001 using the SmartThings stock driver (Z-WAVE SENSOR)

Yep!

I use this: smartthings edge:drivers:logcat

Then ENTER to select ALL drivers. Is there a cmd to select only Z-WAVE SENSOR?

It asks you to enter the number of the driver or press enter for all:

So look up the number in the first column and enter that.

I figured it out. It was 16 in my list.

2025-01-02T00:42:49.953146801Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={alarm_level=0, alarm_type=0, event="WINDOW_DOOR_IS_OPEN", event_parameter="", notification_status="ON", notification_type="ACCESS_CONTROL", v1_alarm_level=0, v1_alarm_type=0, z_wave_alarm_event=22, z_wave_alarm_status="ON", z_wave_alarm_type="ACCESS_CONTROL", zensor_net_source_node_id=0}, cmd_class="NOTIFICATION", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00\xFF\x06\x16\x00", src_channel=0, version=3}
2025-01-02T00:42:50.538703134Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.545618884Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.605669384Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"open"}}
2025-01-02T00:42:50.677036259Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.690350176Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.699453926Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.703017218Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.712517009Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.716056926Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.723704801Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-02T00:42:50.739115551Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-02T00:42:50.761225009Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={sensor_type="DOOR_WINDOW", sensor_value="DETECTED_AN_EVENT"}, cmd_class="SENSOR_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\x0A", src_channel=0, version=2}
2025-01-02T00:42:50.814774093Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.817793718Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.831536134Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"open"}}
2025-01-02T00:42:50.863063676Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.865808259Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.868509259Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.873621468Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:50.874588134Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-02T00:42:51.197370593Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-02T00:42:51.205834134Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={alarm_level=0, alarm_type=0, event="WINDOW_DOOR_IS_CLOSED", event_parameter="", notification_status="ON", notification_type="ACCESS_CONTROL", v1_alarm_level=0, v1_alarm_type=0, z_wave_alarm_event=23, z_wave_alarm_status="ON", z_wave_alarm_type="ACCESS_CONTROL", zensor_net_source_node_id=0}, cmd_class="NOTIFICATION", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00\xFF\x06\x17\x00", src_channel=0, version=3}
2025-01-02T00:42:51.222574843Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.225903593Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.230223259Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"closed"}}
2025-01-02T00:42:51.261103968Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.262213343Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.263281759Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.264318134Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.265363593Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.266315176Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.267240468Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled
2025-01-02T00:42:51.281298384Z TRACE Z-Wave Sensor  Received event with handler unnamed
2025-01-02T00:42:51.282341926Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> received Z-Wave command: {args={sensor_type="DOOR_WINDOW", sensor_value="IDLE"}, cmd_class="SENSOR_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x0A", src_channel=0, version=2}
2025-01-02T00:42:51.299354426Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.302103343Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.306158384Z INFO Z-Wave Sensor  <ZwaveDevice: efb0b54d-2253-47fc-8ea1-9db7e7160632 [76] (Upstairs basement door)> emitting event: {"attribute_id":"contact","capability_id":"contactSensor","component_id":"main","state":{"value":"closed"}}
2025-01-02T00:42:51.325441176Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.326809593Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.327862009Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.328805968Z TRACE Z-Wave Sensor  Found ZwaveDispatcher handler in zwave_sensor
2025-01-02T00:42:51.330046926Z DEBUG Z-Wave Sensor  Upstairs basement door device thread event handled```

Watching the logs, when the door opens, it is instant!

As @Mariano_Colmenarejo said: device sends two messages and that’s okay in my opinion, because they are for different purposes.

The driver emits two open events and that’s not okay in my opinion… But that’s Z-Wave and I don’t even want to know if this is normal behavior.

And all these Found ZwaveDispatcher handler in zwave_sensor lines are a bit too much for only two messages.

…and this is the Switch Driver. Watching the logs, it took 6 seconds for this to start generating from the time the door opened. I’m not sure if there is anything useful in them…

2025-01-02T00:55:37.534230934Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [ff], src_channel: 0x0>
2025-01-02T00:55:37.639947434Z TRACE Z-Wave Switch  Z-Wave command(069152b0) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-02T00:55:37.869400059Z TRACE Z-Wave Switch  Z-Wave command(069152b0) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:55:37.931033642Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:55:37.932342642Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF", src_channel=0, version=1}
2025-01-02T00:55:37.966497934Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:37.970412059Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-02T00:55:37.992484434Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:37.993422309Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-02T00:55:38.644024350Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-02T00:55:38.669637225Z TRACE Z-Wave Switch  Z-Wave command(858901ad) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-02T00:55:38.856073892Z TRACE Z-Wave Switch  Z-Wave command(858901ad) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:55:38.890721142Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:55:38.892729184Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={current_value="ON_ENABLE", duration=0, target_value="ON_ENABLE", value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\xFF\x00", src_channel=0, version=2}
2025-01-02T00:55:38.927405059Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:38.932257350Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-02T00:55:38.950508642Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:38.952149559Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-02T00:55:39.372855142Z INFO Z-Wave Switch  hub handled command: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7:main:switch:on []
2025-01-02T00:55:39.373982475Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [ff], src_channel: 0x0>
2025-01-02T00:55:39.395884184Z TRACE Z-Wave Switch  Z-Wave command(c1e87efa) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-02T00:55:39.537623684Z TRACE Z-Wave Switch  Z-Wave command(c1e87efa) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:55:39.568059267Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:55:39.571697225Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF", src_channel=0, version=1}
2025-01-02T00:55:39.605653392Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:39.609563267Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-02T00:55:39.630995476Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:39.631939476Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-02T00:55:40.407946309Z INFO Z-Wave Switch  hub sending: Z-Wave command (439d7cfa-1159-45f3-a3b9-87b40dbf3ae7): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-02T00:55:40.427283726Z TRACE Z-Wave Switch  Z-Wave command(1646359f) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-02T00:55:40.638583392Z TRACE Z-Wave Switch  Z-Wave command(1646359f) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:55:40.731086809Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:55:40.740252517Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> received Z-Wave command: {args={current_value="ON_ENABLE", duration=0, target_value="ON_ENABLE", value="ON_ENABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\xFF\xFF\x00", src_channel=0, version=2}
2025-01-02T00:55:40.830309101Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:40.835163226Z INFO Z-Wave Switch  <ZwaveDevice: 439d7cfa-1159-45f3-a3b9-87b40dbf3ae7 [7E] (Basement Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"on"}}
2025-01-02T00:55:40.859873726Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:55:40.862783767Z DEBUG Z-Wave Switch  Basement Lights device thread event handled
2025-01-02T00:57:40.169051204Z INFO Z-Wave Switch  hub handled command: e9bf2fde-393e-4f70-9a8f-635466228b13:main:switch:off []
2025-01-02T00:57:40.170779162Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x1, dst_channels: [], encap: 0x0, payload: [00], src_channel: 0x0>
2025-01-02T00:57:40.195654912Z TRACE Z-Wave Switch  Z-Wave command(e36aa8bb) queued for radio transmission: CC:Switch Binary, CID:0x01
2025-01-02T00:57:40.414889162Z TRACE Z-Wave Switch  Z-Wave command(e36aa8bb) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:57:40.468848287Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:57:40.480276246Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00", src_channel=0, version=1}
2025-01-02T00:57:40.522367871Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:57:40.526448871Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-02T00:57:40.567830954Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:57:40.568804829Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled
2025-01-02T00:57:41.202913288Z INFO Z-Wave Switch  hub sending: Z-Wave command (e9bf2fde-393e-4f70-9a8f-635466228b13): <cmd_class: 0x25, cmd_code: 0x2, dst_channels: [], encap: 0x0, payload: [], src_channel: 0x0>
2025-01-02T00:57:41.228493413Z TRACE Z-Wave Switch  Z-Wave command(8ffb23cd) queued for radio transmission: CC:Switch Binary, CID:0x02
2025-01-02T00:57:41.414972329Z TRACE Z-Wave Switch  Z-Wave command(8ffb23cd) transmit status: TRANSMIT_COMPLETE_OK
2025-01-02T00:57:41.450820329Z TRACE Z-Wave Switch  Received event with handler unnamed
2025-01-02T00:57:41.451815829Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> received Z-Wave command: {args={current_value="OFF_DISABLE", duration=0, target_value="OFF_DISABLE", value="OFF_DISABLE"}, cmd_class="SWITCH_BINARY", cmd_id="REPORT", dst_channels={}, encap="NONE", payload="\x00\x00\x00", src_channel=0, version=2}
2025-01-02T00:57:41.504479913Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:57:41.509070121Z INFO Z-Wave Switch  <ZwaveDevice: e9bf2fde-393e-4f70-9a8f-635466228b13 [AB] (Basement Stairway Lights)> emitting event: {"attribute_id":"switch","capability_id":"switch","component_id":"main","state":{"value":"off"}}
2025-01-02T00:57:41.524345871Z TRACE Z-Wave Switch  Found ZwaveDispatcher handler in zwave_switch
2025-01-02T00:57:41.525292871Z DEBUG Z-Wave Switch  Basement Stairway Lights device thread event handled```