Skip to content

fix(protocol): retransmit and fail fast on the write path - #54

Open
mbillow wants to merge 3 commits into
QuiteYellow:mainfrom
mbillow:claude/smartthings-local-write-retry-i4kea9
Open

fix(protocol): retransmit and fail fast on the write path#54
mbillow wants to merge 3 commits into
QuiteYellow:mainfrom
mbillow:claude/smartthings-local-write-retry-i4kea9

Conversation

@mbillow

@mbillow mbillow commented Aug 19, 2026

Copy link
Copy Markdown
Contributor

Picks up the half of mbillow/localthings#384 that was left open after #51 claimed the pacing half.

The asymmetry

post() sends its datagram exactly once:

self._send_dgram(datagram)
if not ev.wait(timeout):
    raise SessionTimeoutError()

get() goes through _exchange_block, which retransmits each block up to _BLOCK_MAX_ATTEMPTS at _BLOCK_ACK_TIMEOUT per attempt. So one lost datagram — request or ACK — is an unrecoverable write, while a read absorbs the identical loss silently. That matches the report in #384: reads keep working, three unrelated resources (/power/vs/0, /temperature/desired/0, /wind/direction/vs/0) intermittently don't.

The bare ev.wait() is a second, separate gap: it skips the _wait_for_block liveness slicing get() uses, so a reader thread dying mid-write burns the full 8 s and reports a device timeout for what is actually a dead session.

What this does

Liveness (active). _wait_for_block becomes _wait_live, and post() waits through it. A reader death mid-write now raises SessionClosedError within one liveness poll instead of at the end of the caller's timeout.

Retransmission (off by default). post() retransmits the CON up to write_max_attempts times inside the caller's deadline, with §4.2 backoff, pacing each retransmit, and the final attempt taking whatever budget is left.

The datagram is built once and resent verbatim. That MID reuse is the load-bearing part: a server implementing §4.5 recognises the duplicate and answers from its dedupe cache instead of re-running the write. A caller-side retry can't offer that — post() mints a fresh MID and token per call, so a retry from above is a genuinely new request the device has no way to dedupe.

It defaults to 1 attempt — byte-for-byte today's behaviour — per @QuiteYellow's ordering caution on #384: retransmitting into a device that's already dropping under load turns one lost write into several, and §4.5 dedupe is unverified on RT-OCF, which doesn't reliably emit RST either. With #51 landed we can see whether writes are still being lost before turning this on, and the flag is then a one-line change rather than a new feature.

Bare-frame matching (active). The empty ACK ("separate response coming", §5.2.2) and RST both answer a request without carrying a token, so _pending — keyed by token — could never match either. The empty ACK was dropped on the floor and RST had no branch at all (TYPE_RST was imported and unused). Both now resolve through a MID registry, registered before the send so a stray frame for an unknown MID can't grow it:

  • empty ACK stops retransmission and waits out the caller's budget for the separate CON
  • RST surfaces as SessionError — a rejection, not the timeout it looked like

refresh_observes() dereg sweep (active). Paced. Unlike the teardown dereg in close(), which wants out quickly, this one runs against a session that has to keep working afterwards, and an unpaced OBSERVE burst is what wedges an appliance (mbillow/localthings#396).

What this deliberately does not do

Pacing of the request paths. subscribe(), post(), and block zero are #51's, and a second layer at the call sites would only have to be unwound when it lands. The time.sleep(0.05) in the refresh_observes subscribe sweep is left alone for the same reason. Worth being explicit: that means the connect-time OBSERVE burst in mbillow/localthings#396 is not fixed by this PR — it still needs #51, then a release.

The read path's empty-ACK handling. Only post() registers a MID, so _exchange_block still retransmits through an empty ACK — and with a fresh MID per attempt, which defeats dedupe. That is pre-existing, and it's on the path the comment itself identifies as where RT-OCF actually uses separate responses, so it deserves its own change rather than a drive-by in a write-path PR. Happy to follow up.

Tests

tests/test_dtls_session_post_retry.py, on the existing _FakeConn/_FakeSock harness. Each was confirmed to fail against the unfixed code:

  • the default sends exactly once — no new load on a device nobody has measured yet
  • a dropped first datagram is recovered when the flag is on
  • retransmits carry the same MID and token as the original
  • a reply landing in the retry's pace window is not resent
  • a reply that beat a dying reader is still returned, not discarded as a closed session
  • an empty ACK stops retransmission; an RST raises SessionError
  • attempts stay inside the caller's deadline, including the pace before a retry
  • a reader death mid-post() raises SessionClosedError fast
  • refresh_observes paces its dereg sweep

One test-harness fix worth calling out: the stubbed _send_dgram didn't stamp _last_send_ts, so pace() read a zero timestamp and never slept — which silently voided the deadline test that was supposed to catch the pace-overrun bug.

Full suite: 280 passed.

@QuiteYellow

QuiteYellow commented Aug 21, 2026

Copy link
Copy Markdown
Owner

Reviewed, and I want this. The MID-reuse argument is the right one, off-by-default is the right call for a device nobody has measured, and the refresh_observes dereg pacing is a good catch that I would have missed.

It needs a rebase first, and the conflict is semantic rather than textual, so I would rather hand it back than resolve it myself.

What changed under you

#51 merged as b3045f5. It paces the first send of every request, post() included:

try:
    self.pace()
    self._check_live()
    self._send_dgram(datagram)

Your loop paces only retransmits (if attempt:), which was correct when you wrote it, because post() did no pacing at all. Applied on top of #51 it silently drops first-send pacing for writes. Reads keep it, writes lose it, which is the asymmetry your own PR is about, pointed the other way.

Why I am not resolving it myself

I tried. Moving pace() and _check_live() above the loop breaks two of your tests, and both are right to break.

test_a_reply_during_the_pace_window_is_not_resent asserts one send. With a pace before the first attempt, your stub answers before anything goes out, the if not ev.is_set() and not acked guard suppresses the send, and it asserts 0 == 1.

test_an_answer_that_beat_a_dying_reader_is_still_returned is the one that convinced me to stop. My pre-loop _check_live() raised SessionClosedError on a write the device had already confirmed. That is exactly the bug the test exists to catch, and my resolution reintroduced it at attempt 0.

Both stubs assume the first send precedes any pace. Any resolution that paces first invalidates that assumption, so this is a question about your test structure and not a merge I should be making on your behalf.

The question

Should post() pay a pace interval before its first attempt?

My answer is yes. A write is a request, that is what #51 is for, and exempting writes puts the un-limited send back on the path most likely to be hit during a storm. But it restructures your stubs, so it is yours to make.

Release

I am cutting v0.1.9 with #51 alone rather than holding it. The reporter on #37 has a fridge that will not reconnect, the cause is the OBSERVE burst, and I have already told them the fix is written and waiting on a release. This goes in the next one.

That does mean LocalThings gets the halves separately rather than together. Given #384 is about writes and #396 is about the subscribe burst, taking the burst fix now costs you nothing you were relying on.

@QuiteYellow

Copy link
Copy Markdown
Owner

I opened #56 after the review above, and it changes one thing here.

Your _inflight_mids and #36's _pending_get_mids are the same registry from opposite ends, so I do not want to merge both. #56 asks you and @atc722 to agree one structure. Hold the rebase until that settles or you risk doing it twice.

The pacing question from my review still stands and is still yours: should post() pay a pace interval before its first attempt? That one is independent of the registry.

@QuiteYellow

QuiteYellow commented Aug 22, 2026

Copy link
Copy Markdown
Owner

main answers the question I left here. #51 put self.pace() as the first statement in post(), so writes already pay an interval before their first send.

Keep that through the rebase. The work is the two stubs that assume the first send precedes any pace.

One other thing that lands on your rebase: #58 took the read-path item you had set aside. _exchange_block now registers once outside its attempt loop and resends one datagram, so the fresh-MID-per-attempt behaviour is gone.

@mbillow
mbillow force-pushed the claude/smartthings-local-write-retry-i4kea9 branch from efb7656 to 8050926 Compare August 23, 2026 04:02
post() sent its datagram exactly once and then waited on a bare
ev.wait(timeout), while get() retransmits every block through
_exchange_block. One lost datagram — request or ACK — was therefore an
unrecoverable write, while a read absorbed the identical loss silently.
That is the report in LocalThings#384: reads keep working, three
unrelated resources intermittently do not.

Liveness. The bare wait also skipped the slicing _exchange_block uses,
so a reader thread dying mid-write burned the caller's whole 8s and
reported a device timeout for what was actually a dead session.
_wait_for_block is no longer block-specific — it becomes _wait_live, and
post() waits through it, so a reader death surfaces as SessionClosedError
within one liveness poll.

Retransmission, off by default. post() resends the CON up to
write_max_attempts times inside the caller's deadline, with §4.2 backoff,
pacing every attempt, and the last attempt taking whatever budget is
left. The datagram is built once and resent verbatim; reusing the MID is
the load-bearing part, because a server implementing §4.5 can then
recognise the duplicate and answer from its dedupe cache instead of
re-running the write. A caller-side retry cannot offer that — post()
mints a fresh MID and token per call, so a retry from above is a
genuinely new request the device has no way to dedupe.

It defaults to 1 attempt: on that path the wire behaviour is unchanged,
one datagram sent in the same order as before, per the ordering caution
on #384. Retransmitting into a device already dropping under load turns
one lost write into several, and §4.5 dedupe is unverified on RT-OCF,
which does not reliably emit RST either. With pacing (QuiteYellow#51) landed we can
see whether writes are still lost before turning this on, and the flag is
then a one-line change.

Two details that are not carried over unchanged from the single-send
version, both covered by tests:

  * timeout now bounds the whole call rather than the wait after the
    send. Attempts share one budget, so it has to be armed before the
    first pace — and a caller that asked for 8s should not wait 8s plus
    however long the rate limiter withheld the request.
  * a retransmission that fails to send is best-effort. A connected UDP
    socket reports the ICMP error queued by an earlier send on the next
    one, and the reader already treats those errnos as advisory; failing
    the exchange there would make retransmitting less robust than leaving
    it off. Attempt 0 still raises, since it is the caller's only
    datagram.

Rebased onto the shared MID registry: the empty-ACK and RST matching this
originally carried is QuiteYellow#57's now, and QuiteYellow#58 gave the read path the same
one-datagram-per-exchange shape, so what remains here is the write
attempt loop and the frames that must stop it. Attempt 0 keeps QuiteYellow#51's
pace-then-check-then-send ordering exactly; the liveness recheck is
skipped only once something has answered, because an answer that beat a
dying reader is a write the device confirmed and must not be discarded.
_close_pending_requests() stamped SessionClosedError onto every pending
container with setdefault(), including one that already held the response
the reader had just dispatched. Both callers read 'err' before 'code' —
post() in its wait loop, _blockwise_get_once on the container
_exchange_block hands back — so a request the device had already answered
surfaced as a closed session.

The window is the reader's own teardown: _reader_loop's finally clears
_reader_running and calls _close_pending_requests(), and a response
dispatched in the same pass has not necessarily been picked up by its
caller yet. Reproduced on the write path 5/5.

Only stamp the error on an exchange that has no answer, mirroring the
guard the RST branch already applies. Shared by both indices, so the read
path gets it too: a final block delivered as the reader exits is an
answer, not a closed session.

Found reviewing the write-path retransmission that sits under this: its
liveness recheck deliberately yields to an answer that beat a dying
reader, which the teardown then overwrote anyway.
refresh_observes() dropped every OBSERVE registration in a tight loop.
Unlike the teardown dereg in close(), which wants out quickly and leaves
a session nobody will use again, this one runs against a session that has
to keep working afterwards — and an unpaced OBSERVE burst is what wedges
an appliance until something forces a new session (LocalThings#396).

The two sleeps that stood in for pacing are gone with it. subscribe()
paces its own send since QuiteYellow#51, so the 50ms between registrations was
always shorter than the wait that followed it — the same redundancy QuiteYellow#59
removed from the bridge's registration loop, at the sibling call site.
The 100ms between the two sweeps is subsumed the same way, by the pace
inside the first subscribe().

Note this does not fix the connect-time OBSERVE burst in #396 on its own:
that path is the bridge's registration loop, which QuiteYellow#51 already paces.
@mbillow
mbillow force-pushed the claude/smartthings-local-write-retry-i4kea9 branch from 8050926 to 1d7b263 Compare August 23, 2026 04:17
@mbillow

mbillow commented Aug 23, 2026

Copy link
Copy Markdown
Contributor Author

@QuiteYellow Rebased onto main (6d9cf40). Three commits now.

The pacing question — yes, and main already does it. self.pace() is the
first statement in post(), so attempt 0 keeps #51's pace → _check_live → send ordering exactly and retransmits pace through the same loop head. No
if attempt: branch anymore.

You were right that it was a test-structure question. Both stubs assumed the
first send precedes any pace; they now stub pace() to answer on its second
call, so the reply lands in the retry's window — which is what they were always
about. test_an_answer_that_beat_a_dying_reader_is_still_returned still catches
the bug your resolution hit: reinstating an unconditional _check_live() at
every attempt fails it again.

Registry — #56 is moot for this side. _inflight_mids is gone; this uses
_pending_mids and _MidExchange. The empty-ACK and RST matching are #57's,
and #58 took the read-path item I'd set aside, so what's left here is the write
attempt loop and the frames that stop it. Nothing to agree with @atc722 — I just
deleted mine.

A bug fell out of the rebase, preexisting, not mine (2nd commit).
_close_pending_requests() stamps SessionClosedError onto every pending
container with setdefault(), including one already holding the response the
reader just dispatched. Both callers read 'err' before 'code', so a request
the device answered surfaces as a closed session. The window is _reader_loop's
own finally: it clears _reader_running and drains pending in the same pass a
response may have been dispatched in. Reproduced on the write path 5/5.

Fixed by only stamping an exchange that has no answer, mirroring the guard the
RST branch already applies. It's shared, so the read path gets it too — a final
block delivered as the reader exits is an answer, not a closed session. Happy to
split this out if you'd rather take it on its own.

Two things about post() that aren't unchanged from the single-send version,
both deliberate and both tested:

  • timeout now bounds the whole call rather than the wait after the send.
    Attempts share one budget, so it has to be armed before the first pace — and a
    caller asking for 8s shouldn't wait 8s plus however long the limiter withheld
    the request. At 5 rps that's ≤200ms of 8s; at 1 rps it's a full second, which
    is why I'd rather it be the caller's second than an extra one.
  • a retransmission that fails to send is best-effort. A connected UDP socket
    reports an earlier send's queued ICMP error on the next one, and the reader
    already treats those errnos as advisory — failing the exchange there made
    turning retransmission on less robust than leaving it off. Attempt 0 still
    raises.

Judgement calls, all easy to back out:

One note for review: the empty ACK stops retransmission through both the send
guard and the wait branch, so no single mutation trips test_separate_ack_stops_retransmission — removing both does. Redundant on purpose, flagged so it doesn't read as untested.

@QuiteYellow

Copy link
Copy Markdown
Owner

Three things have landed since you rebased.

#36 and #61 are on main. #62 is the _wait_live rename, pulled out of your diff and landed on its own. The docstring and the _BLOCK_LIVENESS_POLL_S comment are your wording verbatim, so those hunks should disappear when you rebase.

With #62 in, I test-merged your branch. Three hunks, all mechanical.

_WRITE_ACK_TIMEOUT lands next to a comment #62 touched, so it shows up as an add against an empty side. Keep yours. In post(), #36 added a comment above self.pace() that your attempt loop replaces. Keep yours.

The third is the one to read twice, and it is why #62 went first:

<<<<<<< HEAD
        deadline = time.monotonic() + per_wait
=======
        deadline = time.time() + per_wait
>>>>>>> pr54-test

Keep time.monotonic(). Three lines below, the loop reads deadline - time.monotonic(), so mixing the two pins slice_s to the poll interval and removes the per-attempt timeout: the wait then ends only when the response arrives or the reader dies, so a silent device hangs the call and the retransmission never fires. Every test stubs this function out, so nothing catches it. Before #62 that one line was buried inside a docstring-sized hunk.

#36 also reaches your new test file. It dropped TYPE_ACK and TYPE_RST from dtls_session's imports when the ACK/RST handling moved into classify_coap_response, so ds.TYPE_ACK stops resolving:

-from smartthings_local.protocol.coap import parse_coap
+from smartthings_local.protocol.coap import TYPE_ACK, TYPE_RST, parse_coap

and the same at the two call sites. Both names are in coap.py on your current base as well as on main, so it applies whenever suits, before or after the rebase.

All four resolved that way gives 419 passing here.

Your three judgement calls

Keeping the rename, hence #62. The refresh_observes sleeps: agreed, and pacing the dereg sweep is the better half of that commit. README section: keep.

_close_pending_requests

Leave it in #54. The library change stands alone but its tests sit in the file your first commit creates, so splitting it means rehoming them, and the window needs the reader to die in the same pass a response was dispatched. It can ride.

One ask whenever it suits: timeout bounding the whole call is a public API behaviour change, so it wants a line in the release notes as well as the docstring.

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.

2 participants