feat(logging): add weekly log rotation and retention

.gitignore

@@ -29,6 +29,7 @@ _obj
 _test
 .vscode/
 ChipDNAClient/
+docs/
 
 # Architecture specific extensions/prefixes
 *.[568vq]

cmd/hardlink/main.go

@@ -33,7 +33,7 @@ import (
 )
 
 const (
-	buildVersion     = "v2.0.1"
+	buildVersion     = "v2.1.3"
 	serviceName      = "hardlink"
 	pollingFrequency = 8 * time.Second
 )
@@ -227,6 +227,7 @@ func main() {
 
 		// Start polling for dispenser status every 10 seconds
 		disp.StartPolling(pollingFrequency)
+		disp.StartMaintenance()
 	}
 
 	mux := http.NewServeMux()

internal/dispenser/K720_DISPENSER_CONTRACT.md

@@ -0,0 +1,335 @@
+# K720 dispenser issuance contract
+
+Hardlink treats the K720 as an unreliable mechanical peripheral with a strict transport
+protocol and imperfect status telemetry. The implementation must keep transport
+validation strict while making mechanical decisions from fresh, bounded observations.
+Diagnostic bytes are useful evidence, but they must not override a valid physical
+position or turn an uncertain observation into a fatal guest-facing error.
+
+This document records the dispenser invariants agreed for the clean implementation.
+It is intended to be a design contract: future changes should preserve these rules
+unless production evidence justifies changing them explicitly.
+
+## Ownership and concurrency
+
+- The dispenser worker is the single owner of serial commands and `deliveryPending`.
+  New code must not access the serial port directly from handlers or background
+  goroutines.
+- Commands that can move a card are serialized through the worker. There must never
+  be concurrent AP/FC7/FC0/RS traffic from separate flows.
+- `deliveryPending` is worker-owned state. It must not be duplicated or mutated by
+  HTTP handlers.
+- A real `/issuedoorcard` operation always has priority over maintenance/prestage
+  work.
+- Cancellation of a real caller must stop caller-owned work. Internal bounded
+  observation timeouts must remain distinguishable from caller cancellation.
+- Do not create overlapping maintenance goroutines or timers per request. Any
+  background maintenance must have one clear owner and lifecycle.
+
+## Status and observation model
+
+AP transport parsing is strict. A response is usable only when its framing and
+contents are valid, including ACK/address/header/length/ETX/BCC/type checks.
+
+Malformed, truncated, timed-out or otherwise invalid AP responses are unusable
+observations. They are logged and discarded. They are never converted into a
+fabricated physical state such as `0x30` or `0x38`.
+
+Every fresh valid AP observation reclassifies the current mechanical state. No
+physical position is latched across later observations.
+
+The fourth AP status byte is the physical position used by the preparation logic:
+
+- Encoder confirmed:
+  `0x32, 0x33, 0x36, 0x37, 0x3A, 0x3B, 0x3E, 0x3F`.
+  A card may be handed to `LockSequence` immediately.
+- Valid but uncertain:
+  `0x31, 0x34, 0x35, 0x39, 0x3C, 0x3D`.
+  Continue bounded fresh observation; if no stronger state appears, one encoding
+  opportunity may still be granted after the uncertainty window.
+- No card on sensors:
+  exact `0x30`.
+  This may trigger the bounded mechanical recovery sequence.
+- Card well empty:
+  exact `0x38`.
+  This is the only physical state that becomes `ErrCardWellEmpty`.
+
+The first three diagnostic bytes are advisory. Values such as `Preparing card fails`,
+`Dispense card error`, `Card jammed`, or `Command cannot execute` may coexist with a
+usable physical position. They may be logged, but they must not automatically block
+encoding when the fourth byte confirms a usable card position.
+
+## Preparing the current card
+
+A `/issuedoorcard` request receives at most one `LockSequence` opportunity.
+
+Preparation uses bounded fresh observation:
+
+- Poll interval: 1 second.
+- After a successful FC7, allow 3 seconds of observation before shake recovery is
+  eligible for a persistent exact `0x30`.
+- For uncertain or unusable observations after a successful FC7, use one shared
+  4-second uncertainty window. Switching between uncertain and unusable observations
+  does not restart that window.
+- A later usable observation always takes precedence:
+  encoder confirmed -> handoff;
+  exact `0x38` -> empty;
+  exact `0x30` -> resume the remaining shake budget and reset uncertainty timing.
+- Total preparation budget: 32 seconds.
+
+For persistent exact `0x30`, the request may perform at most three shake recoveries:
+
+`RS -> 2 second settle -> FC7`
+
+There is no additional plain FC7 retry. Including the initial dispatch, the maximum
+per request is four FC7 commands and three RS commands.
+
+If all three shakes are exhausted while the latest usable physical state remains
+exact `0x30`, preparation fails. If the internal preparation deadline is reached
+while the latest state is uncertain or unusable after a successful FC7, the request
+may hand off one encoding opportunity. Exact `0x38` remains empty.
+
+FC7 or RS dispatch failures are real transport/command failures. They are not
+converted into status uncertainty and are not retried merely because their dispatch
+failed.
+
+## Encoding and delivery
+
+`LockSequence` runs exactly once for a prepared card in a single `/issuedoorcard`
+request. The dispenser layer does not implement a second encoding attempt on the same
+physical card.
+
+After `LockSequence`, FC0 is dispatched exactly once to move the current card toward
+the guest:
+
+- `LockSequence` success -> FC0 once -> successful issuance remains successful.
+- `LockSequence` failure -> FC0 once -> return the original encoding error.
+- FC0 errors are logged only. They do not replace the original encoding result and
+  they do not become `ErrCardWellEmpty`.
+
+A failed `LockSequence` does not start next-card prestaging.
+
+The design intentionally does not add retained-card state, per-card failure counters,
+provider-specific encoder retries, special bad-card recovery, CP/capture recovery, or
+multiple encoding attempts per physical card without production evidence requiring
+them.
+
+## Delivery clearance
+
+After FC0, the worker marks the previous delivery as pending. A later FC7 must not be
+sent until the previous delivery has been considered clear.
+
+Delivery clearance uses fresh AP observations and is owned by the worker.
+
+Current bounds:
+
+- Minimum clearance wait: 2 seconds.
+- Clearance timeout: 6 seconds.
+- Poll interval: 1 second.
+
+A valid physical position of `0x30` or `0x34` may clear `deliveryPending` after the
+minimum wait unless the same fresh observation explicitly indicates active
+preparing/dispensing/capturing movement.
+
+Exact `0x38` reports physical empty and does not silently clear the state.
+
+If the internal clearance timeout is reached while the caller context is still
+valid, the worker may make the bounded assumption that delivery has cleared unless
+the latest fresh usable observation establishes exact physical empty (`0x38`) or
+explicit active movement. This fallback may therefore occur while the latest
+physical position is `0x33`; `0x33` itself is not positive clearance evidence.
+The fallback is an internal timeout policy, not a reclassification of the observed
+position.
+
+If the latest fresh usable observation still explicitly indicates movement, that is
+not treated as unknown. `deliveryPending` remains set and the clearance attempt
+times out.
+
+Caller cancellation or deadline always takes precedence over the internal clearance
+fallback. If the caller context expires, return the caller error and do not admit a
+subsequent FC7 from that caller-owned operation.
+
+A later unusable observation supersedes older movement evidence; stale movement
+information must not be latched indefinitely.
+
+## Next-card prestage and guest UX
+
+Preparing the next card is an optimization for the next guest, not part of the
+business success of the current guest's issuance.
+
+After a successful `LockSequence` and FC0, Hardlink may make a short best-effort
+attempt to prestage the next card:
+
+- wait for worker-owned delivery clearance;
+- if clearance is obtained within the bounded prestage context, send exactly one FC7;
+- do not run readiness polling, RS/shake recovery, or the full current-card
+  preparation flow;
+- prestage failure is log-only and must not change the successful `/issuedoorcard`
+  result.
+
+Do not extend the current guest's screen by 15-20 seconds merely to guarantee that
+the next card reaches the encoder. The guest-facing flow must remain bounded even
+when the dispenser is slow to become ready for prestage.
+
+If the short prestage window expires, skip that prestage attempt. A later request or
+maintenance cycle may prepare the next card.
+
+## HTTP contract
+
+Physical empty and operational failure are deliberately different outcomes.
+
+- HTTP 503 is reserved for `ErrCardWellEmpty`, derived only from an exact valid
+  physical `0x38`.
+- All other dispenser preparation, transport, command and encoding failures return
+  HTTP 502.
+- Normal request/protocol validation keeps its existing 400/405/415 behavior.
+- Diagnostic text such as `Preparing card fails` must never by itself produce 503.
+
+Operafyne treats:
+
+- 502 as retryable while attempts remain;
+- 503 as terminal `dispenser_failed`;
+- a maximum of three total issue attempts: the initial attempt plus up to two user
+  retries.
+
+The dispenser layer must preserve this distinction.
+
+## Passive status and alerts
+
+Ordinary status queries remain strict and passive. They must not reuse tolerant
+issuance semantics to fabricate a status or hide malformed transport.
+
+Passive polling captures the current foreground activity generation when the poll is
+queued. The worker skips a passive poll if foreground activity is active when it is
+dispatched or if the captured generation has become obsolete. Passive polling does
+not reset the idle-maintenance clock.
+
+Status/diagnostic observations may be useful for logs and support alerts, but alerts
+must not alter physical state classification or issuance success.
+
+Idle maintenance observations are intentionally quiet: they do not invoke the normal
+stock-update callback or generate repeated support email such as `Preparing card
+fails`. Maintenance failures are local diagnostic events only.
+
+## Idle prestage maintenance
+
+Idle prestaging recovers from a short post-FC0 prestage timeout without keeping the
+current guest waiting.
+
+The implementation uses the existing dispenser worker as the single maintenance
+owner:
+
+- one resettable maintenance timer is owned by the serial-worker loop; there is no
+  maintenance goroutine and no timer created per request;
+- `/issuedoorcard` and `/testissuedoorcard` register foreground activity before
+  using the dispenser/encoder and release it when the handler finishes;
+- foreground activity is reference-counted so overlapping requests suppress
+  maintenance until the last active request finishes;
+- each foreground registration increments an activity generation and invalidates the
+  previous idle deadline;
+- when the last foreground request finishes, the next maintenance attempt is
+  scheduled one minute later;
+- enabling maintenance at startup schedules the first check one minute later when
+  no foreground request is active;
+- a stale timer or stale generation cannot perform maintenance;
+- after a maintenance attempt, the next check is scheduled one minute from completion
+  only if the same generation is still authoritative. A later foreground completion
+  therefore cannot have its newer deadline overwritten by an older maintenance
+  attempt.
+
+Foreground registration and maintenance transaction admission use the same activity
+guard. The guard is used only for admission/state bookkeeping and is never held
+across serial I/O, queue waits, sleeps, callbacks, or `LockSequence`.
+
+A maintenance attempt is deliberately weaker than foreground preparation:
+
+1. create a bounded 5-second maintenance context;
+2. recheck maintenance admission before AP;
+3. obtain one fresh AP using the existing strict transport parser;
+4. classify the fresh status using the common physical classifier;
+5. do nothing for encoder-present, exact `0x38`, unusable, explicit-movement, or
+   otherwise ineligible observations;
+6. when `deliveryPending` is set, require fresh qualifying clearance evidence and the
+   existing minimum clearance wait before clearing it;
+7. never use the foreground six-second assumed-clearance fallback;
+8. recheck foreground count, activity generation, maintenance enabled state, and
+   maintenance context immediately before FC7 admission;
+9. dispatch at most one FC7 and return immediately.
+
+If foreground activity begins while an already-admitted maintenance AP is in
+progress, that AP may finish, but the second admission check prevents maintenance
+from sending FC7 afterward. An FC7 that was already admitted and dispatched before
+foreground registration cannot be recalled.
+
+Maintenance never performs:
+
+- RS or shake recovery;
+- `LockSequence`;
+- `PrepareCurrentCard`;
+- `PrepareNextCard` or `BeginPrepareNextCard`;
+- readiness polling after FC7;
+- the 32-second foreground preparation flow;
+- repeated FC7 attempts;
+- the foreground assumed-clearance fallback.
+
+The 5-second maintenance context bounds new admissions and context-aware waits. An
+already-admitted serial read may still finish according to the existing serial read
+timeout, but no subsequent maintenance transaction is admitted after cancellation or
+expiry.
+
+`StartMaintenance` and `StopMaintenance` are idempotent lifecycle operations.
+`Client.Close` disables maintenance and stops the timer.
+Stopping maintenance cancels the current maintenance context and waits only for an
+already-admitted maintenance transaction to finish under the existing bounded serial
+behavior.
+
+## Automated verification
+
+Tests should preserve the behavioural contract rather than only exercise individual
+functions.
+
+At minimum, cover:
+
+- strict AP framing and malformed/truncated/timeout responses;
+- tolerant issuance observations never fabricating `0x30` or `0x38`;
+- every physical position class and transitions between classes;
+- exact `0x38` as the only `ErrCardWellEmpty` path;
+- persistent `0x30` using at most three `RS -> settle -> FC7` recoveries;
+- no extra FC7 after the shake budget;
+- uncertain/unusable shared timing and later usable-state precedence;
+- caller cancellation versus internal preparation timeout;
+- exactly one `LockSequence` opportunity per request;
+- FC0 exactly once after encoding success or failure;
+- FC0 failure remaining log-only;
+- failed encoding never starting prestage;
+- worker-owned `deliveryPending` and guarded FC7 dispatch;
+- bounded delivery-clearance fallback and explicit-movement timeout;
+- successful issuance remaining successful when next-card prestage fails;
+- HTTP 503 only for exact physical empty and 502 for other issuance failures;
+- Operafyne retry semantics remaining three total attempts.
+
+Idle maintenance verification additionally covers:
+
+- first attempt occurs one minute after the latest issuance finishes;
+- a new issuance resets that idle interval;
+- overlapping foreground requests suppress maintenance until the last request
+  finishes;
+- both `/issuedoorcard` and `/testissuedoorcard` participate in foreground activity
+  registration;
+- stale timer events and stale activity generations cannot perform maintenance;
+- foreground registration before maintenance AP prevents AP admission;
+- foreground registration during an admitted AP prevents the later FC7;
+- passive polls are skipped while foreground activity is active or when their
+  captured generation is stale;
+- maintenance performs one AP and at most one FC7, with no RS/shake/encoding;
+- encoder-present, exact-empty, movement and unusable observations are no-ops;
+- pending delivery requires fresh normal clearance plus the minimum wait and never
+  uses the foreground assumed-clearance fallback;
+- maintenance errors do not produce guest-facing failures, stock callbacks or
+  repeated alert email;
+- repeated maintenance start/stop calls are safe and do not accumulate work;
+- cancellation, `StopMaintenance` and `Client.Close` prevent subsequent maintenance
+  commands after shutdown admission is revoked.
+
+For Hardlink verification, continue excluding the existing test that sends real
+email when running the full suite.

internal/dispenser/delivery_test.go

@@ -0,0 +1,363 @@
+package dispenser
+
+import (
+	"context"
+	"errors"
+	"io"
+	"reflect"
+	"testing"
+	"time"
+)
+
+func apReply(st []byte) []byte {
+	frame := []byte{STX, 0x30, 0x30, 0, byte(len(st) + 2), 'S', 'F'}
+	frame = append(frame, st...)
+	frame = append(frame, ETX)
+	return append(frame, calculateBCC(frame))
+}
+
+func workerRequest(c *Client, ctx context.Context, typ cmdType) cmdResp {
+	ch := make(chan cmdResp, 1)
+	c.handle(cmdReq{typ: typ, ctx: ctx, respCh: ch})
+	return <-ch
+}
+
+func TestDeliveryDispatchBoundary(t *testing.T) {
+	transportAddress(t)
+	for _, tc := range []struct {
+		name        string
+		short       int
+		badACK      bool
+		cancelAfter int
+		pending     bool
+		wantErr     bool
+	}{
+		{name: "success", pending: true},
+		{name: "command short write", short: 1, wantErr: true},
+		{name: "bad ACK", badACK: true, wantErr: true},
+		{name: "ENQ short write", short: 2, pending: true, wantErr: true},
+		{name: "cancel before ENQ", cancelAfter: 1, wantErr: true},
+		{name: "cancel after ENQ", cancelAfter: 2, pending: true, wantErr: true},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			ctx, cancel := context.WithCancel(context.Background())
+			defer cancel()
+			ack := append([]byte(nil), vendorACK...)
+			if tc.badACK {
+				ack[0] = 0
+			}
+			p := &scriptedTransport{chunks: [][]byte{ack}, shortWrite: tc.short}
+			p.afterWrite = func() {
+				if len(p.writes) == tc.cancelAfter {
+					cancel()
+				}
+			}
+			c := &Client{port: p}
+			r := workerRequest(c, ctx, cmdOutOfMouth)
+			if (r.err != nil) != tc.wantErr || c.deliveryPending != tc.pending {
+				t.Errorf("FC0(%s): err=%v pending=%v, want error=%v pending=%v", tc.name, r.err, c.deliveryPending, tc.wantErr, tc.pending)
+			}
+			if len(p.writes) > 2 {
+				t.Errorf("FC0 writes=%d, want no resend", len(p.writes))
+			}
+		})
+	}
+	t.Run("definite failure preserves previous pending", func(t *testing.T) {
+		c := &Client{port: &scriptedTransport{writeErr: io.ErrClosedPipe}, deliveryPending: true}
+		workerRequest(c, context.Background(), cmdOutOfMouth)
+		if !c.deliveryPending {
+			t.Error("failed FC0 erased previous pending")
+		}
+	})
+	t.Run("ENQ transport error remains pending", func(t *testing.T) {
+		p := &scriptedTransport{chunks: [][]byte{vendorACK}}
+		p.afterWrite = func() {
+			if len(p.writes) == 2 {
+				p.writeErr = io.ErrClosedPipe
+			}
+		}
+		c := &Client{port: p}
+		r := workerRequest(c, context.Background(), cmdOutOfMouth)
+		if !errors.Is(r.err, io.ErrClosedPipe) || !c.deliveryPending {
+			t.Errorf("ENQ error=%v pending=%v, want closed pipe and pending", r.err, c.deliveryPending)
+		}
+	})
+}
+
+func TestWorkerClearanceValidation(t *testing.T) {
+	transportAddress(t)
+	for _, tc := range []struct {
+		name  string
+		st    []byte
+		clear bool
+	}{
+		{"clear", status(0x30), true},
+		{"low stock clear", []byte{0x30, 0x30, 0x31, 0x30}, true},
+		{"residual encoder", status(0x33), false},
+		{"all sensors", status(0x37), false},
+		{"ready", status(0x34), true},
+		{"unknown diagnostic", []byte{0x30, 0x30, 0xFF, 0x30}, true},
+		{"jam", []byte{0x30, 0x30, 0x32, 0x30}, true},
+		{"overlap", []byte{0x30, 0x30, 0x34, 0x30}, true},
+		{"rejection", []byte{0x36, 0x30, 0x30, 0x30}, true},
+		{"empty", status(0x38), false},
+		{"preparing", []byte{0x31, 0x30, 0x30, 0x30}, false},
+		{"dispensing", []byte{0x30, 0x38, 0x30, 0x34}, false},
+		{"capturing", []byte{0x30, 0x34, 0x30, 0x30}, false},
+		{"ready with stale errors", []byte{0x36, 0x32, 0x34, 0x34}, true},
+		{"short payload", []byte{0x30, 0x30, 0x30}, false},
+		{"unknown position", status(0x40), false},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(tc.st), vendorACK}}
+			c := &Client{port: p, deliveryPending: true, deliveryStarted: time.Now().Add(-deliveryMinimumWait), lastStatus: status(0x30), lastStatusT: time.Now(), statusTTL: time.Hour}
+			r := workerRequest(c, context.Background(), cmdStatus)
+			if c.deliveryPending == tc.clear {
+				t.Errorf("FC7(% X): err=%v pending=%v, want clear=%v", tc.st, r.err, c.deliveryPending, tc.clear)
+			}
+			want := []string{"AP"}
+			if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+				t.Errorf("commands=%v, want %v", got, want)
+			}
+		})
+	}
+	t.Run("bad BCC cannot clear", func(t *testing.T) {
+		frame := apReply(status(0x30))
+		frame[len(frame)-1] ^= 1
+		p := &scriptedTransport{chunks: [][]byte{vendorACK, frame}}
+		c := &Client{port: p, deliveryPending: true}
+		r := workerRequest(c, context.Background(), cmdStatus)
+		if r.err == nil || !c.deliveryPending {
+			t.Errorf("bad BCC: err=%v pending=%v", r.err, c.deliveryPending)
+		}
+	})
+}
+
+func wireCommands(p *scriptedTransport) []string {
+	var commands []string
+	for _, w := range p.writes {
+		if len(w) > 6 && w[0] == STX {
+			commands = append(commands, string(w[5:len(w)-2]))
+		}
+	}
+	return commands
+}
+
+func deliveryWorkerClient(t *testing.T, p *scriptedTransport) (*Client, *time.Time) {
+	t.Helper()
+	transportAddress(t)
+	now := time.Unix(0, 0)
+	c := &Client{port: p, reqCh: make(chan cmdReq, 16), done: make(chan struct{})}
+	c.sequenceTiming = sequenceTiming{now: func() time.Time { return now }, wait: func(ctx context.Context, d time.Duration) error {
+		if err := ctx.Err(); err != nil {
+			return err
+		}
+		now = now.Add(d)
+		return nil
+	}}
+	stopped := make(chan struct{})
+	go func() { defer close(stopped); c.loop() }()
+	t.Cleanup(func() { c.Close(); <-stopped })
+	return c, &now
+}
+
+func TestDeliveryIncidentReplay(t *testing.T) {
+	for _, next := range []bool{false, true} {
+		t.Run(map[bool]string{false: "current", true: "next"}[next], func(t *testing.T) {
+			p := &scriptedTransport{chunks: [][]byte{
+				vendorACK, apReply(status(0x33)), // current card at encoder; encoding succeeds
+				vendorACK,                        // FC0
+				vendorACK, apReply(status(0x37)), // best effort must defer
+				vendorACK, apReply(status(0x33)), // previous encoder sensor must not succeed
+				vendorACK, apReply(status(0x34)),
+				vendorACK, // FC7
+				vendorACK, apReply(status(0x33)),
+			}}
+			c, now := deliveryWorkerClient(t, p)
+			if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+				t.Fatal(err)
+			}
+			if _, err := c.DeliverCurrentCard(context.Background()); err != nil {
+				t.Fatal(err)
+			}
+			// A cached clear result must not authorize FC7.
+			c.mu.Lock()
+			c.lastStatus = status(0x30)
+			c.lastStatusT = time.Now()
+			c.statusTTL = time.Hour
+			c.mu.Unlock()
+			if err := c.BeginPrepareNextCard(context.Background()); err != nil {
+				t.Fatal(err)
+			}
+			if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP", "FC0", "AP", "AP", "AP", "FC7"}) {
+				t.Fatalf("prestaging commands=%v, want clearance APs then one FC7", got)
+			}
+			prepare := c.PrepareCurrentCard
+			if next {
+				prepare = c.PrepareNextCard
+			}
+			if _, err := prepare(context.Background()); err != nil {
+				t.Fatal(err)
+			}
+			want := []string{"AP", "FC0", "AP", "AP", "AP", "FC7", "AP"}
+			if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+				t.Errorf("incident commands=%v, want %v", got, want)
+			}
+			if elapsed := now.Sub(time.Unix(0, 0)); elapsed != 2*time.Second {
+				t.Errorf("clearance waits=%s, want 2s", elapsed)
+			}
+		})
+	}
+}
+
+func TestDeliveryClearWaitsTwoSeconds(t *testing.T) {
+	for _, position := range []byte{0x30, 0x34} {
+		p := &scriptedTransport{chunks: [][]byte{vendorACK,
+			vendorACK, apReply(status(position)), vendorACK, apReply(status(position)), vendorACK, apReply(status(position)),
+			vendorACK, vendorACK, apReply(status(0x37))}}
+		c, now := deliveryWorkerClient(t, p)
+		if _, err := c.DeliverCurrentCard(context.Background()); err != nil {
+			t.Fatal(err)
+		}
+		if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+			t.Fatal(err)
+		}
+		want := []string{"FC0", "AP", "AP", "AP", "FC7", "AP"}
+		if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+			t.Errorf("clearance %X commands=%v, want %v", position, got, want)
+		}
+		if elapsed := now.Sub(time.Unix(0, 0)); elapsed != deliveryMinimumWait {
+			t.Errorf("clearance %X elapsed=%s, want 2s", position, elapsed)
+		}
+	}
+}
+
+func TestDeliveryPendingIsNotPersisted(t *testing.T) {
+	c := NewClient(nil, 1)
+	defer c.Close()
+	if c.deliveryPending {
+		t.Error("new Client has pending delivery")
+	}
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x37))}}
+	fresh, _ := deliveryWorkerClient(t, p)
+	if _, err := fresh.PrepareCurrentCard(context.Background()); err != nil {
+		t.Errorf("fresh client encoder status: %v", err)
+	}
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP"}) {
+		t.Errorf("restart commands=%v, want AP only", got)
+	}
+}
+
+func TestDeliveryCancellationAfterACKDoesNotSetPending(t *testing.T) {
+	transportAddress(t)
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+	p := &scriptedTransport{chunks: [][]byte{vendorACK}, afterRead: cancel}
+	c := &Client{port: p}
+	r := workerRequest(c, ctx, cmdOutOfMouth)
+	if !errors.Is(r.err, context.Canceled) || c.deliveryPending || len(p.writes) != 1 {
+		t.Errorf("cancel after ACK: err=%v pending=%v writes=%d, want canceled, false, 1", r.err, c.deliveryPending, len(p.writes))
+	}
+}
+
+func TestWorkerSerializesClearanceAndFC7(t *testing.T) {
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK, vendorACK, vendorACK, apReply(status(0x37))}}
+	c, _ := deliveryWorkerClient(t, p)
+	// Set initial state before any request can reach the worker.
+	c.deliveryPending = true
+	c.deliveryStarted = c.now().Add(-deliveryMinimumWait)
+	reading := make(chan struct{})
+	resume := make(chan struct{})
+	p.afterWrite = func() {
+		if len(p.writes) == 1 {
+			close(reading)
+			<-resume
+		}
+	}
+	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
+	defer cancel()
+	fc7 := make(chan error, 1)
+	go func() { fc7 <- c.BeginPrepareNextCard(ctx) }()
+	select {
+	case <-reading:
+	case <-ctx.Done():
+		t.Fatal("worker did not begin AP")
+	}
+	fc0 := make(chan cmdResp, 1)
+	// This FC0 is queued while AP is in progress. It must not slip between
+	// the clearance observation and FC7 dispatch.
+	c.reqCh <- cmdReq{typ: cmdOutOfMouth, ctx: ctx, respCh: fc0}
+	close(resume)
+	if err := <-fc7; err != nil {
+		t.Fatal(err)
+	}
+	if r := <-fc0; r.err != nil {
+		t.Fatal(r.err)
+	}
+
+	want := []string{"AP", "FC7", "FC0"}
+	if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+		t.Errorf("serialized commands=%v, want %v", got, want)
+	}
+}
+
+func TestDeliveryCancellationAfterFreshAPKeepsPending(t *testing.T) {
+	transportAddress(t)
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x34))}}
+	p.afterRead = func() {
+		if len(p.chunks) == 0 {
+			cancel()
+		}
+	}
+	c := &Client{port: p, deliveryPending: true, deliveryStarted: time.Now().Add(-time.Minute)}
+	r := workerRequest(c, ctx, cmdToEncoder)
+	if !errors.Is(r.err, context.Canceled) || !c.deliveryPending {
+		t.Errorf("AP cancellation err=%v pending=%t, want canceled and pending", r.err, c.deliveryPending)
+	}
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP"}) {
+		t.Errorf("cancelled clearance commands=%v, want AP only", got)
+	}
+}
+
+func TestPreparationWireFailuresNeverShake(t *testing.T) {
+	badBCC := apReply(status(0x30))
+	badBCC[len(badBCC)-1] ^= 1
+	for _, frame := range [][]byte{nil, apReply(status(0x30))[:8], badBCC, apReply(status(0x40))} {
+		p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK, vendorACK}}
+		if frame != nil {
+			p.chunks = append(p.chunks, frame)
+		}
+		c, _ := deliveryWorkerClient(t, p)
+		if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+			t.Errorf("frame % X: err=%v, want encoder opportunity", frame, err)
+		}
+		want := []string{"AP", "FC7", "AP", "AP", "AP", "AP", "AP"}
+		if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+			t.Errorf("frame % X commands=%v, want %v without RS or resends", frame, got, want)
+		}
+	}
+}
+
+func TestBeginPrepareNextCardWaitsForClearanceWithoutReadinessPolling(t *testing.T) {
+	for _, position := range []byte{0x30, 0x34} {
+		p := &scriptedTransport{chunks: [][]byte{vendorACK,
+			vendorACK, apReply(status(position)), vendorACK, apReply(status(position)), vendorACK, apReply(status(position)),
+			vendorACK}}
+		c, now := deliveryWorkerClient(t, p)
+		if _, err := c.DeliverCurrentCard(context.Background()); err != nil {
+			t.Fatal(err)
+		}
+		if err := c.BeginPrepareNextCard(context.Background()); err != nil {
+			t.Fatal(err)
+		}
+		want := []string{"FC0", "AP", "AP", "AP", "FC7"}
+		if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+			t.Errorf("BeginPrepareNextCard(%X) commands = %v, want %v", position, got, want)
+		}
+		if elapsed := now.Sub(time.Unix(0, 0)); elapsed != deliveryMinimumWait {
+			t.Errorf("BeginPrepareNextCard(%X) waited %s, want %s", position, elapsed, deliveryMinimumWait)
+		}
+	}
+}

