tonesto7 / homebridge-hubitat-tonesto7

Hubitat Homebridge Plugin
107 stars 34 forks source link

(BUG) Device status not updating outside polling interval #176

Closed iTim314 closed 1 year ago

iTim314 commented 1 year ago

Verify the following before opening an trouble issue

Go over all the following points, and put an x in all the boxes that apply. If you're unsure about any of these, don't hesitate to ask. We're here to help!


About Your Setup

Expected Behavior

If a device's state is manually changed (such as a door lock manually opened or a switch manually activated) that status change should be communicated through the Hubitat and then to Homebridge within a reasonable time.

Current Behavior

The device status change is not reflected in Homebridge (and therefore Apple Home) until the next plugin polling interval (defaults to 3600 seconds).

Steps to Reproduce (for bugs)

Provide a link to a live example, or an unambiguous set of steps to reproduce this bug. Include code to reproduce, if relevant

  1. Setup plugin using the default / recommended settings with at least one Z-wave device whose state can be manually changed from the device (lock, switch, plug, etc.).
  2. Observe that Hubitat, Homebridge, and Apple Home reflect the correct device state.
  3. Change the device state manually (unlock, toggle switch, etc.)
  4. Observe that Hubitat recorded the device state change.
  5. Observe that Homebridge / Apple Home are NOT updating the device state.
  6. Wait for the next polling event, at which Homebridge / Apple Home will record the device state.

Context

**How has this issue affected you? What are you trying to accomplish? Since I first installed the plugin last week. I'm setting up Hubitat/Homebridge for the first time.

—- Please include a copy of any relevant log output to assist in tracking down the bug

iTim314 commented 1 year ago

Adding some more detail:

I uninstalled and reinstalled the plugin on both Homebridge and Hubitat, leaving all settings as default except for debug logging, then restarted both devices. I confirmed I could control the devices over HomeKit.

I then purged the logs, then toggled off and on a switch. Here's the complete Homebridge logs:

[2/14/2023, 3:41:07 PM] [Homebridge UI] Homebridge log truncated by USERNAME_REDACTED.

That's it. Here's the Hubitat logs showing the switch activity with nothing else from the plugin.

[dev:40](http://DOMAIN_REDACTED/logs#)2023-02-14 03:42:36.326 PM[trace](http://DOMAIN_REDACTED/logs#)SwitchBinaryReport: SwitchBinaryReport(value:255)
[dev:40](http://DOMAIN_REDACTED/logs#)2023-02-14 03:42:30.753 PM[trace](http://DOMAIN_REDACTED/logs#)SwitchBinaryReport: SwitchBinaryReport(value:0)

Like before, I can restart Homebridge and the status of every device syncs. This status sync occurs every hour by default, and I can get the status sync to happen nearly instantly by shortening the polling time to something ridiculous like 15 or 20 seconds.

I also confirmed that communication is happening from within the Hubitat plugin:

{ 
   "status": "OK", 
   "homebridge_version": 2.7, 
   "plugin": { 
      "name": "homebridge-hubitat-tonesto7", 
      "platform_name": "Hubitat-v2", 
      "platform_desc": "Hubitat", 
      "version": "2.7.1", "config": { 
         "app_url_local": "http://REDACTED_HUBITAT_IP/apps/api/", 
         "app_url_cloud": "https://cloud.hubitat.com/api/5091babf-2b3f-46f9-9aa0-fc9ed7904389/apps/", 
         "app_id": 24, 
         "access_token": "REDACTED", 
         "use_cloud": false, 
         "polling_seconds": 3600, 
         "round_levels": true, 
         "direct_port": 8000, 
         "direct_ip": "REDACTED_HOMEBRIDGE_IP", 
         "validateTokenId": false, 
         "consider_fan_by_name": true, 
         "consider_light_by_name": false, 
         "adaptive_lighting": true, 
         "adaptive_lighting_offset": 0 
      } 
   } 
}
iTim314 commented 1 year ago

This issue is resolved.

The problem turned out to be a firewall issue. I had it setup to only allow certain traffic between the VLAN where Homebridge ran and the IoT VLAN where Hubitat ran. Everything else was dropped.

Despite my allowing ports for Homebridge, mDNS/Bonjour, and web traffic to and from Homebridge and Hubitat, it apparently wasn't enough as this instant-update feature must be going through a port for which I could not account. Opening all traffic between the Homebridge and Hubitat resolved this issue.