fix(protocol): retransmit and fail fast on the write path - #54
Conversation
|
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 |
|
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. |
efb7656 to
8050926
Compare
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.
8050926 to
1d7b263
Compare
|
@QuiteYellow Rebased onto main (6d9cf40). Three commits now. The pacing question — yes, and main already does it. You were right that it was a test-structure question. Both stubs assumed the Registry — #56 is moot for this side. A bug fell out of the rebase, preexisting, not mine (2nd commit). Fixed by only stamping an exchange that has no answer, mirroring the guard the Two things about
Judgement calls, all easy to back out:
One note for review: the empty ACK stops retransmission through both the send |
|
Three things have landed since you rebased. #36 and #61 are on With #62 in, I test-merged your branch. Three hunks, all mechanical.
The third is the one to read twice, and it is why #62 went first: Keep #36 also reaches your new test file. It dropped -from smartthings_local.protocol.coap import parse_coap
+from smartthings_local.protocol.coap import TYPE_ACK, TYPE_RST, parse_coapand the same at the two call sites. Both names are in All four resolved that way gives 419 passing here. Your three judgement callsKeeping the rename, hence #62. The
|
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.