fixed dispenser delivery confirmation

cmd/hardlink/main.go

@@ -34,7 +34,7 @@ import (
 )
 
 const (
-	buildVersion     = "v1.3.4"
+	buildVersion     = "v1.3.5"
 	serviceName      = "hardlink"
 	pollingFrequency = 8 * time.Second
 )

internal/dispenser/dispenser.go

@@ -1,6 +1,7 @@
 package dispenser
 
 import (
+	"errors"
 	"fmt"
 	"strings"
 	"time"
@@ -22,9 +23,13 @@ const (
 
 	// cache freshness for "continuous status" reads (tune as you wish)
 	defaultStatusTTL = 1500 * time.Millisecond
+
+	CardWellEmptyMessage = "Card well is empty"
 )
 
 var (
+	ErrCardWellEmpty = errors.New(CardWellEmptyMessage)
+
 	SerialPort string
 	Address    []byte
 
@@ -67,10 +72,9 @@ var (
 // Status helpers
 // --------------------
 
-func logStatus(statusBytes []byte) {
+func statusDescription(statusBytes []byte) string {
 	if len(statusBytes) < 4 {
-		log.Infof("Dispenser status: <invalid len=%d>", len(statusBytes))
-		return
+		return fmt.Sprintf("<invalid len=%d>", len(statusBytes))
 	}
 
 	posStatus := []struct {
@@ -94,13 +98,58 @@ func logStatus(statusBytes []byte) {
 			result.WriteString(statusMsg + "; ")
 		}
 	}
-	log.Infof("Dispenser status: %s", result.String())
+	return result.String()
+}
+
+func logStatus(statusBytes []byte) {
+	log.Infof("Dispenser status: %s", statusDescription(statusBytes))
 }
 
 func isAtEncoderPosition(statusBytes []byte) bool {
 	return len(statusBytes) >= 4 && statusBytes[3] == 0x33
 }
 
+func validateDispenserStatusData(statusBytes []byte) error {
+	if len(statusBytes) != 4 {
+		return fmt.Errorf("malformed dispenser status: got %d bytes, want 4", len(statusBytes))
+	}
+
+	statusMaps := []map[byte]string{statusPos0, statusPos1, statusPos2, statusPos3}
+	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)
+		}
+	}
+	return nil
+}
+
+func dispenserStatusError(statusBytes []byte) error {
+	switch statusBytes[0] {
+	case 0x34, 0x32, 0x36:
+		return fmt.Errorf("dispenser error: %s", statusPos0[statusBytes[0]])
+	}
+	switch statusBytes[1] {
+	case 0x32, 0x31:
+		return fmt.Errorf("dispenser error: %s", statusPos1[statusBytes[1]])
+	}
+	switch statusBytes[2] {
+	case 0x34, 0x32:
+		return fmt.Errorf("dispenser error: %s", statusPos2[statusBytes[2]])
+	}
+
+	return nil
+}
+
+func isPreparationMoving(statusBytes []byte) bool {
+	return len(statusBytes) == 4 &&
+		(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 ""

internal/dispenser/dispenserclient.go

@@ -30,12 +30,25 @@ type cmdResp struct {
 	err    error
 }
 
+type sequenceTiming struct {
+	now  func() time.Time
+	wait func(context.Context, time.Duration) error
+}
+
+const (
+	sequencePollInterval = time.Second
+	sequenceRetryAfter   = 6 * time.Second
+	sequenceTimeout      = 12 * time.Second
+)
+
 type Client struct {
 	port *serial.Port
 
 	reqCh chan cmdReq
 	done  chan struct{}
 
+	sequenceTiming sequenceTiming
+
 	// status cache
 	mu          sync.RWMutex
 	lastStatus  []byte
@@ -54,15 +67,31 @@ func NewClient(port *serial.Port, queueSize int) *Client {
 		queueSize = 16
 	}
 	c := &Client{
-		port:      port,
-		reqCh:     make(chan cmdReq, queueSize),
-		done:      make(chan struct{}),
+		port:  port,
+		reqCh: make(chan cmdReq, queueSize),
+		done:  make(chan struct{}),
+		sequenceTiming: sequenceTiming{
+			now:  time.Now,
+			wait: waitForSequence,
+		},
 		statusTTL: defaultStatusTTL,
 	}
 	go c.loop()
 	return c
 }
 
+func waitForSequence(ctx context.Context, duration time.Duration) error {
+	timer := time.NewTimer(duration)
+	defer timer.Stop()
+
+	select {
+	case <-timer.C:
+		return nil
+	case <-ctx.Done():
+		return ctx.Err()
+	}
+}
+
 func (c *Client) Close() {
 	select {
 	case <-c.done:
@@ -268,113 +297,152 @@ func (c *Client) DispenserPrepare(ctx context.Context) (string, error) {
 	return stockStatus, nil
 }
 
-func (c *Client) DispenserStart(ctx context.Context) (string, error) {
-	const funcName = "DispenserStart"
-	stockStatus := ""
-
-	status, err := c.CheckStatus(ctx)
+func (c *Client) readSequenceStatus(ctx context.Context, operation string) ([]byte, string, error) {
+	status, err := c.do(ctx, cmdStatus)
 	if err != nil {
-		return stockStatus, fmt.Errorf("[%s] check status: %w", funcName, err)
+		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)
 	}
 
-	defer func() {
+	stockStatus := ""
+	if len(status) == 4 {
+		stockStatus = stockTake(status)
+		c.setStock(status)
 		logStatus(status)
-	}()
-	stockStatus = stockTake(status)
-	c.setStock(status)
+	}
+	return status, stockStatus, nil
+}
 
-	if isCardWellEmpty(status) {
-		return stockStatus, fmt.Errorf(stockStatus)
+func preparationStatus(operation string, status []byte) (bool, error) {
+	if len(status) != 4 {
+		return false, fmt.Errorf("[%s] %w", operation, validateDispenserStatusData(status))
 	}
 	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
+	}
+	if err := dispenserStatusError(status); err != nil {
+		return false, fmt.Errorf("[%s] %w", operation, err)
+	}
+	return false, nil
+}
+
+func (c *Client) pollForEncoderPosition(
+	ctx context.Context,
+	operation string,
+	retryCommand func(context.Context) error,
+) (string, error) {
+	started := c.sequenceTiming.now()
+	halfway := started.Add(sequenceRetryAfter)
+	deadline := started.Add(sequenceTimeout)
+	retried := false
+	stockStatus := ""
+
+	for {
+		if err := ctx.Err(); err != nil {
+			return stockStatus, fmt.Errorf("[%s] %w", operation, 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
+		if err != nil {
+			return stockStatus, err
+		}
+		ready, err := preparationStatus(operation, status)
+		if err != nil {
+			return stockStatus, err
+		}
+		if ready {
+			return stockStatus, nil
+		}
+
+		now = c.sequenceTiming.now()
+		if !now.Before(deadline) {
+			return stockStatus, fmt.Errorf("[%s] timed out after %s", operation, sequenceTimeout)
+		}
+		if retryCommand != nil && !retried && !now.Before(halfway) {
+			if err := retryCommand(ctx); err != nil {
+				return stockStatus, fmt.Errorf("[%s] retry command: %w", operation, err)
+			}
+			retried = true
+		}
+
+		wait := sequencePollInterval
+		if remaining := deadline.Sub(now); remaining < wait {
+			wait = remaining
+		}
+		if err := c.sequenceTiming.wait(ctx, wait); err != nil {
+			return stockStatus, fmt.Errorf("[%s] %w", operation, err)
+		}
+	}
+}
+
+func (c *Client) prepareCardAtEncoder(ctx context.Context, operation string) (string, error) {
+	status, stockStatus, err := c.readSequenceStatus(ctx, operation)
+	if err != nil {
+		return stockStatus, err
+	}
+	ready, err := preparationStatus(operation, status)
+	if err != nil {
+		return stockStatus, err
+	}
+	if ready {
 		return stockStatus, nil
 	}
 
 	if err := c.ToEncoder(ctx); err != nil {
-		return stockStatus, fmt.Errorf("[%s] to encoder: %w", funcName, err)
-	}
-
-	halfway := time.Now().Add(6 * time.Second)
-	deadline := time.Now().Add(12 * time.Second)
-
-	for {
-		time.Sleep(delay * 2)
-		switch {
-		case time.Now().After(halfway):
-			if err := c.ToEncoder(ctx); err != nil {
-				return stockStatus, fmt.Errorf("[%s] to encoder: %w", funcName, err)
-			}
-		case time.Now().After(deadline):
-			return stockStatus, nil
-		}
-
-		status, _ = c.do(ctx, cmdStatus)
-
-		stockStatus = stockTake(status)
-		c.setStock(status)
-		logStatus(status)
-
-		// error states first
-		if isCardWellEmpty(status) {
-			return stockStatus, fmt.Errorf(stockStatus)
-		}
-
-		if isAtEncoderPosition(status) {
-			return stockStatus, nil
-		}
+		return stockStatus, fmt.Errorf("[%s] to encoder: %w", operation, err)
 	}
+	return c.pollForEncoderPosition(ctx, operation, c.ToEncoder)
 }
 
-func (c *Client) DispenserFinal(ctx context.Context) (string, error) {
-	const funcName = "DispenserFinal"
-	stockStatus := ""
-	var status []byte
+// PrepareCurrentCard authoritatively places the card to be encoded at the encoder.
+func (c *Client) PrepareCurrentCard(ctx context.Context) (string, error) {
+	return c.prepareCardAtEncoder(ctx, "PrepareCurrentCard")
+}
+
+// DeliverCurrentCard presents the encoded card and confirms command acceptance.
+func (c *Client) DeliverCurrentCard(ctx context.Context) (string, error) {
+	const operation = "DeliverCurrentCard"
 
 	if err := c.OutOfMouth(ctx); err != nil {
-		return stockStatus, fmt.Errorf("[%s] out of mouth: %w", funcName, err)
-	}
-
-	time.Sleep(delay)
-	status, err := c.do(ctx, cmdStatus)
-	if err == nil && len(status) >= 4 {
-		c.setStock(status)
-	}
-
-	time.Sleep(delay)
-	if err := c.ToEncoder(ctx); err != nil {
-		return stockStatus, fmt.Errorf("[%s] to encoder: %w", funcName, err)
-	}
-
-	defer func() {
-		logStatus(status)
-	}()
-
-	halfway := time.Now().Add(6 * time.Second)
-	deadline := time.Now().Add(12 * time.Second)
-
-	for {
-		time.Sleep(delay * 2)
-		switch {
-		case time.Now().After(halfway):
-			if err := c.ToEncoder(ctx); err != nil {
-				return stockStatus, fmt.Errorf("[%s] to encoder: %w", funcName, err)
-			}
-		case time.Now().After(deadline):
-			return stockStatus, nil
-		}
-
-		status, _ = c.do(ctx, cmdStatus)
-
-		stockStatus = stockTake(status)
-		c.setStock(status)
-		logStatus(status)
-
-		if isCardWellEmpty(status) {
-			return stockStatus, nil
-		}
-
-		if isAtEncoderPosition(status) {
-			return stockStatus, nil
-		}
+		return "", fmt.Errorf("[%s] out of mouth: %w", operation, err)
 	}
+	return "", nil
+}
+
+// BeginPrepareNextCard starts moving the next card to the encoder without waiting for readiness.
+func (c *Client) BeginPrepareNextCard(ctx context.Context) error {
+	if err := c.ToEncoder(ctx); err != nil {
+		return fmt.Errorf("[BeginPrepareNextCard] to encoder: %w", err)
+	}
+	return nil
+}
+
+// PrepareNextCard places a new card at the encoder for a later issuance attempt.
+func (c *Client) PrepareNextCard(ctx context.Context) (string, error) {
+	return c.prepareCardAtEncoder(ctx, "PrepareNextCard")
 }

internal/dispenser/dispenserclient_test.go

@@ -0,0 +1,404 @@
+package dispenser
+
+import (
+	"bytes"
+	"context"
+	"errors"
+	"strings"
+	"testing"
+	"time"
+
+	log "github.com/sirupsen/logrus"
+)
+
+type fakeSequenceDevice struct {
+	statusResponses []cmdResp
+	commandErrors   map[cmdType][]error
+	commands        []cmdType
+}
+
+func newSequenceTestClient(t *testing.T, statusResponses ...cmdResp) (*Client, *fakeSequenceDevice) {
+	t.Helper()
+
+	device := &fakeSequenceDevice{
+		statusResponses: append([]cmdResp(nil), statusResponses...),
+		commandErrors:   make(map[cmdType][]error),
+	}
+	now := time.Date(2026, time.July, 23, 12, 0, 0, 0, time.UTC)
+	client := &Client{
+		reqCh: make(chan cmdReq),
+		done:  make(chan struct{}),
+		sequenceTiming: sequenceTiming{
+			now: func() time.Time {
+				return now
+			},
+			wait: func(ctx context.Context, duration time.Duration) error {
+				select {
+				case <-ctx.Done():
+					return ctx.Err()
+				default:
+					now = now.Add(duration)
+					return nil
+				}
+			},
+		},
+	}
+
+	go func() {
+		for {
+			select {
+			case <-client.done:
+				return
+			case request := <-client.reqCh:
+				device.commands = append(device.commands, request.typ)
+				if request.typ == cmdStatus {
+					if len(device.statusResponses) == 0 {
+						request.respCh <- cmdResp{err: errors.New("unexpected status read")}
+						continue
+					}
+					response := device.statusResponses[0]
+					device.statusResponses = device.statusResponses[1:]
+					request.respCh <- response
+					continue
+				}
+
+				var err error
+				if queued := device.commandErrors[request.typ]; len(queued) > 0 {
+					err = queued[0]
+					device.commandErrors[request.typ] = queued[1:]
+				}
+				request.respCh <- cmdResp{err: err}
+			}
+		}
+	}()
+	t.Cleanup(client.Close)
+
+	return client, device
+}
+
+func status(position byte) []byte {
+	return []byte{0x30, 0x30, 0x30, position}
+}
+
+func commandCount(commands []cmdType, target cmdType) int {
+	count := 0
+	for _, command := range commands {
+		if command == target {
+			count++
+		}
+	}
+	return count
+}
+
+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 TestPrepareCurrentCardPollingAllowsTransientMovementWithStaleErrors(t *testing.T) {
+	client, device := newSequenceTestClient(t,
+		cmdResp{status: status(0x34)},
+		cmdResp{status: []byte{0x31, 0x38, 0x32, 0x30}},
+		cmdResp{status: []byte{0x30, 0x32, 0x32, 0x33}},
+	)
+
+	stock, err := client.PrepareCurrentCard(context.Background())
+	if err != nil {
+		t.Fatal(err)
+	}
+	if stock != "Card jammed" {
+		t.Fatalf("stock status = %q, want Card jammed", stock)
+	}
+	if got := commandCount(device.commands, cmdToEncoder); got != 1 {
+		t.Fatalf("to-encoder commands = %d, want 1", got)
+	}
+	if got := commandCount(device.commands, cmdStatus); got != 3 {
+		t.Fatalf("status reads = %d, want 3", got)
+	}
+}
+
+func TestPrepareCurrentCardRejectsFailureWithoutEncoderOrMovement(t *testing.T) {
+	tests := []struct {
+		name      string
+		response  cmdResp
+		wantError string
+		wantStock string
+	}{
+		{
+			name:      "status read error",
+			response:  cmdResp{err: errors.New("serial read failed")},
+			wantError: "serial read failed",
+		},
+		{
+			name:      "malformed status",
+			response:  cmdResp{status: []byte{0x30, 0x30, 0x31}},
+			wantError: "malformed dispenser status",
+		},
+		{
+			name:      "unknown status",
+			response:  cmdResp{status: []byte{0x30, 0x30, 0x30, 0x39}},
+			wantError: "unknown dispenser status",
+		},
+		{
+			name:      "jammed preparation",
+			response:  cmdResp{status: []byte{0x30, 0x30, 0x32, 0x34}},
+			wantError: "Card jammed",
+			wantStock: "Card jammed",
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			client, _ := newSequenceTestClient(t, test.response)
+
+			stock, err := client.PrepareCurrentCard(context.Background())
+			if err == nil || !strings.Contains(err.Error(), test.wantError) {
+				t.Fatalf("error = %v, want containing %q", err, test.wantError)
+			}
+			if stock != test.wantStock {
+				t.Fatalf("stock status = %q, want %q", stock, test.wantStock)
+			}
+		})
+	}
+}
+
+func TestPrepareCurrentCardReturnsAuthoritativeEmptyWellError(t *testing.T) {
+	client, device := newSequenceTestClient(t, cmdResp{status: status(0x38)})
+
+	stock, err := client.PrepareCurrentCard(context.Background())
+	if !errors.Is(err, ErrCardWellEmpty) {
+		t.Fatalf("error = %v, want ErrCardWellEmpty", err)
+	}
+	if stock != "Card empty" {
+		t.Fatalf("stock status = %q, want Card empty", stock)
+	}
+	if got := commandCount(device.commands, cmdToEncoder); got != 0 {
+		t.Fatalf("to-encoder commands = %d, want 0", got)
+	}
+}
+
+func TestDeliverCurrentCardSucceedsAfterCommandAcceptanceWithoutStatusPolling(t *testing.T) {
+	staleStatus := []byte{0x30, 0x32, 0x32, 0x33}
+	client, device := newSequenceTestClient(t, cmdResp{status: staleStatus})
+
+	stock, err := client.DeliverCurrentCard(context.Background())
+	if err != nil {
+		t.Fatal(err)
+	}
+	if stock != "" {
+		t.Fatalf("stock status = %q, want empty", stock)
+	}
+	if got := commandCount(device.commands, cmdOutOfMouth); got != 1 {
+		t.Fatalf("out-of-mouth commands = %d, want 1", got)
+	}
+	if got := commandCount(device.commands, cmdStatus); got != 0 {
+		t.Fatalf("status reads = %d, want 0", got)
+	}
+	if len(device.statusResponses) != 1 {
+		t.Fatalf("queued status responses = %d, want stale status unread", len(device.statusResponses))
+	}
+}
+
+func TestDeliverCurrentCardRejectsCommandFailures(t *testing.T) {
+	tests := []struct {
+		name string
+		err  error
+	}{
+		{name: "serial dispatch failure", err: errors.New("serial write failed")},
+		{name: "invalid acknowledgement", err: errors.New("unexpected response status")},
+		{name: "missing acknowledgement", err: errors.New("no response from dispenser")},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			client, device := newSequenceTestClient(t)
+			device.commandErrors[cmdOutOfMouth] = []error{test.err}
+
+			_, err := client.DeliverCurrentCard(context.Background())
+			if err == nil || !strings.Contains(err.Error(), test.err.Error()) {
+				t.Fatalf("error = %v, want containing %q", err, test.err)
+			}
+			if got := commandCount(device.commands, cmdOutOfMouth); got != 1 {
+				t.Fatalf("out-of-mouth commands = %d, want 1", got)
+			}
+			if got := commandCount(device.commands, cmdStatus); got != 0 {
+				t.Fatalf("status reads = %d, want 0", got)
+			}
+		})
+	}
+}
+
+func TestDeliverCurrentCardPreservesContextCancellation(t *testing.T) {
+	client, _ := newSequenceTestClient(t)
+	ctx, cancel := context.WithCancel(context.Background())
+	cancel()
+
+	_, err := client.DeliverCurrentCard(ctx)
+	if !errors.Is(err, context.Canceled) {
+		t.Fatalf("error = %v, want context.Canceled", err)
+	}
+}
+
+func TestPrepareCurrentCardRetriesOnceThenTimesOut(t *testing.T) {
+	responses := make([]cmdResp, 13)
+	for index := range responses {
+		responses[index] = cmdResp{status: status(0x34)}
+	}
+	client, device := newSequenceTestClient(t, responses...)
+
+	_, err := client.PrepareCurrentCard(context.Background())
+	if err == nil || !strings.Contains(err.Error(), "timed out") {
+		t.Fatalf("error = %v, want preparation timeout", err)
+	}
+	if got := commandCount(device.commands, cmdToEncoder); got != 2 {
+		t.Fatalf("to-encoder commands = %d, want initial command plus one halfway retry", got)
+	}
+	if got := commandCount(device.commands, cmdStatus); got != 13 {
+		t.Fatalf("status reads = %d, want 13", got)
+	}
+}
+
+func TestPrepareCurrentCardPropagatesContextCancellation(t *testing.T) {
+	client, _ := newSequenceTestClient(t,
+		cmdResp{status: status(0x34)},
+		cmdResp{status: status(0x34)},
+	)
+	ctx, cancel := context.WithCancel(context.Background())
+	client.sequenceTiming.wait = func(context.Context, time.Duration) error {
+		cancel()
+		return ctx.Err()
+	}
+
+	_, err := client.PrepareCurrentCard(ctx)
+	if !errors.Is(err, context.Canceled) {
+		t.Fatalf("error = %v, want context.Canceled", err)
+	}
+}
+
+func TestBeginPrepareNextCardDispatchesWithoutReadinessPolling(t *testing.T) {
+	client, device := newSequenceTestClient(t)
+
+	if err := client.BeginPrepareNextCard(context.Background()); err != nil {
+		t.Fatal(err)
+	}
+	if got := commandCount(device.commands, cmdToEncoder); got != 1 {
+		t.Fatalf("to-encoder commands = %d, want 1", got)
+	}
+	if got := commandCount(device.commands, cmdStatus); got != 0 {
+		t.Fatalf("status reads = %d, want 0", got)
+	}
+}
+
+func TestBeginPrepareNextCardReturnsDispatchFailureWithoutPolling(t *testing.T) {
+	client, device := newSequenceTestClient(t)
+	device.commandErrors[cmdToEncoder] = []error{errors.New("dispatch failed")}
+
+	err := client.BeginPrepareNextCard(context.Background())
+	if err == nil || !strings.Contains(err.Error(), "dispatch failed") {
+		t.Fatalf("error = %v, want dispatch failure", err)
+	}
+	if got := commandCount(device.commands, cmdToEncoder); got != 1 {
+		t.Fatalf("to-encoder commands = %d, want 1", got)
+	}
+	if got := commandCount(device.commands, cmdStatus); got != 0 {
+		t.Fatalf("status reads = %d, want 0", got)
+	}
+}
+
+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)
+			}
+		})
+	}
+}

internal/handlers/doorcard_handlers_test.go

@@ -0,0 +1,313 @@
+package handlers
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"errors"
+	"net/http"
+	"net/http/httptest"
+	"reflect"
+	"strings"
+	"testing"
+	"time"
+
+	"gitea.futuresens.co.uk/futuresens/cmstypes"
+	"gitea.futuresens.co.uk/futuresens/hardlink/config"
+	"gitea.futuresens.co.uk/futuresens/hardlink/internal/dispenser"
+	"gitea.futuresens.co.uk/futuresens/hardlink/internal/lockserver"
+	log "github.com/sirupsen/logrus"
+)
+
+type dispenserCallResult struct {
+	status string
+	err    error
+}
+
+type fakeDoorCardDispenser struct {
+	prepareCurrent dispenserCallResult
+	deliverCurrent dispenserCallResult
+	beginNextErr   error
+	beginNext      func() error
+	prepareNext    dispenserCallResult
+	calls          []string
+}
+
+func (d *fakeDoorCardDispenser) PrepareCurrentCard(context.Context) (string, error) {
+	d.calls = append(d.calls, "prepare current")
+	return d.prepareCurrent.status, d.prepareCurrent.err
+}
+
+func (d *fakeDoorCardDispenser) DeliverCurrentCard(context.Context) (string, error) {
+	d.calls = append(d.calls, "deliver current")
+	return d.deliverCurrent.status, d.deliverCurrent.err
+}
+
+func (d *fakeDoorCardDispenser) BeginPrepareNextCard(context.Context) error {
+	d.calls = append(d.calls, "begin prepare next")
+	if d.beginNext != nil {
+		return d.beginNext()
+	}
+	return d.beginNextErr
+}
+
+func (d *fakeDoorCardDispenser) PrepareNextCard(context.Context) (string, error) {
+	d.calls = append(d.calls, "prepare next")
+	return d.prepareNext.status, d.prepareNext.err
+}
+
+type fakeDoorCardLockServer struct {
+	sequenceErr   error
+	buildCalls    int
+	sequenceCalls int
+}
+
+func (l *fakeDoorCardLockServer) BuildCommand(lockserver.DoorCardRequest, time.Time, time.Time) error {
+	l.buildCalls++
+	return nil
+}
+
+func (l *fakeDoorCardLockServer) LockSequence() error {
+	l.sequenceCalls++
+	return l.sequenceErr
+}
+
+func performIssueDoorCardRequest(
+	t *testing.T,
+	dispenser *fakeDoorCardDispenser,
+	lock *fakeDoorCardLockServer,
+) (*httptest.ResponseRecorder, cmstypes.StatusRec, *App) {
+	t.Helper()
+
+	payload := lockserver.DoorCardRequest{
+		RoomField:    "101",
+		CheckinTime:  "2026-07-23 15:00:00 +0100",
+		CheckoutTime: "2026-07-24 11:00:00 +0100",
+		FollowStr:    "0",
+	}
+	body, err := json.Marshal(payload)
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	app := &App{
+		disp:       dispenser,
+		lockserver: lock,
+		cfg:        &config.ConfigRec{},
+	}
+	request := httptest.NewRequest(http.MethodPost, "/issuedoorcard", bytes.NewReader(body))
+	request.Header.Set("Content-Type", "application/json")
+	recorder := httptest.NewRecorder()
+
+	app.issueDoorCard(recorder, request)
+
+	var response cmstypes.StatusRec
+	if err := json.Unmarshal(recorder.Body.Bytes(), &response); err != nil {
+		t.Fatalf("decode response %q: %v", recorder.Body.String(), err)
+	}
+	return recorder, response, app
+}
+
+func TestIssueDoorCardPhysicalOutcomeContract(t *testing.T) {
+	encodingErr := errors.New("key encoding failed")
+	tests := []struct {
+		name             string
+		dispenser        fakeDoorCardDispenser
+		lockErr          error
+		wantHTTP         int
+		wantMessage      string
+		wantCalls        []string
+		wantLockSequence int
+		wantCardWell     string
+	}{
+		{
+			name: "initial dispenser preparation failure is unavailable",
+			dispenser: fakeDoorCardDispenser{
+				prepareCurrent: dispenserCallResult{status: "Card jammed", err: errors.New("card jammed")},
+			},
+			wantHTTP:     http.StatusServiceUnavailable,
+			wantMessage:  "Dispense error: card jammed",
+			wantCalls:    []string{"prepare current"},
+			wantCardWell: "Card jammed",
+		},
+		{
+			name: "initial empty card well has stable message",
+			dispenser: fakeDoorCardDispenser{
+				prepareCurrent: dispenserCallResult{status: "Card empty", err: dispenser.ErrCardWellEmpty},
+			},
+			wantHTTP:     http.StatusServiceUnavailable,
+			wantMessage:  dispenser.CardWellEmptyMessage,
+			wantCalls:    []string{"prepare current"},
+			wantCardWell: "Card empty",
+		},
+		{
+			name:             "encoding and accepted delivery command succeed",
+			wantHTTP:         http.StatusOK,
+			wantMessage:      "Card issued successfully",
+			wantCalls:        []string{"prepare current", "deliver current", "begin prepare next"},
+			wantLockSequence: 1,
+		},
+		{
+			name: "successful encoding with delivery command failure is unavailable",
+			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"},
+			wantLockSequence: 1,
+			wantCardWell:     "Card jammed",
+		},
+		{
+			name: "failed next-card dispatch does not undo delivered card",
+			dispenser: fakeDoorCardDispenser{
+				beginNextErr: errors.New("dispatch failed"),
+			},
+			wantHTTP:         http.StatusOK,
+			wantMessage:      "Card issued successfully",
+			wantCalls:        []string{"prepare current", "deliver current", "begin prepare next"},
+			wantLockSequence: 1,
+		},
+		{
+			name:             "encoding failure with safe recovery remains retryable",
+			lockErr:          encodingErr,
+			wantHTTP:         http.StatusBadGateway,
+			wantMessage:      encodingErr.Error(),
+			wantCalls:        []string{"prepare current", "deliver current", "prepare next"},
+			wantLockSequence: 1,
+		},
+		{
+			name: "encoding failure with failed-card delivery failure is unavailable",
+			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",
+			wantCalls:        []string{"prepare current", "deliver current"},
+			wantLockSequence: 1,
+			wantCardWell:     "Card jammed",
+		},
+		{
+			name: "encoding failure with empty card well has stable message",
+			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"},
+			wantLockSequence: 1,
+			wantCardWell:     "Card empty",
+		},
+	}
+
+	for _, test := range tests {
+		t.Run(test.name, func(t *testing.T) {
+			dispenser := test.dispenser
+			lock := &fakeDoorCardLockServer{sequenceErr: test.lockErr}
+
+			recorder, response, app := performIssueDoorCardRequest(t, &dispenser, lock)
+
+			if recorder.Code != test.wantHTTP {
+				t.Fatalf("HTTP status = %d, want %d", recorder.Code, test.wantHTTP)
+			}
+			if response.Code != test.wantHTTP {
+				t.Fatalf("response code = %d, want %d", response.Code, test.wantHTTP)
+			}
+			if response.Message != test.wantMessage {
+				t.Fatalf("response message = %q, want %q", response.Message, test.wantMessage)
+			}
+			if !reflect.DeepEqual(dispenser.calls, test.wantCalls) {
+				t.Fatalf("dispenser calls = %#v, want %#v", dispenser.calls, test.wantCalls)
+			}
+			if lock.sequenceCalls != test.wantLockSequence {
+				t.Fatalf("lock sequence calls = %d, want %d", lock.sequenceCalls, test.wantLockSequence)
+			}
+			if test.wantLockSequence > 0 && lock.buildCalls != 1 {
+				t.Fatalf("build command calls = %d, want 1", lock.buildCalls)
+			}
+			if test.wantLockSequence == 0 && lock.buildCalls != 0 {
+				t.Fatalf("build command calls = %d, want 0", lock.buildCalls)
+			}
+			if got := app.CardWellStatus(); got != test.wantCardWell {
+				t.Fatalf("card-well status = %q, want %q", got, test.wantCardWell)
+			}
+		})
+	}
+}
+
+type responseTrackingRecorder struct {
+	*httptest.ResponseRecorder
+	wroteResponse bool
+}
+
+func (r *responseTrackingRecorder) WriteHeader(statusCode int) {
+	r.wroteResponse = true
+	r.ResponseRecorder.WriteHeader(statusCode)
+}
+
+func (r *responseTrackingRecorder) Write(body []byte) (int, error) {
+	r.wroteResponse = true
+	return r.ResponseRecorder.Write(body)
+}
+
+func TestIssueDoorCardDispatchesNextCardBeforeHTTP200(t *testing.T) {
+	var recorder *responseTrackingRecorder
+	dispatchCalled := false
+	dispenser := &fakeDoorCardDispenser{
+		beginNext: func() error {
+			dispatchCalled = true
+			if recorder.wroteResponse {
+				t.Error("HTTP response started before next-card preparation was dispatched")
+			}
+			return nil
+		},
+	}
+	lock := &fakeDoorCardLockServer{}
+	payload := lockserver.DoorCardRequest{
+		RoomField:    "101",
+		CheckinTime:  "2026-07-23 15:00:00 +0100",
+		CheckoutTime: "2026-07-24 11:00:00 +0100",
+	}
+	body, err := json.Marshal(payload)
+	if err != nil {
+		t.Fatal(err)
+	}
+	app := &App{disp: dispenser, lockserver: lock, cfg: &config.ConfigRec{}}
+	request := httptest.NewRequest(http.MethodPost, "/issuedoorcard", bytes.NewReader(body))
+	request.Header.Set("Content-Type", "application/json")
+	recorder = &responseTrackingRecorder{ResponseRecorder: httptest.NewRecorder()}
+
+	app.issueDoorCard(recorder, request)
+
+	if !dispatchCalled {
+		t.Fatal("next-card preparation was not dispatched")
+	}
+	if recorder.Code != http.StatusOK {
+		t.Fatalf("HTTP status = %d, want %d", recorder.Code, http.StatusOK)
+	}
+}
+
+func TestIssueDoorCardLogsNextCardDispatchFailureAndStillSucceeds(t *testing.T) {
+	var logOutput bytes.Buffer
+	standardLogger := log.StandardLogger()
+	previousOutput := standardLogger.Out
+	standardLogger.SetOutput(&logOutput)
+	t.Cleanup(func() {
+		standardLogger.SetOutput(previousOutput)
+	})
+
+	dispenser := &fakeDoorCardDispenser{beginNextErr: errors.New("dispatch failed")}
+	lock := &fakeDoorCardLockServer{}
+	recorder, _, _ := performIssueDoorCardRequest(t, dispenser, lock)
+
+	if recorder.Code != http.StatusOK {
+		t.Fatalf("HTTP status = %d, want %d", recorder.Code, http.StatusOK)
+	}
+	logged := logOutput.String()
+	if !strings.Contains(logged, "dispatch failed") ||
+		!strings.Contains(logged, "Next card preparation dispatch") {
+		t.Fatalf("dispatch failure log = %q", logged)
+	}
+}

