Skip to content

fix(myuplink): retry a failed read soon and keep a rotated token (1.2.4) - #193

Merged
frahlg merged 2 commits into
mainfrom
fix/myuplink-stale-retry
Oct 25, 2026
Merged

frahlg merged 2 commits into
mainfrom
fix/myuplink-stale-retry

Conversation

@frahlg

@frahlg frahlg commented Oct 25, 2026 •

Copy link
Copy Markdown
Member

Problem

On Fredrik's home box (Core v0.155.1-beta.1, myuplink 1.2.3, the same file as main) Core marks the MyUplink heat pump offline many times a day:

MyUplink: poll failed: Get ".../v2/devices/<id>/points": context deadline exceeded (Client.Timeout exceeded while awaiting headers)
driver telemetry stale — marking offline + reverting to autonomous name=myuplink timeout=1m0s

From Core start on 22 October 15:35 to 25 October 09:00 the journal has 143 failed reads in 124 runs, and exactly 124 stale events: one per run of failures, every time. In 109 of the 124 runs, one read failed and the next one, 30 s later, worked. It still happens: three times between 09:03 and 09:14 on 25 October.

Cause

Timing, not rate limits.

  • A good read takes about 0.3 s. In 24 minutes of sampling Core's last-success time on 25 October, 29 of 36 good reads took under 1 s (median 0.28 s), 3 took 5–15 s (the slowest 14.4 s), and 4 reads failed, each leaving a gap of 75–82 s. Some requests hit the host HTTP client's fixed 15 s timeout: 185 while waiting for headers, 51 while reading the body, 4 connection resets over five days. Failures come at every hour of the day, in bursts (24 October 21:00–21:16, 25 October 06:20–09:15).
  • myUplink documents a limit of 25 requests a minute (dev.myuplink.com, "Rate Limiting and Client Abuse"). The driver makes about 2. The journal has no HTTP 429.
  • The driver returned 30 s after a failure. Core's watchdog marks a driver offline after 60 s without a reading. So one timed-out read gave: last reading, 30 s wait, 15 s timeout, 30 s wait, next reading, which is 75 s. The journal agrees: each stale line comes 15–17 s after the failure, 60 s after the last reading.
  • One slow request blocks the whole poll. The driver makes one request per poll (all points at once), and the Lua VM runs one call at a time, but other drivers are not affected.
  • The driver returned 60 s after a good read. Core caps a returned wait at 30 s (fix(drivers): honour the interval driver_poll returns ftw#1616), so the box already polled every 30 s; 60 s never applied.

What Core does when it marks the driver offline

It logs a WARN, flags the driver offline (the heating page shows it offline), publishes DriverLost, and sends the autonomous default. For this read-only driver driver_default_mode does nothing, so the pump is not touched; FTW never controls it. But sending the default cancels a poll that is in flight. On 22 October that cancelled the very read that would have brought the driver back (<string>:168: context canceled in api_get). One slow request should not cause any of this.

Change (myuplink 1.2.4)

  • After a failed read or sign-in, retry once after 2 s. A second failure in a row waits the full 30 s. One timed-out read now leaves about 47 s without a reading (30 + 15 + 2), under 60 s. Two in a row leave more than 60 s, so an outage of a minute or more still shows as offline. At most one quick retry per outage keeps the driver well under 25 requests a minute.
  • A good read asks for 30 s, the wait Core already applied.
  • A failed read still emits nothing. The driver does not re-send old readings to stay fresh: a failed request to the cloud says nothing about whether the pump is still there, so re-sending them would fake live.

Rotated refresh token

MyUplink: could not persist rotated refresh_token: database is locked (5) (SQLITE_BUSY) appeared once, on 25 October at 06:45.

Could it lose the token? Yes. The driver kept the new token in memory and never tried to store it again. It could only be stored after the next rotation, about an hour later. A driver reload or Core restart or update in that hour started from the token stored before, which myUplink had just replaced. If myUplink no longer accepts a replaced token, the driver cannot sign in until the owner connects again in Settings. Reloads are common on this box: six in five days, one per Core update. This time no reload fell in the window, and the journal has no failed token refresh.

Now the driver stores the token after each poll's reading and retries a failed store on every poll until it succeeds, so the window is one poll (30 s). The store comes after the reading on every return path: once Core waits out a busy database (#1826), one failed store can take 5 s. Stored before the read, a stuck lock plus one timed-out read gave 67.9 s between readings in review; after the read it gives 57.9 s. It warns once per rotation, as before, and logs when the store succeeds. It does not store the token in driver_cleanup: Core lets a stored token override config at start, and a reconnect has just stored a fresh token at that point. An older token, perhaps from replaced app credentials, must not overwrite it.

The busy error itself comes from Core: a database transaction that reads before it writes does not wait for another writer. That fix is srcfl/ftw#1826, a separate Core PR. This driver change does not depend on it, and either can merge first.

Tests

  • drivers/tests/lua_harness/test_myuplink_poll_timing.lua (new): return waits, one quick retry per outage, failed sign-in, a model of Core's run loop and watchdog (one timeout under 60 s, two over), store retried until it succeeds, one warning, no store in driver_cleanup. On the old driver 16 checks fail, including a 75.3 s gap, the same as on the box.
  • The harness also checks that after rotations while the host refuses the store, the newest token is the one stored (keeping the first pending token fails it), that the reading comes before the store, and the 5 s store case above (storing first fails it at 67.9 s).
  • make test-driver ID=myuplink and make check: pass.
  • FTW's Go host (gopher-lua): FTW's go test ./internal/drivers -run 'MyUplink|Persist' passes with this file as drivers/myuplink.lua. A throwaway test against a fake myUplink whose first read stalls 20 s gave the box's exact error after 15.003 s, a 2 s wait, then a good read, and the store of the rotated token after one SQLITE_BUSY.
  • Not yet run on the box.

Notes

  • feat(myuplink): improve NIBE F750 telemetry #160 (NIBE F750 telemetry) also edits myuplink.lua and also claims 1.2.4. It has right of way. Its changes are in the metric and name code; this PR changes the poll timing and the token store. Whichever merges second rebases and takes 1.2.5.
  • FTW's bundled snapshot keeps 1.2.3 until someone moves the pin in drivers/BUNDLED_SOURCE.json.
  • Not changed: the driver does not check whether the pump itself still reports to myUplink. If the pump loses its internet link, the cloud may keep serving its last values and the driver would emit them as fresh. That needs its own look.

🤖 Generated with Claude Code

@chatgpt-codex-connector

chatgpt-codex-connector Bot commented Oct 25, 2026 •

Copy link
Copy Markdown

Codex Review Summary

This comment shows the latest Codex review activity on this pull request.

Review Status Commit Review trigger
📝 Code Review ✅ Completed 2026-10-25T08:25:41.101273Z e8acd27 PR opened
ℹ️ About Codex in GitHub

Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you

  • Open a pull request for review
  • Mark a draft as ready
  • Comment "@codex review" or "@codex security review".

Codex reacts with 👀 while any review is running, comments if it has suggestions, and reacts with 👍 once all reviews finish with no findings.

One request that hits the host's 15 s HTTP timeout left 75 s without a
reading (30 s wait, 15 s timeout, 30 s wait), past Core's 60 s watchdog, so
the heat pump was marked offline on every slow request. Retry a failed read
or sign-in once after 2 s; a second failure in a row waits the full 30 s,
so a real outage still shows as offline. A good read asks for 30 s, the
wait Core already applied.

A rotated refresh_token that the host could not store (SQLITE_BUSY) was
held only in memory until the next rotation. Retry the store on every poll
until it succeeds, but not in driver_cleanup, where a reconnect may just
have stored a newer token.

Signed-off-by: Fredrik Ahlgren <fredrik@sourceful-labs.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@frahlg
frahlg force-pushed the fix/myuplink-stale-retry branch from e8acd27 to 59d9ce5 Compare October 25, 2026 08:25
Once Core waits out a busy database (srcfl/ftw#1826), one failed store can
take 5 s. Stored before the read, that pushed a poll with one timed-out
read to 67.9 s between readings, past the 60 s watchdog. The token is now
stored after the read on every return path, and a rotation during sign-in
is only marked unsaved; the same case gives 57.9 s.

The harness now also checks that, after rotations while the host refuses
the store, the newest token is the one stored.

Signed-off-by: Fredrik Ahlgren <fredrik@sourceful-labs.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@frahlg
frahlg merged commit 2199dbf into main Oct 25, 2026
5 checks passed
@frahlg
frahlg deleted the fix/myuplink-stale-retry branch October 25, 2026 08:57
frahlg added a commit to srcfl/ftw that referenced this pull request Oct 25, 2026
Move the driver pin from 219c462e to device-drivers main 57984984:
easee_cloud 1.4.0 reads Easee's SignalR stream with REST as fallback
(srcfl/device-drivers#192; Core grants its declared ws_hosts since
#1822), and myuplink 1.2.4 retries a slow read after 2 s and
keeps a rotated token (srcfl/device-drivers#193).

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant