fix(dispenser): tolerate unusable AP observations during card preparation
This commit is contained in:
parent
e26331ffa9
commit
b9b2a524dd
@ -33,7 +33,7 @@ import (
|
||||
)
|
||||
|
||||
const (
|
||||
buildVersion = "v2.0.3"
|
||||
buildVersion = "v2.1.0"
|
||||
serviceName = "hardlink"
|
||||
pollingFrequency = 8 * time.Second
|
||||
)
|
||||
|
||||
@ -111,14 +111,11 @@ func TestWorkerClearanceValidation(t *testing.T) {
|
||||
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(), cmdToEncoder)
|
||||
if (r.err == nil) != tc.clear || c.deliveryPending == tc.clear {
|
||||
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 tc.clear {
|
||||
want = append(want, "FC7")
|
||||
}
|
||||
if got := wireCommands(p); !reflect.DeepEqual(got, want) {
|
||||
t.Errorf("commands=%v, want %v", got, want)
|
||||
}
|
||||
@ -129,7 +126,7 @@ func TestWorkerClearanceValidation(t *testing.T) {
|
||||
frame[len(frame)-1] ^= 1
|
||||
p := &scriptedTransport{chunks: [][]byte{vendorACK, frame}}
|
||||
c := &Client{port: p, deliveryPending: true}
|
||||
r := workerRequest(c, context.Background(), cmdToEncoder)
|
||||
r := workerRequest(c, context.Background(), cmdStatus)
|
||||
if r.err == nil || !c.deliveryPending {
|
||||
t.Errorf("bad BCC: err=%v pending=%v", r.err, c.deliveryPending)
|
||||
}
|
||||
@ -235,71 +232,6 @@ func TestDeliveryClearWaitsTwoSeconds(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestDeliveryClearanceWaitStops(t *testing.T) {
|
||||
for _, tc := range []struct {
|
||||
name string
|
||||
response cmdResp
|
||||
cancel bool
|
||||
timeout bool
|
||||
}{
|
||||
{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: "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) {
|
||||
responses := make([]cmdResp, 20)
|
||||
for i := range responses {
|
||||
responses[i] = tc.response
|
||||
}
|
||||
c, d := newSequenceTestClient(t, responses...)
|
||||
ctx, cancel := context.WithCancel(context.Background())
|
||||
defer cancel()
|
||||
if tc.cancel {
|
||||
c.sequenceTiming.wait = func(context.Context, time.Duration) error { cancel(); return ctx.Err() }
|
||||
}
|
||||
started := c.sequenceTiming.now()
|
||||
_, err := c.PrepareCurrentCard(ctx)
|
||||
if err == nil {
|
||||
t.Fatal("preparation succeeded while clearance unavailable")
|
||||
}
|
||||
if tc.cancel && !errors.Is(err, context.Canceled) {
|
||||
t.Errorf("error=%v, want canceled", err)
|
||||
}
|
||||
if tc.timeout {
|
||||
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))
|
||||
}
|
||||
}
|
||||
for _, cmd := range d.commands {
|
||||
if cmd != cmdStatus {
|
||||
t.Errorf("clearance dispatched command %v, want only AP", cmd)
|
||||
}
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
func TestDeliveryClearanceDoesNotConsumeRecoveryWindow(t *testing.T) {
|
||||
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...)
|
||||
start := c.now()
|
||||
if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, ErrPreparationExhausted) {
|
||||
t.Fatalf("preparation error=%v, want exhausted", err)
|
||||
}
|
||||
if elapsed := c.now().Sub(start); elapsed != 33*time.Second {
|
||||
t.Errorf("elapsed=%s, want clearance 15s + shakes 18s", elapsed)
|
||||
}
|
||||
if commandCount(d.commands, cmdReset) != 3 || commandCount(d.commands, cmdToEncoder) != 4 {
|
||||
t.Errorf("commands=%v, want 3 RS and 4 FC7", d.commands)
|
||||
}
|
||||
}
|
||||
|
||||
func TestDeliveryPendingIsNotPersisted(t *testing.T) {
|
||||
c := NewClient(nil, 1)
|
||||
defer c.Close()
|
||||
@ -328,32 +260,6 @@ func TestDeliveryCancellationAfterACKDoesNotSetPending(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestDeliveryClearanceRetainsFullPreparationTimeout(t *testing.T) {
|
||||
responses := make([]cmdResp, 8)
|
||||
for i := range responses {
|
||||
responses[i] = cmdResp{status: status(0x37), deliveryPending: true}
|
||||
}
|
||||
responses = append(responses, positionResponses(0x30, 2)...)
|
||||
c, d := newSequenceTestClient(t, responses...)
|
||||
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)
|
||||
}
|
||||
start := c.now()
|
||||
if _, err := c.PrepareCurrentCard(context.Background()); !errors.Is(err, ErrPreparationExhausted) {
|
||||
t.Fatalf("preparation error=%v, want exhausted", err)
|
||||
}
|
||||
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)
|
||||
}
|
||||
}
|
||||
|
||||
func TestWorkerSerializesClearanceAndFC7(t *testing.T) {
|
||||
p := &scriptedTransport{chunks: [][]byte{vendorACK, apReply(status(0x30)), vendorACK, vendorACK, vendorACK, apReply(status(0x37))}}
|
||||
c, _ := deliveryWorkerClient(t, p)
|
||||
@ -388,10 +294,8 @@ func TestWorkerSerializesClearanceAndFC7(t *testing.T) {
|
||||
if r := <-fc0; r.err != nil {
|
||||
t.Fatal(r.err)
|
||||
}
|
||||
if err := c.ToEncoder(ctx); !errors.Is(err, errDeliveryPending) {
|
||||
t.Errorf("FC7 after queued FC0=%v, want deferred", err)
|
||||
}
|
||||
want := []string{"AP", "FC7", "FC0", "AP"}
|
||||
|
||||
want := []string{"AP", "FC7", "FC0"}
|
||||
if got := wireCommands(p); !reflect.DeepEqual(got, want) {
|
||||
t.Errorf("serialized commands=%v, want %v", got, want)
|
||||
}
|
||||
@ -426,10 +330,10 @@ func TestPreparationWireFailuresNeverShake(t *testing.T) {
|
||||
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)
|
||||
if _, err := c.PrepareCurrentCard(context.Background()); err != nil {
|
||||
t.Errorf("frame % X: err=%v, want encoder opportunity", frame, err)
|
||||
}
|
||||
want := []string{"AP", "FC7", "AP"}
|
||||
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)
|
||||
}
|
||||
|
||||
@ -19,6 +19,7 @@ const (
|
||||
cmdToEncoder
|
||||
cmdOutOfMouth
|
||||
cmdReset
|
||||
cmdDeliveryClearance
|
||||
)
|
||||
|
||||
type cmdReq struct {
|
||||
@ -27,8 +28,6 @@ type cmdReq struct {
|
||||
respCh chan cmdResp
|
||||
}
|
||||
|
||||
var errDeliveryPending = errors.New("next-card preparation deferred: previous delivery is not clear")
|
||||
|
||||
type cmdResp struct {
|
||||
deliveryPending bool
|
||||
status []byte
|
||||
@ -47,7 +46,7 @@ const (
|
||||
sequenceTimeout = 32 * time.Second
|
||||
sequenceUncertainWait = 4 * time.Second
|
||||
sequenceMaxShakes = 3
|
||||
deliveryClearanceTimeout = 16 * time.Second
|
||||
deliveryClearanceTimeout = 6 * time.Second
|
||||
deliveryMinimumWait = 2 * time.Second
|
||||
)
|
||||
|
||||
@ -204,18 +203,13 @@ func (c *Client) handle(req cmdReq) {
|
||||
st, err := c.readWorkerStatus(req.ctx)
|
||||
req.respCh <- cmdResp{status: st, err: err, deliveryPending: c.deliveryPending}
|
||||
|
||||
case cmdDeliveryClearance:
|
||||
st, err := c.waitWorkerDeliveryClearance(req.ctx)
|
||||
req.respCh <- cmdResp{status: st, err: err, deliveryPending: c.deliveryPending}
|
||||
|
||||
case cmdToEncoder:
|
||||
if c.deliveryPending {
|
||||
// Stay inside port ownership: never enqueue a request from the worker.
|
||||
st, err := c.readWorkerStatus(req.ctx)
|
||||
if err == nil {
|
||||
_, err = deliveryClearance(st)
|
||||
}
|
||||
if err == nil && c.deliveryPending {
|
||||
err = errDeliveryPending
|
||||
log.Debugf("next-card preparation deferred; raw status: % X", st)
|
||||
}
|
||||
if err != nil {
|
||||
if _, err := c.waitWorkerDeliveryClearance(req.ctx); err != nil {
|
||||
req.respCh <- cmdResp{err: err}
|
||||
return
|
||||
}
|
||||
@ -405,16 +399,13 @@ func (c *Client) DispenserPrepare(ctx context.Context) (string, error) {
|
||||
|
||||
func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]byte, string, error) {
|
||||
response := c.doResponse(ctx, cmdStatus)
|
||||
status, err := response.status, response.err
|
||||
if err == nil && response.deliveryPending {
|
||||
err = errDeliveryPending
|
||||
if err := ctx.Err(); err != nil {
|
||||
return nil, "", err
|
||||
}
|
||||
if err != nil {
|
||||
if ctxErr := ctx.Err(); ctxErr != nil {
|
||||
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 {
|
||||
@ -425,63 +416,85 @@ func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]by
|
||||
return status, stockStatus, nil
|
||||
}
|
||||
|
||||
// waitForDeliveryClearance reuses the first clear AP as the initial preparation sample.
|
||||
// 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, deliveryClearanceTimeout)
|
||||
// waitWorkerDeliveryClearance runs only inside the serial worker.
|
||||
// An unusable observation never becomes a fabricated physical position.
|
||||
func (c *Client) waitWorkerDeliveryClearance(parent context.Context) ([]byte, error) {
|
||||
ctx, cancel := context.WithTimeout(parent, deliveryClearanceTimeout)
|
||||
defer cancel()
|
||||
deadline := c.sequenceTiming.now().Add(deliveryClearanceTimeout)
|
||||
var lastStatus []byte
|
||||
defer func() {
|
||||
if resultErr != nil {
|
||||
log.Warnf("[%s] delivery clearance stopped: %v; %s raw status: % X", operation, resultErr, statusDescription(lastStatus), lastStatus)
|
||||
}
|
||||
}()
|
||||
deadline := c.now().Add(deliveryClearanceTimeout)
|
||||
var latest []byte
|
||||
for {
|
||||
if err := ctx.Err(); err != nil {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, err)
|
||||
if err := parent.Err(); err != nil {
|
||||
return nil, err
|
||||
}
|
||||
if !c.sequenceTiming.now().Before(deadline) {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, context.DeadlineExceeded)
|
||||
if !c.now().Before(deadline) || ctx.Err() != nil {
|
||||
class, err := classifyPreparationStatus(latest)
|
||||
if err == nil && class == positionWellEmpty {
|
||||
return latest, ErrCardWellEmpty
|
||||
}
|
||||
if err == nil && (isPreparationMoving(latest) || latest[1] == 0x34) {
|
||||
return latest, context.DeadlineExceeded
|
||||
}
|
||||
c.deliveryPending = false
|
||||
log.Warn("delivery clearance assumed after bounded observation fallback")
|
||||
return latest, nil
|
||||
}
|
||||
r := c.doResponse(ctx, cmdStatus)
|
||||
if len(r.status) > 0 {
|
||||
lastStatus = r.status
|
||||
st, err := c.readWorkerStatus(ctx)
|
||||
if parent.Err() != nil {
|
||||
return nil, parent.Err()
|
||||
}
|
||||
if r.err != nil {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance status: %w", operation, r.err)
|
||||
latest = usableObservation(st, err, "delivery clearance")
|
||||
if latest != nil && latest[3] == 0x38 {
|
||||
return latest, ErrCardWellEmpty
|
||||
}
|
||||
if len(r.status) == 4 {
|
||||
stock = stockTake(r.status)
|
||||
c.setStock(r.status)
|
||||
if !c.deliveryPending {
|
||||
return latest, nil
|
||||
}
|
||||
if err := ctx.Err(); err != nil {
|
||||
return nil, stock, err
|
||||
}
|
||||
if !c.sequenceTiming.now().Before(deadline) {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, context.DeadlineExceeded)
|
||||
}
|
||||
if !r.deliveryPending {
|
||||
return r.status, stock, nil
|
||||
}
|
||||
if _, err := deliveryClearance(r.status); err != nil {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, err)
|
||||
remaining := deadline.Sub(c.now())
|
||||
if remaining <= 0 || ctx.Err() != nil {
|
||||
continue
|
||||
}
|
||||
wait := sequencePollInterval
|
||||
if remaining := deadline.Sub(c.sequenceTiming.now()); remaining < wait {
|
||||
if remaining < wait {
|
||||
wait = remaining
|
||||
}
|
||||
if err := c.sequenceTiming.wait(ctx, wait); err != nil {
|
||||
return nil, stock, fmt.Errorf("[%s] delivery clearance: %w", operation, err)
|
||||
if err := c.sequenceTiming.wait(ctx, wait); err != nil && parent.Err() != nil {
|
||||
return nil, parent.Err()
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// usableObservation preserves strict validation while discarding unusable telemetry.
|
||||
func usableObservation(status []byte, err error, operation string) []byte {
|
||||
if err == nil {
|
||||
_, err = classifyPreparationStatus(status)
|
||||
}
|
||||
if err != nil {
|
||||
log.Warnf("[%s] unusable AP observation; raw status: % X error=%v", operation, status, err)
|
||||
return nil
|
||||
}
|
||||
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 stock, err
|
||||
}
|
||||
status = usableObservation(status, nil, operation)
|
||||
started := c.now()
|
||||
deadline := started.Add(sequenceTimeout)
|
||||
ctx, cancel := context.WithTimeoutCause(parent, sequenceTimeout, ErrPreparationExhausted)
|
||||
@ -502,6 +515,26 @@ func (c *Client) prepareCardAtEncoder(parent context.Context, operation string)
|
||||
}
|
||||
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
|
||||
@ -535,18 +568,17 @@ func (c *Client) prepareCardAtEncoder(parent context.Context, operation string)
|
||||
}
|
||||
for {
|
||||
if err := checkDeadline(); err != nil {
|
||||
return stock, err
|
||||
}
|
||||
class, err := classifyPreparationStatus(status)
|
||||
if err != nil {
|
||||
return stock, err
|
||||
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, checkDeadline()
|
||||
return stock, observationResult(checkDeadline())
|
||||
case positionWellEmpty:
|
||||
stage = "empty"
|
||||
return stock, ErrCardWellEmpty
|
||||
@ -583,29 +615,29 @@ func (c *Client) prepareCardAtEncoder(parent context.Context, operation string)
|
||||
return stock, err
|
||||
}
|
||||
} else {
|
||||
if class == positionUncertain {
|
||||
if class == positionUncertain || class == "" {
|
||||
if uncertainSince.IsZero() {
|
||||
uncertainSince = c.now()
|
||||
}
|
||||
if c.now().Sub(uncertainSince) >= sequenceUncertainWait {
|
||||
stage = "uncertain position handoff"
|
||||
return stock, checkDeadline()
|
||||
return stock, observationResult(checkDeadline())
|
||||
}
|
||||
} else {
|
||||
uncertainSince = time.Time{}
|
||||
}
|
||||
stage = "polling"
|
||||
if err := wait(sequencePollInterval); err != nil {
|
||||
return stock, err
|
||||
return stock, observationResult(err)
|
||||
}
|
||||
}
|
||||
stage = "fresh AP"
|
||||
if err := checkDeadline(); err != nil {
|
||||
return stock, err
|
||||
return stock, observationResult(err)
|
||||
}
|
||||
status, stock, err = c.readSequenceStatus(ctx, operation)
|
||||
if deadlineErr := checkDeadline(); deadlineErr != nil {
|
||||
return stock, deadlineErr
|
||||
return stock, observationResult(deadlineErr)
|
||||
}
|
||||
if err != nil {
|
||||
return stock, err
|
||||
@ -628,39 +660,13 @@ func (c *Client) DeliverCurrentCard(ctx context.Context) (string, error) {
|
||||
return "", nil
|
||||
}
|
||||
|
||||
// BeginPrepareNextCard waits for delivery clearance and dispatches FC7 once,
|
||||
// without waiting for encoder 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 {
|
||||
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
|
||||
}
|
||||
if err := c.ToEncoder(ctx); err != nil {
|
||||
return fmt.Errorf("[BeginPrepareNextCard] to encoder: %w", err)
|
||||
}
|
||||
return nil
|
||||
}
|
||||
|
||||
// PrepareNextCard runs the same bounded physical preparation for a later issuance attempt.
|
||||
|
||||
@ -52,6 +52,10 @@ 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 {
|
||||
@ -63,6 +67,10 @@ func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *
|
||||
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
|
||||
@ -369,8 +377,8 @@ 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 _, 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)
|
||||
@ -391,6 +399,9 @@ func TestPreparationTransportAndDispatchFailuresDoNotShake(t *testing.T) {
|
||||
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())
|
||||
@ -465,7 +476,7 @@ func TestPreparationCallerDeadlineIsNotRetryableExhaustion(t *testing.T) {
|
||||
}
|
||||
}
|
||||
|
||||
func TestPreparationExpiredEncoderSampleDoesNotHandoff(t *testing.T) {
|
||||
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 }
|
||||
@ -475,45 +486,10 @@ func TestPreparationExpiredEncoderSampleDoesNotHandoff(t *testing.T) {
|
||||
}
|
||||
}
|
||||
_, err := c.PrepareCurrentCard(context.Background())
|
||||
if !errors.Is(err, ErrPreparationExhausted) {
|
||||
t.Errorf("late encoder sample: err=%v, want preparation exhausted", err)
|
||||
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)
|
||||
}
|
||||
}
|
||||
|
||||
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)
|
||||
}
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
242
internal/dispenser/observation_test.go
Normal file
242
internal/dispenser/observation_test.go
Normal file
@ -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)
|
||||
}
|
||||
}
|
||||
}
|
||||
@ -121,11 +121,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",
|
||||
@ -353,3 +353,27 @@ func TestIssueDoorCardLogsDeliveryFailureWithoutReplacingEncoderOutcome(t *testi
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
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)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@ -302,7 +302,7 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
|
||||
errorhandlers.WriteError(w, http.StatusBadGateway, err.Error())
|
||||
return
|
||||
}
|
||||
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispense error: "+err.Error())
|
||||
errorhandlers.WriteError(w, http.StatusBadGateway, "Dispense error: "+err.Error())
|
||||
return
|
||||
}
|
||||
|
||||
|
||||
@ -2,6 +2,9 @@
|
||||
|
||||
builtVersion is a const in main.go
|
||||
|
||||
#### 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
|
||||
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user