futuresens/hardlink
6
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

fix(dispenser): simplify card preparation and recovery

Browse Source
This commit is contained in:
yurii 2026-09-27 22:21:28 +01:00
parent 99c74f49b6
commit e26331ffa9
6 changed files with 710 additions and 952 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

186
internal/dispenser/delivery_test.go
View File

@ -95,18 +95,22 @@ func TestWorkerClearanceValidation(t *testing.T) {
{"low stock clear", []byte{0x30, 0x30, 0x31, 0x30}, true},
{"residual encoder", status(0x33), false},
{"all sensors", status(0x37), false},
{"mouth", status(0x34), false},
{"unknown diagnostic", []byte{0x30, 0x30, 0xFF, 0x30}, false},
{"jam", []byte{0x30, 0x30, 0x32, 0x30}, false},
{"overlap", []byte{0x30, 0x30, 0x34, 0x30}, false},
{"rejection", []byte{0x36, 0x30, 0x30, 0x30}, 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(), lastStatus: status(0x30), lastStatusT: time.Now(), statusTTL: time.Hour}
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(), cmdToEncoder)
if (r.err == nil) != tc.clear || c.deliveryPending == tc.clear {
t.Errorf("FC7(% X): err=%v pending=%v, want clear=%v", tc.st, r.err, c.deliveryPending, tc.clear)
@ -169,8 +173,6 @@ func TestDeliveryIncidentReplay(t *testing.T) {
vendorACK, apReply(status(0x37)), // best effort must defer
vendorACK, apReply(status(0x33)), // previous encoder sensor must not succeed
vendorACK, apReply(status(0x34)),
vendorACK, apReply(status(0x37)),
vendorACK, apReply(status(0x30)), // clearance
vendorACK, // FC7
vendorACK, apReply(status(0x33)),
}}
@ -187,11 +189,11 @@ func TestDeliveryIncidentReplay(t *testing.T) {
c.lastStatusT = time.Now()
c.statusTTL = time.Hour
c.mu.Unlock()
if err := c.BeginPrepareNextCard(context.Background()); !errors.Is(err, errDeliveryPending) {
t.Fatalf("BeginPrepareNextCard=%v, want deferred", err)
if err := c.BeginPrepareNextCard(context.Background()); err != nil {
t.Fatal(err)
}
if got := wireCommands(p); !reflect.DeepEqual(got, []string{"AP", "FC0", "AP"}) {
t.Fatalf("before clearance commands=%v", got)
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 {
@ -200,31 +202,36 @@ func TestDeliveryIncidentReplay(t *testing.T) {
if _, err := prepare(context.Background()); err != nil {
t.Fatal(err)
}
want := []string{"AP", "FC0", "AP", "AP", "AP", "AP", "AP", "FC7", "AP"}
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 != 3*time.Second {
t.Errorf("clearance waits=%s, want 3s", elapsed)
if elapsed := now.Sub(time.Unix(0, 0)); elapsed != 2*time.Second {
t.Errorf("clearance waits=%s, want 2s", elapsed)
}
})
}
}
func TestDeliveryClearImmediately(t *testing.T) {
p := &scriptedTransport{chunks: [][]byte{vendorACK, vendorACK, apReply(status(0x30)), vendorACK, vendorACK, apReply(status(0x33))}}
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)
}
if got := wireCommands(p); !reflect.DeepEqual(got, []string{"FC0", "AP", "FC7", "AP"}) {
t.Errorf("commands=%v, want FC0 AP FC7 AP", got)
}
if !now.Equal(time.Unix(0, 0)) {
t.Errorf("immediate clearance waited until %v", now)
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)
}
}
}
@ -238,7 +245,7 @@ func TestDeliveryClearanceWaitStops(t *testing.T) {
{name: "cancel", response: cmdResp{status: status(0x37), deliveryPending: true}, cancel: true},
{name: "timeout", response: cmdResp{status: status(0x37), deliveryPending: true}, timeout: true},
{name: "transport", response: cmdResp{err: io.ErrUnexpectedEOF}},
{name: "jam", response: cmdResp{status: []byte{0x30, 0x30, 0x32, 0x30}, deliveryPending: true}},
{name: "movement", response: cmdResp{status: []byte{0x31, 0x30, 0x32, 0x30}, deliveryPending: true}},
{name: "empty", response: cmdResp{status: status(0x38), deliveryPending: true}},
} {
t.Run(tc.name, func(t *testing.T) {
@ -261,7 +268,7 @@ func TestDeliveryClearanceWaitStops(t *testing.T) {
t.Errorf("error=%v, want canceled", err)
}
if tc.timeout {
if !errors.Is(err, context.DeadlineExceeded) || c.sequenceTiming.now().Sub(started) != sequenceTimeout {
if !errors.Is(err, context.DeadlineExceeded) || c.sequenceTiming.now().Sub(started) != deliveryClearanceTimeout {
t.Errorf("timeout err=%v elapsed=%s", err, c.sequenceTiming.now().Sub(started))
}
}
@ -275,27 +282,21 @@ func TestDeliveryClearanceWaitStops(t *testing.T) {
}
func TestDeliveryClearanceDoesNotConsumeRecoveryWindow(t *testing.T) {
responses := []cmdResp{{status: status(0x37), deliveryPending: true}, {status: status(0x33), deliveryPending: true}, {status: status(0x30)}}
responses = append(responses, prepareFailureResponses(0x32, 7)...)
responses = append(responses, cmdResp{status: status(0x30)}, cmdResp{status: status(0x33)})
responses := make([]cmdResp, 15)
for i := range responses {
responses[i] = cmdResp{status: status(0x37), deliveryPending: true}
}
responses = append(responses, positionResponses(0x30, 17)...)
c, d := newSequenceTestClient(t, responses...)
if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
t.Fatal(err)
start := c.now()
if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, ErrPreparationExhausted) {
t.Fatalf("preparation error=%v, want exhausted", err)
}
var initial, reset time.Time
for i, cmd := range d.commands {
if cmd == cmdToEncoder && initial.IsZero() {
initial = d.commandTimes[i]
}
if cmd == cmdReset {
reset = d.commandTimes[i]
}
if elapsed := c.now().Sub(start); elapsed != 33*time.Second {
t.Errorf("elapsed=%s, want clearance 15s + shakes 18s", elapsed)
}
if reset.Sub(initial) != sequenceRetryAfter || commandCount(d.commands, cmdReset) != 1 || commandCount(d.commands, cmdToEncoder) != 2 {
t.Errorf("recovery commands=%v reset delay=%s, want two FC7 and one RS at 6s", d.commands, reset.Sub(initial))
}
if got := c.sequenceTiming.now().Sub(reset); got != sequenceResetWait+sequencePollInterval {
t.Errorf("post-reset elapsed=%s, want settle plus poll=3s", got)
if commandCount(d.commands, cmdReset) != 3 || commandCount(d.commands, cmdToEncoder) != 4 {
t.Errorf("commands=%v, want 3 RS and 4 FC7", d.commands)
}
}
@ -332,18 +333,24 @@ func TestDeliveryClearanceRetainsFullPreparationTimeout(t *testing.T) {
for i := range responses {
responses[i] = cmdResp{status: status(0x37), deliveryPending: true}
}
responses = append(responses, cmdResp{status: status(0x30)})
responses = append(responses, prepareFailureResponses(0x32, 30)...)
responses = append(responses, positionResponses(0x30, 2)...)
c, d := newSequenceTestClient(t, responses...)
started := c.sequenceTiming.now()
if _, err := c.PrepareCurrentCard(context.Background()); err == nil {
t.Fatal("persistent failure succeeded")
wait := c.sequenceTiming.wait
c.sequenceTiming.wait = func(ctx context.Context, duration time.Duration) error {
if commandCount(d.commands, cmdToEncoder) > 0 {
duration = sequenceTimeout
}
return wait(ctx, duration)
}
if got := c.sequenceTiming.now().Sub(started); got != 8*time.Second+sequenceTimeout {
t.Errorf("total duration=%s, want clearance 8s + preparation 16s", got)
start := c.now()
if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, ErrPreparationExhausted) {
t.Fatalf("preparation error=%v, want exhausted", err)
}
if commandCount(d.commands, cmdReset) != 1 || commandCount(d.commands, cmdToEncoder) != 2 {
t.Errorf("commands=%v, want one RS and two FC7", d.commands)
if elapsed := c.now().Sub(start); elapsed != 8*time.Second+sequenceTimeout {
t.Errorf("elapsed=%s, want clearance 8s + preparation 32s", elapsed)
}
if commandCount(d.commands, cmdReset) != 0 || commandCount(d.commands, cmdToEncoder) != 1 {
t.Errorf("commands=%v, want one FC7 and no RS after deadline", d.commands)
}
}
@ -352,7 +359,7 @@ func TestWorkerSerializesClearanceAndFC7(t *testing.T) {
c, _ := deliveryWorkerClient(t, p)
// Set initial state before any request can reach the worker.
c.deliveryPending = true
c.deliveryStarted = time.Now()
c.deliveryStarted = c.now().Add(-deliveryMinimumWait)
reading := make(chan struct{})
resume := make(chan struct{})
p.afterWrite = func() {
@ -389,3 +396,64 @@ func TestWorkerSerializesClearanceAndFC7(t *testing.T) {
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 || errors.Is(err, ErrPreparationExhausted) {
t.Errorf("frame % X: err=%v, want transport/protocol failure", frame, err)
}
want := []string{"AP", "FC7", "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)
}
}
}

59
internal/dispenser/dispenser.go
View File

@ -40,6 +40,9 @@ const (
var (
ErrCardWellEmpty = errors.New(CardWellEmptyMessage)
// ErrPreparationExhausted permits a new, independent UI preparation attempt.
ErrPreparationExhausted = errors.New("card preparation exhausted")
SerialPort string
Address []byte
@ -142,38 +145,35 @@ func isAtEncoderPosition(statusBytes []byte) bool {
return valid && flags&positionEncoder != 0
}
func validateDispenserStatusData(statusBytes []byte) error {
if len(statusBytes) != 4 {
return fmt.Errorf("malformed dispenser status: got %d bytes, want 4", len(statusBytes))
}
type preparationClass string
statusMaps := []map[byte]string{statusPos0, statusPos1, statusPos2}
for position, mapper := range statusMaps {
if _, ok := mapper[statusBytes[position]]; !ok {
return fmt.Errorf("unknown dispenser status 0x%X at position %d", statusBytes[position], position+1)
}
}
if _, valid := decodePositionStatus(statusBytes[3]); !valid {
return fmt.Errorf("unknown dispenser status 0x%X at position 4", statusBytes[3])
}
return nil
}
const (
encoderConfirmed preparationClass = "encoder confirmed"
positionUncertain preparationClass = "valid but uncertain"
positionWellEmpty preparationClass = "empty"
positionNoCard preparationClass = "no card on sensors"
)
func dispenserStatusError(statusBytes []byte) error {
switch statusBytes[0] {
case 0x34, 0x32, 0x36:
return fmt.Errorf("dispenser error: %s", statusPos0[statusBytes[0]])
// classifyPreparationStatus is the only readiness gate after AP wire validation.
// Diagnostics describe the device; they do not veto a physical position class.
func classifyPreparationStatus(status []byte) (preparationClass, error) {
if len(status) != 4 {
return "", fmt.Errorf("malformed dispenser status: got %d bytes, want 4", len(status))
}
switch statusBytes[1] {
case 0x32, 0x31:
return fmt.Errorf("dispenser error: %s", statusPos1[statusBytes[1]])
flags, valid := decodePositionStatus(status[3])
if !valid {
return "", fmt.Errorf("malformed dispenser position encoding: 0x%X", status[3])
}
switch statusBytes[2] {
case 0x34, 0x32:
return fmt.Errorf("dispenser error: %s", statusPos2[statusBytes[2]])
switch {
case flags&positionEncoder != 0:
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 {
@ -181,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 ""

403
internal/dispenser/dispenserclient.go
View File

@ -41,10 +41,14 @@ type sequenceTiming struct {
}
const (
sequencePollInterval = time.Second
sequenceRetryAfter = 6 * time.Second
sequenceResetWait = 2 * time.Second
sequenceTimeout = 16 * time.Second
sequencePollInterval = time.Second
sequenceShakeAfter = 3 * time.Second
sequenceResetWait = 2 * time.Second
sequenceTimeout = 32 * time.Second
sequenceUncertainWait = 4 * time.Second
sequenceMaxShakes = 3
deliveryClearanceTimeout = 16 * time.Second
deliveryMinimumWait = 2 * time.Second
)
type Client struct {
@ -217,19 +221,22 @@ func (c *Client) handle(req cmdReq) {
}
}
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:
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 = time.Now()
c.deliveryStarted = c.now()
log.Info("delivery ENQ attempted; awaiting mechanical clearance")
}
// A movement command makes any previously cached position unreliable.
@ -243,19 +250,24 @@ func (c *Client) handle(req cmdReq) {
// deliveryClearance deliberately does not apply encoder-success precedence.
func deliveryClearance(status []byte) (bool, error) {
if err := validateDispenserStatusData(status); err != nil {
class, err := classifyPreparationStatus(status)
if err != nil {
return false, err
}
if isCardWellEmpty(status) {
if class == positionWellEmpty {
return false, ErrCardWellEmpty
}
if isPreparationMoving(status) {
if isPreparationMoving(status) || status[1] == 0x34 {
return false, nil
}
if err := dispenserStatusError(status); err != nil {
return false, err
return status[3] == 0x30 || status[3] == 0x34, nil
}
func (c *Client) now() time.Time {
if c.sequenceTiming.now != nil {
return c.sequenceTiming.now()
}
return status[0] == 0x30 && status[1] == 0x30 && status[3] == 0x30, nil
return time.Now()
}
// readWorkerStatus is called only by the serial worker and always reads fresh AP.
@ -264,13 +276,18 @@ func (c *Client) readWorkerStatus(ctx context.Context) ([]byte, error) {
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 {
} else if clear && c.now().Sub(c.deliveryStarted) >= deliveryMinimumWait {
c.deliveryPending = false
log.Infof("previous delivery cleared after %s; FC7 permitted", time.Since(c.deliveryStarted))
log.Infof("previous delivery cleared after %s; FC7 permitted", c.now().Sub(c.deliveryStarted))
}
}
if len(st) == 4 {
@ -408,186 +425,12 @@ func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]by
return status, stockStatus, nil
}
func preparationStatus(operation string, status []byte, allowCombinedFailure bool) (bool, error) {
// A confirmed read sensor takes precedence over every other diagnostic.
if isAtEncoderPosition(status) {
if hasPreparationDiagnostics(status) {
log.Warnf(
"[%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
}
// Some dispenser firmware briefly reports 0x32 ("Preparing card fails")
// while the card is still travelling to the encoder. Treat that one
// diagnostic as transient during an active preparation sequence and let
// pollForEncoderPosition decide encoder success or timeout. Do not mask
// independent hard errors reported in the other status bytes.
// Combined command rejection is also recoverable before the one retry.
if status[0] == 0x32 || (status[0] == 0x36 && allowCombinedFailure) {
statusWithoutPrepareFailure := append([]byte(nil), status...)
statusWithoutPrepareFailure[0] = 0x30
if err := dispenserStatusError(statusWithoutPrepareFailure); err != nil {
return false, fmt.Errorf("[%s] %w", operation, err)
}
log.Warnf(
"[%s] transient preparation failure (%s); waiting for encoder position, raw status: % X",
operation,
statusDescription(status),
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) (stockStatus string, resultErr error) {
started := c.sequenceTiming.now()
recoveryAt := started.Add(sequenceRetryAfter)
deadline := started.Add(sequenceTimeout)
ctx, cancel := context.WithTimeout(ctx, sequenceTimeout)
defer cancel()
retried := false
resetAttempted := false
retryAfterReset := false
consecutiveFailures := 0
stage := "initial polling"
var lastStatus []byte
defer func() {
if resultErr != nil {
log.Warnf("[%s] card preparation failed; stage=%s reset_attempted=%t raw status: % X: %v", operation, stage, resetAttempted, lastStatus, resultErr)
}
}()
checkDeadline := func() error {
if err := ctx.Err(); err != nil {
return fmt.Errorf("[%s] %s: %w", operation, stage, err)
}
if !c.sequenceTiming.now().Before(deadline) {
return fmt.Errorf("[%s] %s: timed out after %s", operation, stage, sequenceTimeout)
}
return nil
}
for {
if err := checkDeadline(); err != nil {
return stockStatus, err
}
status, currentStockStatus, err := c.readSequenceStatus(ctx, operation)
stockStatus = currentStockStatus
lastStatus = status
if err != nil {
return stockStatus, err
}
if err := checkDeadline(); err != nil {
return stockStatus, err
}
ready, err := preparationStatus(operation, status, !retried || retryAfterReset)
if err != nil {
return stockStatus, err
}
if ready {
if resetAttempted {
log.Infof("[%s] card preparation recovered after reset", operation)
}
return stockStatus, nil
}
moving := isPreparationMoving(status)
prepareFailed := status[0] == 0x32 || status[0] == 0x36
if prepareFailed && !moving {
consecutiveFailures++
} else {
consecutiveFailures = 0
}
if !moving && retryAfterReset {
stage = "post-reset FC7"
if err := checkDeadline(); err != nil {
return stockStatus, err
}
log.Infof("[%s] reset settle wait completed; retrying card preparation", operation)
if err := c.ToEncoder(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] post-reset retry command: %w", operation, err)
}
retryAfterReset = false
stage = "polling after reset and retry"
} else if !moving && !retried && !c.sequenceTiming.now().Before(recoveryAt) {
if prepareFailed && consecutiveFailures >= 2 {
stage = "RS recovery"
if err := checkDeadline(); err != nil {
return stockStatus, err
}
retried = true
resetAttempted = true
log.Warnf("[%s] persistent prepare failure; resetting dispenser, raw status: % X", operation, status)
if err := c.Reset(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] reset command: %w", operation, err)
}
stage = "reset settle"
if err := checkDeadline(); err != nil {
return stockStatus, err
}
log.Infof("[%s] reset dispatched; waiting for mechanical settling", operation)
wait := sequenceResetWait
if remaining := deadline.Sub(c.sequenceTiming.now()); remaining < wait {
wait = remaining
}
if err := c.sequenceTiming.wait(ctx, wait); err != nil {
return stockStatus, fmt.Errorf("[%s] reset settle: %w", operation, err)
}
retryAfterReset = true
stage = "post-reset status"
continue // Always read fresh physical status before the retry.
}
if !prepareFailed {
stage = "FC7 retry"
if err := checkDeadline(); err != nil {
return stockStatus, err
}
retried = true
if err := c.ToEncoder(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] retry command: %w", operation, err)
}
}
}
if err := checkDeadline(); err != nil {
return stockStatus, err
}
wait := sequencePollInterval
if remaining := deadline.Sub(c.sequenceTiming.now()); remaining < wait {
wait = remaining
}
if err := c.sequenceTiming.wait(ctx, wait); err != nil {
return stockStatus, fmt.Errorf("[%s] %s: %w", operation, stage, err)
}
}
}
// waitForDeliveryClearance reuses the first clear AP as the initial preparation sample.
// Its bounded window is separate from recovery, which starts after initial FC7.
// Its bounded window is separate from subsequent preparation and recovery.
func (c *Client) waitForDeliveryClearance(ctx context.Context, operation string) (status []byte, stock string, resultErr error) {
ctx, cancel := context.WithTimeout(ctx, sequenceTimeout)
ctx, cancel := context.WithTimeout(ctx, deliveryClearanceTimeout)
defer cancel()
deadline := c.sequenceTiming.now().Add(sequenceTimeout)
deadline := c.sequenceTiming.now().Add(deliveryClearanceTimeout)
var lastStatus []byte
defer func() {
if resultErr != nil {
@ -634,26 +477,143 @@ func (c *Client) waitForDeliveryClearance(ctx context.Context, operation string)
}
}
func (c *Client) prepareCardAtEncoder(ctx context.Context, operation string) (string, error) {
status, stockStatus, err := c.waitForDeliveryClearance(ctx, operation)
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
}
ready, err := preparationStatus(operation, status, true)
if err != nil {
return stockStatus, err
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()
}
if ready {
return stockStatus, 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()
}
if err := c.ToEncoder(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] to encoder: %w", operation, err)
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, err
}
class, err := classifyPreparationStatus(status)
if err != nil {
return stock, err
}
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, 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 {
if uncertainSince.IsZero() {
uncertainSince = c.now()
}
if c.now().Sub(uncertainSince) >= sequenceUncertainWait {
stage = "uncertain position handoff"
return stock, checkDeadline()
}
} else {
uncertainSince = time.Time{}
}
stage = "polling"
if err := wait(sequencePollInterval); err != nil {
return stock, err
}
}
stage = "fresh AP"
if err := checkDeadline(); err != nil {
return stock, err
}
status, stock, err = c.readSequenceStatus(ctx, operation)
if deadlineErr := checkDeadline(); deadlineErr != nil {
return stock, deadlineErr
}
if err != nil {
return stock, err
}
}
return c.pollForEncoderPosition(ctx, operation)
}
// PrepareCurrentCard authoritatively places the card to be encoded at the encoder.
// PrepareCurrentCard grants one encoder opportunity after bounded physical preparation.
func (c *Client) PrepareCurrentCard(ctx context.Context) (string, error) {
return c.prepareCardAtEncoder(ctx, "PrepareCurrentCard")
}
@ -668,15 +628,42 @@ 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 delivery clearance and dispatches FC7 once,
// without waiting 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)
ctx, cancel := context.WithTimeout(ctx, deliveryClearanceTimeout)
defer cancel()
deadline := c.now().Add(deliveryClearanceTimeout)
for {
if err := ctx.Err(); err != nil {
return err
}
if !c.now().Before(deadline) {
return context.DeadlineExceeded
}
// The worker checks fresh AP while delivery is pending and dispatches
// FC7 only once clear, within the same ownership boundary.
err := c.ToEncoder(ctx)
if !errors.Is(err, errDeliveryPending) {
if err != nil {
return fmt.Errorf("[BeginPrepareNextCard] to encoder: %w", err)
}
return nil
}
wait := sequencePollInterval
if remaining := deadline.Sub(c.now()); remaining < wait {
wait = remaining
}
if wait <= 0 {
return context.DeadlineExceeded
}
if err := c.sequenceTiming.wait(ctx, wait); err != nil {
return err
}
}
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")
}

920
internal/dispenser/dispenserclient_test.go
View File

@ -9,8 +9,6 @@ import (
"strings"
"testing"
"time"
log "github.com/sirupsen/logrus"
)
type fakeSequenceDevice struct {
@ -18,6 +16,7 @@ type fakeSequenceDevice struct {
commandErrors map[cmdType][]error
commands []cmdType
commandTimes []time.Time
onCommand func(cmdType)
}
func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *fakeSequenceDevice) {
@ -55,6 +54,9 @@ func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *
case request := <-client.reqCh:
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")}
@ -94,200 +96,6 @@ func commandCount(commands []cmdType, target cmdType) int {
return count
}
func prepareFailureResponses(code byte, count int) []cmdResp {
responses := make([]cmdResp, count)
for i := range responses {
responses[i] = cmdResp{status: []byte{code, 0x30, 0x30, 0x30}}
}
return responses
}
func TestPreparationResetRecovery(t *testing.T) {
for _, operation := range []string{"current", "next"} {
for _, code := range []byte{0x32, 0x36} {
t.Run(operation+string(rune(code)), func(t *testing.T) {
responses := prepareFailureResponses(code, 9) // Initial read, seven polls, post-reset read.
responses = append(responses, cmdResp{status: status(0x33)})
client, device := newSequenceTestClient(t, responses...)
// An apparently fresh passive cache must never replace physical reads.
client.lastStatus = status(0x33)
client.lastStatusT = time.Now()
client.statusTTL = time.Hour
prepare := client.PrepareCurrentCard
if operation == "next" {
prepare = client.PrepareNextCard
}
if _, err := prepare(context.Background()); err != nil {
t.Fatalf("prepare(%s, %X) = %v, want success", operation, code, err)
}
want := []cmdType{cmdStatus, cmdToEncoder}
for i := 0; i < 7; i++ {
want = append(want, cmdStatus)
}
want = append(want, cmdReset, cmdStatus, cmdToEncoder, cmdStatus)
if !reflect.DeepEqual(device.commands, want) {
t.Errorf("prepare commands = %v, want %v", device.commands, want)
}
if len(device.commandTimes) != len(want) {
t.Fatalf("command times = %d, want %d", len(device.commandTimes), len(want))
}
if elapsed := device.commandTimes[9].Sub(device.commandTimes[1]); elapsed != sequenceRetryAfter {
t.Errorf("RS elapsed = %s, want %s", elapsed, sequenceRetryAfter)
}
if elapsed := device.commandTimes[10].Sub(device.commandTimes[9]); elapsed != sequenceResetWait {
t.Errorf("post-reset status elapsed = %s, want %s", elapsed, sequenceResetWait)
}
})
}
}
}
func TestPreparationFailureAfterReset(t *testing.T) {
for _, test := range []struct {
name string
code byte
wantError string
}{
{"prepare failure times out", 0x32, "timed out"},
{"combined failure is final", 0x36, "Command cannot execute"},
} {
t.Run(test.name, func(t *testing.T) {
client, device := newSequenceTestClient(t, prepareFailureResponses(test.code, 30)...)
_, err := client.PrepareCurrentCard(context.Background())
if err == nil || !strings.Contains(err.Error(), test.wantError) {
t.Errorf("PrepareCurrentCard(%X) error = %v, want %q", test.code, err, test.wantError)
}
if resets, commands := commandCount(device.commands, cmdReset), commandCount(device.commands, cmdToEncoder); resets != 1 || commands != 2 {
t.Errorf("recovery commands = %v, want one RS and two FC7", device.commands)
}
})
}
}
func TestPreparationHardErrorsNeverReset(t *testing.T) {
for _, failure := range [][]byte{
{0x32, 0x30, 0x32, 0x30}, // Jam alongside prepare failure.
{0x36, 0x30, 0x34, 0x30}, // Overlap alongside combined failure.
{0x32, 0x30, 0x30, 0x38}, // Empty.
{0x36, 0x32, 0x30, 0x30}, // Independent dispense error.
{0x32, 0x31, 0x30, 0x30}, // Independent capture error.
{0x34, 0x30, 0x30, 0x30}, // Command rejection alone.
{0x30, 0x30, 0x30, 0x40}, // Unknown.
{0x32}, // Malformed.
} {
responses := prepareFailureResponses(0x32, 7)
responses = append(responses, cmdResp{status: failure})
client, device := newSequenceTestClient(t, responses...)
if _, err := client.PrepareCurrentCard(context.Background()); err == nil {
t.Errorf("PrepareCurrentCard(% X) error = nil, want hard error", failure)
}
if got := commandCount(device.commands, cmdReset); got != 0 {
t.Errorf("PrepareCurrentCard(% X) resets = %d, want 0", failure, got)
}
}
}
func TestPreparationProgressAtRecoveryThreshold(t *testing.T) {
for _, moving := range [][]byte{{0x31, 0x30, 0x30, 0x30}, {0x32, 0x38, 0x30, 0x30}} {
responses := prepareFailureResponses(0x32, 7)
responses = append(responses, cmdResp{status: moving}, cmdResp{status: moving}, cmdResp{status: status(0x33)})
client, device := newSequenceTestClient(t, responses...)
if _, err := client.PrepareCurrentCard(context.Background()); err != nil {
t.Fatalf("PrepareCurrentCard(moving % X) = %v, want success", moving, err)
}
if commandCount(device.commands, cmdReset) != 0 || commandCount(device.commands, cmdToEncoder) != 1 {
t.Errorf("PrepareCurrentCard(moving % X) commands = %v, want initial FC7 only", moving, device.commands)
}
}
}
func TestPreparationRequiresConsecutiveFailures(t *testing.T) {
responses := prepareFailureResponses(0x32, 7)
responses = append(responses,
cmdResp{status: []byte{0x31, 0x30, 0x30, 0x30}},
cmdResp{status: []byte{0x32, 0x30, 0x30, 0x30}},
cmdResp{status: status(0x33)},
)
client, device := newSequenceTestClient(t, responses...)
if _, err := client.PrepareCurrentCard(context.Background()); err != nil {
t.Fatal(err)
}
if got := commandCount(device.commands, cmdReset); got != 0 {
t.Errorf("PrepareCurrentCard(interrupted failure sequence) resets = %d, want 0", got)
}
}
func TestPreparationPostResetStatus(t *testing.T) {
for _, test := range []struct {
name string
responses []cmdResp
wantFC7 int
wantError string
}{
{"already at encoder", []cmdResp{{status: status(0x33)}}, 1, ""},
{"moving then encoder", []cmdResp{{status: []byte{0x31, 0x30, 0x30, 0x30}}, {status: status(0x33)}}, 1, ""},
{"moving then stationary", []cmdResp{{status: []byte{0x31, 0x30, 0x30, 0x30}}, {status: status(0x30)}, {status: status(0x33)}}, 2, ""},
{"hard error", []cmdResp{{status: []byte{0x32, 0x30, 0x32, 0x30}}}, 1, "Card jammed"},
{"read failure", []cmdResp{{err: errors.New("post-reset read failed")}}, 1, "post-reset read failed"},
} {
t.Run(test.name, func(t *testing.T) {
responses := append(prepareFailureResponses(0x32, 8), test.responses...)
client, device := newSequenceTestClient(t, responses...)
_, err := client.PrepareCurrentCard(context.Background())
if test.wantError == "" && err != nil {
t.Errorf("PrepareCurrentCard(%s) = %v, want success", test.name, err)
}
if test.wantError != "" && (err == nil || !strings.Contains(err.Error(), test.wantError)) {
t.Errorf("PrepareCurrentCard(%s) = %v, want %q", test.name, err, test.wantError)
}
if commandCount(device.commands, cmdReset) != 1 || commandCount(device.commands, cmdToEncoder) != test.wantFC7 {
t.Errorf("PrepareCurrentCard(%s) commands = %v, want one RS and %d FC7", test.name, device.commands, test.wantFC7)
}
})
}
}
func TestPreparationRecoveryCommandFailures(t *testing.T) {
for _, command := range []cmdType{cmdReset, cmdToEncoder} {
client, device := newSequenceTestClient(t, prepareFailureResponses(0x32, 9)...)
failure := errors.New("command failed")
device.commandErrors[command] = []error{failure}
wantFC7 := 1
if command == cmdToEncoder {
device.commandErrors[command] = []error{nil, failure}
wantFC7 = 2
}
_, err := client.PrepareCurrentCard(context.Background())
if !errors.Is(err, failure) {
t.Errorf("PrepareCurrentCard(failed command %v) = %v, want %v", command, err, failure)
}
if commandCount(device.commands, cmdReset) != 1 || commandCount(device.commands, cmdToEncoder) != wantFC7 {
t.Errorf("PrepareCurrentCard(failed command %v) commands = %v, want one RS and %d FC7", command, device.commands, wantFC7)
}
}
}
func TestPreparationCancellationDuringResetSettle(t *testing.T) {
client, device := newSequenceTestClient(t, prepareFailureResponses(0x32, 9)...)
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
wait := client.sequenceTiming.wait
client.sequenceTiming.wait = func(ctx context.Context, duration time.Duration) error {
if duration == sequenceResetWait {
cancel()
}
return wait(ctx, duration)
}
_, err := client.PrepareCurrentCard(ctx)
if !errors.Is(err, context.Canceled) {
t.Errorf("PrepareCurrentCard(cancel during reset) = %v, want context.Canceled", err)
}
if commandCount(device.commands, cmdReset) != 1 || commandCount(device.commands, cmdToEncoder) != 1 || device.commands[len(device.commands)-1] != cmdReset {
t.Errorf("PrepareCurrentCard(cancel during reset) commands = %v, want no commands after RS", device.commands)
}
}
func TestResetPacket(t *testing.T) {
got := createPacket([]byte{0x30, 0x30}, commandRS)
want := []byte{0x02, 0x30, 0x30, 0x00, 0x02, 0x52, 0x53, 0x03, 0x02}
@ -296,234 +104,6 @@ func TestResetPacket(t *testing.T) {
}
}
func TestPreparationDeadlineDuringResetSettle(t *testing.T) {
client, device := newSequenceTestClient(t, prepareFailureResponses(0x32, 4)...)
wait := client.sequenceTiming.wait
waits := 0
client.sequenceTiming.wait = func(ctx context.Context, duration time.Duration) error {
waits++
if waits == 1 {
// Simulate a delayed poll, leaving only one second for recovery.
duration = 15 * time.Second
} else if duration != time.Second {
t.Errorf("reset settle duration = %s, want remaining 1s", duration)
}
return wait(ctx, duration)
}
_, err := client.PrepareCurrentCard(context.Background())
if err == nil || !strings.Contains(err.Error(), "timed out") {
t.Errorf("PrepareCurrentCard(late recovery) = %v, want timeout", err)
}
want := []cmdType{cmdStatus, cmdToEncoder, cmdStatus, cmdStatus, cmdReset}
if !reflect.DeepEqual(device.commands, want) {
t.Errorf("PrepareCurrentCard(late recovery) commands = %v, want %v", device.commands, want)
}
}
func TestPreparationPlainRetryConsumesRecoveryBudget(t *testing.T) {
responses := make([]cmdResp, 8)
for i := range responses {
responses[i] = cmdResp{status: status(0x34)}
}
responses = append(responses, prepareFailureResponses(0x32, 20)...)
client, device := newSequenceTestClient(t, responses...)
_, err := client.PrepareCurrentCard(context.Background())
if err == nil || !strings.Contains(err.Error(), "timed out") {
t.Errorf("PrepareCurrentCard(failure after plain retry) = %v, want timeout", err)
}
if commandCount(device.commands, cmdReset) != 0 || commandCount(device.commands, cmdToEncoder) != 2 {
t.Errorf("PrepareCurrentCard(failure after plain retry) commands = %v, want two FC7 and no RS", device.commands)
}
}
func TestPreparationFirstAttemptDoesNotReset(t *testing.T) {
for _, failures := range []int{0, 2} {
responses := []cmdResp{{status: status(0x34)}}
responses = append(responses, prepareFailureResponses(0x32, failures)...)
responses = append(responses, cmdResp{status: status(0x33)})
client, device := newSequenceTestClient(t, responses...)
if _, err := client.PrepareCurrentCard(context.Background()); err != nil {
t.Errorf("PrepareCurrentCard(%d transient failures) = %v, want success", failures, err)
}
if commandCount(device.commands, cmdReset) != 0 || commandCount(device.commands, cmdToEncoder) != 1 {
t.Errorf("PrepareCurrentCard(%d transient failures) commands = %v, want one FC7 and no RS", failures, device.commands)
}
}
}
func TestPrepareCurrentCardAcceptsEncoderPositionWithStaleDiagnostics(t *testing.T) {
tests := []struct {
name string
status []byte
wantStock string
}{
{
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 TestPrepareCurrentCardToleratesTransientPrepareFailureUntilEncoder(t *testing.T) {
client, device := newSequenceTestClient(t,
cmdResp{status: []byte{0x32, 0x30, 0x30, 0x30}},
cmdResp{status: []byte{0x32, 0x30, 0x30, 0x30}},
cmdResp{status: []byte{0x32, 0x30, 0x30, 0x30}},
cmdResp{status: []byte{0x32, 0x30, 0x30, 0x33}},
)
stock, err := client.PrepareCurrentCard(context.Background())
if err != nil {
t.Fatal(err)
}
if stock != "Preparing card fails" {
t.Fatalf("stock status = %q, want Preparing card fails", 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 != 4 {
t.Fatalf("status reads = %d, want 4", got)
}
}
func TestPrepareCurrentCardDoesNotMaskHardErrorAlongsideTransientPrepareFailure(t *testing.T) {
client, _ := newSequenceTestClient(t,
cmdResp{status: []byte{0x32, 0x30, 0x32, 0x30}},
)
_, err := client.PrepareCurrentCard(context.Background())
if err == nil || !strings.Contains(err.Error(), "Card jammed") {
t.Fatalf("error = %v, want Card jammed", err)
}
}
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, 0x40}},
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)
}
}
func TestDeliverCurrentCardSucceedsAfterCommandAcceptanceWithoutStatusPolling(t *testing.T) {
staleStatus := []byte{0x30, 0x32, 0x32, 0x33}
client, device := newSequenceTestClient(t, cmdResp{status: staleStatus})
@ -586,42 +166,6 @@ func TestDeliverCurrentCardPreservesContextCancellation(t *testing.T) {
}
}
func TestPrepareCurrentCardRetriesOnceThenTimesOut(t *testing.T) {
responses := make([]cmdResp, 17)
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 != 17 {
t.Fatalf("status reads = %d, want 17", 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)
@ -652,160 +196,6 @@ func TestBeginPrepareNextCardReturnsDispatchFailureWithoutPolling(t *testing.T)
}
}
func TestPrepareCardAtEncoderRequiresConfirmedEncoderState(t *testing.T) {
tests := []struct {
name string
responses []cmdResp
wantError string
wantToEncoder int
}{
{
name: "already at encoder",
responses: []cmdResp{{status: status(0x33)}},
wantToEncoder: 0,
},
{
name: "moves ready card to encoder",
responses: []cmdResp{
{status: status(0x34)},
{status: status(0x33)},
},
wantToEncoder: 1,
},
{
name: "empty card well",
responses: []cmdResp{{status: status(0x38)}},
wantError: CardWellEmptyMessage,
wantToEncoder: 0,
},
}
for _, test := range tests {
t.Run(test.name, func(t *testing.T) {
client, device := newSequenceTestClient(t, test.responses...)
_, err := client.PrepareNextCard(context.Background())
if test.wantError == "" && err != nil {
t.Fatal(err)
}
if test.wantError != "" && (err == nil || !strings.Contains(err.Error(), test.wantError)) {
t.Fatalf("error = %v, want containing %q", err, test.wantError)
}
if got := commandCount(device.commands, cmdToEncoder); got != test.wantToEncoder {
t.Fatalf("to-encoder commands = %d, want %d", got, test.wantToEncoder)
}
})
}
}
func TestPositionFlags(t *testing.T) {
for position := byte(0x30); position <= 0x3F; position++ {
t.Run(fmt.Sprintf("%02X", position), func(t *testing.T) {
st := status(position)
wantEncoder := position&0x02 != 0
wantEmpty := position&0x08 != 0
if got := isAtEncoderPosition(st); got != wantEncoder {
t.Errorf("isAtEncoderPosition(% X) = %t, want %t", st, got, wantEncoder)
}
if got := isCardWellEmpty(st); got != wantEmpty {
t.Errorf("isCardWellEmpty(% X) = %t, want %t", st, got, wantEmpty)
}
if err := validateDispenserStatusData(st); err != nil {
t.Errorf("validateDispenserStatusData(% X) = %v, want nil", st, err)
}
ready, err := preparationStatus("test", st, true)
if ready != wantEncoder {
t.Errorf("preparationStatus(% X) ready = %t, want %t", st, ready, wantEncoder)
}
wantEmptyError := wantEmpty && !wantEncoder
if errors.Is(err, ErrCardWellEmpty) != wantEmptyError || (err != nil && !wantEmptyError) {
t.Errorf("preparationStatus(% X) error = %v, want empty error %t", st, err, wantEmptyError)
}
wantStock := ""
if wantEmpty {
wantStock = "Card empty"
}
if got := stockTake(st); got != wantStock {
t.Errorf("stockTake(% X) = %q, want %q", st, got, wantStock)
}
})
}
}
func TestEncoderPositionPrecedesDiagnostics(t *testing.T) {
for _, position := range []byte{0x32, 0x33, 0x36, 0x37, 0x3A, 0x3B, 0x3E, 0x3F} {
for _, diagnostics := range [][]byte{
{0x30, 0x30, 0x30},
{0x32, 0x30, 0x30},
{0x36, 0x30, 0x30},
{0x34, 0x32, 0x32},
{0x30, 0x31, 0x34},
{0xFF, 0xFF, 0xFF},
} {
st := append(append([]byte(nil), diagnostics...), position)
for _, operation := range []string{"current", "next"} {
t.Run(fmt.Sprintf("%s/% X", operation, st), func(t *testing.T) {
client, device := newSequenceTestClient(t, cmdResp{status: st})
prepare := client.PrepareCurrentCard
if operation == "next" {
prepare = client.PrepareNextCard
}
if _, err := prepare(context.Background()); err != nil {
t.Errorf("prepare(% X) = %v, want success", st, err)
}
want := []cmdType{cmdStatus}
if !reflect.DeepEqual(device.commands, want) {
t.Errorf("prepare(% X) commands = %v, want %v", st, device.commands, want)
}
})
}
}
}
}
func TestCombinedEncoderPositionStopsRecovery(t *testing.T) {
for _, afterReset := range []bool{false, true} {
t.Run(fmt.Sprintf("afterReset=%t", afterReset), func(t *testing.T) {
count := 7 // Encoder confirmation at the recovery threshold, before RS.
wantResets := 0
if afterReset {
count = 8 // Encoder confirmation on the fresh post-reset read.
wantResets = 1
}
responses := append(prepareFailureResponses(0x32, count), cmdResp{status: []byte{0x36, 0x32, 0x34, 0x3F}})
client, device := newSequenceTestClient(t, responses...)
if _, err := client.PrepareCurrentCard(context.Background()); err != nil {
t.Errorf("PrepareCurrentCard(combined encoder) = %v, want success", err)
}
if got := commandCount(device.commands, cmdReset); got != wantResets {
t.Errorf("PrepareCurrentCard(combined encoder) RS count = %d, want %d", got, wantResets)
}
if got := commandCount(device.commands, cmdToEncoder); got != 1 {
t.Errorf("PrepareCurrentCard(combined encoder) FC7 count = %d, want 1", got)
}
})
}
}
func TestInvalidPositionEncoding(t *testing.T) {
for _, st := range [][]byte{nil, {0x30, 0x30, 0x30}, status(0x02), status(0x2F), status(0x40), status(0x72), status(0xFF)} {
if isAtEncoderPosition(st) || isCardWellEmpty(st) {
t.Errorf("invalid status % X confirmed encoder or empty, want neither", st)
}
if ready, err := preparationStatus("test", st, true); ready || err == nil {
t.Errorf("preparationStatus(% X) = (%t, %v), want false and error", st, ready, err)
}
}
st := []byte{0xFF, 0xFF, 0xFF, 0x37, 0xFF}
if ready, err := preparationStatus("test", st, false); !ready || err != nil {
t.Errorf("preparationStatus(% X) = (%t, %v), want encoder precedence", st, ready, err)
}
st = append(status(0x35), 0xFF)
if ready, err := preparationStatus("test", st, true); ready || err == nil {
t.Errorf("preparationStatus(% X) = (%t, %v), want malformed error", st, ready, err)
}
}
func TestPositionDescriptions(t *testing.T) {
for _, test := range []struct {
position byte
@ -825,3 +215,305 @@ func TestPositionDescriptions(t *testing.T) {
}
}
}
func positionResponses(position byte, count int) []cmdResp {
responses := make([]cmdResp, count)
for i := range responses {
responses[i] = cmdResp{status: status(position)}
}
return responses
}
func TestPreparationClasses(t *testing.T) {
classes := map[preparationClass][]byte{
encoderConfirmed: {0x32, 0x33, 0x36, 0x37, 0x3A, 0x3B, 0x3E, 0x3F},
positionUncertain: {0x31, 0x34, 0x35, 0x39, 0x3C, 0x3D},
positionWellEmpty: {0x38}, positionNoCard: {0x30},
}
for want, positions := range classes {
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)
}
}
}
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 || errors.Is(err, ErrPreparationExhausted) {
t.Errorf("AP failure %v error=%v, want transport/malformed error", 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} {
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 TestPreparationExpiredEncoderSampleDoesNotHandoff(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 !errors.Is(err, ErrPreparationExhausted) {
t.Errorf("late encoder sample: err=%v, want preparation exhausted", err)
}
if len(d.commands) != 3 {
t.Errorf("late encoder sample commands=%v, want AP FC7 AP", d.commands)
}
}
func TestBeginPrepareNextCardStopsWhileDeliveryPending(t *testing.T) {
for _, mode := range []string{"cancel", "deadline", "clearance timeout", "transport failure"} {
t.Run(mode, func(t *testing.T) {
c, d := newSequenceTestClient(t)
d.commandErrors[cmdToEncoder] = []error{errDeliveryPending}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
wantErr := error(context.Canceled)
c.sequenceTiming.wait = func(context.Context, time.Duration) error {
cancel()
return context.Canceled
}
switch mode {
case "deadline":
wantErr = context.DeadlineExceeded
c.sequenceTiming.wait = func(context.Context, time.Duration) error { return context.DeadlineExceeded }
case "clearance timeout":
wantErr = context.DeadlineExceeded
now := c.now()
c.sequenceTiming.now = func() time.Time { return now }
c.sequenceTiming.wait = func(context.Context, time.Duration) error { now = now.Add(deliveryClearanceTimeout); return nil }
case "transport failure":
wantErr = errors.New("AP read failed")
d.commandErrors[cmdToEncoder] = []error{wantErr}
}
if err := c.BeginPrepareNextCard(ctx); !errors.Is(err, wantErr) {
t.Errorf("BeginPrepareNextCard(%s) = %v, want %v", mode, err, wantErr)
}
if !reflect.DeepEqual(d.commands, []cmdType{cmdToEncoder}) {
t.Errorf("BeginPrepareNextCard(%s) commands = %v, want one guarded FC7 request", mode, d.commands)
}
})
}
}

60
internal/handlers/doorcard_handlers_test.go
View File

@ -140,6 +140,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 +155,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,
wantMessage: "Card delivery could not be confirmed",
wantCalls: []string{"prepare current", "deliver current"},
wantHTTP: http.StatusOK,
wantMessage: "Card issued successfully",
wantCalls: []string{"prepare current", "deliver current", "begin prepare next"},
wantLockSequence: 1,
wantCardWell: "Card jammed",
},
@ -179,36 +186,35 @@ func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
wantLockSequence: 1,
},
{
name: "encoding failure with safe recovery remains retryable",
name: "encoding failure ends after delivery",
lockErr: encodingErr,
wantHTTP: http.StatusBadGateway,
wantMessage: encodingErr.Error(),
wantCalls: []string{"prepare current", "deliver current", "prepare next"},
wantCalls: []string{"prepare current", "deliver current"},
wantLockSequence: 1,
},
{
name: "encoding failure with failed-card delivery failure is unavailable",
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,
wantMessage: "Dispenser recovery failed; another encoding attempt is not safe",
wantHTTP: http.StatusBadGateway,
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,
wantMessage: dispenser.CardWellEmptyMessage,
wantCalls: []string{"prepare current", "deliver current", "prepare next"},
wantHTTP: http.StatusBadGateway,
wantMessage: encodingErr.Error(),
wantCalls: []string{"prepare current", "deliver current"},
wantLockSequence: 1,
wantCardWell: "Card empty",
},
}
@ -321,3 +327,29 @@ 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())
}
}
}

34
internal/handlers/handlers.go
View File

@ -6,7 +6,6 @@ import (
"encoding/json"
"encoding/xml"
"errors"
"fmt"
"io"
"net/http"
"strings"
@ -299,6 +298,10 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
return
}
if errors.Is(err, dispenser.ErrPreparationExhausted) {
errorhandlers.WriteError(w, http.StatusBadGateway, err.Error())
return
}
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispense error: "+err.Error())
return
}
@ -307,8 +310,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 +327,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)
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
}
// FC0 is attempted once; the next UI request owns all further preparation.
errorhandlers.WriteError(w, http.StatusBadGateway, encodingErr.Error())
return
}