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

fix(dispenser): recover stuck card preparation with reset

Browse Source
This commit is contained in:
yurii 2026-09-24 15:07:40 +01:00
parent aeb86f55b9
commit 4dfe139c3b
5 changed files with 396 additions and 35 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
cmd/hardlink/main.go
View File

@ -33,7 +33,7 @@ import (
)
const (
buildVersion = "v2.0.2"
buildVersion = "v2.0.3"
serviceName = "hardlink"
pollingFrequency = 8 * time.Second
)

15
internal/dispenser/dispenser.go
View File

@ -35,6 +35,7 @@ var (
commandFC7 = []byte{ETX, 0x46, 0x43, 0x37} // "FC7"
commandFC0 = []byte{ETX, 0x46, 0x43, 0x30} // "FC0"
commandRS = []byte{0x02, 0x52, 0x53} // Length 2, "RS"
statusPos0 = map[byte]string{
0x38: "Keep",
@ -316,6 +317,20 @@ func cardToEncoderPosition(port *serial.Port) error {
return nil
}
func resetDispenser(port *serial.Port) error {
response, err := sendAndReceive(port, createPacket(Address, commandRS), delay)
if err != nil {
return fmt.Errorf("error sending reset command: %w", err)
}
if err := checkACK(response); err != nil {
return err
}
if _, err := port.Write(append([]byte{ENQ}, Address...)); err != nil {
return fmt.Errorf("error sending ENQ to reset device: %w", err)
}
return nil
}
func cardOutOfMouth(port *serial.Port) error {
enq := append([]byte{ENQ}, Address...)

145
internal/dispenser/dispenserclient.go
View File

@ -17,6 +17,7 @@ const (
cmdStatus cmdType = iota
cmdToEncoder
cmdOutOfMouth
cmdReset
)
type cmdReq struct {
@ -38,7 +39,8 @@ type sequenceTiming struct {
const (
sequencePollInterval = time.Second
sequenceRetryAfter = 6 * time.Second
sequenceTimeout = 12 * time.Second
sequenceResetWait = 2 * time.Second
sequenceTimeout = 16 * time.Second
)
type Client struct {
@ -205,6 +207,11 @@ func (c *Client) handle(req cmdReq) {
c.invalidateStatusCache()
req.respCh <- cmdResp{err: err}
case cmdReset:
err := resetDispenser(c.port)
c.invalidateStatusCache()
req.respCh <- cmdResp{err: err}
case cmdOutOfMouth:
err := cardOutOfMouth(c.port)
// A movement command makes any previously cached position unreliable.
@ -262,6 +269,12 @@ func (c *Client) ToEncoder(ctx context.Context) error {
return err
}
// Reset dispatches RS through the port owner; acceptance does not imply mechanical completion.
func (c *Client) Reset(ctx context.Context) error {
_, err := c.do(ctx, cmdReset)
return err
}
func (c *Client) OutOfMouth(ctx context.Context) error {
_, err := c.do(ctx, cmdOutOfMouth)
return err
@ -326,7 +339,7 @@ func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]by
return status, stockStatus, nil
}
func preparationStatus(operation string, status []byte) (bool, error) {
func preparationStatus(operation string, status []byte, allowCombinedFailure bool) (bool, error) {
if len(status) != 4 {
return false, fmt.Errorf("[%s] %w", operation, validateDispenserStatusData(status))
}
@ -356,7 +369,8 @@ func preparationStatus(operation string, status []byte) (bool, error) {
// diagnostic as transient during an active preparation sequence and let
// pollForEncoderPosition decide success (0x33) or timeout. Do not mask
// independent hard errors reported in the other status bytes.
if status[0] == 0x32 {
// 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 {
@ -364,8 +378,9 @@ func preparationStatus(operation string, status []byte) (bool, error) {
}
log.Warnf(
"[%s] transient Preparing card fails; waiting for encoder position, raw status: % X",
"[%s] transient preparation failure (%s); waiting for encoder position, raw status: % X",
operation,
statusDescription(status),
status,
)
return false, nil
@ -377,57 +392,125 @@ func preparationStatus(operation string, status []byte) (bool, error) {
return false, nil
}
func (c *Client) pollForEncoderPosition(
ctx context.Context,
operation string,
retryCommand func(context.Context) error,
) (string, error) {
func (c *Client) pollForEncoderPosition(ctx context.Context, operation string) (stockStatus string, resultErr error) {
started := c.sequenceTiming.now()
halfway := started.Add(sequenceRetryAfter)
recoveryAt := started.Add(sequenceRetryAfter)
deadline := started.Add(sequenceTimeout)
ctx, cancel := context.WithTimeout(ctx, sequenceTimeout)
defer cancel()
retried := false
stockStatus := ""
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 := ctx.Err(); err != nil {
return stockStatus, fmt.Errorf("[%s] %w", operation, err)
if err := checkDeadline(); err != nil {
return stockStatus, err
}
now := c.sequenceTiming.now()
if !now.Before(deadline) {
return stockStatus, fmt.Errorf("[%s] timed out after %s", operation, sequenceTimeout)
}
status, currentStockStatus, err := c.readSequenceStatus(ctx, operation)
stockStatus = currentStockStatus
lastStatus = status
if err != nil {
return stockStatus, err
}
ready, err := preparationStatus(operation, status)
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
}
now = c.sequenceTiming.now()
if !now.Before(deadline) {
return stockStatus, fmt.Errorf("[%s] timed out after %s", operation, sequenceTimeout)
moving := isPreparationMoving(status)
prepareFailed := status[0] == 0x32 || status[0] == 0x36
if prepareFailed && !moving {
consecutiveFailures++
} else {
consecutiveFailures = 0
}
if retryCommand != nil && !retried && !now.Before(halfway) {
if err := retryCommand(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] retry command: %w", operation, err)
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)
}
}
retried = true
}
if err := checkDeadline(); err != nil {
return stockStatus, err
}
wait := sequencePollInterval
if remaining := deadline.Sub(now); remaining < wait {
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] %w", operation, err)
return stockStatus, fmt.Errorf("[%s] %s: %w", operation, stage, err)
}
}
}
@ -437,7 +520,7 @@ func (c *Client) prepareCardAtEncoder(ctx context.Context, operation string) (st
if err != nil {
return stockStatus, err
}
ready, err := preparationStatus(operation, status)
ready, err := preparationStatus(operation, status, true)
if err != nil {
return stockStatus, err
}
@ -448,7 +531,7 @@ func (c *Client) prepareCardAtEncoder(ctx context.Context, operation string) (st
if err := c.ToEncoder(ctx); err != nil {
return stockStatus, fmt.Errorf("[%s] to encoder: %w", operation, err)
}
return c.pollForEncoderPosition(ctx, operation, c.ToEncoder)
return c.pollForEncoderPosition(ctx, operation)
}
// PrepareCurrentCard authoritatively places the card to be encoded at the encoder.

266
internal/dispenser/dispenserclient_test.go
View File

@ -4,6 +4,7 @@ import (
"bytes"
"context"
"errors"
"reflect"
"strings"
"testing"
"time"
@ -15,6 +16,7 @@ type fakeSequenceDevice struct {
statusResponses []cmdResp
commandErrors map[cmdType][]error
commands []cmdType
commandTimes []time.Time
}
func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *fakeSequenceDevice) {
@ -51,6 +53,7 @@ func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *
return
case request := <-client.reqCh:
device.commands = append(device.commands, request.typ)
device.commandTimes = append(device.commandTimes, now)
if request.typ == cmdStatus {
if len(device.statusResponses) == 0 {
request.respCh <- cmdResp{err: errors.New("unexpected status read")}
@ -90,6 +93,263 @@ 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, 0x39}, // 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}
if !bytes.Equal(got, want) {
t.Errorf("createPacket(RS) = % X, want % X", got, want)
}
}
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
@ -326,7 +586,7 @@ func TestDeliverCurrentCardPreservesContextCancellation(t *testing.T) {
}
func TestPrepareCurrentCardRetriesOnceThenTimesOut(t *testing.T) {
responses := make([]cmdResp, 13)
responses := make([]cmdResp, 17)
for index := range responses {
responses[index] = cmdResp{status: status(0x34)}
}
@ -339,8 +599,8 @@ func TestPrepareCurrentCardRetriesOnceThenTimesOut(t *testing.T) {
if got := commandCount(device.commands, cmdToEncoder); got != 2 {
t.Fatalf("to-encoder commands = %d, want initial command plus one halfway retry", got)
}
if got := commandCount(device.commands, cmdStatus); got != 13 {
t.Fatalf("status reads = %d, want 13", got)
if got := commandCount(device.commands, cmdStatus); got != 17 {
t.Fatalf("status reads = %d, want 17", got)
}
}

3
release notes.md
View File

@ -2,6 +2,9 @@
builtVersion is a const in main.go
#### v2.0.3 - 24 September 2026
fix(dispenser): recover stuck card preparation with reset
#### v2.0.2 - 22 September 2026
fix(dispenser): retry on transient prepare failure