internal/dispenser/dispenser.go

@@ -1,8 +1,11 @@
 package dispenser
 
 import (
+	"context"
+	"encoding/binary"
 	"errors"
 	"fmt"
+	"io"
 	"strings"
 	"time"
 
@@ -27,14 +30,25 @@ const (
 	CardWellEmptyMessage = "Card well is empty"
 )
 
+const (
+	positionPreDispense = 0x01
+	positionEncoder     = 0x02
+	positionMouth       = 0x04
+	positionEmpty       = 0x08
+)
+
 var (
 	ErrCardWellEmpty = errors.New(CardWellEmptyMessage)
 
+	// ErrPreparationExhausted permits a new, independent UI preparation attempt.
+	ErrPreparationExhausted = errors.New("card preparation exhausted")
+
 	SerialPort string
 	Address    []byte
 
 	commandFC7 = []byte{ETX, 0x46, 0x43, 0x37} // "FC7"
 	commandFC0 = []byte{ETX, 0x46, 0x43, 0x30} // "FC0"
+	commandRS  = []byte{0x02, 0x52, 0x53}      // Length 2, "RS"
 
 	statusPos0 = map[byte]string{
 		0x38: "Keep",
@@ -58,20 +72,21 @@ var (
 		0x31: "Card pre-empty",
 		0x30: "Normal",
 	}
-	statusPos3 = map[byte]string{
-		0x38: "Card empty",
-		0x34: "Card ready position",
-		0x33: "Card at encoder position",
-		0x32: "Card at hold card position",
-		0x31: "Card out of card mouth position",
-		0x30: "Normal",
-	}
 )
 
 // --------------------
 // Status helpers
 // --------------------
 
+// decodePositionStatus decodes the manual's 0x30 + combined sensor/empty flags.
+// Sensor 2 (0x02) is the read position; sensor 1 and sensor 2 together give 0x33.
+func decodePositionStatus(value byte) (flags byte, valid bool) {
+	if value&0xF0 != 0x30 {
+		return 0, false
+	}
+	return value & 0x0F, true
+}
+
 func statusDescription(statusBytes []byte) string {
 	if len(statusBytes) < 4 {
 		return fmt.Sprintf("<invalid len=%d>", len(statusBytes))
@@ -85,7 +100,6 @@ func statusDescription(statusBytes []byte) string {
 		{pos: 1, value: statusBytes[0], mapper: statusPos0},
 		{pos: 2, value: statusBytes[1], mapper: statusPos1},
 		{pos: 3, value: statusBytes[2], mapper: statusPos2},
-		{pos: 4, value: statusBytes[3], mapper: statusPos3},
 	}
 
 	var result strings.Builder
@@ -98,6 +112,24 @@ func statusDescription(statusBytes []byte) string {
 			result.WriteString(statusMsg + "; ")
 		}
 	}
+	flags, valid := decodePositionStatus(statusBytes[3])
+	if !valid {
+		fmt.Fprintf(&result, "Unknown status 0x%X at position 4; ", statusBytes[3])
+	} else {
+		for _, position := range []struct {
+			mask byte
+			text string
+		}{
+			{positionPreDispense, "Card at pre-dispense position"},
+			{positionEncoder, "Card at encoder position"},
+			{positionMouth, "Card at mouth position"},
+			{positionEmpty, "Card empty"},
+		} {
+			if flags&position.mask != 0 {
+				result.WriteString(position.text + "; ")
+			}
+		}
+	}
 	return result.String()
 }
 
@@ -106,38 +138,42 @@ func logStatus(statusBytes []byte) {
 }
 
 func isAtEncoderPosition(statusBytes []byte) bool {
-	return len(statusBytes) >= 4 && statusBytes[3] == 0x33
+	if len(statusBytes) < 4 {
+		return false
+	}
+	flags, valid := decodePositionStatus(statusBytes[3])
+	return valid && flags&positionEncoder != 0
 }
 
-func validateDispenserStatusData(statusBytes []byte) error {
+type preparationClass string
-	if len(statusBytes) != 4 {
-		return fmt.Errorf("malformed dispenser status: got %d bytes, want 4", len(statusBytes))
-	}
 
-	statusMaps := []map[byte]string{statusPos0, statusPos1, statusPos2, statusPos3}
+const (
-	for position, mapper := range statusMaps {
+	encoderConfirmed  preparationClass = "encoder confirmed"
-		if _, ok := mapper[statusBytes[position]]; !ok {
+	positionUncertain preparationClass = "valid but uncertain"
-			return fmt.Errorf("unknown dispenser status 0x%X at position %d", statusBytes[position], position+1)
+	positionWellEmpty preparationClass = "empty"
-		}
+	positionNoCard    preparationClass = "no card on sensors"
-	}
+)
-	return nil
-}
 
-func dispenserStatusError(statusBytes []byte) error {
+// classifyPreparationStatus is the only readiness gate after AP wire validation.
-	switch statusBytes[0] {
+// Diagnostics describe the device; they do not veto a physical position class.
-	case 0x34, 0x32, 0x36:
+func classifyPreparationStatus(status []byte) (preparationClass, error) {
-		return fmt.Errorf("dispenser error: %s", statusPos0[statusBytes[0]])
+	if len(status) != 4 {
+		return "", fmt.Errorf("malformed dispenser status: got %d bytes, want 4", len(status))
 	}
-	switch statusBytes[1] {
+	flags, valid := decodePositionStatus(status[3])
-	case 0x32, 0x31:
+	if !valid {
-		return fmt.Errorf("dispenser error: %s", statusPos1[statusBytes[1]])
+		return "", fmt.Errorf("malformed dispenser position encoding: 0x%X", status[3])
 	}
-	switch statusBytes[2] {
+	switch {
-	case 0x34, 0x32:
+	case flags&positionEncoder != 0:
-		return fmt.Errorf("dispenser error: %s", statusPos2[statusBytes[2]])
+		return encoderConfirmed, nil
+	case status[3] == 0x38:
+		return positionWellEmpty, nil
+	case status[3] == 0x30:
+		return positionNoCard, nil
+	default:
+		return positionUncertain, nil
 	}
-
-	return nil
 }
 
 func isPreparationMoving(statusBytes []byte) bool {
@@ -145,11 +181,6 @@ func isPreparationMoving(statusBytes []byte) bool {
 		(statusBytes[0] == 0x31 || statusBytes[1] == 0x38)
 }
 
-func hasPreparationDiagnostics(statusBytes []byte) bool {
-	return len(statusBytes) == 4 &&
-		(statusBytes[0] != 0x30 || statusBytes[1] != 0x30 || statusBytes[2] != 0x30)
-}
-
 func stockTake(statusBytes []byte) string {
 	if len(statusBytes) < 4 {
 		return ""
@@ -161,14 +192,18 @@ func stockTake(statusBytes []byte) string {
 	if statusBytes[2] != 0x30 {
 		status = statusPos2[statusBytes[2]]
 	}
-	if statusBytes[3] == 0x38 {
+	if isCardWellEmpty(statusBytes) {
-		status = statusPos3[statusBytes[3]]
+		status = "Card empty"
 	}
 	return status
 }
 
 func isCardWellEmpty(statusBytes []byte) bool {
-	return len(statusBytes) >= 4 && statusBytes[3] == 0x38
+	if len(statusBytes) < 4 {
+		return false
+	}
+	flags, valid := decodePositionStatus(statusBytes[3])
+	return valid && flags&positionEmpty != 0
 }
 
 func checkACK(statusResp []byte) error {
@@ -207,20 +242,154 @@ func createPacket(address []byte, command []byte) []byte {
 
 func buildCheckAP(address []byte) []byte { return createPacket(address, []byte{STX, 0x41, 0x50}) }
 
-func sendAndReceive(port *serial.Port, packet []byte, delay time.Duration) ([]byte, error) {
+// serialTransport is used only by the serial-port owner.
-	_, err := port.Write(packet)
+type serialTransport interface {
-	if err != nil {
+	io.Reader
-		return nil, fmt.Errorf("error writing to port: %w", err)
+	io.Writer
 }
 
-	time.Sleep(delay)
+func writePacket(ctx context.Context, port serialTransport, packet []byte) error {
-
+	_, err := writePacketAttempt(ctx, port, packet)
-	buf := make([]byte, 128)
+	return err
-	n, err := port.Read(buf)
-	if err != nil {
-		return nil, fmt.Errorf("error reading from port: %w", err)
 }
-	return buf[:n], nil
+
+// writePacketAttempt distinguishes cancellation before Write from an ambiguous write.
+func writePacketAttempt(ctx context.Context, port serialTransport, packet []byte) (bool, error) {
+	if err := ctx.Err(); err != nil {
+		return false, err
+	}
+	n, err := port.Write(packet)
+	if err != nil {
+		return true, fmt.Errorf("write dispenser packet: %w", err)
+	}
+	if n != len(packet) {
+		return true, fmt.Errorf("write dispenser packet (%d/%d bytes): %w", n, len(packet), io.ErrShortWrite)
+	}
+	return true, ctx.Err()
+}
+
+func readExact(ctx context.Context, port serialTransport, data []byte) error {
+	for len(data) > 0 {
+		if err := ctx.Err(); err != nil {
+			return err
+		}
+		n, err := port.Read(data)
+		data = data[n:]
+		if ctxErr := ctx.Err(); ctxErr != nil {
+			return ctxErr
+		}
+		if err != nil {
+			return fmt.Errorf("read dispenser response: %w", err)
+		}
+		if n == 0 {
+			return fmt.Errorf("read dispenser response: %w", io.ErrNoProgress)
+		}
+	}
+	return nil
+}
+
+func sendAndReadACK(ctx context.Context, port serialTransport, packet []byte, processingDelay time.Duration) error {
+	if err := writePacket(ctx, port, packet); err != nil {
+		return err
+	}
+	if err := waitForSequence(ctx, processingDelay); err != nil {
+		return err
+	}
+	return readACK(ctx, port)
+}
+
+// readACK scans sequentially without reading beyond a complete candidate.
+// Wrong-address candidates are consumed in full; no bytes persist across calls.
+func readACK(ctx context.Context, port serialTransport) (err error) {
+	const scanLimit = 64
+	seen := make([]byte, 0, scanLimit)
+	defer func() {
+		if err != nil {
+			log.Warnf("dispenser ACK acquisition failed: address=% X seen=% X error=%v", Address, seen, err)
+		}
+	}()
+	var candidate [3]byte
+	used := 0
+	for len(seen) < scanLimit {
+		if err := ctx.Err(); err != nil {
+			return err
+		}
+		need := 1
+		if used > 0 {
+			need = len(candidate) - used
+		}
+		need = min(need, scanLimit-len(seen))
+		chunk := candidate[used : used+need]
+		n, readErr := port.Read(chunk)
+		seen = append(seen, chunk[:n]...)
+		log.Debugf("dispenser ACK RX: address=% X n=%d bytes=% X error=%v", Address, n, chunk[:n], readErr)
+		if err := ctx.Err(); err != nil {
+			return err
+		}
+		used += n
+		if used == 1 && candidate[0] != ACK && candidate[0] != NAK {
+			log.Debugf("dispenser ACK ignored leading byte: % X", candidate[:1])
+			used = 0
+		} else if used == len(candidate) {
+			if len(Address) >= 2 && candidate[1] == Address[0] && candidate[2] == Address[1] {
+				log.Debugf("dispenser ACK/NAK accepted: address=% X token=% X", Address, candidate[:])
+				if candidate[0] == ACK && len(seen) > len(candidate) {
+					log.Warnf("dispenser ACK resynchronized: address=% X ignored=% X accepted=% X", Address, seen[:len(seen)-len(candidate)], candidate[:])
+				}
+				return checkACK(candidate[:])
+			}
+			log.Debugf("dispenser ACK ignored wrong-address candidate: address=% X candidate=% X", Address, candidate[:])
+			used = 0
+		}
+		if readErr != nil {
+			return fmt.Errorf("read ACK: %w", readErr)
+		}
+		if n == 0 {
+			return fmt.Errorf("read ACK: %w", io.ErrNoProgress)
+		}
+	}
+	return fmt.Errorf("read ACK: scan limit of %d bytes exhausted", scanLimit)
+}
+
+// queryStatus accepts only the fixed RF/AP payload sizes, before reading a body.
+func queryStatus(ctx context.Context, port serialTransport, command []byte, statusCount int, processingDelay time.Duration) ([]byte, error) {
+	if err := sendAndReadACK(ctx, port, createPacket(Address, command), processingDelay); err != nil {
+		return nil, err
+	}
+	if err := writePacket(ctx, port, append([]byte{ENQ}, Address...)); err != nil {
+		return nil, err
+	}
+	if err := waitForSequence(ctx, processingDelay); err != nil {
+		return nil, err
+	}
+	header := make([]byte, 5)
+	if err := readExact(ctx, port, header); err != nil {
+		return nil, fmt.Errorf("read status header: %w", err)
+	}
+	if header[0] != STX {
+		return nil, fmt.Errorf("invalid status STX: % X", header)
+	}
+	if len(Address) != 2 || header[1] != Address[0] || header[2] != Address[1] {
+		return nil, fmt.Errorf("unexpected status address: % X", header[1:3])
+	}
+	length := int(binary.BigEndian.Uint16(header[3:5]))
+	if length != statusCount+2 {
+		return nil, fmt.Errorf("invalid status payload length: got %d, want %d", length, statusCount+2)
+	}
+	frame := append(header, make([]byte, length+2)...)
+	if err := readExact(ctx, port, frame[5:]); err != nil {
+		return nil, fmt.Errorf("read status body: %w", err)
+	}
+	if frame[len(frame)-2] != ETX {
+		return nil, fmt.Errorf("invalid status ETX: % X", frame)
+	}
+	if calculateBCC(frame[:len(frame)-1]) != frame[len(frame)-1] {
+		return nil, fmt.Errorf("invalid status BCC: % X", frame)
+	}
+	if frame[5] != 'S' || frame[6] != 'F' {
+		return nil, fmt.Errorf("unexpected status response type: % X", frame[5:7])
+	}
+	return frame[7 : 7+statusCount], nil
 }
 
 // --------------------
@@ -270,69 +439,31 @@ func InitializeDispenser() (*serial.Port, error) {
 // --------------------
 
 // checkDispenserStatus talks to the device and returns the 4 status bytes [pos0..pos3].
-func checkDispenserStatus(port *serial.Port) ([]byte, error) {
+func checkDispenserStatus(ctx context.Context, port serialTransport) ([]byte, error) {
-	checkCmd := buildCheckAP(Address)
+	return queryStatus(ctx, port, []byte{0x02, 'A', 'P'}, 4, delay)
-	enq := append([]byte{ENQ}, Address...)
-
-	statusResp, err := sendAndReceive(port, checkCmd, delay)
-	if err != nil {
-		return nil, fmt.Errorf("error sending check command: %w", err)
-	}
-	if len(statusResp) == 0 {
-		return nil, fmt.Errorf("no response from dispenser")
-	}
-	if err := checkACK(statusResp); err != nil {
-		return nil, err
 }
 
-	statusResp, err = sendAndReceive(port, enq, delay)
+// dispatchCommand confirms ACK and sends ENQ; it does not wait for movement.
-	if err != nil {
+func dispatchCommand(ctx context.Context, port serialTransport, command []byte, processingDelay time.Duration) error {
-		return nil, fmt.Errorf("error sending ENQ: %w", err)
+	if err := sendAndReadACK(ctx, port, createPacket(Address, command), processingDelay); err != nil {
+		return err
 	}
-	if len(statusResp) < 13 {
+	return writePacket(ctx, port, append([]byte{ENQ}, Address...))
-		return nil, fmt.Errorf("incomplete status response from dispenser: % X", statusResp)
-	}
-	return statusResp[7:11], nil
 }
 
-func cardToEncoderPosition(port *serial.Port) error {
+func cardToEncoderPosition(ctx context.Context, port serialTransport) error {
-	enq := append([]byte{ENQ}, Address...)
-
-	dispenseCmd := createPacket(Address, commandFC7)
 	log.Println("Send card to encoder position")
-
+	return dispatchCommand(ctx, port, commandFC7, delay)
-	statusResp, err := sendAndReceive(port, dispenseCmd, delay)
-	if err != nil {
-		return fmt.Errorf("error sending card to encoder position: %w", err)
-	}
-	if err := checkACK(statusResp); err != nil {
-		return err
 }
 
-	_, err = port.Write(enq)
+func resetDispenser(ctx context.Context, port serialTransport) error {
-	if err != nil {
+	return dispatchCommand(ctx, port, commandRS, delay)
-		return fmt.Errorf("error sending ENQ to prompt device: %w", err)
-	}
-	return nil
 }
 
-func cardOutOfMouth(port *serial.Port) error {
+func cardOutOfMouth(ctx context.Context, port serialTransport) (bool, error) {
-	enq := append([]byte{ENQ}, Address...)
-
-	dispenseCmd := createPacket(Address, commandFC0)
 	log.Println("Send card to out mouth position")
-
+	if err := sendAndReadACK(ctx, port, createPacket(Address, commandFC0), delay); err != nil {
-	statusResp, err := sendAndReceive(port, dispenseCmd, delay)
+		return false, err
-	if err != nil {
-		return fmt.Errorf("error sending out of mouth command: %w", err)
 	}
-	if err := checkACK(statusResp); err != nil {
+	return writePacketAttempt(ctx, port, append([]byte{ENQ}, Address...))
-		return err
-	}
-
-	_, err = port.Write(enq)
-	if err != nil {
-		return fmt.Errorf("error sending ENQ to prompt device: %w", err)
-	}
-	return nil
 }

internal/dispenser/dispenserclient.go

@@ -3,6 +3,7 @@ package dispenser
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"sync"
 	"time"
@@ -17,15 +18,20 @@ const (
 	cmdStatus cmdType = iota
 	cmdToEncoder
 	cmdOutOfMouth
+	cmdReset
+	cmdDeliveryClearance
 )
 
 type cmdReq struct {
+	passive    bool
+	generation uint64
 	typ        cmdType
 	ctx        context.Context
 	respCh     chan cmdResp
 }
 
 type cmdResp struct {
+	deliveryPending bool
 	status          []byte
 	err             error
 }
@@ -37,16 +43,28 @@ type sequenceTiming struct {
 
 const (
 	sequencePollInterval     = time.Second
-	sequenceRetryAfter   = 6 * time.Second
+	sequenceShakeAfter       = 3 * time.Second
-	sequenceTimeout      = 12 * time.Second
+	sequenceResetWait        = 2 * time.Second
+	sequenceTimeout          = 32 * time.Second
+	sequenceUncertainWait    = 4 * time.Second
+	sequenceMaxShakes        = 3
+	deliveryClearanceTimeout = 6 * time.Second
+	deliveryMinimumWait      = 2 * time.Second
 )
 
 type Client struct {
-	port *serial.Port
+	activity     activityGuard
+	activityWake chan struct{}
+	closeOnce    sync.Once
+	port         serialTransport
 
 	reqCh chan cmdReq
 	done  chan struct{}
 
+	// Owned exclusively by the serial worker.
+	deliveryPending bool
+	deliveryStarted time.Time
+
 	sequenceTiming sequenceTiming
 
 	// status cache
@@ -67,6 +85,7 @@ func NewClient(port *serial.Port, queueSize int) *Client {
 		queueSize = 16
 	}
 	c := &Client{
+		activityWake: make(chan struct{}, 1),
 		port:         port,
 		reqCh:        make(chan cmdReq, queueSize),
 		done:         make(chan struct{}),
@@ -93,12 +112,13 @@ func waitForSequence(ctx context.Context, duration time.Duration) error {
 }
 
 func (c *Client) Close() {
-	select {
+	c.closeOnce.Do(func() {
-	case <-c.done:
+		c.activity.Lock()
-		return
+		c.activity.closed = true
-	default:
+		c.activity.Unlock()
+		c.StopMaintenance()
 		close(c.done)
-	}
+	})
 }
 
 // SetStatusTTL sets the duration for which cached status is considered fresh.
@@ -137,7 +157,7 @@ func (c *Client) setStock(statusBytes []byte) {
 }
 
 // StartPolling performs a periodic status refresh.
-// It will NOT interrupt commands: it enqueues only when queue is idle.
+// Passive requests are admitted by the worker only for the captured idle generation.
 func (c *Client) StartPolling(interval time.Duration) {
 	if interval <= 0 {
 		return
@@ -155,8 +175,13 @@ func (c *Client) StartPolling(interval time.Duration) {
 				if len(c.reqCh) != 0 {
 					continue
 				}
+				generation, idle := c.passiveGeneration()
+				if !idle {
+					continue
+				}
 				ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second)
-				_, err := c.CheckStatus(ctx)
+				response := c.sendRequest(cmdReq{typ: cmdStatus, ctx: ctx, passive: true, generation: generation})
+				err := response.err
 				if err != nil {
 					log.Debugf("dispenser polling: %v", err)
 				}
@@ -167,12 +192,28 @@ func (c *Client) StartPolling(interval time.Duration) {
 }
 
 func (c *Client) loop() {
+	timer := time.NewTimer(time.Hour)
+	defer timer.Stop()
 	for {
+		if !timer.Stop() {
+			select {
+			case <-timer.C:
+			default:
+			}
+		}
+		var tick <-chan time.Time
+		if delay, enabled := c.maintenanceDelay(); enabled {
+			timer.Reset(delay)
+			tick = timer.C
+		}
 		select {
 		case <-c.done:
 			return
+		case <-c.activityWake:
 		case req := <-c.reqCh:
 			c.handle(req)
+		case <-tick:
+			c.maintainIdleCard()
 		}
 	}
 }
@@ -185,26 +226,58 @@ func (c *Client) handle(req cmdReq) {
 	default:
 	}
 
+	if req.passive {
+		if !c.admitPassive(req.ctx, req.generation) {
+			req.respCh <- cmdResp{}
+			return
+		}
+		c.mu.RLock()
+		st := append([]byte(nil), c.lastStatus...)
+		fresh := len(st) == 4 && time.Since(c.lastStatusT) <= c.statusTTL
+		c.mu.RUnlock()
+		if fresh {
+			c.setStock(st)
+			req.respCh <- cmdResp{status: st}
+			return
+		}
+	}
 	switch req.typ {
 	case cmdStatus:
-		st, err := checkDispenserStatus(c.port)
+		st, err := c.readWorkerStatus(req.ctx)
-		if err == nil && len(st) == 4 {
+		req.respCh <- cmdResp{status: st, err: err, deliveryPending: c.deliveryPending}
-			c.mu.Lock()
-			c.lastStatus = append([]byte(nil), st...)
-			c.lastStatusT = time.Now()
-			c.mu.Unlock()
 
-			// publish stock/cardwell
+	case cmdDeliveryClearance:
-			c.setStock(st)
+		st, err := c.waitWorkerDeliveryClearance(req.ctx)
-		}
+		req.respCh <- cmdResp{status: st, err: err, deliveryPending: c.deliveryPending}
-		req.respCh <- cmdResp{status: st, err: err}
 
 	case cmdToEncoder:
-		err := cardToEncoderPosition(c.port)
+		if c.deliveryPending {
+			if _, err := c.waitWorkerDeliveryClearance(req.ctx); err != nil {
+				req.respCh <- cmdResp{err: err}
+				return
+			}
+		}
+		err := cardToEncoderPosition(req.ctx, c.port)
+		log.Infof("FC7 dispatch finished; dispatched=%t error=%v", err == nil, err)
+		c.invalidateStatusCache()
+		req.respCh <- cmdResp{err: err}
+
+	case cmdReset:
+		err := resetDispenser(req.ctx, c.port)
+		log.Infof("RS dispatch finished; dispatched=%t error=%v", err == nil, err)
+		c.invalidateStatusCache()
 		req.respCh <- cmdResp{err: err}
 
 	case cmdOutOfMouth:
-		err := cardOutOfMouth(c.port)
+		attempted, err := cardOutOfMouth(req.ctx, c.port)
+		log.Infof("FC0 dispatch finished; ENQ_attempted=%t error=%v", attempted, err)
+		if attempted {
+			c.deliveryPending = true
+			c.deliveryStarted = c.now()
+			log.Info("delivery ENQ attempted; awaiting mechanical clearance")
+		}
+		// A movement command makes any previously cached position unreliable.
+		c.invalidateStatusCache()
 		req.respCh <- cmdResp{err: err}
 
 	default:
@@ -212,21 +285,91 @@ func (c *Client) handle(req cmdReq) {
 	}
 }
 
-func (c *Client) do(ctx context.Context, typ cmdType) ([]byte, error) {
+// deliveryClearance deliberately does not apply encoder-success precedence.
-	rch := make(chan cmdResp, 1)
+func deliveryClearance(status []byte) (bool, error) {
-	req := cmdReq{typ: typ, ctx: ctx, respCh: rch}
+	class, err := classifyPreparationStatus(status)
-
+	if err != nil {
-	select {
+		return false, err
-	case c.reqCh <- req:
+	}
-	case <-ctx.Done():
+	if class == positionWellEmpty {
-		return nil, ctx.Err()
+		return false, ErrCardWellEmpty
+	}
+	if isPreparationMoving(status) || status[1] == 0x34 {
+		return false, nil
+	}
+	return status[3] == 0x30 || status[3] == 0x34, nil
 }
 
-	select {
+func (c *Client) now() time.Time {
-	case r := <-rch:
+	if c.sequenceTiming.now != nil {
+		return c.sequenceTiming.now()
+	}
+	return time.Now()
+}
+
+// readWorkerStatus is called only by the serial worker and always reads fresh AP.
+func (c *Client) readWorkerStatus(ctx context.Context) ([]byte, error) {
+	st, err := checkDispenserStatus(ctx, c.port)
+	if err != nil {
+		return st, err
+	}
+	if err := ctx.Err(); err != nil {
+		return st, err
+	}
+	if c.deliveryPending {
+		class, _ := classifyPreparationStatus(st)
+		log.Infof("delivery clearance AP; class=%s elapsed=%s raw status: % X", class, c.now().Sub(c.deliveryStarted), st)
+		clear, clearanceErr := deliveryClearance(st)
+		if clearanceErr != nil {
+			log.Warnf("delivery clearance failed: %v; %s raw status: % X", clearanceErr, statusDescription(st), st)
+		} else if clear && c.now().Sub(c.deliveryStarted) >= deliveryMinimumWait {
+			c.deliveryPending = false
+			log.Infof("previous delivery cleared after %s; FC7 permitted", c.now().Sub(c.deliveryStarted))
+		}
+	}
+	if len(st) == 4 {
+		c.mu.Lock()
+		c.lastStatus = append([]byte(nil), st...)
+		c.lastStatusT = time.Now()
+		c.mu.Unlock()
+		c.setStock(st)
+	}
+	return st, nil
+}
+
+func (c *Client) do(ctx context.Context, typ cmdType) ([]byte, error) {
+	r := c.doResponse(ctx, typ)
 	return r.status, r.err
-	case <-ctx.Done():
+}
-		return nil, ctx.Err()
+
+func (c *Client) doResponse(ctx context.Context, typ cmdType) cmdResp {
+	return c.sendRequest(cmdReq{typ: typ, ctx: ctx})
+}
+
+func (c *Client) sendRequest(req cmdReq) cmdResp {
+	if err := req.ctx.Err(); err != nil {
+		return cmdResp{err: err}
+	}
+	req.respCh = make(chan cmdResp, 1)
+	select {
+	case <-c.done:
+		return cmdResp{err: context.Canceled}
+	default:
+	}
+	select {
+	case c.reqCh <- req:
+	case <-c.done:
+		return cmdResp{err: context.Canceled}
+	case <-req.ctx.Done():
+		return cmdResp{err: req.ctx.Err()}
+	}
+	select {
+	case r := <-req.respCh:
+		return r
+	case <-c.done:
+		return cmdResp{err: context.Canceled}
+	case <-req.ctx.Done():
+		return cmdResp{err: req.ctx.Err()}
 	}
 }
 
@@ -246,11 +389,24 @@ func (c *Client) CheckStatus(ctx context.Context) ([]byte, error) {
 	return c.do(ctx, cmdStatus)
 }
 
+func (c *Client) invalidateStatusCache() {
+	c.mu.Lock()
+	c.lastStatus = nil
+	c.lastStatusT = time.Time{}
+	c.mu.Unlock()
+}
+
 func (c *Client) ToEncoder(ctx context.Context) error {
 	_, err := c.do(ctx, cmdToEncoder)
 	return err
 }
 
+// Reset dispatches RS through the port owner; acceptance does not imply mechanical completion.
+func (c *Client) Reset(ctx context.Context) error {
+	_, err := c.do(ctx, cmdReset)
+	return err
+}
+
 func (c *Client) OutOfMouth(ctx context.Context) error {
 	_, err := c.do(ctx, cmdOutOfMouth)
 	return err
@@ -298,13 +454,14 @@ func (c *Client) DispenserPrepare(ctx context.Context) (string, error) {
 }
 
 func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]byte, string, error) {
-	status, err := c.do(ctx, cmdStatus)
+	response := c.doResponse(ctx, cmdStatus)
-	if err != nil {
+	if err := ctx.Err(); err != nil {
-		if ctxErr := ctx.Err(); ctxErr != nil {
+		return nil, "", err
-			return nil, "", fmt.Errorf("[%s] read status: %w", operation, ctxErr)
 	}
-		return nil, "", fmt.Errorf("[%s] read status: %w", operation, err)
+	if response.deliveryPending {
+		return c.waitForDeliveryClearance(ctx, operation)
 	}
+	status := usableObservation(response.status, response.err, operation)
 
 	stockStatus := ""
 	if len(status) == 4 {
@@ -315,111 +472,236 @@ func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]by
 	return status, stockStatus, nil
 }
 
-func preparationStatus(operation string, status []byte) (bool, error) {
+// waitWorkerDeliveryClearance runs only inside the serial worker.
-	if len(status) != 4 {
+// An unusable observation never becomes a fabricated physical position.
-		return false, fmt.Errorf("[%s] %w", operation, validateDispenserStatusData(status))
+func (c *Client) waitWorkerDeliveryClearance(parent context.Context) ([]byte, error) {
-	}
+	ctx, cancel := context.WithTimeout(parent, deliveryClearanceTimeout)
-	if isAtEncoderPosition(status) {
+	defer cancel()
-		if hasPreparationDiagnostics(status) {
+	deadline := c.now().Add(deliveryClearanceTimeout)
-			log.Warnf(
+	var latest []byte
-				"[%s] card confirmed at encoder with dispenser diagnostics: %s raw status: % X",
-				operation,
-				statusDescription(status),
-				status,
-			)
-		}
-		return true, nil
-	}
-	if err := validateDispenserStatusData(status); err != nil {
-		return false, fmt.Errorf("[%s] %w", operation, err)
-	}
-	if isCardWellEmpty(status) {
-		return false, fmt.Errorf("[%s] %w", operation, ErrCardWellEmpty)
-	}
-	if isPreparationMoving(status) {
-		return false, nil
-	}
-	if err := dispenserStatusError(status); err != nil {
-		return false, fmt.Errorf("[%s] %w", operation, err)
-	}
-	return false, nil
-}
-
-func (c *Client) pollForEncoderPosition(
-	ctx context.Context,
-	operation string,
-	retryCommand func(context.Context) error,
-) (string, error) {
-	started := c.sequenceTiming.now()
-	halfway := started.Add(sequenceRetryAfter)
-	deadline := started.Add(sequenceTimeout)
-	retried := false
-	stockStatus := ""
-
 	for {
-		if err := ctx.Err(); err != nil {
+		if err := parent.Err(); err != nil {
-			return stockStatus, fmt.Errorf("[%s] %w", operation, err)
+			return nil, err
 		}
-
+		if !c.now().Before(deadline) || ctx.Err() != nil {
-		now := c.sequenceTiming.now()
+			class, err := classifyPreparationStatus(latest)
-		if !now.Before(deadline) {
+			if err == nil && class == positionWellEmpty {
-			return stockStatus, fmt.Errorf("[%s] timed out after %s", operation, sequenceTimeout)
+				return latest, ErrCardWellEmpty
 			}
-
+			if err == nil && (isPreparationMoving(latest) || latest[1] == 0x34) {
-		status, currentStockStatus, err := c.readSequenceStatus(ctx, operation)
+				return latest, context.DeadlineExceeded
-		stockStatus = currentStockStatus
-		if err != nil {
-			return stockStatus, err
 			}
-		ready, err := preparationStatus(operation, status)
+			c.deliveryPending = false
-		if err != nil {
+			log.Warn("delivery clearance assumed after bounded observation fallback")
-			return stockStatus, err
+			return latest, nil
 		}
-		if ready {
+		st, err := c.readWorkerStatus(ctx)
-			return stockStatus, nil
+		if parent.Err() != nil {
+			return nil, parent.Err()
 		}
-
+		latest = usableObservation(st, err, "delivery clearance")
-		now = c.sequenceTiming.now()
+		if latest != nil && latest[3] == 0x38 {
-		if !now.Before(deadline) {
+			return latest, ErrCardWellEmpty
-			return stockStatus, fmt.Errorf("[%s] timed out after %s", operation, sequenceTimeout)
 		}
-		if retryCommand != nil && !retried && !now.Before(halfway) {
+		if !c.deliveryPending {
-			if err := retryCommand(ctx); err != nil {
+			return latest, nil
-				return stockStatus, fmt.Errorf("[%s] retry command: %w", operation, err)
 		}
-			retried = true
+		remaining := deadline.Sub(c.now())
+		if remaining <= 0 || ctx.Err() != nil {
+			continue
 		}
-
 		wait := sequencePollInterval
-		if remaining := deadline.Sub(now); remaining < wait {
+		if remaining < wait {
 			wait = remaining
 		}
-		if err := c.sequenceTiming.wait(ctx, wait); err != nil {
+		if err := c.sequenceTiming.wait(ctx, wait); err != nil && parent.Err() != nil {
-			return stockStatus, fmt.Errorf("[%s] %w", operation, err)
+			return nil, parent.Err()
 		}
 	}
 }
 
-func (c *Client) prepareCardAtEncoder(ctx context.Context, operation string) (string, error) {
+// usableObservation preserves strict validation while discarding unusable telemetry.
-	status, stockStatus, err := c.readSequenceStatus(ctx, operation)
+func usableObservation(status []byte, err error, operation string) []byte {
+	if err == nil {
+		_, err = classifyPreparationStatus(status)
+	}
 	if err != nil {
-		return stockStatus, err
+		log.Warnf("[%s] unusable AP observation; raw status: % X error=%v", operation, status, err)
+		return nil
 	}
-	ready, err := preparationStatus(operation, status)
+	return status
+}
+
+// waitForDeliveryClearance uses a worker request; no worker recursively enqueues.
+func (c *Client) waitForDeliveryClearance(ctx context.Context, operation string) ([]byte, string, error) {
+	r := c.doResponse(ctx, cmdDeliveryClearance)
+	stock := ""
+	if len(r.status) == 4 {
+		stock = stockTake(r.status)
+	}
+	if r.err != nil {
+		return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, r.err)
+	}
+	return r.status, stock, nil
+}
+
+func (c *Client) prepareCardAtEncoder(parent context.Context, operation string) (stock string, resultErr error) {
+	status, stock, err := c.waitForDeliveryClearance(parent, operation)
 	if err != nil {
-		return stockStatus, err
+		return stock, err
+	}
+	status = usableObservation(status, nil, operation)
+	started := c.now()
+	deadline := started.Add(sequenceTimeout)
+	ctx, cancel := context.WithTimeoutCause(parent, sequenceTimeout, ErrPreparationExhausted)
+	defer cancel()
+	shakes := 0
+	stage := "initial status"
+	var lastFC7, uncertainSince time.Time
+	var previous preparationClass
+	defer func() {
+		log.Infof("[%s] preparation finished; stage=%s shakes=%d elapsed=%s raw status: % X error=%v", operation, stage, shakes, c.now().Sub(started), status, resultErr)
+	}()
+	checkDeadline := func() error {
+		if err := parent.Err(); err != nil {
+			return err
+		}
+		if !c.now().Before(deadline) || errors.Is(context.Cause(ctx), ErrPreparationExhausted) {
+			return ErrPreparationExhausted
+		}
+		return ctx.Err()
+	}
+	// Only observation exhaustion can grant a deadline handoff. Command and
+	// reset-settle failures never pass through this policy.
+	observationResult := func(err error) error {
+		if parent.Err() != nil {
+			return parent.Err()
+		}
+		if !errors.Is(err, ErrPreparationExhausted) || lastFC7.IsZero() {
+			return err
+		}
+		class, _ := classifyPreparationStatus(status)
+		switch class {
+		case positionWellEmpty:
+			return ErrCardWellEmpty
+		case positionNoCard:
+			return err
+		default:
+			stage = "observation deadline encoder handoff"
+			return nil
+		}
+	}
+	wait := func(duration time.Duration) error {
+		if err := checkDeadline(); err != nil {
+			return err
+		}
+		if remaining := deadline.Sub(c.now()); remaining < duration {
+			duration = remaining
+		}
+		if err := c.sequenceTiming.wait(ctx, duration); err != nil {
+			if deadlineErr := checkDeadline(); deadlineErr != nil {
+				return deadlineErr
+			}
+			return err
+		}
+		return checkDeadline()
+	}
+	sendFC7 := func() error {
+		stage = "FC7 dispatch"
+		if err := checkDeadline(); err != nil {
+			return err
+		}
+		err := c.ToEncoder(ctx)
+		if deadlineErr := checkDeadline(); deadlineErr != nil {
+			return deadlineErr
+		}
+		if err != nil {
+			return fmt.Errorf("[%s] FC7 dispatch: %w", operation, err)
+		}
+		lastFC7 = c.now()
+		log.Infof("[%s] FC7 dispatched; shake=%d elapsed=%s", operation, shakes, lastFC7.Sub(started))
+		return nil
+	}
+	for {
+		if err := checkDeadline(); err != nil {
+			return stock, observationResult(err)
+		}
+		class, _ := classifyPreparationStatus(status)
+		// No class means unusable telemetry, sharing the uncertainty timer.
+
+		log.Infof("[%s] fresh AP; class=%s previous=%s elapsed=%s shake=%d raw status: % X", operation, class, previous, c.now().Sub(started), shakes, status)
+		previous = class
+		switch class {
+		case encoderConfirmed:
+			stage = "encoder sensor handoff"
+			return stock, observationResult(checkDeadline())
+		case positionWellEmpty:
+			stage = "empty"
+			return stock, ErrCardWellEmpty
+		}
+		if lastFC7.IsZero() {
+			if err := sendFC7(); err != nil {
+				return stock, err
+			}
+		} else if class == positionNoCard && c.now().Sub(lastFC7) >= sequenceShakeAfter {
+			uncertainSince = time.Time{}
+			if shakes == sequenceMaxShakes {
+				stage = "three shakes exhausted"
+				return stock, ErrPreparationExhausted
+			}
+			shakes++
+			stage = "RS dispatch"
+			if err := checkDeadline(); err != nil {
+				return stock, err
+			}
+			err := c.Reset(ctx)
+			if deadlineErr := checkDeadline(); deadlineErr != nil {
+				return stock, deadlineErr
+			}
+			if err != nil {
+				return stock, fmt.Errorf("[%s] RS dispatch: %w", operation, err)
+			}
+			stage = "reset settling"
+			log.Infof("[%s] RS dispatched; shake=%d settling=%s", operation, shakes, sequenceResetWait)
+			if err := wait(sequenceResetWait); err != nil {
+				return stock, err
+			}
+			log.Infof("[%s] reset settle wait completed; shake=%d", operation, shakes)
+			if err := sendFC7(); err != nil {
+				return stock, err
+			}
+		} else {
+			if class == positionUncertain || class == "" {
+				if uncertainSince.IsZero() {
+					uncertainSince = c.now()
+				}
+				if c.now().Sub(uncertainSince) >= sequenceUncertainWait {
+					stage = "uncertain position handoff"
+					return stock, observationResult(checkDeadline())
+				}
+			} else {
+				uncertainSince = time.Time{}
+			}
+			stage = "polling"
+			if err := wait(sequencePollInterval); err != nil {
+				return stock, observationResult(err)
+			}
+		}
+		stage = "fresh AP"
+		if err := checkDeadline(); err != nil {
+			return stock, observationResult(err)
+		}
+		status, stock, err = c.readSequenceStatus(ctx, operation)
+		if deadlineErr := checkDeadline(); deadlineErr != nil {
+			return stock, observationResult(deadlineErr)
+		}
+		if err != nil {
+			return stock, err
+		}
 	}
-	if ready {
-		return stockStatus, nil
 }
 
-	if err := c.ToEncoder(ctx); err != nil {
+// PrepareCurrentCard grants one encoder opportunity after bounded physical preparation.
-		return stockStatus, fmt.Errorf("[%s] to encoder: %w", operation, err)
-	}
-	return c.pollForEncoderPosition(ctx, operation, c.ToEncoder)
-}
-
-// PrepareCurrentCard authoritatively places the card to be encoded at the encoder.
 func (c *Client) PrepareCurrentCard(ctx context.Context) (string, error) {
 	return c.prepareCardAtEncoder(ctx, "PrepareCurrentCard")
 }
@@ -434,7 +716,8 @@ func (c *Client) DeliverCurrentCard(ctx context.Context) (string, error) {
 	return "", nil
 }
 
-// BeginPrepareNextCard starts moving the next card to the encoder without waiting for readiness.
+// BeginPrepareNextCard waits for worker-owned clearance and dispatches one FC7.
+// It does not wait for encoder readiness.
 func (c *Client) BeginPrepareNextCard(ctx context.Context) error {
 	if err := c.ToEncoder(ctx); err != nil {
 		return fmt.Errorf("[BeginPrepareNextCard] to encoder: %w", err)
@@ -442,7 +725,7 @@ func (c *Client) BeginPrepareNextCard(ctx context.Context) error {
 	return nil
 }
 
-// PrepareNextCard places a new card at the encoder for a later issuance attempt.
+// PrepareNextCard runs the same bounded physical preparation for a later issuance attempt.
 func (c *Client) PrepareNextCard(ctx context.Context) (string, error) {
 	return c.prepareCardAtEncoder(ctx, "PrepareNextCard")
 }

internal/dispenser/dispenserclient_test.go

@@ -4,17 +4,19 @@ import (
 	"bytes"
 	"context"
 	"errors"
+	"fmt"
+	"reflect"
 	"strings"
 	"testing"
 	"time"
-
-	log "github.com/sirupsen/logrus"
 )
 
 type fakeSequenceDevice struct {
 	statusResponses []cmdResp
 	commandErrors   map[cmdType][]error
 	commands        []cmdType
+	commandTimes    []time.Time
+	onCommand       func(cmdType)
 }
 
 func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *fakeSequenceDevice) {
@@ -50,13 +52,25 @@ func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *
 			case <-client.done:
 				return
 			case request := <-client.reqCh:
+				clearance := request.typ == cmdDeliveryClearance
+				if clearance {
+					request.typ = cmdStatus
+				}
 				device.commands = append(device.commands, request.typ)
+				device.commandTimes = append(device.commandTimes, now)
+				if device.onCommand != nil {
+					device.onCommand(request.typ)
+				}
 				if request.typ == cmdStatus {
 					if len(device.statusResponses) == 0 {
 						request.respCh <- cmdResp{err: errors.New("unexpected status read")}
 						continue
 					}
 					response := device.statusResponses[0]
+					if clearance && request.ctx.Err() == nil {
+						response.status = usableObservation(response.status, response.err, "fake clearance")
+						response.err = nil
+					}
 					device.statusResponses = device.statusResponses[1:]
 					request.respCh <- response
 					continue
@@ -90,142 +104,11 @@ func commandCount(commands []cmdType, target cmdType) int {
 	return count
 }
 
-func TestPrepareCurrentCardAcceptsEncoderPositionWithStaleDiagnostics(t *testing.T) {
+func TestResetPacket(t *testing.T) {
-	tests := []struct {
+	got := createPacket([]byte{0x30, 0x30}, commandRS)
-		name      string
+	want := []byte{0x02, 0x30, 0x30, 0x00, 0x02, 0x52, 0x53, 0x03, 0x02}
-		status    []byte
+	if !bytes.Equal(got, want) {
-		wantStock string
+		t.Errorf("createPacket(RS) = % X, want % X", got, want)
-	}{
-		{
-			name:      "dispense error and jam",
-			status:    []byte{0x30, 0x32, 0x32, 0x33},
-			wantStock: "Card jammed",
-		},
-		{
-			name:      "supply diagnostics",
-			status:    []byte{0x32, 0x30, 0x31, 0x33},
-			wantStock: "Card pre-empty",
-		},
-		{
-			name:   "combined stale jam and supply diagnostics",
-			status: []byte{0x30, 0x32, 0x33, 0x33},
-		},
-	}
-
-	for _, test := range tests {
-		t.Run(test.name, func(t *testing.T) {
-			var logOutput bytes.Buffer
-			standardLogger := log.StandardLogger()
-			previousOutput := standardLogger.Out
-			standardLogger.SetOutput(&logOutput)
-			t.Cleanup(func() {
-				standardLogger.SetOutput(previousOutput)
-			})
-
-			client, device := newSequenceTestClient(t, cmdResp{status: test.status})
-
-			stock, err := client.PrepareCurrentCard(context.Background())
-			if err != nil {
-				t.Fatal(err)
-			}
-			if stock != test.wantStock {
-				t.Fatalf("stock status = %q, want %q", stock, test.wantStock)
-			}
-			if got := commandCount(device.commands, cmdToEncoder); got != 0 {
-				t.Fatalf("to-encoder commands = %d, want 0", got)
-			}
-			if got := commandCount(device.commands, cmdStatus); got != 1 {
-				t.Fatalf("status reads = %d, want 1", got)
-			}
-			logged := logOutput.String()
-			if !strings.Contains(logged, "card confirmed at encoder") ||
-				!strings.Contains(logged, statusDescription(test.status)) ||
-				!strings.Contains(logged, "raw status") {
-				t.Fatalf("encoder diagnostic log = %q", logged)
-			}
-		})
-	}
-}
-
-func TestPrepareCurrentCardPollingAllowsTransientMovementWithStaleErrors(t *testing.T) {
-	client, device := newSequenceTestClient(t,
-		cmdResp{status: status(0x34)},
-		cmdResp{status: []byte{0x31, 0x38, 0x32, 0x30}},
-		cmdResp{status: []byte{0x30, 0x32, 0x32, 0x33}},
-	)
-
-	stock, err := client.PrepareCurrentCard(context.Background())
-	if err != nil {
-		t.Fatal(err)
-	}
-	if stock != "Card jammed" {
-		t.Fatalf("stock status = %q, want Card jammed", stock)
-	}
-	if got := commandCount(device.commands, cmdToEncoder); got != 1 {
-		t.Fatalf("to-encoder commands = %d, want 1", got)
-	}
-	if got := commandCount(device.commands, cmdStatus); got != 3 {
-		t.Fatalf("status reads = %d, want 3", got)
-	}
-}
-
-func TestPrepareCurrentCardRejectsFailureWithoutEncoderOrMovement(t *testing.T) {
-	tests := []struct {
-		name      string
-		response  cmdResp
-		wantError string
-		wantStock string
-	}{
-		{
-			name:      "status read error",
-			response:  cmdResp{err: errors.New("serial read failed")},
-			wantError: "serial read failed",
-		},
-		{
-			name:      "malformed status",
-			response:  cmdResp{status: []byte{0x30, 0x30, 0x31}},
-			wantError: "malformed dispenser status",
-		},
-		{
-			name:      "unknown status",
-			response:  cmdResp{status: []byte{0x30, 0x30, 0x30, 0x39}},
-			wantError: "unknown dispenser status",
-		},
-		{
-			name:      "jammed preparation",
-			response:  cmdResp{status: []byte{0x30, 0x30, 0x32, 0x34}},
-			wantError: "Card jammed",
-			wantStock: "Card jammed",
-		},
-	}
-
-	for _, test := range tests {
-		t.Run(test.name, func(t *testing.T) {
-			client, _ := newSequenceTestClient(t, test.response)
-
-			stock, err := client.PrepareCurrentCard(context.Background())
-			if err == nil || !strings.Contains(err.Error(), test.wantError) {
-				t.Fatalf("error = %v, want containing %q", err, test.wantError)
-			}
-			if stock != test.wantStock {
-				t.Fatalf("stock status = %q, want %q", stock, test.wantStock)
-			}
-		})
-	}
-}
-
-func TestPrepareCurrentCardReturnsAuthoritativeEmptyWellError(t *testing.T) {
-	client, device := newSequenceTestClient(t, cmdResp{status: status(0x38)})
-
-	stock, err := client.PrepareCurrentCard(context.Background())
-	if !errors.Is(err, ErrCardWellEmpty) {
-		t.Fatalf("error = %v, want ErrCardWellEmpty", err)
-	}
-	if stock != "Card empty" {
-		t.Fatalf("stock status = %q, want Card empty", stock)
-	}
-	if got := commandCount(device.commands, cmdToEncoder); got != 0 {
-		t.Fatalf("to-encoder commands = %d, want 0", got)
 	}
 }
 
@@ -291,42 +174,6 @@ func TestDeliverCurrentCardPreservesContextCancellation(t *testing.T) {
 	}
 }
 
-func TestPrepareCurrentCardRetriesOnceThenTimesOut(t *testing.T) {
-	responses := make([]cmdResp, 13)
-	for index := range responses {
-		responses[index] = cmdResp{status: status(0x34)}
-	}
-	client, device := newSequenceTestClient(t, responses...)
-
-	_, err := client.PrepareCurrentCard(context.Background())
-	if err == nil || !strings.Contains(err.Error(), "timed out") {
-		t.Fatalf("error = %v, want preparation timeout", err)
-	}
-	if got := commandCount(device.commands, cmdToEncoder); got != 2 {
-		t.Fatalf("to-encoder commands = %d, want initial command plus one halfway retry", got)
-	}
-	if got := commandCount(device.commands, cmdStatus); got != 13 {
-		t.Fatalf("status reads = %d, want 13", got)
-	}
-}
-
-func TestPrepareCurrentCardPropagatesContextCancellation(t *testing.T) {
-	client, _ := newSequenceTestClient(t,
-		cmdResp{status: status(0x34)},
-		cmdResp{status: status(0x34)},
-	)
-	ctx, cancel := context.WithCancel(context.Background())
-	client.sequenceTiming.wait = func(context.Context, time.Duration) error {
-		cancel()
-		return ctx.Err()
-	}
-
-	_, err := client.PrepareCurrentCard(ctx)
-	if !errors.Is(err, context.Canceled) {
-		t.Fatalf("error = %v, want context.Canceled", err)
-	}
-}
-
 func TestBeginPrepareNextCardDispatchesWithoutReadinessPolling(t *testing.T) {
 	client, device := newSequenceTestClient(t)
 
@@ -357,48 +204,292 @@ func TestBeginPrepareNextCardReturnsDispatchFailureWithoutPolling(t *testing.T)
 	}
 }
 
-func TestPrepareCardAtEncoderRequiresConfirmedEncoderState(t *testing.T) {
+func TestPositionDescriptions(t *testing.T) {
-	tests := []struct {
+	for _, test := range []struct {
-		name          string
+		position byte
-		responses     []cmdResp
+		want     string
-		wantError     string
-		wantToEncoder int
 	}{
-		{
+		{0x30, ""},
-			name:          "already at encoder",
+		{0x31, "Card at pre-dispense position; "},
-			responses:     []cmdResp{{status: status(0x33)}},
+		{0x32, "Card at encoder position; "},
-			wantToEncoder: 0,
+		{0x34, "Card at mouth position; "},
-		},
+		{0x37, "Card at pre-dispense position; Card at encoder position; Card at mouth position; "},
-		{
+		{0x39, "Card at pre-dispense position; Card empty; "},
-			name: "moves ready card to encoder",
+		{0x3F, "Card at pre-dispense position; Card at encoder position; Card at mouth position; Card empty; "},
-			responses: []cmdResp{
+		{0x40, "Unknown status 0x40 at position 4; "},
-				{status: status(0x34)},
+	} {
-				{status: status(0x33)},
+		if got := statusDescription(status(test.position)); got != test.want {
-			},
+			t.Errorf("statusDescription(position %X) = %q, want %q", test.position, got, test.want)
-			wantToEncoder: 1,
+		}
-		},
+	}
-		{
-			name:          "empty card well",
-			responses:     []cmdResp{{status: status(0x38)}},
-			wantError:     CardWellEmptyMessage,
-			wantToEncoder: 0,
-		},
 }
 
-	for _, test := range tests {
+func positionResponses(position byte, count int) []cmdResp {
-		t.Run(test.name, func(t *testing.T) {
+	responses := make([]cmdResp, count)
-			client, device := newSequenceTestClient(t, test.responses...)
+	for i := range responses {
+		responses[i] = cmdResp{status: status(position)}
+	}
+	return responses
+}
 
-			_, err := client.PrepareNextCard(context.Background())
+func TestPreparationClasses(t *testing.T) {
-			if test.wantError == "" && err != nil {
+	classes := map[preparationClass][]byte{
-				t.Fatal(err)
+		encoderConfirmed:  {0x32, 0x33, 0x36, 0x37, 0x3A, 0x3B, 0x3E, 0x3F},
+		positionUncertain: {0x31, 0x34, 0x35, 0x39, 0x3C, 0x3D},
+		positionWellEmpty: {0x38}, positionNoCard: {0x30},
 	}
-			if test.wantError != "" && (err == nil || !strings.Contains(err.Error(), test.wantError)) {
+	for want, positions := range classes {
-				t.Fatalf("error = %v, want containing %q", err, test.wantError)
+		for _, position := range positions {
+			st := []byte{0xFF, 0x36, 0x32, position}
+			if got, err := classifyPreparationStatus(st); got != want || err != nil {
+				t.Errorf("classify(% X)=%s,%v, want %s", st, got, err, want)
 			}
-			if got := commandCount(device.commands, cmdToEncoder); got != test.wantToEncoder {
+		}
-				t.Fatalf("to-encoder commands = %d, want %d", got, test.wantToEncoder)
+	}
+	for _, st := range [][]byte{nil, {0x30}, status(0x02), status(0x40), status(0xFF), {0x30, 0x30, 0x30, 0x37, 0x30}} {
+		if got, err := classifyPreparationStatus(st); err == nil {
+			t.Errorf("classify(% X)=%s,nil, want malformed error", st, got)
+		}
+	}
+}
+
+func TestPreparationAllPositionsBothMethods(t *testing.T) {
+	for _, next := range []bool{false, true} {
+		for position := byte(0x30); position <= 0x3F; position++ {
+			t.Run(fmt.Sprintf("next=%t/position=%X", next, position), func(t *testing.T) {
+				responses := positionResponses(position, 40)
+				for i := range responses {
+					responses[i].status[0], responses[i].status[1], responses[i].status[2] = 0xFF, 0x38, 0x34
+				}
+				c, d := newSequenceTestClient(t, responses...)
+				// Passive encoder data must never replace fresh AP.
+				c.lastStatus, c.lastStatusT, c.statusTTL = status(0x33), time.Now(), time.Hour
+				prepare := c.PrepareCurrentCard
+				if next {
+					prepare = c.PrepareNextCard
+				}
+				started := c.now()
+				_, err := prepare(context.Background())
+				wantFC7, wantRS, wantElapsed := 0, 0, time.Duration(0)
+				var wantErr error
+				switch position {
+				case 0x30:
+					wantFC7, wantRS, wantElapsed, wantErr = 4, 3, 18*time.Second, ErrPreparationExhausted
+				case 0x38:
+					wantErr = ErrCardWellEmpty
+				case 0x31, 0x34, 0x35, 0x39, 0x3C, 0x3D:
+					wantFC7, wantElapsed = 1, 4*time.Second
+				}
+				if !errors.Is(err, wantErr) {
+					t.Errorf("prepare(%X) error=%v, want %v", position, err, wantErr)
+				}
+				if commandCount(d.commands, cmdToEncoder) != wantFC7 || commandCount(d.commands, cmdReset) != wantRS {
+					t.Errorf("prepare(%X) commands=%v, want FC7=%d RS=%d", position, d.commands, wantFC7, wantRS)
+				}
+				if got := c.now().Sub(started); got != wantElapsed {
+					t.Errorf("prepare(%X) elapsed=%s, want %s", position, got, wantElapsed)
 				}
 			})
 		}
 	}
+}
+
+func TestThreeShakesAreRequestLocalAndSettled(t *testing.T) {
+	c, d := newSequenceTestClient(t, positionResponses(0x30, 34)...)
+	for request := 0; request < 2; request++ {
+		start := len(d.commands)
+		if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, ErrPreparationExhausted) {
+			t.Fatalf("request %d error=%v, want exhausted", request, err)
+		}
+		want := []cmdType{cmdStatus, cmdToEncoder}
+		for attempt := 0; attempt < 4; attempt++ {
+			want = append(want, cmdStatus, cmdStatus, cmdStatus, cmdStatus)
+			if attempt < 3 {
+				want = append(want, cmdReset, cmdToEncoder)
+			}
+		}
+		if !reflect.DeepEqual(d.commands[start:], want) {
+			t.Errorf("request %d commands=%v, want %v", request, d.commands[start:], want)
+		}
+		var lastFC7 time.Time
+		for i := start; i < len(d.commands); i++ {
+			if d.commands[i] == cmdReset && d.commandTimes[i].Sub(lastFC7) != 3*time.Second {
+				t.Errorf("RS at %s after FC7, want 3s", d.commandTimes[i].Sub(lastFC7))
+			}
+			if d.commands[i] == cmdToEncoder {
+				if i > start && d.commands[i-1] == cmdReset && d.commandTimes[i].Sub(d.commandTimes[i-1]) != 2*time.Second {
+					t.Errorf("FC7 settle=%s, want 2s", d.commandTimes[i].Sub(d.commandTimes[i-1]))
+				}
+				lastFC7 = d.commandTimes[i]
+			}
+		}
+	}
+}
+
+func TestPreparationReclassifiesEverySample(t *testing.T) {
+	for _, tc := range []struct {
+		name      string
+		positions []byte
+		wantRS    int
+		wantTime  time.Duration
+		wantErr   error
+	}{
+		{"uncertain changes do not restart timer", []byte{0x30, 0x31, 0x34, 0x35, 0x39, 0x3C}, 0, 4 * time.Second, nil},
+		{"uncertain becomes encoder", []byte{0x30, 0x34, 0x37}, 0, time.Second, nil},
+		{"uncertain becomes empty", []byte{0x30, 0x34, 0x38}, 0, time.Second, ErrCardWellEmpty},
+		{"no sensors becomes empty", []byte{0x30, 0x30, 0x38}, 0, time.Second, ErrCardWellEmpty},
+		{"uncertain returns to shake path twice", []byte{0x30, 0x34, 0x30, 0x30, 0x30, 0x34, 0x34, 0x30, 0x30, 0x37}, 2, 10 * time.Second, nil},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			var responses []cmdResp
+			for _, p := range tc.positions {
+				responses = append(responses, cmdResp{status: status(p)})
+			}
+			c, d := newSequenceTestClient(t, responses...)
+			start := c.now()
+			_, err := c.PrepareCurrentCard(context.Background())
+			if !errors.Is(err, tc.wantErr) || c.now().Sub(start) != tc.wantTime || commandCount(d.commands, cmdReset) != tc.wantRS {
+				t.Errorf("prepare(%s) error=%v elapsed=%s commands=%v, want error=%v time=%s RS=%d", tc.name, err, c.now().Sub(start), d.commands, tc.wantErr, tc.wantTime, tc.wantRS)
+			}
+		})
+	}
+}
+
+func TestEveryShakeReclassifiesEncoderEmptyAndUncertain(t *testing.T) {
+	for shake := 1; shake <= 3; shake++ {
+		for _, position := range []byte{0x37, 0x38, 0x35} {
+			responses := positionResponses(0x30, 1+4*shake)
+			responses = append(responses, positionResponses(position, 5)...)
+			c, d := newSequenceTestClient(t, responses...)
+			_, err := c.PrepareCurrentCard(context.Background())
+			var wantErr error
+			if position == 0x38 {
+				wantErr = ErrCardWellEmpty
+			}
+			if !errors.Is(err, wantErr) || commandCount(d.commands, cmdReset) != shake || commandCount(d.commands, cmdToEncoder) != shake+1 {
+				t.Errorf("shake %d position=%X error=%v commands=%v, want %v and no further shake", shake, position, err, d.commands, wantErr)
+			}
+		}
+	}
+}
+
+func TestPreparationTransportAndDispatchFailuresDoNotShake(t *testing.T) {
+	failure := errors.New("serial failure")
+	for _, response := range []cmdResp{{err: failure}, {status: []byte{0x30}}, {status: status(0x40)}} {
+		c, d := newSequenceTestClient(t, cmdResp{status: status(0x30)}, response)
+		if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+			t.Errorf("AP failure %v error=%v, want encoder opportunity", response, err)
+		}
+		if commandCount(d.commands, cmdToEncoder) != 1 || commandCount(d.commands, cmdReset) != 0 {
+			t.Errorf("AP failure commands=%v, want FC7 once and no RS", d.commands)
+		}
+	}
+	for _, command := range []cmdType{cmdToEncoder, cmdReset} {
+		c, d := newSequenceTestClient(t, positionResponses(0x30, 10)...)
+		d.commandErrors[command] = []error{failure}
+		if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, failure) {
+			t.Errorf("command %v error=%v, want serial failure", command, err)
+		}
+		if commandCount(d.commands, command) != 1 {
+			t.Errorf("command %v retried: %v", command, d.commands)
+		}
+	}
+}
+
+func TestPreparationStopsAtCancellationAndDeadlineStages(t *testing.T) {
+	for _, stage := range []string{"initial AP", "FC7", "poll", "RS", "settle"} {
+		for _, callerCanceled := range []bool{false, true} {
+			if stage == "initial AP" && !callerCanceled {
+				continue
+			}
+			t.Run(fmt.Sprintf("%s/cancel=%t", stage, callerCanceled), func(t *testing.T) {
+				c, d := newSequenceTestClient(t, positionResponses(0x30, 30)...)
+				ctx, cancel := context.WithCancel(context.Background())
+				t.Cleanup(cancel)
+				now := c.now()
+				c.sequenceTiming.now = func() time.Time { return now }
+				stoppedAt := -1
+				stop := func() {
+					if stoppedAt >= 0 {
+						return
+					}
+					stoppedAt = len(d.commands)
+					if callerCanceled {
+						cancel()
+					} else {
+						now = now.Add(sequenceTimeout)
+					}
+				}
+				c.sequenceTiming.wait = func(_ context.Context, duration time.Duration) error {
+					now = now.Add(duration)
+					if (stage == "poll" && duration == sequencePollInterval) || (stage == "settle" && duration == sequenceResetWait) {
+						stop()
+					}
+					return nil
+				}
+				d.onCommand = func(cmd cmdType) {
+					if (stage == "initial AP" && cmd == cmdStatus) || (stage == "FC7" && cmd == cmdToEncoder) || (stage == "RS" && cmd == cmdReset) {
+						stop()
+					}
+				}
+				_, err := c.PrepareCurrentCard(ctx)
+				wantErr := error(ErrPreparationExhausted)
+				if callerCanceled {
+					wantErr = context.Canceled
+				} else if stage == "initial AP" {
+					wantErr = context.DeadlineExceeded
+				}
+				if !errors.Is(err, wantErr) || len(d.commands) != stoppedAt {
+					t.Errorf("stage=%s cancel=%t error=%v commands=%v stoppedAt=%d, want %v and no commands after stop", stage, callerCanceled, err, d.commands, stoppedAt, wantErr)
+				}
+			})
+		}
+	}
+}
+
+func TestPositionFlagsRemainDiagnostic(t *testing.T) {
+	for position := byte(0x30); position <= 0x3F; position++ {
+		st := status(position)
+		if got := isAtEncoderPosition(st); got != (position&0x02 != 0) {
+			t.Errorf("encoder sensor(%X)=%t", position, got)
+		}
+		if got := isCardWellEmpty(st); got != (position&0x08 != 0) {
+			t.Errorf("stock empty flag(%X)=%t", position, got)
+		}
+		wantStock := ""
+		if position&0x08 != 0 {
+			wantStock = "Card empty"
+		}
+		if got := stockTake(st); got != wantStock {
+			t.Errorf("stockTake(%X)=%q, want %q", position, got, wantStock)
+		}
+	}
+}
+
+func TestPreparationCallerDeadlineIsNotRetryableExhaustion(t *testing.T) {
+	c, d := newSequenceTestClient(t)
+	ctx, cancel := context.WithDeadline(context.Background(), time.Now().Add(-time.Second))
+	defer cancel()
+	_, err := c.PrepareCurrentCard(ctx)
+	if !errors.Is(err, context.DeadlineExceeded) || errors.Is(err, ErrPreparationExhausted) || len(d.commands) != 0 {
+		t.Errorf("expired caller: err=%v commands=%v, want caller deadline and no commands", err, d.commands)
+	}
+}
+
+func TestPreparationExpiredEncoderSampleHandsOff(t *testing.T) {
+	c, d := newSequenceTestClient(t, cmdResp{status: status(0x30)}, cmdResp{status: status(0x37)})
+	now := c.now()
+	c.sequenceTiming.now = func() time.Time { return now }
+	d.onCommand = func(cmd cmdType) {
+		if cmd == cmdStatus && commandCount(d.commands, cmdStatus) == 2 {
+			now = now.Add(sequenceTimeout)
+		}
+	}
+	_, err := c.PrepareCurrentCard(context.Background())
+	if err != nil {
+		t.Errorf("late encoder sample: err=%v, want handoff", err)
+	}
+	if len(d.commands) != 3 {
+		t.Errorf("late encoder sample commands=%v, want AP FC7 AP", d.commands)
+	}
+}

internal/dispenser/maintenance.go

@@ -0,0 +1,180 @@
+package dispenser
+
+import (
+	"context"
+	"sync"
+	"time"
+
+	log "github.com/sirupsen/logrus"
+)
+
+const maintenanceInterval = time.Minute
+const maintenanceTimeout = 5 * time.Second
+
+// activityGuard arbitrates admission, not the duration of serial transactions.
+// The serial worker remains the sole owner of the port and deliveryPending.
+type activityGuard struct {
+	sync.Mutex
+	foreground int
+	generation uint64
+	enabled    bool
+	closed     bool
+	next       time.Time
+	cancel     context.CancelFunc
+	finished   chan struct{}
+}
+
+func (c *Client) wakeWorker() {
+	select {
+	case c.activityWake <- struct{}{}:
+	default:
+	}
+}
+
+// BeginForeground suppresses idle work until the returned release function runs.
+func (c *Client) BeginForeground() func() {
+	c.activity.Lock()
+	c.activity.foreground++
+	c.activity.generation++
+	c.activity.next = time.Time{}
+	c.activity.Unlock()
+	c.wakeWorker()
+	var once sync.Once
+	return func() {
+		once.Do(func() {
+			c.activity.Lock()
+			c.activity.foreground--
+			if c.activity.foreground == 0 && c.activity.enabled && !c.activity.closed {
+				c.activity.next = c.now().Add(maintenanceInterval)
+			}
+			c.activity.Unlock()
+			c.wakeWorker()
+		})
+	}
+}
+
+// StartMaintenance enables the worker timer once, with an initial one-minute delay.
+func (c *Client) StartMaintenance() {
+	c.activity.Lock()
+	if !c.activity.enabled && !c.activity.closed {
+		c.activity.enabled = true
+		c.activity.generation++
+		if c.activity.foreground == 0 {
+			c.activity.next = c.now().Add(maintenanceInterval)
+		}
+	}
+	c.activity.Unlock()
+	c.wakeWorker()
+}
+
+// StopMaintenance prevents new admissions and waits for an admitted attempt to exit.
+// An underlying serial read can finish only according to its existing read timeout.
+func (c *Client) StopMaintenance() {
+	c.activity.Lock()
+	c.activity.enabled = false
+	c.activity.generation++
+	c.activity.next = time.Time{}
+	if c.activity.cancel != nil {
+		c.activity.cancel()
+	}
+	finished := c.activity.finished
+	c.activity.Unlock()
+	c.wakeWorker()
+	if finished != nil {
+		<-finished
+	}
+}
+
+func (c *Client) maintenanceDelay() (time.Duration, bool) {
+	c.activity.Lock()
+	defer c.activity.Unlock()
+	if !c.activity.enabled || c.activity.closed || c.activity.foreground != 0 || c.activity.next.IsZero() {
+		return 0, false
+	}
+	remaining := c.activity.next.Sub(c.now())
+	if remaining < 0 {
+		remaining = 0
+	}
+	return remaining, true
+}
+
+func (c *Client) passiveGeneration() (uint64, bool) {
+	c.activity.Lock()
+	defer c.activity.Unlock()
+	return c.activity.generation, c.activity.foreground == 0 && !c.activity.closed
+}
+
+func (c *Client) admitPassive(ctx context.Context, generation uint64) bool {
+	c.activity.Lock()
+	defer c.activity.Unlock()
+	return ctx.Err() == nil && !c.activity.closed && c.activity.foreground == 0 && c.activity.generation == generation
+}
+
+func (c *Client) admitMaintenance(ctx context.Context, generation uint64) bool {
+	c.activity.Lock()
+	defer c.activity.Unlock()
+	return ctx.Err() == nil && c.activity.enabled && !c.activity.closed && c.activity.foreground == 0 && c.activity.generation == generation
+}
+
+// maintainIdleCard is called only by the serial worker, never through its queue.
+func (c *Client) maintainIdleCard() {
+	c.activity.Lock()
+	if !c.activity.enabled || c.activity.closed || c.activity.foreground != 0 || c.activity.next.IsZero() || c.now().Before(c.activity.next) {
+		c.activity.Unlock()
+		return
+	}
+	ctx, cancel := context.WithTimeout(context.Background(), maintenanceTimeout)
+	generation := c.activity.generation
+	finished := make(chan struct{})
+	c.activity.cancel, c.activity.finished = cancel, finished
+	c.activity.Unlock()
+	defer func() {
+		cancel()
+		c.activity.Lock()
+		c.activity.cancel, c.activity.finished = nil, nil
+		if c.activity.enabled && !c.activity.closed && c.activity.foreground == 0 && c.activity.generation == generation {
+			c.activity.next = c.now().Add(maintenanceInterval)
+		}
+		close(finished)
+		c.activity.Unlock()
+	}()
+	if !c.admitMaintenance(ctx, generation) {
+		return
+	}
+	// Quiet observation: do not publish stock callbacks or manufacture cached status.
+	st, err := checkDispenserStatus(ctx, c.port)
+	if err != nil {
+		log.Debugf("idle dispenser maintenance AP: %v", err)
+		return
+	}
+	class, err := classifyPreparationStatus(st)
+	if err != nil {
+		log.Debugf("idle dispenser maintenance unusable AP: %v", err)
+		return
+	}
+	log.Debugf("idle dispenser maintenance AP; class=%s raw status: % X", class, st)
+	if class == encoderConfirmed || class == positionWellEmpty {
+		return
+	}
+	clear, err := deliveryClearance(st)
+	if err != nil || !clear {
+		return
+	}
+	if c.deliveryPending && c.now().Sub(c.deliveryStarted) < deliveryMinimumWait {
+		return
+	}
+	// This is the admission boundary shared with foreground registration and stop.
+	if !c.admitMaintenance(ctx, generation) {
+		return
+	}
+	if c.deliveryPending {
+		c.deliveryPending = false
+	}
+	err = cardToEncoderPosition(ctx, c.port)
+	c.invalidateStatusCache()
+	if err != nil {
+		log.Warnf("idle dispenser maintenance FC7 dispatch: %v", err)
+		return
+	}
+	log.Info("idle dispenser maintenance FC7 dispatched")
+}

internal/dispenser/maintenance_test.go

@@ -0,0 +1,362 @@
+package dispenser
+
+import (
+	"context"
+	"errors"
+	"reflect"
+	"sync"
+	"testing"
+	"time"
+)
+
+func maintenanceClient(t *testing.T, p *scriptedTransport) (*Client, *time.Time) {
+	t.Helper()
+	transportAddress(t)
+	now := time.Unix(100, 0)
+	c := &Client{port: p, done: make(chan struct{}), activityWake: make(chan struct{}, 1), sequenceTiming: sequenceTiming{now: func() time.Time { return now }, wait: waitForSequence}}
+	t.Cleanup(c.Close)
+	return c, &now
+}
+
+func TestMaintenanceIdleScheduling(t *testing.T) {
+	c, now := maintenanceClient(t, &scriptedTransport{})
+	c.StartMaintenance()
+	first := c.activity.next
+	c.StartMaintenance()
+	if c.activity.next != first {
+		t.Fatal("repeated start reset the timer")
+	}
+	*now = now.Add(59 * time.Second)
+	c.maintainIdleCard()
+	if len(c.port.(*scriptedTransport).writes) != 0 {
+		t.Fatal("maintenance ran before one minute")
+	}
+	release1 := c.BeginForeground()
+	release2 := c.BeginForeground()
+	release1()
+	if _, enabled := c.maintenanceDelay(); enabled {
+		t.Fatal("timer enabled while another issuance active")
+	}
+	*now = now.Add(20 * time.Second)
+	release2()
+	release2()
+	if delay, enabled := c.maintenanceDelay(); !enabled || delay != time.Minute {
+		t.Fatalf("after last release delay=%v enabled=%t", delay, enabled)
+	}
+	c.StopMaintenance()
+	if _, enabled := c.maintenanceDelay(); enabled {
+		t.Fatal("stop left timer enabled")
+	}
+}
+
+func TestMaintenanceUsesCommonEligibility(t *testing.T) {
+	for _, tc := range []struct {
+		name    string
+		st      []byte
+		pending bool
+		age     time.Duration
+		fc7     bool
+	}{
+		{"clear", status(0x30), false, 0, true},
+		{"staging", status(0x34), true, 3 * time.Second, true},
+		{"too early", status(0x30), true, time.Second, false},
+		{"encoder", status(0x33), true, time.Minute, false},
+		{"empty", status(0x38), false, 0, false},
+		{"uncertain", status(0x35), false, 0, false},
+		{"movement", []byte{0x31, 0x30, 0x30, 0x34}, true, time.Minute, false},
+		{"invalid", status(0x40), true, time.Minute, false},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(tc.st), vendorACK}}
+			c, now := maintenanceClient(t, p)
+			c.StartMaintenance()
+			*now = now.Add(time.Minute)
+			c.deliveryPending = tc.pending
+			c.deliveryStarted = now.Add(-tc.age)
+			callbacks := 0
+			c.OnStockUpdate(func(string) { callbacks++ })
+			c.maintainIdleCard()
+			want := []string{"AP"}
+			if tc.fc7 {
+				want = append(want, "FC7")
+			}
+			if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+				t.Errorf("commands=%v want %v", got, want)
+			}
+			if callbacks != 0 {
+				t.Errorf("maintenance published %d stock callbacks", callbacks)
+			}
+			if tc.pending && !tc.fc7 && !c.deliveryPending {
+				t.Error("ineligible maintenance cleared pending")
+			}
+			if delay, enabled := c.maintenanceDelay(); !enabled || delay != time.Minute {
+				t.Errorf("next maintenance delay=%v enabled=%t", delay, enabled)
+			}
+		})
+	}
+}
+
+func TestMaintenanceForegroundBetweenAPAndFC7(t *testing.T) {
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK}}
+	c, now := maintenanceClient(t, p)
+	c.StartMaintenance()
+	*now = now.Add(time.Minute)
+	var release func()
+	p.afterRead = func() {
+		if len(p.chunks) == 1 && release == nil {
+			release = c.BeginForeground()
+		}
+	}
+	c.maintainIdleCard()
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP"}) {
+		t.Errorf("foreground during AP commands=%v want AP only", got)
+	}
+	if release == nil {
+		t.Fatal("barrier not reached")
+	}
+	release()
+	if delay, _ := c.maintenanceDelay(); delay != time.Minute {
+		t.Errorf("foreground completion delay=%v", delay)
+	}
+}
+
+func TestMaintenanceAdmissionConditions(t *testing.T) {
+	c, _ := maintenanceClient(t, &scriptedTransport{})
+	c.StartMaintenance()
+	generation := c.activity.generation
+	ctx, cancel := context.WithCancel(context.Background())
+	if !c.admitMaintenance(ctx, generation) {
+		t.Fatal("idle admission rejected")
+	}
+	cancel()
+	if c.admitMaintenance(ctx, generation) {
+		t.Fatal("canceled admission accepted")
+	}
+	expired, stop := context.WithDeadline(context.Background(), time.Now().Add(-time.Second))
+	defer stop()
+	if c.admitMaintenance(expired, generation) {
+		t.Fatal("expired admission accepted")
+	}
+	release := c.BeginForeground()
+	if c.admitMaintenance(context.Background(), generation) {
+		t.Fatal("foreground/stale admission accepted")
+	}
+	release()
+	if c.admitMaintenance(context.Background(), generation) {
+		t.Fatal("obsolete generation accepted")
+	}
+	generation = c.activity.generation
+	c.StopMaintenance()
+	if c.admitMaintenance(context.Background(), generation) {
+		t.Fatal("stopped admission accepted")
+	}
+}
+
+func TestPassivePollGenerationAtDispatch(t *testing.T) {
+	c, _ := maintenanceClient(t, &scriptedTransport{})
+	generation, _ := c.passiveGeneration()
+	release := c.BeginForeground()
+	for _, active := range []bool{true, false} {
+		if !active {
+			release()
+		}
+		response := make(chan cmdResp, 1)
+		c.handle(cmdReq{ctx: context.Background(), typ: cmdStatus, passive: true, generation: generation, respCh: response})
+		<-response
+		if len(c.port.(*scriptedTransport).writes) != 0 {
+			t.Errorf("active=%t stale passive request touched port", active)
+		}
+	}
+}
+
+func TestMaintenanceStopWaitsForAdmittedRead(t *testing.T) {
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK}}
+	c, now := maintenanceClient(t, p)
+	c.StartMaintenance()
+	*now = now.Add(time.Minute)
+	entered, resume := make(chan struct{}), make(chan struct{})
+	var once sync.Once
+	p.afterRead = func() { once.Do(func() { close(entered); <-resume }) }
+	finished := make(chan struct{})
+	go func() { c.maintainIdleCard(); close(finished) }()
+	<-entered
+	stopped := make(chan struct{})
+	go func() { c.StopMaintenance(); close(stopped) }()
+	// Wait until stop has disabled admission.
+	for {
+		c.activity.Lock()
+		enabled := c.activity.enabled
+		c.activity.Unlock()
+		if !enabled {
+			break
+		}
+		time.Sleep(time.Millisecond)
+	}
+	select {
+	case <-stopped:
+		t.Fatal("stop returned before admitted read finished")
+	default:
+	}
+	close(resume)
+	<-finished
+	<-stopped
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP"}) {
+		t.Errorf("stop commands=%v want AP only", got)
+	}
+	c.StopMaintenance()
+	c.Close()
+	c.Close()
+}
+
+func TestMaintenanceWorkerTimerWake(t *testing.T) {
+	c := NewClient(nil, 1)
+	c.StartMaintenance()
+	release := c.BeginForeground()
+	// An immediate obsolete timer is harmless while foreground is registered.
+	c.activity.Lock()
+	c.activity.next = time.Now().Add(-time.Second)
+	c.activity.Unlock()
+	c.wakeWorker()
+	release()
+	if delay, enabled := c.maintenanceDelay(); !enabled || delay <= 59*time.Second {
+		t.Errorf("worker schedule delay=%v enabled=%t", delay, enabled)
+	}
+	c.Close()
+	if r := c.doResponse(context.Background(), cmdStatus); r.err == nil {
+		t.Fatal("closed client accepted a request")
+	}
+}
+
+func TestMaintenanceWorkerTimerDispatch(t *testing.T) {
+	transportAddress(t)
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK}}
+	c := &Client{port: p, reqCh: make(chan cmdReq, 1), done: make(chan struct{}), activityWake: make(chan struct{}, 1), sequenceTiming: sequenceTiming{now: time.Now, wait: waitForSequence}}
+	c.StartMaintenance()
+	c.activity.Lock()
+	c.activity.next = time.Now().Add(-time.Second)
+	c.activity.Unlock()
+	workerDone := make(chan struct{})
+	go func() { defer close(workerDone); c.loop() }()
+	t.Cleanup(func() { c.Close(); <-workerDone })
+	dispatched := make(chan struct{})
+	// Observe completion through the activity guard, without touching the transport concurrently.
+	go func() {
+		for {
+			c.activity.Lock()
+			next := c.activity.next
+			c.activity.Unlock()
+			if time.Until(next) > 50*time.Second {
+				close(dispatched)
+				return
+			}
+			select {
+			case <-c.done:
+				return
+			case <-time.After(time.Millisecond):
+			}
+		}
+	}()
+	select {
+	case <-dispatched:
+	case <-time.After(4 * time.Second):
+		t.Fatal("worker timer did not finish maintenance")
+	}
+	c.StopMaintenance()
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP", "FC7"}) {
+		t.Errorf("timer commands=%v", got)
+	}
+}
+
+func TestForegroundEncoderClearanceCharacterization(t *testing.T) {
+	for _, movement := range []bool{false, true} {
+		st := status(0x33)
+		if movement {
+			st[0] = 0x31
+		}
+		p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(st), vendorACK, apReply(st), vendorACK, apReply(st), vendorACK}}
+		c, now := maintenanceClient(t, p)
+		c.deliveryPending = true
+		c.deliveryStarted = now.Add(-time.Minute)
+		c.sequenceTiming.wait = func(context.Context, time.Duration) error { *now = now.Add(2 * time.Second); return nil }
+		r := workerRequest(c, context.Background(), cmdToEncoder)
+		want := []string{"AP", "AP", "AP"}
+		if movement {
+			if !errors.Is(r.err, context.DeadlineExceeded) || !c.deliveryPending {
+				t.Errorf("movement err=%v pending=%t", r.err, c.deliveryPending)
+			}
+		} else {
+			want = append(want, "FC7")
+			if r.err != nil || c.deliveryPending {
+				t.Errorf("internal fallback err=%v pending=%t", r.err, c.deliveryPending)
+			}
+		}
+		if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+			t.Errorf("movement=%t commands=%v want %v", movement, got, want)
+		}
+	}
+}
+
+func TestForegroundEncoderClearanceCallerDeadline(t *testing.T) {
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x33)), vendorACK, apReply(status(0x33)), vendorACK, apReply(status(0x33))}}
+	c, now := maintenanceClient(t, p)
+	c.deliveryPending = true
+	c.deliveryStarted = *now
+	start := *now
+	samples := 0
+	p.afterRead = func() {
+		if len(p.chunks)%2 == 0 { // Only complete frame reads advance the observation clock.
+			if len(p.chunks) == 4 || len(p.chunks) == 2 || len(p.chunks) == 0 {
+				samples++
+				*now = now.Add(time.Second)
+			}
+		}
+	}
+	ctx, cancel := context.WithTimeout(context.Background(), 4*time.Second)
+	defer cancel()
+	c.sequenceTiming.wait = func(context.Context, time.Duration) error {
+		if samples == 3 {
+			<-ctx.Done()
+			return ctx.Err()
+		}
+		*now = now.Add(time.Second)
+		return nil
+	}
+	r := workerRequest(c, ctx, cmdToEncoder)
+	if !errors.Is(r.err, context.DeadlineExceeded) || !c.deliveryPending {
+		t.Errorf("caller deadline err=%v pending=%t", r.err, c.deliveryPending)
+	}
+	if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP", "AP", "AP"}) {
+		t.Errorf("caller deadline commands=%v want AP only", got)
+	}
+	if elapsed := now.Sub(start); elapsed != 5*time.Second {
+		t.Errorf("last observation elapsed=%v want 5s", elapsed)
+	}
+}
+
+func TestMaintenanceFailuresAreQuietAndRetryLater(t *testing.T) {
+	for _, mechanical := range []bool{false, true} {
+		p := &scriptedTransport{chunks: [][]byte{{0x10, 0x06, 0x30}}}
+		if mechanical {
+			p.chunks = [][]byte{vendorACK, apReply(status(0x30))}
+		}
+		c, now := maintenanceClient(t, p)
+		c.StartMaintenance()
+		*now = now.Add(time.Minute)
+		callbacks := 0
+		c.OnStockUpdate(func(string) { callbacks++ })
+		c.maintainIdleCard()
+		want := []string{"AP"}
+		if mechanical {
+			want = append(want, "FC7")
+		}
+		if got := wireCommands(p); !reflect.DeepEqual(got, want) {
+			t.Errorf("mechanical=%t commands=%v want %v", mechanical, got, want)
+		}
+		if callbacks != 0 {
+			t.Errorf("maintenance failure callbacks=%d", callbacks)
+		}
+		if delay, enabled := c.maintenanceDelay(); !enabled || delay != time.Minute {
+			t.Errorf("retry delay=%v enabled=%t", delay, enabled)
+		}
+	}
+}

internal/dispenser/observation_test.go

@@ -0,0 +1,242 @@
+package dispenser
+
+import (
+	"context"
+	"errors"
+	"fmt"
+	"io"
+	"testing"
+	"time"
+)
+
+func TestStrictAPFailuresBecomeUnusablePreparationObservations(t *testing.T) {
+	transportAddress(t)
+	cases := []struct {
+		name    string
+		chunks  [][]byte
+		readErr error
+	}{
+		{"invalid ACK 10 06 30", [][]byte{{0x10, 0x06, 0x30}}, nil},
+		{"truncated", [][]byte{vendorACK, vendorAP[:8]}, nil},
+		{"no response", nil, nil},
+		{"timeout", nil, context.DeadlineExceeded},
+		{"read failure", nil, io.ErrClosedPipe},
+	}
+	for _, offset := range []int{0, 1, 2, 3, 4, 5, 6, 11, 12} {
+		frame := append([]byte(nil), vendorAP...)
+		frame[offset] ^= 0xff
+		if offset == 5 || offset == 6 || offset == 11 {
+			frame[12] = calculateBCC(frame[:12])
+		}
+		cases = append(cases, struct {
+			name    string
+			chunks  [][]byte
+			readErr error
+		}{fmt.Sprintf("frame byte %d", offset), [][]byte{vendorACK, frame}, nil})
+	}
+	for _, tc := range cases {
+		t.Run(tc.name, func(t *testing.T) {
+			p := &scriptedTransport{chunks: tc.chunks, readErr: tc.readErr}
+			st, err := queryStatus(context.Background(), p, vendorFrames[0].command, 4, 0)
+			if err == nil {
+				t.Fatal("strict queryStatus accepted invalid transaction")
+			}
+			c, d := newSequenceTestClient(t, cmdResp{status: st, err: err}, cmdResp{status: status(0x37)})
+			if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+				t.Errorf("preparation after %s = %v, want opportunity", tc.name, err)
+			}
+			if commandCount(d.commands, cmdToEncoder) != 1 || commandCount(d.commands, cmdReset) != 0 {
+				t.Errorf("commands=%v, want one FC7 and no RS", d.commands)
+			}
+		})
+	}
+}
+
+func TestUnusableObservationsReclassifyAndShareUncertainty(t *testing.T) {
+	for _, later := range []byte{0x38, 0x30, 0x37, 0x35, 0x40} {
+		t.Run(fmt.Sprintf("later %X", later), func(t *testing.T) {
+			responses := []cmdResp{{err: io.ErrUnexpectedEOF}, {status: status(0x40)}}
+			responses = append(responses, positionResponses(later, 25)...)
+			c, d := newSequenceTestClient(t, responses...)
+			_, err := c.PrepareCurrentCard(context.Background())
+			var want error
+			if later == 0x38 {
+				want = ErrCardWellEmpty
+			}
+			if later == 0x30 {
+				want = ErrPreparationExhausted
+			}
+			if !errors.Is(err, want) {
+				t.Errorf("later %X error=%v, want %v", later, err, want)
+			}
+			resets := 0
+			if later == 0x30 {
+				resets = 3
+			}
+			if commandCount(d.commands, cmdReset) != resets {
+				t.Errorf("later %X commands=%v, want %d RS", later, d.commands, resets)
+			}
+		})
+	}
+	c, d := newSequenceTestClient(t, cmdResp{err: io.EOF}, cmdResp{err: io.EOF}, cmdResp{status: status(0x35)}, cmdResp{status: status(0x40)}, cmdResp{err: io.EOF}, cmdResp{status: status(0x39)})
+	start := c.now()
+	if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
+		t.Fatal(err)
+	}
+	if elapsed := c.now().Sub(start); elapsed != sequenceUncertainWait {
+		t.Errorf("mixed uncertainty elapsed=%v, want %v", elapsed, sequenceUncertainWait)
+	}
+	if commandCount(d.commands, cmdToEncoder) != 1 {
+		t.Errorf("mixed uncertainty commands=%v, want one FC7", d.commands)
+	}
+}
+
+func TestObservationAtPreparationDeadline(t *testing.T) {
+	for _, last := range []cmdResp{{err: io.EOF}, {status: status(0x40)}, {status: status(0x35)}, {status: status(0x30)}, {status: status(0x38)}} {
+		c, d := newSequenceTestClient(t, cmdResp{status: status(0x30)}, last)
+		now := c.now()
+		c.sequenceTiming.now = func() time.Time { return now }
+		d.onCommand = func(cmd cmdType) {
+			if cmd == cmdStatus && commandCount(d.commands, cmdStatus) == 2 {
+				now = now.Add(sequenceTimeout)
+			}
+		}
+		_, err := c.PrepareCurrentCard(context.Background())
+		var want error
+		if len(last.status) == 4 && last.status[3] == 0x30 {
+			want = ErrPreparationExhausted
+		}
+		if len(last.status) == 4 && last.status[3] == 0x38 {
+			want = ErrCardWellEmpty
+		}
+		if !errors.Is(err, want) {
+			t.Errorf("deadline observation=%v error=%v, want %v", last, err, want)
+		}
+	}
+}
+
+func TestWorkerClearanceFallbackAndMovement(t *testing.T) {
+	for _, mode := range []string{"unusable", "ambiguous", "movement", "movement then unusable", "empty", "cancel"} {
+		t.Run(mode, func(t *testing.T) {
+			p := &scriptedTransport{}
+			for i := 0; i < 6; i++ {
+				switch mode {
+				case "unusable", "cancel":
+					p.chunks = append(p.chunks, []byte{0x10, 0x06, 0x30})
+				case "ambiguous":
+					p.chunks = append(p.chunks, vendorACK, apReply(status(0x37)))
+				case "empty":
+					p.chunks = append(p.chunks, vendorACK, apReply(status(0x38)))
+				default:
+					if mode == "movement then unusable" && i > 0 {
+						p.chunks = append(p.chunks, []byte{0x10, 0x06, 0x30})
+					} else {
+						p.chunks = append(p.chunks, vendorACK, apReply([]byte{0x31, 0x30, 0x30, 0x34}))
+					}
+				}
+			}
+			c, now := deliveryWorkerClient(t, p)
+			c.sequenceTiming.wait = func(ctx context.Context, d time.Duration) error {
+				if ctx.Err() != nil {
+					return ctx.Err()
+				}
+				*now = now.Add(2 * d)
+				return nil
+			}
+			c.deliveryPending = true
+			c.deliveryStarted = c.now()
+			ctx, cancel := context.WithCancel(context.Background())
+			defer cancel()
+			if mode == "cancel" {
+				p.afterRead = cancel
+			}
+			r := c.doResponse(ctx, cmdDeliveryClearance)
+			if mode == "cancel" {
+				if !errors.Is(r.err, context.Canceled) {
+					t.Errorf("cancel=%v", r.err)
+				}
+				return
+			}
+			var want error
+			if mode == "movement" {
+				want = context.DeadlineExceeded
+			}
+			if mode == "empty" {
+				want = ErrCardWellEmpty
+			}
+			if !errors.Is(r.err, want) {
+				t.Errorf("clearance %s error=%v want %v", mode, r.err, want)
+			}
+			if c.deliveryPending != (want != nil) {
+				t.Errorf("clearance %s pending=%t", mode, c.deliveryPending)
+			}
+			if mode != "empty" && now.Sub(time.Unix(0, 0)) != deliveryClearanceTimeout {
+				t.Errorf("clearance %s wait=%v want 6s", mode, now.Sub(time.Unix(0, 0)))
+			}
+			for _, command := range wireCommands(p) {
+				if command != "AP" {
+					t.Errorf("clearance issued %s, want AP only", command)
+				}
+			}
+		})
+	}
+}
+
+func TestWorkerAssumedClearanceAllowsOneFC7(t *testing.T) {
+	for _, prepare := range []bool{false, true} {
+		p := &scriptedTransport{}
+		dispatched := false
+		p.afterWrite = func() {
+			w := p.writes[len(p.writes)-1]
+			if len(w) <= 6 || w[0] != STX {
+				return
+			}
+			switch string(w[5 : len(w)-2]) {
+			case "AP":
+				if dispatched {
+					p.chunks = append(p.chunks, vendorACK, apReply(status(0x35)))
+				} else {
+					p.chunks = append(p.chunks, []byte{0x10, 0x06, 0x30})
+				}
+			case "FC7":
+				dispatched = true
+				p.chunks = append(p.chunks, vendorACK)
+			}
+		}
+		c, now := deliveryWorkerClient(t, p)
+		c.deliveryPending = true
+		c.deliveryStarted = c.now()
+		var err error
+		if prepare {
+			_, err = c.PrepareCurrentCard(context.Background())
+		} else {
+			err = c.BeginPrepareNextCard(context.Background())
+		}
+		if err != nil {
+			t.Fatalf("prepare=%t error=%v", prepare, err)
+		}
+		wantElapsed := deliveryClearanceTimeout
+		if prepare {
+			wantElapsed += sequenceUncertainWait
+		}
+		if elapsed := now.Sub(time.Unix(0, 0)); elapsed != wantElapsed {
+			t.Errorf("prepare=%t elapsed=%v want %v", prepare, elapsed, wantElapsed)
+		}
+		commands := wireCommands(p)
+		fc7 := 0
+		for _, cmd := range commands {
+			if cmd == "FC7" {
+				fc7++
+			}
+			if cmd == "RS" {
+				t.Errorf("unexpected RS: %v", commands)
+			}
+		}
+		if fc7 != 1 || c.deliveryPending {
+			t.Errorf("prepare=%t commands=%v pending=%t, want one FC7 and cleared", prepare, commands, c.deliveryPending)
+		}
+		if !prepare && commands[len(commands)-1] != "FC7" {
+			t.Errorf("prestaging polled after FC7: %v", commands)
+		}
+	}
+}

internal/dispenser/transport_test.go

@@ -0,0 +1,417 @@
+package dispenser
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"fmt"
+	"io"
+	"os"
+	"testing"
+	"time"
+)
+
+// Golden frames reconstructed from K720_Dll.dll's big-endian length and XOR
+// algorithm (SendCmd 0x100050C0, Query 0x10005280, SensorQuery 0x10005420).
+var vendorFrames = []struct {
+	name    string
+	command []byte
+	frame   []byte
+}{
+	{"AP", []byte{2, 'A', 'P'}, []byte{2, 0x30, 0x30, 0, 2, 0x41, 0x50, 3, 0x12}},
+	{"RF", []byte{2, 'R', 'F'}, []byte{2, 0x30, 0x30, 0, 2, 0x52, 0x46, 3, 0x17}},
+	{"FC7", commandFC7, []byte{2, 0x30, 0x30, 0, 3, 0x46, 0x43, 0x37, 3, 0x30}},
+	{"FC0", commandFC0, []byte{2, 0x30, 0x30, 0, 3, 0x46, 0x43, 0x30, 3, 0x37}},
+	{"RS", commandRS, []byte{2, 0x30, 0x30, 0, 2, 0x52, 0x53, 3, 2}},
+}
+
+func TestACKScannerFragmentation(t *testing.T) {
+	transportAddress(t)
+	for _, address := range []string{"00", "15"} {
+		Address = []byte(address)
+		wrong := []byte("15")
+		if address == "15" {
+			wrong = []byte("00")
+		}
+		for _, prefix := range [][]byte{nil, {0x30}, {0x10}, {address[1]}, {ACK, wrong[0], wrong[1], 0x30}, {NAK, wrong[0], wrong[1]}} {
+			for _, token := range []byte{ACK, NAK} {
+				wire := append(append([]byte(nil), prefix...), token, Address[0], Address[1])
+				for mask := 0; mask < 1<<(len(wire)-1); mask++ {
+					t.Run(fmt.Sprintf("%s/%X/%d", address, wire, mask), func(t *testing.T) {
+						p := &scriptedTransport{}
+						start := 0
+						for i := 1; i < len(wire); i++ {
+							if mask&(1<<(i-1)) != 0 {
+								p.chunks = append(p.chunks, wire[start:i])
+								start = i
+							}
+						}
+						p.chunks = append(p.chunks, wire[start:])
+						err := dispatchCommand(context.Background(), p, commandFC7, 0)
+						if (err != nil) != (token == NAK) {
+							t.Fatalf("dispatchCommand(% X)=%v", wire, err)
+						}
+						want := [][]byte{createPacket(Address, commandFC7)}
+						if token == ACK {
+							want = append(want, append([]byte{ENQ}, Address...))
+						}
+						if len(p.writes) != len(want) {
+							t.Fatalf("writes=% X want=% X", p.writes, want)
+						}
+						for i := range want {
+							if !bytes.Equal(p.writes[i], want[i]) {
+								t.Errorf("write=% X want=% X", p.writes[i], want[i])
+							}
+						}
+						if len(p.chunks) != 0 {
+							t.Errorf("unread token bytes=% X", p.chunks)
+						}
+					})
+				}
+			}
+		}
+	}
+}
+
+func TestACKScannerBoundsAndFollowingTransaction(t *testing.T) {
+	transportAddress(t)
+	for _, address := range []string{"00", "15"} {
+		Address = []byte(address)
+		ack := append([]byte{ACK}, Address...)
+		for _, leading := range []int{61, 62, 64} {
+			wire := append(bytes.Repeat([]byte{0xff}, leading), ack...)
+			p := &scriptedTransport{chunks: [][]byte{wire}}
+			err := dispatchCommand(context.Background(), p, commandRS, 0)
+			if (err == nil) != (leading == 61) {
+				t.Errorf("leading=%d error=%v", leading, err)
+			}
+			if leading != 61 && (len(p.writes) != 1 || len(bytes.Join(p.chunks, nil)) != len(wire)-64) {
+				t.Fatalf("scan exceeded bound: writes=% X remaining=% X", p.writes, p.chunks)
+			}
+		}
+		wire := append(append(append([]byte{0x10}, ack...), ack...), 0xfe)
+		p := &scriptedTransport{chunks: [][]byte{wire}}
+		for i := 0; i < 2; i++ {
+			if err := dispatchCommand(context.Background(), p, commandFC7, 0); err != nil {
+				t.Fatal(err)
+			}
+		}
+		if len(p.writes) != 4 || !bytes.Equal(bytes.Join(p.chunks, nil), []byte{0xfe}) {
+			t.Fatalf("transaction boundary lost: writes=% X remaining=% X", p.writes, p.chunks)
+		}
+	}
+}
+
+type ackReadErrorTransport struct {
+	*scriptedTransport
+	reads, failAt int
+	err           error
+}
+
+func (p *ackReadErrorTransport) Read(b []byte) (int, error) {
+	p.reads++
+	n, err := p.scriptedTransport.Read(b)
+	if p.reads == p.failAt {
+		return n, p.err
+	}
+	return n, err
+}
+
+func TestACKScannerReadErrors(t *testing.T) {
+	transportAddress(t)
+	for _, address := range []string{"00", "15"} {
+		Address = []byte(address)
+		for _, token := range []byte{ACK, NAK} {
+			for _, readErr := range []error{io.EOF, os.ErrDeadlineExceeded, io.ErrClosedPipe} {
+				for _, failAt := range []int{1, 2} {
+					p := &ackReadErrorTransport{scriptedTransport: &scriptedTransport{chunks: [][]byte{{token, Address[0], Address[1]}}}, failAt: failAt, err: readErr}
+					err := dispatchCommand(context.Background(), p, commandFC7, 0)
+					if failAt == 1 && !errors.Is(err, readErr) {
+						t.Fatalf("incomplete token error=%v want=%v", err, readErr)
+					}
+					if failAt == 2 && ((err == nil) != (token == ACK) || errors.Is(err, readErr)) {
+						t.Fatalf("complete token %02X with read error returned %v", token, err)
+					}
+					wantWrites := 1
+					if failAt == 2 && token == ACK {
+						wantWrites = 2
+					}
+					if len(p.writes) != wantWrites || p.reads != failAt {
+						t.Fatalf("writes=%d reads=%d want=%d/%d", len(p.writes), p.reads, wantWrites, failAt)
+					}
+				}
+			}
+		}
+		for _, wire := range [][]byte{nil, {0x30, ACK, Address[0]}, {0xff, 0xfe}, {ACK, Address[0]}} {
+			p := &scriptedTransport{chunks: [][]byte{wire}}
+			if err := dispatchCommand(context.Background(), p, commandFC7, 0); err == nil || len(p.writes) != 1 {
+				t.Fatalf("incomplete/garbage % X: err=%v writes=% X", wire, err, p.writes)
+			}
+		}
+		for _, cancelAt := range []int{1, 2} {
+			ctx, cancel := context.WithCancel(context.Background())
+			p := &ackReadErrorTransport{scriptedTransport: &scriptedTransport{chunks: [][]byte{{ACK, Address[0], Address[1]}}}, failAt: 2, err: io.EOF}
+			p.afterRead = func() {
+				if p.reads == cancelAt {
+					cancel()
+				}
+			}
+			err := dispatchCommand(ctx, p, commandFC7, 0)
+			cancel()
+			if !errors.Is(err, context.Canceled) || len(p.writes) != 1 || p.reads != cancelAt {
+				t.Fatalf("cancel read %d: err=%v writes=%d reads=%d", cancelAt, err, len(p.writes), p.reads)
+			}
+		}
+	}
+}
+
+func TestVendorOutboundFrames(t *testing.T) {
+	for _, tc := range vendorFrames {
+		t.Run(tc.name, func(t *testing.T) {
+			if got := createPacket([]byte("00"), tc.command); !bytes.Equal(got, tc.frame) {
+				t.Errorf("createPacket(%s) = % X, want % X", tc.name, got, tc.frame)
+			}
+			if got := calculateBCC(tc.frame[:len(tc.frame)-1]); got != tc.frame[len(tc.frame)-1] {
+				t.Errorf("calculateBCC(%s) = %02X, want %02X", tc.name, got, tc.frame[len(tc.frame)-1])
+			}
+		})
+	}
+}
+
+type scriptedTransport struct {
+	chunks     [][]byte
+	writes     [][]byte
+	readErr    error
+	writeErr   error
+	shortWrite int
+	afterRead  func()
+	afterWrite func()
+}
+
+func (p *scriptedTransport) Read(b []byte) (int, error) {
+	if len(p.chunks) == 0 {
+		if p.readErr != nil {
+			return 0, p.readErr
+		}
+		return 0, io.EOF
+	}
+	n := copy(b, p.chunks[0])
+	p.chunks[0] = p.chunks[0][n:]
+	if len(p.chunks[0]) == 0 {
+		p.chunks = p.chunks[1:]
+	}
+	if p.afterRead != nil {
+		p.afterRead()
+	}
+	return n, nil
+}
+func (p *scriptedTransport) Write(b []byte) (int, error) {
+	p.writes = append(p.writes, append([]byte(nil), b...))
+	if p.afterWrite != nil {
+		p.afterWrite()
+	}
+	if p.writeErr != nil {
+		return 0, p.writeErr
+	}
+	if p.shortWrite == len(p.writes) {
+		return len(b) - 1, nil
+	}
+	return len(b), nil
+}
+func transportAddress(t *testing.T) {
+	t.Helper()
+	old := Address
+	Address = []byte("00")
+	t.Cleanup(func() { Address = old })
+}
+
+// Independent SF response vectors: status is 30 30 30 [33].
+var vendorAP = []byte{2, 0x30, 0x30, 0, 6, 'S', 'F', 0x30, 0x30, 0x30, 0x33, 3, 0x11}
+var vendorRF = []byte{2, 0x30, 0x30, 0, 5, 'S', 'F', 0x30, 0x30, 0x30, 3, 0x21}
+var vendorACK = []byte{6, 0x30, 0x30}
+
+func TestVendorQueryFragmentation(t *testing.T) {
+	transportAddress(t)
+	for i, frame := range [][]byte{vendorAP, vendorRF} {
+		wire := append(append([]byte(nil), vendorACK...), frame...)
+		for split := 1; split < len(wire); split++ {
+			t.Run(fmt.Sprintf("%s/split%d", vendorFrames[i].name, split), func(t *testing.T) {
+				p := &scriptedTransport{chunks: [][]byte{wire[:split], wire[split:]}}
+				got, err := queryStatus(context.Background(), p, vendorFrames[i].command, 4-i, 0)
+				if err != nil || !bytes.Equal(got, frame[7:len(frame)-2]) {
+					t.Fatalf("queryStatus(split=%d) = % X, %v, want % X, nil", split, got, err, frame[7:len(frame)-2])
+				}
+				if len(p.writes) != 2 || !bytes.Equal(p.writes[0], vendorFrames[i].frame) || !bytes.Equal(p.writes[1], []byte{5, 0x30, 0x30}) {
+					t.Errorf("queryStatus writes = % X, want command then ENQ", p.writes)
+				}
+			})
+		}
+		t.Run(vendorFrames[i].name+"/one-byte", func(t *testing.T) {
+			p := &scriptedTransport{}
+			for _, b := range wire {
+				p.chunks = append(p.chunks, []byte{b})
+			}
+			if _, err := queryStatus(context.Background(), p, vendorFrames[i].command, 4-i, 0); err != nil {
+				t.Errorf("queryStatus(one-byte reads) = %v, want nil", err)
+			}
+		})
+	}
+}
+
+func TestVendorQueryRejectsInvalidFrames(t *testing.T) {
+	transportAddress(t)
+	for _, tc := range []struct {
+		name   string
+		offset int
+		value  byte
+	}{
+		{"STX", 0, 1}, {"address high", 1, '1'}, {"address low", 2, '1'},
+		{"zero length", 4, 0}, {"short length", 4, 5}, {"long length", 4, 7}, {"high length", 3, 0xff},
+		{"type S", 5, 'X'}, {"type F", 6, 'X'}, {"ETX", 11, 4}, {"BCC", 12, 0},
+	} {
+		t.Run(tc.name, func(t *testing.T) {
+			frame := append([]byte(nil), vendorAP...)
+			frame[tc.offset] = tc.value
+			// Keep checksum valid when testing type/ETX to isolate those checks.
+			if tc.offset == 5 || tc.offset == 6 || tc.offset == 11 {
+				frame[12] = 0
+				for _, b := range frame[:12] {
+					frame[12] ^= b
+				}
+			}
+			p := &scriptedTransport{chunks: [][]byte{vendorACK, frame}}
+			if got, err := queryStatus(context.Background(), p, vendorFrames[0].command, 4, 0); err == nil || got != nil {
+				t.Errorf("queryStatus(%s) = % X, %v, want nil/error", tc.name, got, err)
+			}
+			if len(p.writes) != 2 {
+				t.Errorf("queryStatus(%s) writes=%d, want 2 without resend", tc.name, len(p.writes))
+			}
+		})
+	}
+	for n := 0; n < len(vendorAP); n++ {
+		t.Run(fmt.Sprintf("truncated%d", n), func(t *testing.T) {
+			p := &scriptedTransport{chunks: [][]byte{vendorACK, vendorAP[:n]}}
+			if _, err := queryStatus(context.Background(), p, vendorFrames[0].command, 4, 0); err == nil {
+				t.Errorf("queryStatus(%d-byte frame) succeeded, want error", n)
+			}
+		})
+	}
+}
+
+func TestTransportACKAndMechanicalDispatch(t *testing.T) {
+	transportAddress(t)
+	for _, tc := range vendorFrames[2:] {
+		p := &scriptedTransport{chunks: [][]byte{{6}, {'0'}, {'0'}}}
+		if err := dispatchCommand(context.Background(), p, tc.command, 0); err != nil {
+			t.Fatalf("dispatchCommand(%s)=%v, want nil", tc.name, err)
+		}
+		if len(p.writes) != 2 || !bytes.Equal(p.writes[0], tc.frame) || !bytes.Equal(p.writes[1], []byte{5, '0', '0'}) {
+			t.Errorf("dispatchCommand(%s) writes=% X, want command then ENQ", tc.name, p.writes)
+		}
+	}
+	for _, ack := range [][]byte{{0x15, '0', '0'}, {6, '1', '0'}, {6, '0', '1'}, {6}, {6, '0'}, {}} {
+		p := &scriptedTransport{chunks: [][]byte{ack}}
+		if err := dispatchCommand(context.Background(), p, commandFC7, 0); err == nil {
+			t.Errorf("dispatchCommand(ACK=% X) succeeded, want error", ack)
+		}
+		if len(p.writes) != 1 {
+			t.Errorf("dispatchCommand(ACK=% X) writes=%d, want 1", ack, len(p.writes))
+		}
+	}
+}
+
+func TestTransportShortWritesAndErrors(t *testing.T) {
+	transportAddress(t)
+	failure := errors.New("serial failure")
+	for _, stage := range []int{1, 2} {
+		p := &scriptedTransport{chunks: [][]byte{vendorACK}, shortWrite: stage}
+		if err := dispatchCommand(context.Background(), p, commandFC7, 0); !errors.Is(err, io.ErrShortWrite) {
+			t.Errorf("dispatchCommand(short write %d)=%v, want ErrShortWrite", stage, err)
+		}
+		if len(p.writes) != stage {
+			t.Errorf("short write %d writes=%d, want %d", stage, len(p.writes), stage)
+		}
+	}
+	for _, p := range []*scriptedTransport{{writeErr: failure}, {readErr: failure}, {chunks: [][]byte{{}}}} {
+		if err := dispatchCommand(context.Background(), p, commandRS, 0); err == nil {
+			t.Error("dispatchCommand(I/O failure) succeeded, want error")
+		}
+		if len(p.writes) != 1 {
+			t.Errorf("dispatchCommand(I/O failure) writes=%d, want 1", len(p.writes))
+		}
+	}
+}
+
+func TestTransportCancellation(t *testing.T) {
+	transportAddress(t)
+	for _, stage := range []string{"before write", "processing wait", "after ACK", "after ENQ", "after header"} {
+		t.Run(stage, func(t *testing.T) {
+			ctx, cancel := context.WithCancel(context.Background())
+			defer cancel()
+			p := &scriptedTransport{chunks: [][]byte{vendorACK, vendorAP}}
+			wantWrites := 1
+			switch stage {
+			case "before write":
+				cancel()
+				wantWrites = 0
+			case "processing wait":
+				p.afterWrite = cancel
+			case "after ACK":
+				p.afterRead = func() {
+					if len(p.chunks) == 1 {
+						cancel()
+					}
+				}
+			case "after ENQ":
+				wantWrites = 2
+				p.afterWrite = func() {
+					if len(p.writes) == 2 {
+						cancel()
+					}
+				}
+			case "after header":
+				wantWrites = 2
+				reads := 0
+				p.afterRead = func() {
+					reads++
+					if reads == 3 {
+						cancel()
+					}
+				}
+			}
+			if _, err := queryStatus(ctx, p, vendorFrames[0].command, 4, 0); !errors.Is(err, context.Canceled) {
+				t.Errorf("queryStatus(cancel %s)=%v, want Canceled", stage, err)
+			}
+			if len(p.writes) != wantWrites {
+				t.Errorf("queryStatus(cancel %s) writes=%d, want %d", stage, len(p.writes), wantWrites)
+			}
+		})
+	}
+	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Millisecond)
+	defer cancel()
+	p := &scriptedTransport{}
+	if err := dispatchCommand(ctx, p, commandRS, time.Second); !errors.Is(err, context.DeadlineExceeded) {
+		t.Errorf("dispatchCommand(deadline in wait)=%v, want DeadlineExceeded", err)
+	}
+	if len(p.writes) != 1 {
+		t.Errorf("dispatchCommand(deadline) writes=%d, want 1", len(p.writes))
+	}
+}
+
+func TestTransportTrailingDataNotConsumedAsStatus(t *testing.T) {
+	transportAddress(t)
+	frame := append(append([]byte(nil), vendorAP...), 0xff, 0xfe, 0xfd)
+	p := &scriptedTransport{chunks: [][]byte{vendorACK, frame}}
+	if _, err := queryStatus(context.Background(), p, vendorFrames[0].command, 4, 0); err != nil {
+		t.Fatalf("queryStatus(frame with trailing bytes)=%v, want nil", err)
+	}
+	if len(p.chunks) != 1 || !bytes.Equal(p.chunks[0], []byte{0xff, 0xfe, 0xfd}) {
+		t.Fatalf("remaining bytes=% X, want FF FE FD", p.chunks)
+	}
+	if err := dispatchCommand(context.Background(), p, commandFC7, 0); err == nil {
+		t.Error("dispatchCommand(trailing garbage) succeeded, want invalid ACK")
+	}
+	if len(p.writes) != 3 {
+		t.Errorf("writes after trailing garbage=%d, want 3 (no ENQ/resend)", len(p.writes))
+	}
+}

internal/handlers/doorcard_handlers_test.go

@@ -30,10 +30,17 @@ type fakeDoorCardDispenser struct {
 	beginNextErr    error
 	beginNext       func() error
 	prepareNext     dispenserCallResult
+	activity        int
+	registrations   int
+	releases        int
+	outsideActivity bool
 	calls           []string
 }
 
 func (d *fakeDoorCardDispenser) PrepareCurrentCard(context.Context) (string, error) {
+	if d.activity == 0 {
+		d.outsideActivity = true
+	}
 	d.calls = append(d.calls, "prepare current")
 	return d.prepareCurrent.status, d.prepareCurrent.err
 }
@@ -121,11 +128,11 @@ func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
 		wantCardWell     string
 	}{
 		{
-			name: "initial dispenser preparation failure is unavailable",
+			name: "initial dispenser preparation failure is retryable",
 			dispenser: fakeDoorCardDispenser{
 				prepareCurrent: dispenserCallResult{status: "Card jammed", err: errors.New("card jammed")},
 			},
-			wantHTTP:     http.StatusServiceUnavailable,
+			wantHTTP:     http.StatusBadGateway,
 			wantMessage:  "Dispense error: card jammed",
 			wantCalls:    []string{"prepare current"},
 			wantCardWell: "Card jammed",
@@ -140,6 +147,13 @@ func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
 			wantCalls:    []string{"prepare current"},
 			wantCardWell: "Card empty",
 		},
+		{
+			name:        "exhausted preparation is retryable without encoding or delivery",
+			dispenser:   fakeDoorCardDispenser{prepareCurrent: dispenserCallResult{err: errors.Join(errors.New("preparation"), dispenser.ErrPreparationExhausted)}},
+			wantHTTP:    http.StatusBadGateway,
+			wantMessage: "preparation\ncard preparation exhausted",
+			wantCalls:   []string{"prepare current"},
+		},
 		{
 			name:             "encoding and accepted delivery command succeed",
 			wantHTTP:         http.StatusOK,
@@ -148,13 +162,13 @@ func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
 			wantLockSequence: 1,
 		},
 		{
-			name: "successful encoding with delivery command failure is unavailable",
+			name: "successful encoding with delivery command failure still prestages and succeeds",
 			dispenser: fakeDoorCardDispenser{
 				deliverCurrent: dispenserCallResult{status: "Card jammed", err: errors.New("delivery jammed")},
 			},
-			wantHTTP:         http.StatusServiceUnavailable,
+			wantHTTP:         http.StatusOK,
-			wantMessage:      "Card delivery could not be confirmed",
+			wantMessage:      "Card issued successfully",
-			wantCalls:        []string{"prepare current", "deliver current"},
+			wantCalls:        []string{"prepare current", "deliver current", "begin prepare next"},
 			wantLockSequence: 1,
 			wantCardWell:     "Card jammed",
 		},
@@ -169,36 +183,45 @@ func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
 			wantLockSequence: 1,
 		},
 		{
-			name:             "encoding failure with safe recovery remains retryable",
+			name: "delivery clearance deferral does not undo successful issuance",
-			lockErr:          encodingErr,
+			dispenser: fakeDoorCardDispenser{
-			wantHTTP:         http.StatusBadGateway,
+				beginNextErr: errors.New("next-card preparation deferred: previous delivery is not clear"),
-			wantMessage:      encodingErr.Error(),
+			},
-			wantCalls:        []string{"prepare current", "deliver current", "prepare next"},
+			wantHTTP:         http.StatusOK,
+			wantMessage:      "Card issued successfully",
+			wantCalls:        []string{"prepare current", "deliver current", "begin prepare next"},
 			wantLockSequence: 1,
 		},
 		{
-			name: "encoding failure with failed-card delivery failure is unavailable",
+			name:             "encoding failure ends after delivery",
+			lockErr:          encodingErr,
+			wantHTTP:         http.StatusBadGateway,
+			wantMessage:      encodingErr.Error(),
+			wantCalls:        []string{"prepare current", "deliver current"},
+			wantLockSequence: 1,
+		},
+		{
+			name: "encoding failure remains retryable despite FC0 failure",
 			dispenser: fakeDoorCardDispenser{
 				deliverCurrent: dispenserCallResult{status: "Card jammed", err: errors.New("delivery jammed")},
 			},
 			lockErr:          encodingErr,
-			wantHTTP:         http.StatusServiceUnavailable,
+			wantHTTP:         http.StatusBadGateway,
-			wantMessage:      "Dispenser recovery failed; another encoding attempt is not safe",
+			wantMessage:      encodingErr.Error(),
 			wantCalls:        []string{"prepare current", "deliver current"},
 			wantLockSequence: 1,
 			wantCardWell:     "Card jammed",
 		},
 		{
-			name: "encoding failure with empty card well has stable message",
+			name: "encoding failure never prepares next card",
 			dispenser: fakeDoorCardDispenser{
 				prepareNext: dispenserCallResult{status: "Card empty", err: dispenser.ErrCardWellEmpty},
 			},
 			lockErr:          encodingErr,
-			wantHTTP:         http.StatusServiceUnavailable,
+			wantHTTP:         http.StatusBadGateway,
-			wantMessage:      dispenser.CardWellEmptyMessage,
+			wantMessage:      encodingErr.Error(),
-			wantCalls:        []string{"prepare current", "deliver current", "prepare next"},
+			wantCalls:        []string{"prepare current", "deliver current"},
 			wantLockSequence: 1,
-			wantCardWell:     "Card empty",
 		},
 	}
 
@@ -311,3 +334,78 @@ func TestIssueDoorCardLogsNextCardDispatchFailureAndStillSucceeds(t *testing.T)
 		t.Fatalf("dispatch failure log = %q", logged)
 	}
 }
+
+func TestIssueDoorCardLogsDeliveryFailureWithoutReplacingEncoderOutcome(t *testing.T) {
+	for _, encodingErr := range []error{nil, errors.New("original encoder failure")} {
+		var output bytes.Buffer
+		logger := log.StandardLogger()
+		previous := logger.Out
+		logger.SetOutput(&output)
+		d := &fakeDoorCardDispenser{deliverCurrent: dispenserCallResult{err: errors.New("FC0 dispatch failed")}}
+		lock := &fakeDoorCardLockServer{sequenceErr: encodingErr}
+		recorder, response, _ := performIssueDoorCardRequest(t, d, lock)
+		logger.SetOutput(previous)
+		wantHTTP := http.StatusOK
+		if encodingErr != nil {
+			wantHTTP = http.StatusBadGateway
+		}
+		if recorder.Code != wantHTTP {
+			t.Errorf("issueDoorCard(%v) HTTP = %d, want %d", encodingErr, recorder.Code, wantHTTP)
+		}
+		if encodingErr != nil && response.Message != encodingErr.Error() {
+			t.Errorf("issueDoorCard message = %q, want %q", response.Message, encodingErr.Error())
+		}
+		if !strings.Contains(output.String(), "FC0 dispatch failed") || !strings.Contains(output.String(), "Card delivery") {
+			t.Errorf("issueDoorCard delivery log = %q, want FC0 failure and Card delivery", output.String())
+		}
+	}
+}
+
+func TestIssueDoorCardOnlyEmptyPreparationReturns503(t *testing.T) {
+	for _, failure := range []error{
+		dispenser.ErrCardWellEmpty, errors.Join(errors.New("wrapped"), dispenser.ErrCardWellEmpty),
+		dispenser.ErrPreparationExhausted, context.Canceled, context.DeadlineExceeded,
+		errors.New("malformed AP"), errors.New("truncated AP"), errors.New("no response"),
+		errors.New("serial read failed"), errors.New("serial write failed"), errors.New("FC7 dispatch failed"),
+		errors.New("RS dispatch failed"), errors.New(dispenser.CardWellEmptyMessage), errors.New("other preparation error"),
+	} {
+		d := &fakeDoorCardDispenser{prepareCurrent: dispenserCallResult{err: failure}}
+		lock := &fakeDoorCardLockServer{}
+		recorder, response, _ := performIssueDoorCardRequest(t, d, lock)
+		want := http.StatusBadGateway
+		if errors.Is(failure, dispenser.ErrCardWellEmpty) {
+			want = http.StatusServiceUnavailable
+		}
+		if recorder.Code != want || response.Code != want {
+			t.Errorf("preparation %v HTTP=%d body=%d, want %d", failure, recorder.Code, response.Code, want)
+		}
+		if lock.sequenceCalls != 0 || !reflect.DeepEqual(d.calls, []string{"prepare current"}) {
+			t.Errorf("preparation %v encoder=%d calls=%v, want no physical continuation", failure, lock.sequenceCalls, d.calls)
+		}
+	}
+}
+
+func (d *fakeDoorCardDispenser) BeginForeground() func() {
+	d.activity++
+	d.registrations++
+	return func() { d.activity--; d.releases++ }
+}
+
+func TestDoorCardForegroundLifecycle(t *testing.T) {
+	for _, testEndpoint := range []bool{false, true} {
+		d := &fakeDoorCardDispenser{prepareCurrent: dispenserCallResult{err: errors.New("stop before encoding")}}
+		lock := &fakeDoorCardLockServer{}
+		_, _, app := performIssueDoorCardRequest(t, d, lock)
+		if d.registrations != 1 || d.releases != 1 || d.activity != 0 || d.outsideActivity {
+			t.Fatalf("issue registration=%d release=%d active=%d outside=%t", d.registrations, d.releases, d.activity, d.outsideActivity)
+		}
+		if testEndpoint {
+			req := httptest.NewRequest(http.MethodPost, "/testissuedoorcard", strings.NewReader("{}"))
+			req.Header.Set("Content-Type", "application/json")
+			app.testIssueDoorCard(httptest.NewRecorder(), req)
+			if d.registrations != 2 || d.releases != 2 || d.activity != 0 || d.outsideActivity {
+				t.Errorf("test endpoint registration=%d release=%d active=%d outside=%t", d.registrations, d.releases, d.activity, d.outsideActivity)
+			}
+		}
+	}
+}

internal/handlers/handlers.go

@@ -6,7 +6,6 @@ import (
 	"encoding/json"
 	"encoding/xml"
 	"errors"
-	"fmt"
 	"io"
 	"net/http"
 	"strings"
@@ -28,6 +27,7 @@ import (
 )
 
 type doorCardDispenser interface {
+	BeginForeground() func()
 	PrepareCurrentCard(context.Context) (string, error)
 	DeliverCurrentCard(context.Context) (string, error)
 	BeginPrepareNextCard(context.Context) error
@@ -291,6 +291,9 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
+	release := app.disp.BeginForeground()
+	defer release()
+
 	status, err := app.disp.PrepareCurrentCard(r.Context())
 	app.SetCardWellStatus(status)
 	if err != nil {
@@ -299,7 +302,11 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
 			errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
 			return
 		}
-		errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispense error: "+err.Error())
+		if errors.Is(err, dispenser.ErrPreparationExhausted) {
+			errorhandlers.WriteError(w, http.StatusBadGateway, err.Error())
+			return
+		}
+		errorhandlers.WriteError(w, http.StatusBadGateway, "Dispense error: "+err.Error())
 		return
 	}
 
@@ -307,8 +314,11 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
 	// build lock server command
 	app.lockserver.BuildCommand(doorReq, checkIn, checkOut)
 
-	// lock server sequence
+	// Each request performs at most one encoder operation.
+	encodingStarted := time.Now()
+	log.Info("LockSequence started")
 	encodingErr := app.lockserver.LockSequence()
+	log.Infof("LockSequence finished; success=%t duration=%s", encodingErr == nil, time.Since(encodingStarted))
 	if encodingErr != nil {
 		logging.Error(types.ServiceName, encodingErr.Error(), "Key encoding", string(op), "", "", 0)
 	}
@@ -321,32 +331,10 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
 	status, deliveryErr := app.disp.DeliverCurrentCard(finalizeCtx)
 	app.SetCardWellStatus(status)
 	if deliveryErr != nil {
-		if encodingErr != nil {
-			recoveryErr := fmt.Errorf("key encoding failed: %v; dispenser recovery failed: %w", encodingErr, deliveryErr)
-			logging.Error(types.ServiceName, recoveryErr.Error(), "Dispenser recovery", string(op), "", "", 0)
-			errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispenser recovery failed; another encoding attempt is not safe")
-			return
-		}
-
 		logging.Error(types.ServiceName, deliveryErr.Error(), "Card delivery", string(op), "", "", 0)
-		errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Card delivery could not be confirmed")
-		return
 	}
-
 	if encodingErr != nil {
-		status, preparationErr := app.disp.PrepareNextCard(finalizeCtx)
+		// FC0 is attempted once; the next UI request owns all further preparation.
-		app.SetCardWellStatus(status)
-		if preparationErr != nil {
-			recoveryErr := fmt.Errorf("key encoding failed: %v; dispenser recovery failed: %w", encodingErr, preparationErr)
-			logging.Error(types.ServiceName, recoveryErr.Error(), "Dispenser recovery", string(op), "", "", 0)
-			if errors.Is(preparationErr, dispenser.ErrCardWellEmpty) {
-				errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
-				return
-			}
-			errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispenser recovery failed; another encoding attempt is not safe")
-			return
-		}
-
 		errorhandlers.WriteError(w, http.StatusBadGateway, encodingErr.Error())
 		return
 	}

internal/handlers/testhandlers.go

@@ -59,6 +59,9 @@ func (app *App) testIssueDoorCard(w http.ResponseWriter, r *http.Request) {
 
 	// Ensure dispenser ready (card at encoder) BEFORE we attempt encoding.
 	// With queued dispenser ops, this will not clash with polling.
+	release := app.disp.BeginForeground()
+	defer release()
+
 	status, err := app.disp.PrepareCurrentCard(r.Context())
 	app.SetCardWellStatus(status)
 	if err != nil {

internal/logging/logging.go

@@ -2,17 +2,22 @@ package logging
 
 import (
 	"fmt"
+	"io"
 	"os"
+	"path/filepath"
 	"time"
 
 	log "github.com/sirupsen/logrus"
 )
 
-// setupLogging ensures log directory, opens log file, and configures logrus.
+// SetupLogging ensures the log directory, opens the rotating log writer, and configures logrus.
-// Returns the *os.File so caller can defer its Close().
+func SetupLogging(logDir, serviceName, buildVersion string) (io.WriteCloser, error) {
-func SetupLogging(logDir, serviceName, buildVersion string) (*os.File, error) {
+	if err := os.MkdirAll(logDir, 0o755); err != nil {
-	fileName := logDir + serviceName + ".log"
+		return nil, fmt.Errorf("create log directory: %w", err)
-	f, err := os.OpenFile(fileName, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0666)
+	}
+
+	fileName := filepath.Join(logDir, serviceName+".log")
+	f, err := newWeeklyLogWriter(fileName, time.Local, defaultWeeklyLogRuntime())
 	if err != nil {
 		return nil, fmt.Errorf("open log file: %w", err)
 	}

internal/logging/weekly_writer.go

@@ -0,0 +1,319 @@
+package logging
+
+import (
+	"errors"
+	"fmt"
+	"io"
+	"io/fs"
+	"log/slog"
+	"os"
+	"path/filepath"
+	"strconv"
+	"strings"
+	"sync"
+	"time"
+	_ "time/tzdata"
+)
+
+const weeklyLogRetention = 13
+
+type logRotationTimer interface {
+	C() <-chan time.Time
+	Stop() bool
+}
+
+type realLogRotationTimer struct {
+	*time.Timer
+}
+
+func (t realLogRotationTimer) C() <-chan time.Time {
+	return t.Timer.C
+}
+
+type weeklyLogRuntime struct {
+	now        func() time.Time
+	newTimer   func(time.Duration) logRotationTimer
+	rename     func(string, string) error
+	diagnostic io.Writer
+}
+
+func defaultWeeklyLogRuntime() weeklyLogRuntime {
+	return weeklyLogRuntime{
+		now: time.Now,
+		newTimer: func(duration time.Duration) logRotationTimer {
+			return realLogRotationTimer{Timer: time.NewTimer(duration)}
+		},
+		rename:     os.Rename,
+		diagnostic: os.Stderr,
+	}
+}
+
+type weeklyLogWriter struct {
+	path       string
+	location   *time.Location
+	now        func() time.Time
+	newTimer   func(time.Duration) logRotationTimer
+	rename     func(string, string) error
+	diagnostic io.Writer
+
+	mu        sync.Mutex
+	file      *os.File
+	weekStart time.Time
+	closed    bool
+	stop      chan struct{}
+	done      chan struct{}
+	closeOnce sync.Once
+	closeErr  error
+}
+
+func newWeeklyLogWriter(path string, location *time.Location, runtime weeklyLogRuntime) (*weeklyLogWriter, error) {
+	if location == nil {
+		location = time.Local
+	}
+	if runtime.now == nil {
+		runtime.now = time.Now
+	}
+	if runtime.newTimer == nil {
+		runtime.newTimer = defaultWeeklyLogRuntime().newTimer
+	}
+	if runtime.rename == nil {
+		runtime.rename = os.Rename
+	}
+	if runtime.diagnostic == nil {
+		runtime.diagnostic = os.Stderr
+	}
+
+	now := runtime.now().In(location)
+	weekStart := logWeekStart(now, location)
+	if info, err := os.Stat(path); err == nil {
+		weekStart = logWeekStart(info.ModTime(), location)
+	} else if !errors.Is(err, os.ErrNotExist) {
+		return nil, fmt.Errorf("inspect active log: %w", err)
+	}
+
+	file, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o666)
+	if err != nil {
+		return nil, err
+	}
+
+	writer := &weeklyLogWriter{
+		path:       path,
+		location:   location,
+		now:        runtime.now,
+		newTimer:   runtime.newTimer,
+		rename:     runtime.rename,
+		diagnostic: runtime.diagnostic,
+		file:       file,
+		weekStart:  weekStart,
+		stop:       make(chan struct{}),
+		done:       make(chan struct{}),
+	}
+	writer.rotateIfNeeded(now)
+	go writer.run()
+	return writer, nil
+}
+
+func (w *weeklyLogWriter) Write(data []byte) (int, error) {
+	now := w.now().In(w.location)
+	w.mu.Lock()
+	rotationErr := w.rotateIfNeededLocked(now)
+	if w.closed || w.file == nil {
+		w.mu.Unlock()
+		w.reportRotationError(rotationErr)
+		return 0, os.ErrClosed
+	}
+	n, writeErr := w.file.Write(data)
+	w.mu.Unlock()
+	w.reportRotationError(rotationErr)
+	return n, writeErr
+}
+
+func (w *weeklyLogWriter) Close() error {
+	w.closeOnce.Do(func() {
+		close(w.stop)
+		<-w.done
+
+		w.mu.Lock()
+		w.closed = true
+		if w.file != nil {
+			w.closeErr = w.file.Close()
+			w.file = nil
+		}
+		w.mu.Unlock()
+	})
+	return w.closeErr
+}
+
+func (w *weeklyLogWriter) run() {
+	defer close(w.done)
+	for {
+		now := w.now().In(w.location)
+		next := nextLogWeekStart(now, w.location)
+		duration := next.Sub(now)
+		if duration <= 0 {
+			duration = time.Nanosecond
+		}
+		timer := w.newTimer(duration)
+		select {
+		case <-timer.C():
+			w.rotateIfNeeded(w.now().In(w.location))
+		case <-w.stop:
+			timer.Stop()
+			return
+		}
+	}
+}
+
+func (w *weeklyLogWriter) rotateIfNeeded(now time.Time) {
+	w.mu.Lock()
+	err := w.rotateIfNeededLocked(now)
+	w.mu.Unlock()
+	w.reportRotationError(err)
+}
+
+func (w *weeklyLogWriter) rotateIfNeededLocked(now time.Time) error {
+	if w.closed {
+		return nil
+	}
+	targetWeek := logWeekStart(now, w.location)
+	if !targetWeek.After(w.weekStart) {
+		return nil
+	}
+
+	// Record the attempted week even if rotation fails so every write in a
+	// broken environment does not retry and emit another diagnostic.
+	w.weekStart = targetWeek
+	return w.rotateLocked()
+}
+
+func (w *weeklyLogWriter) rotateLocked() error {
+	if w.file == nil {
+		return fmt.Errorf("active log file is unavailable")
+	}
+	if err := w.file.Close(); err != nil {
+		w.file = nil
+		return errors.Join(fmt.Errorf("close active log: %w", err), w.reopenActiveLocked())
+	}
+	w.file = nil
+
+	if err := w.cleanupOlderGenerationsLocked(); err != nil {
+		return errors.Join(err, w.reopenActiveLocked())
+	}
+	if err := removeIfExists(w.generationPath(weeklyLogRetention)); err != nil {
+		return errors.Join(fmt.Errorf("remove oldest weekly log: %w", err), w.reopenActiveLocked())
+	}
+	for generation := weeklyLogRetention - 1; generation >= 1; generation-- {
+		source := w.generationPath(generation)
+		if _, err := os.Stat(source); err != nil {
+			if errors.Is(err, os.ErrNotExist) {
+				continue
+			}
+			return errors.Join(fmt.Errorf("inspect weekly log generation %d: %w", generation, err), w.reopenActiveLocked())
+		}
+		if err := w.rename(source, w.generationPath(generation+1)); err != nil {
+			return errors.Join(fmt.Errorf("shift weekly log generation %d: %w", generation, err), w.reopenActiveLocked())
+		}
+	}
+
+	activeRenamed := false
+	if _, err := os.Stat(w.path); err == nil {
+		if err := w.rename(w.path, w.generationPath(1)); err != nil {
+			return errors.Join(fmt.Errorf("archive active log: %w", err), w.reopenActiveLocked())
+		}
+		activeRenamed = true
+	} else if !errors.Is(err, os.ErrNotExist) {
+		return errors.Join(fmt.Errorf("inspect active log: %w", err), w.reopenActiveLocked())
+	}
+
+	file, err := os.OpenFile(w.path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o666)
+	if err == nil {
+		w.file = file
+		return nil
+	}
+
+	rotationErr := fmt.Errorf("open new active log: %w", err)
+	if activeRenamed {
+		if rollbackErr := w.rename(w.generationPath(1), w.path); rollbackErr != nil {
+			rotationErr = errors.Join(rotationErr, fmt.Errorf("restore archived active log: %w", rollbackErr))
+		}
+	}
+	return errors.Join(rotationErr, w.reopenActiveLocked())
+}
+
+func (w *weeklyLogWriter) cleanupOlderGenerationsLocked() error {
+	directory := filepath.Dir(w.path)
+	entries, err := os.ReadDir(directory)
+	if err != nil {
+		return fmt.Errorf("list weekly log directory: %w", err)
+	}
+	base := filepath.Base(w.path)
+	extension := filepath.Ext(base)
+	stem := strings.TrimSuffix(base, extension)
+	prefix := stem + "."
+
+	for _, entry := range entries {
+		if entry.IsDir() {
+			continue
+		}
+		name := entry.Name()
+		if !strings.HasPrefix(name, prefix) || !strings.HasSuffix(name, extension) {
+			continue
+		}
+		generationText := strings.TrimSuffix(strings.TrimPrefix(name, prefix), extension)
+		generation, err := strconv.Atoi(generationText)
+		if err != nil || generation <= weeklyLogRetention {
+			continue
+		}
+		if err := os.Remove(filepath.Join(directory, name)); err != nil && !errors.Is(err, os.ErrNotExist) {
+			return fmt.Errorf("remove weekly log generation %d: %w", generation, err)
+		}
+	}
+	return nil
+}
+
+func (w *weeklyLogWriter) reopenActiveLocked() error {
+	file, err := os.OpenFile(w.path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o666)
+	if err != nil {
+		return fmt.Errorf("reopen active log: %w", err)
+	}
+	w.file = file
+	return nil
+}
+
+func (w *weeklyLogWriter) generationPath(generation int) string {
+	extension := filepath.Ext(w.path)
+	stem := strings.TrimSuffix(w.path, extension)
+	return fmt.Sprintf("%s.%d%s", stem, generation, extension)
+}
+
+func (w *weeklyLogWriter) reportRotationError(err error) {
+	if err == nil {
+		return
+	}
+	slog.New(slog.NewJSONHandler(w.diagnostic, nil)).Warn(
+		"weekly log rotation failed",
+		"module", "logging",
+		"action", "weekly_log_rotation_failed",
+		"path", w.path,
+		"error.message", err.Error(),
+	)
+}
+
+func logWeekStart(value time.Time, location *time.Location) time.Time {
+	local := value.In(location)
+	daysSinceMonday := (int(local.Weekday()) + 6) % 7
+	monday := local.AddDate(0, 0, -daysSinceMonday)
+	return time.Date(monday.Year(), monday.Month(), monday.Day(), 0, 0, 0, 0, location)
+}
+
+func nextLogWeekStart(value time.Time, location *time.Location) time.Time {
+	return logWeekStart(value, location).AddDate(0, 0, 7)
+}
+
+func removeIfExists(path string) error {
+	err := os.Remove(path)
+	if errors.Is(err, fs.ErrNotExist) {
+		return nil
+	}
+	return err
+}

internal/logging/weekly_writer_test.go

@@ -0,0 +1,387 @@
+package logging
+
+import (
+	"bytes"
+	"errors"
+	"fmt"
+	"io"
+	"os"
+	"path/filepath"
+	"strings"
+	"sync"
+	"sync/atomic"
+	"testing"
+	"time"
+
+	log "github.com/sirupsen/logrus"
+)
+
+func TestWeeklyLogRotationShiftsAndRetainsExactGenerations(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "active")
+	for generation := 1; generation <= 14; generation++ {
+		writeLogTestFile(t, weeklyLogTestGeneration(path, generation), fmt.Sprintf("generation-%d", generation))
+	}
+	writeLogTestFile(t, weeklyLogTestGeneration(path, 19), "generation-19")
+	for name, contents := range map[string]string{
+		"hardlink.backup.14.log": "related-looking backup",
+		"another.14.log":         "unrelated log",
+		"hardlink.14.log.bak":    "different extension",
+	} {
+		writeLogTestFile(t, filepath.Join(directory, name), contents)
+	}
+
+	sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC)
+	setLogTestModTime(t, path, sunday)
+	writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{})
+	writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC))
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	requireLogTestContents(t, path, "")
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "active")
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 2), "generation-1")
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 13), "generation-12")
+	for _, generation := range []int{14, 19} {
+		if _, err := os.Stat(weeklyLogTestGeneration(path, generation)); !errors.Is(err, os.ErrNotExist) {
+			t.Errorf("generation %d exists after rotation, want removed: %v", generation, err)
+		}
+	}
+	for name, contents := range map[string]string{
+		"hardlink.backup.14.log": "related-looking backup",
+		"another.14.log":         "unrelated log",
+		"hardlink.14.log.bak":    "different extension",
+	} {
+		requireLogTestContents(t, filepath.Join(directory, name), contents)
+	}
+}
+
+func TestWeeklyLogRotationOccursOncePerWeek(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "week-zero\n")
+	sunday := time.Date(2026, time.January, 4, 18, 0, 0, 0, time.UTC)
+	setLogTestModTime(t, path, sunday)
+	writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{})
+
+	writer.rotateIfNeeded(time.Date(2026, time.January, 4, 23, 59, 59, 0, time.UTC))
+	if _, err := os.Stat(weeklyLogTestGeneration(path, 1)); !errors.Is(err, os.ErrNotExist) {
+		t.Fatalf("rotation before Monday: %v, want no generation", err)
+	}
+	writer.rotateIfNeeded(time.Date(2026, time.January, 5, 0, 0, 0, 0, time.UTC))
+	if _, err := writer.Write([]byte("week-one\n")); err != nil {
+		t.Fatal(err)
+	}
+	writer.rotateIfNeeded(time.Date(2026, time.January, 6, 12, 0, 0, 0, time.UTC))
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "week-zero\n")
+	requireLogTestContents(t, path, "week-one\n")
+	if _, err := os.Stat(weeklyLogTestGeneration(path, 2)); !errors.Is(err, os.ErrNotExist) {
+		t.Errorf("same-week rotation created generation 2: %v", err)
+	}
+}
+
+func TestWeeklyLogStartupRotatesOnceAfterSeveralMissedWeeks(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "old active")
+	writeLogTestFile(t, weeklyLogTestGeneration(path, 1), "older history")
+	setLogTestModTime(t, path, time.Date(2026, time.January, 5, 12, 0, 0, 0, time.UTC))
+
+	now := time.Date(2026, time.February, 23, 9, 0, 0, 0, time.UTC)
+	writer := newLogTestWriter(t, path, now, weeklyLogRuntime{})
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "old active")
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 2), "older history")
+	if _, err := os.Stat(weeklyLogTestGeneration(path, 3)); !errors.Is(err, os.ErrNotExist) {
+		t.Errorf("missed weeks created generation 3: %v", err)
+	}
+}
+
+func TestWeeklyLogSchedulerUsesLocalMondayBoundary(t *testing.T) {
+	location, err := time.LoadLocation("Europe/London")
+	if err != nil {
+		t.Fatal(err)
+	}
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "sunday")
+	sunday := time.Date(2026, time.March, 29, 0, 0, 0, 0, location)
+	setLogTestModTime(t, path, sunday)
+
+	clock := &atomic.Pointer[time.Time]{}
+	clock.Store(&sunday)
+	created := make(chan *logTestTimer, 2)
+	rotated := make(chan struct{})
+	runtime := weeklyLogRuntime{
+		now: func() time.Time { return *clock.Load() },
+		newTimer: func(duration time.Duration) logRotationTimer {
+			timer := &logTestTimer{duration: duration, ch: make(chan time.Time, 1)}
+			created <- timer
+			return timer
+		},
+		rename: func(oldPath, newPath string) error {
+			err := os.Rename(oldPath, newPath)
+			if oldPath == path && err == nil {
+				close(rotated)
+			}
+			return err
+		},
+	}
+	writer, err := newWeeklyLogWriter(path, location, runtime)
+	if err != nil {
+		t.Fatal(err)
+	}
+	timer := <-created
+	if timer.duration != 23*time.Hour {
+		t.Fatalf("timer duration = %v, want 23h across DST boundary", timer.duration)
+	}
+	monday := time.Date(2026, time.March, 30, 0, 0, 0, 0, location)
+	clock.Store(&monday)
+	timer.ch <- monday
+	<-rotated
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+	requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "sunday")
+}
+
+func TestWeeklyLogConcurrentWritesRemainCompleteAcrossRotation(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC)
+	writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{})
+
+	const goroutines = 8
+	const recordsPerGoroutine = 100
+	writeErrors := make(chan error, goroutines)
+	var writers sync.WaitGroup
+	writers.Add(goroutines)
+	for worker := 0; worker < goroutines; worker++ {
+		go func() {
+			defer writers.Done()
+			for record := 0; record < recordsPerGoroutine; record++ {
+				if _, err := writer.Write([]byte(fmt.Sprintf("%d:%d\n", worker, record))); err != nil {
+					writeErrors <- err
+					return
+				}
+			}
+		}()
+	}
+	writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC))
+	writers.Wait()
+	close(writeErrors)
+	for err := range writeErrors {
+		t.Errorf("weeklyLogWriter.Write() error = %v, want nil", err)
+	}
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	contents := readLogTestFile(t, weeklyLogTestGeneration(path, 1)) + readLogTestFile(t, path)
+	lines := strings.Split(strings.TrimSpace(contents), "\n")
+	if len(lines) != goroutines*recordsPerGoroutine {
+		t.Fatalf("record count = %d, want %d", len(lines), goroutines*recordsPerGoroutine)
+	}
+	seen := make(map[string]bool, len(lines))
+	for _, line := range lines {
+		if _, _, ok := strings.Cut(line, ":"); !ok {
+			t.Fatalf("record %q has no separator", line)
+		}
+		seen[line] = true
+	}
+	if len(seen) != goroutines*recordsPerGoroutine {
+		t.Errorf("unique record count = %d, want %d", len(seen), goroutines*recordsPerGoroutine)
+	}
+}
+
+func TestWeeklyLogCloseWaitsForRotationAndIsIdempotent(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "active")
+	sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC)
+	setLogTestModTime(t, path, sunday)
+	started := make(chan struct{})
+	release := make(chan struct{})
+	runtime := weeklyLogRuntime{rename: func(oldPath, newPath string) error {
+		if oldPath == path {
+			close(started)
+			<-release
+		}
+		return os.Rename(oldPath, newPath)
+	}}
+	writer := newLogTestWriter(t, path, sunday, runtime)
+	rotationDone := make(chan struct{})
+	go func() {
+		writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC))
+		close(rotationDone)
+	}()
+	<-started
+
+	closeDone := make(chan error, 1)
+	go func() { closeDone <- writer.Close() }()
+	select {
+	case err := <-closeDone:
+		t.Fatalf("weeklyLogWriter.Close() during rotation returned %v, want blocked", err)
+	case <-time.After(20 * time.Millisecond):
+	}
+	close(release)
+	<-rotationDone
+	if err := <-closeDone; err != nil {
+		t.Fatal(err)
+	}
+	if err := writer.Close(); err != nil {
+		t.Errorf("second weeklyLogWriter.Close() error = %v, want nil", err)
+	}
+	if _, err := writer.Write([]byte("after close")); !errors.Is(err, os.ErrClosed) {
+		t.Errorf("weeklyLogWriter.Write() after close error = %v, want os.ErrClosed", err)
+	}
+}
+
+func TestWeeklyLogRotationFailureIsNonRecursiveAndPreservesWrites(t *testing.T) {
+	directory := t.TempDir()
+	path := filepath.Join(directory, "hardlink.log")
+	writeLogTestFile(t, path, "before\n")
+	sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC)
+	setLogTestModTime(t, path, sunday)
+	var diagnostics bytes.Buffer
+	runtime := weeklyLogRuntime{
+		rename: func(oldPath, newPath string) error {
+			if oldPath == path {
+				return errors.New("injected rename failure")
+			}
+			return os.Rename(oldPath, newPath)
+		},
+		diagnostic: &diagnostics,
+	}
+	writer := newLogTestWriter(t, path, sunday, runtime)
+	writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC))
+	if _, err := writer.Write([]byte("after\n")); err != nil {
+		t.Fatalf("weeklyLogWriter.Write() after failed rotation error = %v, want nil", err)
+	}
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	requireLogTestContents(t, path, "before\nafter\n")
+	if !strings.Contains(diagnostics.String(), "weekly_log_rotation_failed") || !strings.Contains(diagnostics.String(), "injected rename failure") {
+		t.Errorf("rotation diagnostic = %q, want action and injected error", diagnostics.String())
+	}
+	if strings.Contains(readLogTestFile(t, path), "weekly log rotation failed") {
+		t.Error("rotation diagnostic recursively entered active log")
+	}
+}
+
+func TestSetupLoggingKeepsFilenameAndJSONFormat(t *testing.T) {
+	logger := log.StandardLogger()
+	previousOutput := logger.Out
+	previousFormatter := logger.Formatter
+	previousLevel := logger.Level
+	t.Cleanup(func() {
+		logger.SetOutput(previousOutput)
+		logger.SetFormatter(previousFormatter)
+		logger.SetLevel(previousLevel)
+	})
+
+	directory := filepath.Join(t.TempDir(), "nested", "logs")
+	writer, err := SetupLogging(directory, "hardlink", "v-test")
+	if err != nil {
+		t.Fatal(err)
+	}
+	log.WithField("probe", "value").Info("test record")
+	if err := writer.Close(); err != nil {
+		t.Fatal(err)
+	}
+
+	contents := readLogTestFile(t, filepath.Join(directory, "hardlink.log"))
+	for _, want := range []string{`"buildVersion":"v-test"`, `"msg":"Logging initialized"`, `"probe":"value"`, `"msg":"test record"`} {
+		if !strings.Contains(contents, want) {
+			t.Errorf("hardlink.log contents missing %q: %s", want, contents)
+		}
+	}
+	if _, err := os.Stat(filepath.Join(directory, "hardlink.1.log")); !errors.Is(err, os.ErrNotExist) {
+		t.Errorf("SetupLogging() created archive during current week: %v", err)
+	}
+}
+
+type logTestTimer struct {
+	duration time.Duration
+	ch       chan time.Time
+	stopped  atomic.Bool
+}
+
+func (t *logTestTimer) C() <-chan time.Time {
+	return t.ch
+}
+
+func (t *logTestTimer) Stop() bool {
+	return !t.stopped.Swap(true)
+}
+
+func newLogTestWriter(t *testing.T, path string, now time.Time, overrides weeklyLogRuntime) *weeklyLogWriter {
+	t.Helper()
+	runtime := defaultWeeklyLogRuntime()
+	runtime.now = func() time.Time { return now }
+	if overrides.now != nil {
+		runtime.now = overrides.now
+	}
+	if overrides.newTimer != nil {
+		runtime.newTimer = overrides.newTimer
+	}
+	if overrides.rename != nil {
+		runtime.rename = overrides.rename
+	}
+	if overrides.diagnostic != nil {
+		runtime.diagnostic = overrides.diagnostic
+	}
+	writer, err := newWeeklyLogWriter(path, now.Location(), runtime)
+	if err != nil {
+		t.Fatal(err)
+	}
+	return writer
+}
+
+func weeklyLogTestGeneration(path string, generation int) string {
+	extension := filepath.Ext(path)
+	return fmt.Sprintf("%s.%d%s", strings.TrimSuffix(path, extension), generation, extension)
+}
+
+func writeLogTestFile(t *testing.T, path, contents string) {
+	t.Helper()
+	if err := os.WriteFile(path, []byte(contents), 0o600); err != nil {
+		t.Fatal(err)
+	}
+}
+
+func setLogTestModTime(t *testing.T, path string, value time.Time) {
+	t.Helper()
+	if err := os.Chtimes(path, value, value); err != nil {
+		t.Fatal(err)
+	}
+}
+
+func readLogTestFile(t *testing.T, path string) string {
+	t.Helper()
+	contents, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	return string(contents)
+}
+
+func requireLogTestContents(t *testing.T, path, want string) {
+	t.Helper()
+	if got := readLogTestFile(t, path); got != want {
+		t.Errorf("%s contents = %q, want %q", filepath.Base(path), got, want)
+	}
+}
+
+var _ io.WriteCloser = (*weeklyLogWriter)(nil)

release notes.md

@@ -2,6 +2,24 @@
 
 builtVersion is a const in main.go
 
+#### v2.1.3 - 30 September 2026
+feat(logging): add weekly log rotation and retention
+
+#### v2.1.2 - 30 September 2026
+fix(dispenser): scan ACK responses without assuming 3-byte reads
+
+#### v2.1.1 - 28 September 2026
+feat(dispenser): add worker-owned idle card prestaging
+
+#### v2.1.0 - 28 September 2026
+fix(dispenser): tolerate unusable AP observations during card preparation
+
+#### v2.0.3 - 24 September 2026
+fix(dispenser): recover stuck card preparation with reset
+
+#### v2.0.2 - 22 September 2026
+fix(dispenser): retry on transient prepare failure
+
 #### v2.0.1 - 10 September 2026
 feat: add CreditCall preauth streaming