fix(connection): stop reconnect storms, unbounded poll cycles and event-loop stalls

[greggo74]

What this is

My IP150/paradoxmyhome setup was dropping its panel connection several times a
day. Rather than patch around it locally I worked through the connection and
polling paths and ended up with 13 findings, most of which reproduce without any
hardware. This PR fixes them and adds regression tests for each.

Happy to split this into smaller PRs if that is easier to review — say the word
and I will break it up by tier.

Tier 1 — most likely to cause the drops

1. IO_TIMEOUT from pai.conf was silently ignored. cfg.IO_TIMEOUT was
   captured into default arguments at import time, so the configured value never
   reached any request path. Anyone who raised it to work around timeouts has
   been running the default all along.
2. The poll cycle had no upper bound and degraded into a poll storm once
   replies started arriving late. Now bounded by Panel.status_cycle_budget; a
   cycle that exceeds it is cancelled and counted as a missing reply, so it
   surfaces as "Replies missing" and a reconnect instead of silence.
3. Reconnect backoff used 2 ^ retry — bitwise XOR, not exponentiation.
   The real sequence was 3, 0, 1, 6, 7… so the second retry fired immediately.
   Now 2, 4, 8, 16, 30, 30 s.
4. Failed IP connection attempts leaked the previous socket, holding open the
   IP150's single session slot so the retry could not get in.

Tier 2 — STUN / paradoxmyhome path

5. refresh_session_if_required() did blocking socket I/O on the event loop.
6. time.sleep(5) inside an async function, plus an unbounded HTTP call.
7. STUN response parsing assumed one recv() returns a whole message.
8. A failed STUN refresh did not mark the connection dead.

Tier 3 — smaller, still real

9. busy.release() could be called without holding the lock.
10. asyncio.gather abandoned sibling requests on first failure.
11. A failed close left the connection half-torn-down.
12. A status parse failure crashed the merge instead of counting as a missing reply.
13. disconnect() could construct a connection object during shutdown.

Behaviour changes worth knowing about

• Reconnect backoff is slower for a brief blip, far more reliable for a real
  outage, because PAI stops hammering the module.
• IP connect attempts are now 5 s apart (CONNECT_RETRY_DELAY), so a failing
  connect() takes ~10 s longer before handing back to the main retry loop.
• Raising IO_TIMEOUT now actually takes effect — existing configs should
  re-check their value.
• A failed IP attempt now closes its STUN session, so the next attempt re-fetches
  SWAN site info instead of reusing a possibly stale xoraddr. Costs one extra
  HTTPS round trip per retry.
• PRT3 overrides the cycle budget, because its single virtual address expands
  into one request per area and zone.

Testing

21 new regression tests across tests/connection/, tests/lib/,
tests/paradox/ and tests/test_main_uptime.py. Full suite for the touched
areas: 319 passed. Each finding has a test that fails before its fix.

Note on CONNECTION_STABILITY_REVIEW.md

The first commit adds the full write-up as a document in the repo root, with the
reasoning and file/line references behind each finding. I have kept it because it
makes the second commit reviewable, but I am happy to drop that commit if you
would rather it lived only in this PR description.

[yozik04]

Did you try dev branch?

[greggo74]

Next on my list of todo. I'll do it today and let you know.
Tapped the PR option instead of branching option when Claude asked me.

[yozik04]

I think I fixed a lot in dev. Your feedback would be useful if I can promote these changes to master.

[greggo74]

Hi. Finally got around to testing. Claude told me the binary on my docker was about 18min old, so I'm not surprised you'd fixed some stuff.
I'd still had used with regular disconnects, trouble at startup, but after installing this PR branched from dev, with a pai.conf change to a timeout item (set to 2sec instead of default 0.5 sec) it becomes rock solid. I then also switched from the cloud service to a direct IP connection to my system and even with the near instantaneous responsive time to events, it still stayed rock solid - no warnings, no errors, no dropouts. 6hrs with no status changes so far.

[yozik04]

But I understood that problem existed only on serial connection. Local IP connection was always stable.

[greggo74]

I was definitely having many disconnections and timeouts every day using the cloud (sites id) connection.
I've done 3 things so far: had Claude identify and correct some connection related issues in PAI, changed my responses timeout from 0.5src to 2dec - both of which resolved the stability issues. The last thing I did was switch to local IP instead of cloud and that simply improved responsiveness and event reception speed.

At some stage today I'll revert my PAI to dev without my changes and re-test and let you know.

[greggo74]

Here's the analysis based on my question:

Q: Does the reference dev bench of PAI have the same adaptable timeout that we changed from default (0.5s) to 2.0 sec? We’re trying to work out if your changes to PAI have made any tangible improvements to connectivity stability issues I had.

TLDR A: the changes improve cloud-based timeouts/errors, but less likely for direct IP connections.

A: Only partly. I tested it directly: I ran upstream dev (without your changes) and your branch, each loading a config with IO_TIMEOUT = 2 the way pai-service starts up, and read back the timeouts each part of the code actually uses.

What's being waited for Upstream dev (reference) Your branch (deployed)
IP150 login and IP-level messages 2 s: honours the setting 2 s
Panel status polls and replies (three separate waits) stuck at 0.5 s, whatever pai.conf says 2 s