internal/handlers/handlers.go

@@ -5,6 +5,8 @@ import (
 	"database/sql"
 	"encoding/json"
 	"encoding/xml"
+	"errors"
+	"fmt"
 	"io"
 	"net/http"
 	"strings"
@@ -25,8 +27,15 @@ import (
 	log "github.com/sirupsen/logrus"
 )
 
+type doorCardDispenser interface {
+	PrepareCurrentCard(context.Context) (string, error)
+	DeliverCurrentCard(context.Context) (string, error)
+	BeginPrepareNextCard(context.Context) error
+	PrepareNextCard(context.Context) (string, error)
+}
+
 type App struct {
-	disp               *dispenser.Client
+	disp               doorCardDispenser
 	lockserver         lockserver.LockServer
 	paymentService     *paymentsvc.Service
 	isPayment          bool
@@ -376,47 +385,69 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	// Ensure dispenser ready (card at encoder) BEFORE we attempt encoding.
-	// With queued dispenser ops, this will not clash with polling.
-	status, err := app.disp.DispenserStart(r.Context())
+	status, err := app.disp.PrepareCurrentCard(r.Context())
 	app.SetCardWellStatus(status)
 	if err != nil {
 		logging.Error(types.ServiceName, err.Error(), "Dispense error", string(op), "", "", 0)
+		if errors.Is(err, dispenser.ErrCardWellEmpty) {
+			errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
+			return
+		}
 		errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispense error: "+err.Error())
 		return
 	}
 
-	// Always attempt to finalize after we have moved a card / started an issuance flow.
-	// This guarantees we eject and prepare the next card even on lock failures.
-	finalize := func() {
-		if app.disp == nil {
-			return
-		}
-		ctx, cancel := context.WithTimeout(context.Background(), 20*time.Second)
-		defer cancel()
-
-		status, ferr := app.disp.DispenserFinal(ctx)
-		if ferr != nil {
-			logging.Error(types.ServiceName, ferr.Error(), "Dispenser final error", string(op), "", "", 0)
-			return
-		}
-		app.SetCardWellStatus(status)
-	}
-
 	// doorReq.RoomField = "104"
 	// build lock server command
 	app.lockserver.BuildCommand(doorReq, checkIn, checkOut)
 
 	// lock server sequence
-	if err := app.lockserver.LockSequence(); err != nil {
-		logging.Error(types.ServiceName, err.Error(), "Key encoding", string(op), "", "", 0)
-		finalize()
-		errorhandlers.WriteError(w, http.StatusBadGateway, err.Error())
+	encodingErr := app.lockserver.LockSequence()
+	if encodingErr != nil {
+		logging.Error(types.ServiceName, encodingErr.Error(), "Key encoding", string(op), "", "", 0)
+	}
+
+	// Once encoding has started, finish the physical dispenser sequence even if
+	// the HTTP client disconnects. Finalization remains bounded by one shared timeout.
+	finalizeCtx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
+	defer cancel()
+
+	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
 	}
 
-	// final dispenser steps
-	finalize()
+	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
+		}
+
+		errorhandlers.WriteError(w, http.StatusBadGateway, encodingErr.Error())
+		return
+	}
+
+	if preparationErr := app.disp.BeginPrepareNextCard(finalizeCtx); preparationErr != nil {
+		logging.Error(types.ServiceName, preparationErr.Error(), "Next card preparation dispatch", string(op), "", "", 0)
+	}
 
 	theResponse.Code = http.StatusOK
 	theResponse.Message = "Card issued successfully"

internal/handlers/testhandlers.go

@@ -9,10 +9,10 @@ import (
 	"time"
 
 	"gitea.futuresens.co.uk/futuresens/cmstypes"
+	"gitea.futuresens.co.uk/futuresens/hardlink/internal/creditcall"
 	"gitea.futuresens.co.uk/futuresens/hardlink/internal/errorhandlers"
 	"gitea.futuresens.co.uk/futuresens/hardlink/internal/lockserver"
 	"gitea.futuresens.co.uk/futuresens/hardlink/internal/mail"
-	"gitea.futuresens.co.uk/futuresens/hardlink/internal/creditcall"
 	"gitea.futuresens.co.uk/futuresens/hardlink/internal/types"
 	"gitea.futuresens.co.uk/futuresens/logging"
 	log "github.com/sirupsen/logrus"
@@ -59,7 +59,7 @@ func (app *App) testIssueDoorCard(w http.ResponseWriter, r *http.Request) {
 
 	// Ensure dispenser ready (card at encoder) BEFORE we attempt encoding.
 	// With queued dispenser ops, this will not clash with polling.
-	status, err := app.disp.DispenserStart(r.Context())
+	status, err := app.disp.PrepareCurrentCard(r.Context())
 	app.SetCardWellStatus(status)
 	if err != nil {
 		logging.Error(types.ServiceName, err.Error(), "Dispense error", string(op), "", "", 0)

release notes.md

@@ -2,6 +2,9 @@
 
 builtVersion is a const in main.go
 
+#### v1.3.5 - 23 July 2026
+fixed dispenser delivery confirmation
+
 #### v1.3.4 - 23 July 2026
 added support for Dojo terminal-unavailable responses