Skip to content

HomeKit state change notifications delayed by minutes - connections cycling every 60 seconds #320

@jflammia

Description

@jflammia

Environment

  • Firmware Version: 2.1.1
  • Hardware: homekit-ratgdo (ESP8266-based)
  • GDO Security Type: Security+ 2.0
  • WiFi Signal: -52 dBm (excellent)
  • Free Heap: ~24,000 bytes
  • Crash Count: 0
  • Auto-Reboot: Configured every 24 hours
  • Last Door Change: 12/1/2025, 4:55:05 PM EST

Problem Description

When the garage door closes (and sometimes when it opens), HomeKit notifications are delayed by multiple minutes before the state change appears in the Home app
and triggers automations.

Key observation: Commands sent TO the device (open/close) execute immediately. Only state change notifications FROM the device are delayed.

Expected Behavior

When the door state changes, HomeKit should receive the update within seconds via a pushed event notification over a persistent HAP connection.

Actual Behavior

Looking at the device logs, I observe an abnormal pattern where the HomeKit hub connects, polls, and disconnects every ~60 seconds instead of maintaining a
persistent connection for event subscriptions:

 I (00:42:07.526) HomeKit: Got new client: remote 192.168.10.151:61429
 I (00:42:07.539) HomeKit: [Client] Pair Verify Step 1/2
 I (00:42:08.198) HomeKit: [Client] Pair Verify Step 2/2
 I (00:42:08.233) HomeKit: Verification successful, secure session established
 I (00:42:08.258) HomeKit: [Client] Get Accessories          ← Polls state
 E (00:43:08.299) HomeKit: [Client] The socket is null! (or is closed)
 E (00:43:08.303) HomeKit: [Client] The socket is null! (or is closed)
 I (00:43:08.360) HomeKit: [Client] Disconnected!            ← Connection dropped
 I (00:43:07.648) HomeKit: Got new client: remote 192.168.10.151:61432  ← Cycle repeats

This pattern repeats indefinitely with new connections every 60 seconds. The logs show:

  • ✅ Pair verification succeeds
  • ✅ "Get Accessories" is called (polling)
  • ❌ No characteristic subscriptions visible
  • ❌ Connection drops with "socket is null" errors
  • ❌ No event push notifications in logs

When a door state change occurs between these polling cycles, the notification is delayed until the hub eventually discovers the new state.

Full Log Sample

I (00:42:07.526) HomeKit: Got new client 1073701556: local 192.168.10.104:5556, remote 192.168.10.151:61429
I (00:42:07.529) HomeKit: Setting Timeout to 500ms
I (00:42:07.532) ratgdo-homekit: Client connected... paired
I (00:42:07.539) HomeKit: [Client 1073701556] Pair Verify Step 1/2
I (00:42:08.173) HomeKit: Free heap: 22648
E (00:42:08.178) HomeKit: [Client 1073695444] The socket is null! (or is closed)
E (00:42:08.183) HomeKit: [Client 1073695444] The socket is null! (or is closed)
E (00:42:08.187) HomeKit: [Client 1073695444] The socket is null! (or is closed)
I (00:42:08.194) HomeKit: [Client 1073701556] Pair Verify Step 2/2
I (00:42:08.198) HomeKit: [Client 1073701556] Found pairing with F5216FCA-9524-4176-942F-992FF98122FA
I (00:42:08.231) ratgdo-homekit: Client verified
I (00:42:08.233) HomeKit: [Client 1073701556] Verification successful, secure session established
I (00:42:08.235) HomeKit: Free heap: 22936
I (00:42:08.239) HomeKit: [Client 1073695444] Disconnected!
I (00:42:08.244) HomeKit: [Client 1073695444] Closing client connection
I (00:42:08.252) ratgdo-homekit: Client disconnected
I (00:42:08.258) HomeKit: [Client 1073701556] Get Accessories
I (00:42:45.201) ratgdo-packet: PACKET(0x54600A @ 0x3DD8A) Status - Status: [DoorState Closed]
I (00:43:07.648) HomeKit: Got new client 1073699748: local 192.168.10.104:5556, remote 192.168.10.151:61432
I (00:43:07.651) HomeKit: Setting Timeout to 500ms
I (00:43:07.654) ratgdo-homekit: Client connected... paired
I (00:43:07.660) HomeKit: [Client 1073699748] Pair Verify Step 1/2
I (00:43:08.293) HomeKit: Free heap: 22664
E (00:43:08.299) HomeKit: [Client 1073701556] The socket is null! (or is closed)
E (00:43:08.303) HomeKit: [Client 1073701556] The socket is null! (or is closed)
E (00:43:08.306) HomeKit: [Client 1073701556] The socket is null! (or is closed)
I (00:43:08.315) HomeKit: [Client 1073699748] Pair Verify Step 2/2
I (00:43:08.319) HomeKit: [Client 1073699748] Found pairing with F5216FCA-9524-4176-942F-992FF98122FA
I (00:43:08.350) ratgdo-homekit: Client verified
I (00:43:08.352) HomeKit: [Client 1073699748] Verification successful, secure session established
I (00:43:08.354) HomeKit: Free heap: 22952
I (00:43:08.360) HomeKit: [Client 1073701556] Disconnected!
I (00:43:08.362) HomeKit: [Client 1073701556] Closing client connection
I (00:43:08.370) ratgdo-homekit: Client disconnected
I (00:43:08.378) HomeKit: [Client 1073699748] Get Accessories

Possibly Related

This symptom pattern is similar to #187 (closed status delayed by minutes), which was fixed in v1.4.3. However, I'm experiencing this on v2.1.1.

What I've Ruled Out

  • ❌ Network issues - WiFi signal is excellent (-52 dBm), ping latency is ~11ms
  • ❌ HomeKit hub problems - Other HomeKit devices work correctly with instant notifications
  • ❌ Uptime/memory issues - Problem occurs immediately after fresh reboot; auto-reboot configured every 24 hours
  • ❌ Command responsiveness - Open/close commands execute immediately

Questions

  1. Is the 60-second connection cycling with "socket is null" errors expected behavior?
  2. Should I see characteristic subscription messages in the logs after "Get Accessories"?
  3. Is there a configuration that affects HomeKit connection persistence?

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions