fix(protocol): retransmit and fail fast on the write path - #54
Conversation
post() sent its datagram exactly once and waited on a bare ev.wait(), while get() retransmits every block through _exchange_block. One lost datagram was therefore an unrecoverable write and a silent no-op for a read -- the asymmetry behind three unrelated resources on one AC all failing with SessionTimeoutError (LocalThings#384). - Extract _wait_live() from _wait_for_block() and wait through it in post(). A reader thread dying mid-write now raises SessionClosedError within a liveness poll instead of burning the caller's whole timeout and reporting a dead session as a device timeout. - Retransmit the CON up to write_max_attempts times inside the caller's deadline, reusing the same Message ID. The MID reuse is what makes retransmitting a non-idempotent POST safe: a server implementing RFC 7252 4.5 answers the duplicate from its dedupe cache rather than re-running the write, which a caller-side retry can never offer since it mints a fresh MID. Defaults to 1 attempt -- byte-for-byte today's behaviour -- because a device already dropping under load turns one lost write into several, and RT-OCF's dedupe is unverified. Enable it once pacing has been shown insufficient on real hardware. - Pace the dereg sweep in refresh_observes(). 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 until something forces a new session (LocalThings#396). Pacing of the request paths themselves is deliberately left alone: subscribe(), post() and block zero are QuiteYellow#51, and a second layer at the call sites would only have to be unwound when it lands.
- Do not resend when the answer is already in hand. A response can land in the pace window before a retry, and resending then puts a second copy of a non-idempotent write on the wire for nothing. - Match the empty ACK on MID. "Separate response coming" (RFC 7252 5.2.2) stops the retransmit timer, but that frame carries no token, so _dispatch_coap dropped it and the timer ran on -- resending a request the device had already taken. _separate_acks is keyed by MID and registered before the send, so a stray ACK for an unknown MID cannot grow it, and the read path is unaffected. - Clamp the retry decision to what a pace costs. pace() sleeps up to a whole rate-limit interval, so deciding to retry on "any budget left" returned past the caller's timeout -- 1s on a 0.5s call at 1 rps. The test session's _send_dgram stub now stamps _last_send_ts as the real one does. Without it pace() read a zero timestamp and never slept, which silently voided the deadline test that was meant to catch the third bug.
- Handle TYPE_RST. It was imported and never used: a device rejecting a POST neither resolved the token nor stopped retransmission, so the write was resent for the whole budget and then reported as a timeout, which reads as a device that went quiet rather than one that said no. Like the empty ACK it is a bare frame, so the MID registry now carries the token and both paths resolve through it. - Check ev before _check_live() on a retry. Both can happen in the pace window -- the response lands and the reader exits -- and checking liveness first threw away a write the device had confirmed, raising SessionClosedError for a command that actually took. Also narrows the empty-ACK comment, which implied more coverage than it has: only post() registers a MID, so _exchange_block still retransmits through an empty ACK with a fresh MID each time. That is pre-existing and wants its own change on the read path.
|
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 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 try:
self.pace()
self._check_live()
self._send_dgram(datagram)Your loop paces only retransmits ( Why I am not resolving it myselfI tried. Moving
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 questionShould 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. ReleaseI 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. |
|
I opened #56 after the review above, and it changes one thing here. Your The pacing question from my review still stands and is still yours: should |
2 participants
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:get()goes through_exchange_block, which retransmits each block up to_BLOCK_MAX_ATTEMPTSat_BLOCK_ACK_TIMEOUTper 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_blockliveness slicingget()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_blockbecomes_wait_live, andpost()waits through it. A reader death mid-write now raisesSessionClosedErrorwithin one liveness poll instead of at the end of the caller's timeout.Retransmission (off by default).
post()retransmits the CON up towrite_max_attemptstimes 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_RSTwas 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:SessionError— a rejection, not the timeout it looked likerefresh_observes()dereg sweep (active). Paced. Unlike the teardown dereg inclose(), 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. Thetime.sleep(0.05)in therefresh_observessubscribe 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_blockstill 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/_FakeSockharness. Each was confirmed to fail against the unfixed code:SessionErrorpost()raisesSessionClosedErrorfastrefresh_observespaces its dereg sweepOne test-harness fix worth calling out: the stubbed
_send_dgramdidn't stamp_last_send_ts, sopace()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.