Slow recovery (~3.5h) after controller-initiated TCP reset; outage only logged at DEBUG

[aramshaw]

Summary

Overnight ~8.8h DEBUG soak (HA integration v0.3.1). Healthy for the first ~4h40m, then:

• 04:17:04 [airtouch2.common.NetClient] ConnectionResetError - the controller reset the TCP socket (peer-initiated).
• The client then looped Connecting to 192.168.4.45 on port 9200 ~92 times over 3h32m with no successful session and no data exchanged.
• Recovered cleanly at 07:49:10 - full re-handshake (GroupStatus/AcStatus/RequestFavouriteStatus) and favourites re-read.

Net: HA entities would have been unavailable for ~3.5h overnight.

Observations

• Each reconnect attempt took ~65-135s, not the ~10s backoff cap - consistent with open_connection blocking on the OS TCP connect timeout (no SYN-ACK), i.e. the controller was not responding to connection attempts during the gap (not a fast ECONNREFUSED).
• The reconnect logic is otherwise correct: it retried indefinitely and re-synced fully on recovery.
• The disconnect + prolonged outage are logged only at DEBUG - in normal operation there'd be no visible signal that the device was unavailable for hours.

Hypotheses (to confirm)

• Controller-side: the AirTouch may stop accepting new connections while idle / overnight, or holds a single client slot and didn't release the stale session until it aged out (or until the system became active in the morning).
• Possibly intermittent / environmental (network, controller firmware). Needs more soak nights to see if it recurs.

Suggested investigation / fixes

• Add an explicit short connect timeout (asyncio.wait_for(open_connection(...), ~5s)) so attempts are frequent and predictable instead of blocking on the OS timeout - more chances to grab the slot the moment it frees.
• Ensure the old reader/writer is fully closed before reconnecting (avoid leaving half-open sessions occupying the controller slot).
• Surface the disconnect / prolonged-reconnect at WARNING and confirm HA marks entities unavailable during the gap.
• Diagnostic: next time it happens, check whether the controller is pingable / reachable on 9200 from another client during the gap (controller-side vs client-side).

Note

This is a different failure mode from the ACK-lockout dropouts already fixed (those are solved - proven over multi-hour soaks). This is connection recovery after a controller-initiated reset. Worth getting right before upstreaming.

[aramshaw]

Correction from the re-filtered (INFO+WARNING) log: the outage was NOT debug-only. v0.3.1 already logged it at WARNING - Connection lost, reconnecting at 04:17, then ~92 Could not connect to host 192.168.4.45 WARNINGs across the 3.5h gap. The "DEBUG-only" impression was an artifact of the earlier debug-only export. So a default-level HA user WOULD have seen this outage.

Remaining refinement: ~92 identical per-attempt WARNINGs for a single outage is noisy - prefer log-once-on-drop + a periodic summary over per-attempt. (v0.3.2 added the 10s connect timeout + entities-unavailable; the extra WARNING line was largely redundant given the pre-existing per-attempt warnings.)