Upstream reads the setting for the IP150 part only by accident: that module happens to be loaded after the config. The waits for panel replies are fixed at 0.5 s when PAI starts, before your pai.conf is read. Your fix makes all of them read the setting at the time they wait.

What that means for the problems you had:

•	Dropped IP150 login after every restart: upstream with IO_TIMEOUT = 2 would probably have fixed this too.
•	The late-reply flood over the cloud relay: that's the "No handler for message 5" warning about every 25 seconds, and the polls behind it that timed out. Upstream would not have fixed this, because the panel polls stay at 0.5 s. That part of the improvement genuinely needed your change.

The honest caveat: yesterday I changed three things within two hours:

1.	the December 2023 build → current dev plus your changes,
2.	the 0.5 s → 2 s timeout,
3.	the cloud relay → a direct LAN connection.

Since the LAN switch 16¾ hours ago there have been no connection losses, no errors and no restarts. The warnings are down from about 2.6 a minute to 0.7 an hour. But on the LAN, replies take milliseconds, so the timeout barely matters any more, and the LAN change alone could account for most of the gain. The evidence so far proves your timeout fix matters over the cloud relay. It doesn't yet prove your changes make a difference on the setup you run now. Also, the old container only kept about 13 hours of logs, which show one dropout, so I don't have a solid "before" baseline for your original problem.

[greggo74]

I reverted back to your dev, left my timeout at 2s and switched back to cloud...

What happened, step by step:

1.	11:38:11: first login attempt times out. PAI reached your site through the relay and sent the login, but the IP150 didn't answer within 2 seconds. Your branch had been connected to the IP150 over the LAN until eight seconds earlier. The IP150 allows only one session and is slow to notice the old one has gone, so it was still busy. That part is expected on any build.
2.	11:38:18: second attempt, "Connection reset by peer" within 1 ms of the login. Plain dev doesn't close the failed attempt's connection before retrying (finding #4 in your review document). The old connection is left open, orphaned, still holding the IP150's single slot, so the new attempt collides with PAI's own leftover and gets reset.
3.	11:38:30: "File descriptor … is used by transport". This is the same bug in its most visible form. Plain dev reused the relay socket for the new attempt, but that socket was still attached to the previous, never-closed attempt. Python's networking layer refused to attach it twice and raised the error. The traceback shows it exactly: create_connection(sock=self.stun_session.get_socket()) on a socket still held by the old transport.
4.	11:38:37: success on the sixth attempt. Once the IP150 finally released the old LAN session, the login worked (Authentication Success, then Running at 11:39:06).

What your PR changes here:

•	A failed attempt now always closes its connection and the relay socket (finally: … await self.close()), so no leftovers.
•	Retries wait before trying again, instead of firing back-to-back.

On your branch, step 1 would still happen (the IP150 needs time), but the retries wouldn't trip over their own leftovers. Steps 2 and 3 shouldn't occur at all.

[greggo74]

Rebased onto current dev (dc9384b, #619). No code changes: git range-diff shows both commits identical, and the full suite passes on the rebased branch (1721 passed).

A/B run A: plain dev @ dc9384b, cloud relay (SITE/STUN), IO_TIMEOUT = 2, otherwise the same pai.conf. Ran 29 Sep 11:38 → 1 Oct 15:24 AEST (51.8 h).

Panel connection losses	0
Connected	99.9 %
Restarts	1: an external SIGTERM on 30 Sep 23:07 (clean shutdown, Running again 44 s after start)
Time to Running	55 s on the first start, 44 s after the restart
ERROR lines	12. Eleven were in the first 25 s of the 29 Sep start: relay login timeouts, 2 × Connection reset by peer, and one File descriptor … is used by transport RuntimeError on the STUN socket. The other was at the SIGTERM shutdown.
No handler for message 5 warnings	1333 (≈ 618 per 24 h)

So you were right: on dev the disconnects are gone, even over the relay. What this PR still changes:

1. IO_TIMEOUT is frozen at import for the status polls. On dev it is a default argument in HandlerRegistry.wait_until_complete (paradox/lib/handlers.py:97), AsyncMessageManager.wait_for_message (paradox/lib/async_message_manager.py:42) and Paradox.send_wait (paradox/paradox.py:497), so a value in pai.conf never reaches them. Over the relay (≈ 0.5 s round trip), replies to the 10 s polls arrive after the 0.5 s wait and are logged as No handler for message 5; that is the ~618/day above. wait_for_ip_message does honour it, because ip/connection.py is only imported after the config is loaded. The PR reads cfg.IO_TIMEOUT at call time.
2. Reconnect backoff: retry_time_wait = 2 ^ retry (paradox/main.py:124) is XOR, not a power, so the second retry waits 0 s.
3. Failed IP connect attempts leave the socket open. That is the File descriptor … is used by transport error on the first start above.

I didn't run B (this PR on the same relay setup). On 1 Oct I went back to a direct LAN connection to the IP150, where plain dev has been quiet: 25.7 h, 0 errors, 0 connection losses, 10 No handler warnings. So there are no like-for-like relay numbers for the PR build. I'm happy to split the PR if you'd rather take only some of it, e.g. just 1 and 2.

[sonarqubecloud]

Quality Gate passed

Issues
0 New issues
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarQube Cloud