Compare commits

..

12 Commits

26 changed files with 4779 additions and 661 deletions

1
.gitignore vendored
View File

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

View File

@ -2,7 +2,7 @@
Deploy ChipDNAClientCLI, then hardlink, then Operafyne. No database or configuration
migration is needed. The existing CreditCall provider selection enables the new
sale route; CreditCall does not implement the generic payment provider interface.
SALE and PREAUTH routes; CreditCall does not implement the generic payment provider interface.
## Contracts
@ -10,6 +10,15 @@ sale route; CreditCall does not implement the generic payment provider interface
`{"amount":1234,"confirmNo":"BOOKING-123","currency":"GBP"}`. Amount remains in
minor units. CreditCall uses its existing SDK transaction reference generation.
`POST /api/payment/preauth` accepts string fields `amount`, `transactionType`
and `checkoutDate`. Positive preauth sends the existing `Sale` input and checkout
string; zero-value verification sends `{"amount":"","transactionType":"AccountVerification","checkoutDate":""}`.
The returned `ACCOUNT VERIFICATION` type is matched case-insensitively and succeeds
without persistence. Returned approved `SALE` schedules existing SQL persistence
using provider-returned `TOTAL_AMOUNT`, never the request amount. PREAUTH does not
confirm. Checkout remains departure-derived midnight UTC in the existing string
format; SQL's existing date conversion and 48-hour release calculation are unchanged.
For CreditCall, responses contain newline-delimited JSON:
```json
@ -19,7 +28,7 @@ For CreditCall, responses contain newline-delimited JSON:
`outcome` is `approved`, `declined`, `cancelled`, `timeout`, or `error`. Approval
is produced only by the shared CreditCall transaction/finalization core, including
the existing confirmation behavior. `httpStatus` preserves the equivalent legacy
SALE confirmation behavior; PREAUTH uses its existing unconfirmed-result rules. `httpStatus` preserves the equivalent legacy
operation status even after streaming commits HTTP 200. `status` preserves the
existing processor `StatusRec`. Failure `message` preserves the plain description
used by the legacy flow, including its existing interpretation quirks.
@ -31,20 +40,32 @@ continue using their existing `{"type":"result","response":...}` contract.
Hardlink calls `POST /start-transaction-stream/` on ChipDNAClientCLI with
`{"amount":"1234","transactionType":"Sale"}`. Its NDJSON consists of allowlisted
`status` frames (`source`, `value`), a single `result` containing the required SDK
fields, or a sanitized `error`. Receipt XML may be a JSON string field needed by
`status` frames (`source`, `value`), a single `result` containing allowlisted SDK
fields, or a sanitized `error`. `TRANSACTION_TYPE` and optional `TOTAL_AMOUNT`
are included only when returned by the provider. They are never synthesized and
are not added to the kiosk-facing result. AccountVerification normally omits
`TOTAL_AMOUNT`. Receipt XML may be a JSON string field needed by
hardlink's existing receipt handler; it is never a raw line in the stream.
Confirmation continues through the existing, separate XML endpoint.
SALE confirmation continues through the existing, separate XML endpoint.
## Lifetime and compatibility
- `/start-transaction/`, `/takepayment`, and `/takepreauth` retain their existing
external contracts. Preauthorization and SQL persistence/release remain legacy.
- Start and each confirmation call retain their independent 300-second timeout.
external contracts. Both SALE and PREAUTH now stream to Operafyne; existing SQL
persistence/release behavior remains unchanged.
- Operafyne uses a private 120-second CreditCall client for SALE and PREAUTH.
This is only the kiosk wait boundary; Dojo/PayBridge clients are unchanged.
Timeout/cancellation is technical, not an authoritative decline or automatically
retryable result. It never triggers a second start or legacy endpoint fallback.
- Validation uses the inbound request. At financial dispatch handoff, hardlink
detaches cancellation with `context.WithoutCancel`. Inbound cancellation and
write failures control only delivery; result processing, SALE confirmation,
receipts and PREAUTH persistence scheduling continue independently.
- Start and each SALE confirmation call retain their independent 300-second timeout.
Confirmation still uses two attempts, retrying transport/read errors with the
existing two-second delay. The generic whole-operation timeout is not used.
- Kiosk cancellation or failed/blocked kiosk delivery does not cancel upstream reading,
confirmation, or receipt handling. Progress queues may drop hints when full;
confirmation, receipt handling, or PREAUTH persistence scheduling. Progress queues may drop hints when full;
final results have a separate slot and are delivered at most once.
- Only the response writer writes frames. Transaction execution never waits
for progress delivery. No additional delivery timer or whole-operation deadline
@ -55,17 +76,20 @@ Confirmation continues through the existing, separate XML endpoint.
observational window. A supplied nonempty reference must match. The window opens
immediately before the SDK start call and closes immediately at
`TransactionFinished`; finalization never waits for card removal.
- Unidentified `CardRemovalRequested` and `CardRemovalEnforced` updates are omitted
because they can arrive after financial completion. They require a matching
explicit reference. `Removed` remains omitted even with a reference.
- `CardRemovalRequested` and `CardRemovalEnforced` follow the same active-window
rule as other progress, including when no reference is supplied. Real Miura
insertion-recovery sequences can repeat present-card and remove-card prompts
within one transaction; these repeated prompts are not deduplicated. Outside
the active window they are discarded. `Removed` remains omitted even with a
reference, and the existing `Inserted` mapping is unchanged.
- Ownership is best-effort UI observation. SDK 3.17 does not establish that every
queued reference-less non-removal callback has drained before another transaction
queued reference-less callback, including removal, has drained before another transaction
starts. Such a callback may briefly display stale progress in a later active
window. This accepted limitation must never affect success, decline, cancellation,
timeout outcomes, confirmation, retry, receipts, PMS posting, or business state.
- After timeout, an ambiguous start error, an asynchronous SDK error during an
active window, or reference reuse/overlap, progress remains suppressed for that
`Client` lifetime. New transactions, elapsed time, callbacks and automatic
`Client` lifetime across SALE and PREAUTH. New transactions, elapsed time, callbacks and automatic
reconnect do not reset the guard. Payments remain enabled.
- Only the exact synchronous `ClientNotConnectedToServer` error safely clears an
unsuppressed window and releases its unused reference: SDK 3.17 `StartCommand`
@ -88,6 +112,13 @@ with MSBuild, then run `Tests/bin/Debug/ChipDNAClient.StreamingTests.exe`. The
test executable links the production streaming code and needs no terminal.
In Operafyne, run `go test -count=1 ./...`; the service tests cover structured
CreditCall sales, unchanged preauth requests, failure/retry parity, and existing
CreditCall SALE/PREAUTH, unchanged legacy requests, the 120-second UX boundary,
cancellation after dispatch, failure/retry parity, and existing
Dojo/PayBridge response handling. Run `go vet ./...`, `go build ./...`, and
`git diff --check` in both Go repositories.
Physical account-verification testing confirmed approved `ACCOUNT VERIFICATION`
with no `TOTAL_AMOUNT`. A monetary `/takepayment` test confirmed returned minor
units; positive PREAUTH through the new transport still needs physical Miura
validation. Automated tests do not replace that check. Receipt fields such as
`NoChargeDeclaration` retain the existing provider-entry rendering behavior.

View File

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

View File

@ -125,6 +125,15 @@ func BuildPaymentRedirectURL(result map[string]string) string {
}
func BuildPreauthRedirectURL(result map[string]string) (string, bool) {
approved, persist := PreauthDecision(result)
if approved {
return BuildSuccessURL(result), persist
}
return BuildFailureURL(result[types.TransactionResult], result[types.Errors]), false
}
// PreauthDecision preserves the returned-type approval and persistence rules.
func PreauthDecision(result map[string]string) (approved, persist bool) {
res := result[types.TransactionResult]
tType := result[types.TransactionType]
@ -136,7 +145,7 @@ func BuildPreauthRedirectURL(result map[string]string) (string, bool) {
log.WithField(types.LogResult, result[types.TransactionResult]).
Info("Account verification approved")
return BuildSuccessURL(result), false
return true, false
// Transaction type Sale?
case strings.EqualFold(tType, types.SaleTransactionType):
@ -144,12 +153,12 @@ func BuildPreauthRedirectURL(result map[string]string) (string, bool) {
log.WithField(types.LogResult, result[types.ConfirmResult]).
Info("Amount preauthorized successfully")
return BuildSuccessURL(result), true
return true, true
}
}
// Not approved
return BuildFailureURL(res, result[types.Errors]), false
return false, false
}
func BuildSuccessURL(result map[string]string) string {

View File

@ -0,0 +1,35 @@
package creditcall
import (
"strings"
"testing"
"gitea.futuresens.co.uk/futuresens/hardlink/internal/types"
)
func TestPreauthLegacyDecision(t *testing.T) {
for _, tc := range []struct {
name, result, kind string
approved, save bool
}{
{"sale", "APPROVED", "SALE", true, true},
{"verification", "APPROVED", "ACCOUNT VERIFICATION", true, false},
{"mixed case", "Approved", "Account Verification", true, false},
{"request spelling is not result spelling", "APPROVED", "AccountVerification", false, false},
{"missing type", "APPROVED", "", false, false},
{"declined sale", "DECLINED", "SALE", false, false},
{"declined verification", "DECLINED", "ACCOUNT VERIFICATION", false, false},
{"missing result", "", "SALE", false, false},
} {
t.Run(tc.name, func(t *testing.T) {
fields := map[string]string{types.TransactionResult: tc.result, types.TransactionType: tc.kind, types.Errors: "provider detail"}
redirect, save := BuildPreauthRedirectURL(fields)
if strings.HasPrefix(redirect, "/successful?") != tc.approved || save != tc.save {
t.Errorf("BuildPreauthRedirectURL(%v) = %q,%t, want approved=%t save=%t", fields, redirect, save, tc.approved, tc.save)
}
if _, ok := fields[types.TotalAmount]; ok {
t.Error("BuildPreauthRedirectURL fabricated TOTAL_AMOUNT")
}
})
}
}

View File

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

View File

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

View File

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

View File

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

View File

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

View File

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

View File

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

View 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)
}
}
}

View File

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

View File

@ -0,0 +1,53 @@
package handlers
import (
"context"
"net/http"
"gitea.futuresens.co.uk/futuresens/cmstypes"
"gitea.futuresens.co.uk/futuresens/hardlink/internal/creditcall"
"gitea.futuresens.co.uk/futuresens/hardlink/internal/types"
"gitea.futuresens.co.uk/futuresens/logging"
)
type creditCallPreauthRequest struct {
Amount string `json:"amount"`
TransactionType string `json:"transactionType"`
CheckoutDate string `json:"checkoutDate"`
}
func (app *App) streamCreditCallPreauth(w http.ResponseWriter, r *http.Request) {
app.streamCreditCall(w, r, true)
}
// executeCreditCallPreauth finalizes the existing unconfirmed transaction.
// The outcome container and its wire projections are shared with SALE; its execution is not.
func (app *App) executeCreditCallPreauth(ctx context.Context, request cmstypes.TransactionRec,
start func(*http.Client) (creditcall.TransactionResultXML, error)) creditCallSaleOutcome {
const op = logging.Op("takePreauthorization")
outcome := creditCallSaleOutcome{
HTTPStatus: http.StatusBadGateway,
Status: cmstypes.StatusRec{Code: http.StatusInternalServerError, Message: "500 Internal server error"},
}
transaction, err := start(app.creditCallClient())
if err != nil {
logging.Error(types.ServiceName, err.Error(), "Preauth processing error", string(op), "", "", 0)
outcome.FailureType = types.ResultError
outcome.FailureDescription = "No response from payment processor"
return outcome
}
var result creditcall.PaymentResult
result.FillFromTransactionResult(transaction)
app.printCreditCallReceipt(result.CardholderReceipt)
approved, persist := creditcall.PreauthDecision(result.Fields)
outcome.HTTPStatus = http.StatusOK
outcome.Status = result.Status
outcome.Payment = result
outcome.Approved = approved
outcome.FailureType = result.Fields[types.TransactionResult]
outcome.FailureDescription = result.Fields[types.Errors]
if persist {
go app.persistPreauth(ctx, result.Fields, request.CheckoutDate)
}
return outcome
}

View File

@ -0,0 +1,393 @@
package handlers
import (
"context"
"database/sql"
"database/sql/driver"
"encoding/json"
"encoding/xml"
"errors"
"io"
"net/http"
"net/http/httptest"
"os"
"reflect"
"strings"
"sync/atomic"
"testing"
"time"
"gitea.futuresens.co.uk/futuresens/cmstypes"
"gitea.futuresens.co.uk/futuresens/hardlink/internal/types"
"gitea.futuresens.co.uk/futuresens/hardlink/paymentstatus"
)
type preauthTestConnector struct {
inserts chan []driver.NamedValue
count atomic.Int32
}
func (c *preauthTestConnector) Connect(context.Context) (driver.Conn, error) {
return &preauthTestConn{c}, nil
}
func (c *preauthTestConnector) Driver() driver.Driver { return preauthTestDriver{c} }
type preauthTestDriver struct{ c *preauthTestConnector }
func (d preauthTestDriver) Open(string) (driver.Conn, error) { return &preauthTestConn{d.c}, nil }
type preauthTestConn struct{ c *preauthTestConnector }
func (*preauthTestConn) Prepare(string) (driver.Stmt, error) {
return nil, errors.New("unexpected prepare")
}
func (*preauthTestConn) Close() error { return nil }
func (*preauthTestConn) Begin() (driver.Tx, error) { return nil, errors.New("unexpected begin") }
func (*preauthTestConn) Ping(context.Context) error { return nil }
func (c *preauthTestConn) ExecContext(ctx context.Context, query string, args []driver.NamedValue) (driver.Result, error) {
if ctx.Err() != nil {
return nil, ctx.Err()
}
if !strings.Contains(query, "INSERT INTO dbo.Preauthorizations") {
return nil, errors.New("unexpected SQL")
}
c.c.count.Add(1)
c.c.inserts <- append([]driver.NamedValue(nil), args...)
return driver.RowsAffected(1), nil
}
func preauthTestDatabase(t *testing.T, app *App) *preauthTestConnector {
t.Helper()
c := &preauthTestConnector{inserts: make(chan []driver.NamedValue, 4)}
app.db = sql.OpenDB(c)
app.cfg.LogDir = t.TempDir()
t.Cleanup(func() { app.db.Close() })
return c
}
func waitPreauthInsert(t *testing.T, c *preauthTestConnector) map[string]any {
t.Helper()
select {
case args := <-c.inserts:
result := map[string]any{}
for _, arg := range args {
result[arg.Name] = arg.Value
}
return result
case <-time.After(3 * time.Second):
t.Fatal("preauth persistence did not reach SQL")
}
return nil
}
func preauthLegacyRequest(amount, kind, checkout string) *http.Request {
body, _ := xml.Marshal(cmstypes.TransactionRec{AmountMinorUnits: amount, TransactionType: kind, CheckoutDate: checkout})
r := httptest.NewRequest(http.MethodPost, "/takepreauth", strings.NewReader(string(body)))
r.Header.Set("Content-Type", "text/xml")
return r
}
func TestCreditCallPreauthLegacyCharacterization(t *testing.T) {
for _, tc := range []struct {
name, amount, requestType, result, resultType, total string
save, approved bool
}{
{"positive", "12000", "Sale", "APPROVED", "SALE", "3100", true, true},
{"declined", "12000", "Sale", "DECLINED", "SALE", "", false, false},
{"verification", "", "AccountVerification", "APPROVED", "ACCOUNT VERIFICATION", "", false, true},
{"verification failure", "", "AccountVerification", "DECLINED", "ACCOUNT VERIFICATION", "", false, false},
{"unexpected type", "12000", "Sale", "APPROVED", "Refund", "", false, false},
} {
t.Run(tc.name, func(t *testing.T) {
var starts, prints int
checkout := ""
if tc.amount != "" {
checkout = "2026-09-11 00:00:00 +0000"
}
fields := map[string]string{types.TransactionResult: tc.result, types.TransactionType: tc.resultType, types.Reference: "preauth-ref", types.PanMasked: "************1133", types.CardType: "Visa", types.ExpiryDate: "1228", types.CardHash: "card-hash", types.CardReference: "card-reference", types.ReceiptDataCardholder: "receipt"}
if tc.total != "" {
fields[types.TotalAmount] = tc.total
}
app := newCreditCallTestApp(t, func(w http.ResponseWriter, r *http.Request) {
starts++
if r.URL.Path != "/start-transaction/" {
t.Errorf("PREAUTH upstream path=%s, want start only", r.URL.Path)
}
var input cmstypes.TransactionRec
if err := xml.NewDecoder(r.Body).Decode(&input); err != nil {
t.Error(err)
}
if input.AmountMinorUnits != tc.amount || input.TransactionType != tc.requestType || input.CheckoutDate != checkout {
t.Errorf("PREAUTH input=%+v, want amount=%q type=%q checkout=%q", input, tc.amount, tc.requestType, checkout)
}
// Legacy ignores upstream HTTP status when XML contains a result.
w.WriteHeader(http.StatusBadGateway)
io.WriteString(w, chipDNAFixture(t, fields))
})
c := preauthTestDatabase(t, app)
app.creditCallReceipt = func(receipt string) {
prints++
if receipt != "receipt" {
t.Errorf("receipt=%q, want receipt", receipt)
}
}
recorder := httptest.NewRecorder()
app.takePreauthorization(recorder, preauthLegacyRequest(tc.amount, tc.requestType, checkout))
var response cmstypes.ResponseRec
if err := json.Unmarshal(recorder.Body.Bytes(), &response); err != nil {
t.Fatal(err)
}
if recorder.Code != 200 || response.Status.Code != 200 || starts != 1 || prints != 1 || strings.HasPrefix(response.Data, "/successful?") != tc.approved {
t.Errorf("PREAUTH response=%+v HTTP=%d starts=%d prints=%d, want approved=%t one start/receipt", response, recorder.Code, starts, prints, tc.approved)
}
if tc.save {
got := waitPreauthInsert(t, c)
if got["TotalMinorUnits"] != "3100" || got["TxnReference"] != "preauth-ref" {
t.Errorf("persisted=%v, want provider amount/reference", got)
}
departure := time.Date(2026, 9, 11, 0, 0, 0, 0, time.Local).UTC()
if got["DepartureDate"] != departure || got["ReleaseDate"] != departure.Add(48*time.Hour) {
t.Errorf("persisted dates=%v, want existing local midnight plus 48 hours", got)
}
} else if c.count.Load() != 0 {
t.Error("non-persisting result inserted SQL")
}
})
}
}
func preauthStreamRequest(amount, kind, checkout string) *http.Request {
body, _ := json.Marshal(creditCallPreauthRequest{Amount: amount, TransactionType: kind, CheckoutDate: checkout})
r := httptest.NewRequest(http.MethodPost, "/api/payment/preauth", strings.NewReader(string(body)))
r.Header.Set("Content-Type", "application/json")
return r
}
func TestCreditCallPreauthStreamingParity(t *testing.T) {
for _, tc := range []struct {
name, result, kind, total string
approved, persist bool
}{
{"monetary", "APPROVED", "SALE", "3100", true, true},
{"verification", "APPROVED", "ACCOUNT VERIFICATION", "", true, false},
{"declined", "DECLINED", "SALE", "", false, false},
{"verification failed", "DECLINED", "ACCOUNT VERIFICATION", "", false, false},
{"unknown approved type", "APPROVED", "AccountVerification", "", false, false},
} {
t.Run(tc.name, func(t *testing.T) {
fields := map[string]string{types.TransactionResult: tc.result, types.TransactionType: tc.kind, types.Reference: "preauth-ref", types.PanMasked: "************1133", types.CardType: "Visa", types.ExpiryDate: "1228", types.CardHash: "hash", types.CardReference: "cardref", types.ReceiptDataCardholder: "receipt"}
if tc.total != "" {
fields[types.TotalAmount] = tc.total
}
amount, kind, date := "12000", "Sale", "2026-09-11 00:00:00 +0000"
if strings.Contains(tc.name, "verification") {
amount, kind, date = "", "AccountVerification", ""
}
var legacy cmstypes.ResponseRec
for _, stream := range []bool{false, true} {
calls, prints := 0, 0
app := newCreditCallTestApp(t, func(w http.ResponseWriter, r *http.Request) {
calls++
if stream {
if r.URL.Path != "/start-transaction-stream/" {
t.Errorf("stream called %s, want one generic start", r.URL.Path)
}
var input creditCallPreauthRequest
if err := json.NewDecoder(r.Body).Decode(&input); err != nil {
t.Error(err)
}
if input.Amount != amount || input.TransactionType != kind {
t.Errorf("upstream input=%+v, want %q/%q", input, amount, kind)
}
for _, event := range []struct{ source, value string }{{"UPDATE", "CardRequested"}, {"CARD_STATUS", "Inserted"}, {"UPDATE", "CardRemovalRequested"}, {"CARD_STATUS", "Removed"}, {"UPDATE", "CardRequested"}, {"UPDATE", "CardRemovalEnforced"}, {"UPDATE", "PinEntryStarted"}, {"UPDATE", "OnlineAuthCompleted"}} {
json.NewEncoder(w).Encode(map[string]any{"type": "status", "source": event.source, "value": event.value})
}
json.NewEncoder(w).Encode(map[string]any{"type": "result", "result": fields})
json.NewEncoder(w).Encode(map[string]any{"type": "result", "result": fields})
} else {
io.WriteString(w, chipDNAFixture(t, fields))
}
})
c := preauthTestDatabase(t, app)
app.creditCallReceipt = func(receipt string) {
prints++
if receipt != "receipt" {
t.Errorf("receipt=%q, want retained receipt", receipt)
}
}
recorder := httptest.NewRecorder()
if stream {
app.streamCreditCallPreauth(recorder, preauthStreamRequest(amount, kind, date))
frames := decodePaymentStream(t, recorder.Body)
var statuses []string
for _, frame := range frames {
if frame.Type == "status" {
statuses = append(statuses, frame.Code)
}
}
want := []string{paymentstatus.PresentCard, paymentstatus.DoNotRemoveCard, paymentstatus.RemoveCard, paymentstatus.PresentCard, paymentstatus.RemoveCard, paymentstatus.EnterPIN, paymentstatus.PleaseWait}
if !reflect.DeepEqual(statuses, want) {
t.Errorf("preauth statuses=%v, want %v", statuses, want)
}
final := frames[len(frames)-1].Result
if final == nil {
t.Fatal("missing structured final")
}
if (final.Outcome == "approved") != tc.approved || final.Status != legacy.Status || final.HTTPStatus != 200 {
t.Errorf("stream final=%+v, legacy=%+v", final, legacy)
}
if tc.approved && (final.TransactionReference != "preauth-ref" || final.CardType != "Visa" || final.MaskedCardNumber != "************1133" || final.ExpiryDate != "1228" || final.CardHash != "hash" || final.CardReference != "cardref") {
t.Errorf("preauth fields lost: %+v", final)
}
if len(frames) != len(want)+1 {
t.Errorf("frames=%d, want one final", len(frames))
}
} else {
app.takePreauthorization(recorder, preauthLegacyRequest(amount, kind, date))
if err := json.Unmarshal(recorder.Body.Bytes(), &legacy); err != nil {
t.Fatal(err)
}
}
if calls != 1 || prints != 1 {
t.Errorf("calls/prints=%d/%d, want 1/1", calls, prints)
}
if tc.persist {
got := waitPreauthInsert(t, c)
if got["TotalMinorUnits"] != tc.total {
t.Errorf("SQL amount=%v, want provider %q", got["TotalMinorUnits"], tc.total)
}
} else if c.count.Load() != 0 {
t.Error("verification/failure persisted")
}
}
})
}
}
func TestCreditCallInboundCancellationAfterDispatch(t *testing.T) {
for _, preauth := range []bool{false, true} {
t.Run(map[bool]string{false: "sale", true: "preauth"}[preauth], func(t *testing.T) {
dispatched := make(chan struct{})
release := make(chan struct{})
var starts, confirms, receipts atomic.Int32
app := newCreditCallTestApp(t, func(w http.ResponseWriter, r *http.Request) {
if r.URL.Path == "/confirm-transaction/" {
confirms.Add(1)
io.WriteString(w, chipDNAFixture(t, map[string]string{types.TransactionResult: "APPROVED", types.ReceiptDataCardholder: "receipt"}))
return
}
starts.Add(1)
close(dispatched)
<-release
if r.Context().Err() != nil {
t.Errorf("financial upstream was cancelled: %v", r.Context().Err())
return
}
json.NewEncoder(w).Encode(map[string]any{"type": "result", "result": map[string]string{types.TransactionResult: "APPROVED", types.TransactionType: "SALE", types.TotalAmount: "3100", types.Reference: "delayed-ref", types.ReceiptDataCardholder: "receipt"}})
})
c := preauthTestDatabase(t, app)
app.creditCallReceipt = func(receipt string) {
if receipt != "receipt" {
t.Errorf("receipt=%q", receipt)
}
receipts.Add(1)
}
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
recorder := httptest.NewRecorder()
done := make(chan struct{})
go func() {
defer close(done)
if preauth {
app.streamCreditCallPreauth(recorder, preauthStreamRequest("12000", "Sale", "2026-09-11 00:00:00 +0000").WithContext(ctx))
} else {
app.streamCreditCallSale(recorder, saleRequest(true).WithContext(ctx))
}
}()
select {
case <-dispatched:
case <-time.After(3 * time.Second):
close(release)
t.Fatal("no upstream dispatch")
}
cancel() // Exact acceptance boundary: upstream has observed StartTransaction.
close(release)
select {
case <-done:
case <-time.After(3 * time.Second):
t.Fatal("cancelled inbound request stopped finalization")
}
wantConfirms := int32(1)
if preauth {
wantConfirms = 0
got := waitPreauthInsert(t, c)
if got["TotalMinorUnits"] != "3100" {
t.Errorf("delayed persistence=%v", got)
}
if c.count.Load() != 1 {
t.Errorf("delayed persistence count=%d, want exactly one", c.count.Load())
}
}
if starts.Load() != 1 || receipts.Load() != 1 || confirms.Load() != wantConfirms {
t.Errorf("starts/receipts/confirms=%d/%d/%d, want 1/1/%d", starts.Load(), receipts.Load(), confirms.Load(), wantConfirms)
}
if recorder.Body.Len() != 0 {
t.Errorf("cancelled delivery wrote %s", recorder.Body.String())
}
})
}
}
func TestCreditCallPreauthMissingAmountNeverSynthesized(t *testing.T) {
app := newCreditCallTestApp(t, func(w http.ResponseWriter, r *http.Request) {
json.NewEncoder(w).Encode(map[string]any{"type": "result", "result": map[string]string{types.TransactionResult: "APPROVED", types.TransactionType: "SALE", types.Reference: "missing-amount"}})
})
c := preauthTestDatabase(t, app)
app.creditCallReceipt = func(string) {}
recorder := httptest.NewRecorder()
app.streamCreditCallPreauth(recorder, preauthStreamRequest("9999", "Sale", "2026-09-11 00:00:00 +0000"))
frames := decodePaymentStream(t, recorder.Body)
if frames[0].Result.Outcome != "approved" {
t.Fatalf("missing amount changed approval: %+v", frames[0].Result)
}
deadline := time.Now().Add(3 * time.Second)
for {
data, err := os.ReadFile(app.spoolPath())
var record preauthSpoolRecord
if err == nil && json.Unmarshal(data, &record) == nil {
if _, ok := record.Fields[types.TotalAmount]; ok {
t.Errorf("spool fabricated amount: %v", record.Fields)
}
if record.CheckoutDate != "2026-09-11 00:00:00 +0000" {
t.Errorf("spool checkout=%q", record.CheckoutDate)
}
break
}
if time.Now().After(deadline) {
t.Fatal("missing provider amount did not retain existing spool fallback")
}
time.Sleep(time.Millisecond)
}
if c.count.Load() != 0 {
t.Error("SQL inserted fabricated amount")
}
}
func TestCreditCallPreauthStreamFailureAndCancelledBeforeDispatch(t *testing.T) {
for _, body := range []string{"", "{", "{}\n", "<xml/>\n", "{\"type\":\"result\",\"result\":{}}\n", "{\"type\":\"result\",\"result\":{\"TRANSACTION_RESULT\":\"APPROVED\"}}"} {
app := newCreditCallTestApp(t, func(w http.ResponseWriter, r *http.Request) { io.WriteString(w, body) })
calls := 0
transport := app.creditCallTransport
app.creditCallTransport = creditCallRoundTrip(func(r *http.Request) (*http.Response, error) { calls++; return transport.RoundTrip(r) })
app.creditCallReceipt = func(string) { t.Error("malformed stream printed receipt") }
recorder := httptest.NewRecorder()
app.streamCreditCallPreauth(recorder, preauthStreamRequest("", "AccountVerification", ""))
frames := decodePaymentStream(t, recorder.Body)
if calls != 1 || len(frames) != 1 || frames[0].Result.Outcome != "error" || frames[0].Result.HTTPStatus != 502 {
t.Errorf("invalid stream %q: calls=%d frames=%+v", body, calls, frames)
}
ctx, cancel := context.WithCancel(context.Background())
cancel()
app.streamCreditCallPreauth(httptest.NewRecorder(), preauthStreamRequest("", "AccountVerification", "").WithContext(ctx))
if calls != 1 {
t.Error("already-cancelled request dispatched a transaction")
}
}
}

View File

@ -63,6 +63,10 @@ func (outcome creditCallSaleOutcome) streamResult() creditCallStreamResult {
func (app *App) EnableCreditCallStreaming() { app.creditCallStreamEnabled = true }
func (app *App) streamCreditCallSale(w http.ResponseWriter, r *http.Request) {
app.streamCreditCall(w, r, false)
}
func (app *App) streamCreditCall(w http.ResponseWriter, r *http.Request, preauth bool) {
setPaymentCORS(w)
if r.Method == http.MethodOptions {
w.WriteHeader(http.StatusNoContent)
@ -97,6 +101,10 @@ func (app *App) streamCreditCallSale(w http.ResponseWriter, r *http.Request) {
w.WriteHeader(status)
send(paymentStreamMessage{Type: "result", Result: &result})
}
if preauth && !app.creditCallStreamEnabled {
reject(http.StatusServiceUnavailable, "CreditCall preauthorization streaming is not enabled")
return
}
if !app.isPayment && !app.cfg.TestMode {
mail.SendEmailOnError(app.cfg.Hotel, app.cfg.Kiosk, "Payment Error", "Attempted payment while payment processing is disabled")
reject(http.StatusServiceUnavailable, "Payment processing is disabled")
@ -111,6 +119,15 @@ func (app *App) streamCreditCallSale(w http.ResponseWriter, r *http.Request) {
return
}
defer r.Body.Close()
var transaction cmstypes.TransactionRec
if preauth {
var request creditCallPreauthRequest
if err := json.NewDecoder(r.Body).Decode(&request); err != nil {
reject(http.StatusBadRequest, "Invalid JSON payload")
return
}
transaction = cmstypes.TransactionRec{AmountMinorUnits: request.Amount, TransactionType: request.TransactionType, CheckoutDate: request.CheckoutDate}
} else {
var request SalePaymentRequest
if err := json.NewDecoder(r.Body).Decode(&request); err != nil {
reject(http.StatusBadRequest, "Invalid JSON payload")
@ -120,24 +137,35 @@ func (app *App) streamCreditCallSale(w http.ResponseWriter, r *http.Request) {
reject(http.StatusBadRequest, "Amount must be greater than zero")
return
}
transaction = cmstypes.TransactionRec{AmountMinorUnits: strconv.FormatInt(request.Amount, 10), TransactionType: "Sale"}
}
if _, ok := w.(http.Flusher); !ok {
reject(http.StatusInternalServerError, "Streaming payment updates are not supported")
return
}
// Validation belongs to the incoming request. This handoff owns financial dispatch.
if r.Context().Err() != nil {
return
}
financialContext := context.WithoutCancel(r.Context())
progress := make(chan string, 128)
finished := make(chan creditCallSaleOutcome, 1)
go func() {
outcome := app.executeCreditCallSale(cmstypes.TransactionRec{
AmountMinorUnits: strconv.FormatInt(request.Amount, 10), TransactionType: "Sale",
}, func(client *http.Client) (creditcall.TransactionResultXML, error) {
return callChipDNAStream(client, request.Amount, func(code string) {
start := func(client *http.Client) (creditcall.TransactionResultXML, error) {
return callChipDNATransactionStream(financialContext, client, transaction, func(code string) {
select {
case progress <- code:
default: // Observational progress may be dropped under backpressure.
}
})
})
}
var outcome creditCallSaleOutcome
if preauth {
outcome = app.executeCreditCallPreauth(financialContext, transaction, start)
} else {
outcome = app.executeCreditCallSale(transaction, start)
}
close(progress)
finished <- outcome // Independent of the bounded progress queue.
}()
@ -163,16 +191,22 @@ func (app *App) streamCreditCallSale(w http.ResponseWriter, r *http.Request) {
}
func callChipDNAStream(client *http.Client, amount int64, onStatus func(string)) (creditcall.TransactionResultXML, error) {
return callChipDNATransactionStream(context.Background(), client, cmstypes.TransactionRec{
AmountMinorUnits: strconv.FormatInt(amount, 10), TransactionType: "Sale",
}, onStatus)
}
func callChipDNATransactionStream(ctx context.Context, client *http.Client, transaction cmstypes.TransactionRec, onStatus func(string)) (creditcall.TransactionResultXML, error) {
var result creditcall.TransactionResultXML
payload, err := json.Marshal(struct {
Amount string `json:"amount"`
TransactionType string `json:"transactionType"`
}{strconv.FormatInt(amount, 10), "Sale"})
}{transaction.AmountMinorUnits, transaction.TransactionType})
if err != nil {
return result, err
}
// Background plus Client.Timeout reproduces the independent per-call bound.
req, err := http.NewRequestWithContext(context.Background(), http.MethodPost, types.LinkStartTransactionStream, bytes.NewReader(payload))
// Dispatch owns ctx; Client.Timeout retains the independent 300-second call bound.
req, err := http.NewRequestWithContext(ctx, http.MethodPost, types.LinkStartTransactionStream, bytes.NewReader(payload))
if err != nil {
return result, err
}

View File

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

View File

@ -6,7 +6,6 @@ import (
"encoding/json"
"encoding/xml"
"errors"
"fmt"
"io"
"net/http"
"strings"
@ -28,6 +27,7 @@ import (
)
type doorCardDispenser interface {
BeginForeground() func()
PrepareCurrentCard(context.Context) (string, error)
DeliverCurrentCard(context.Context) (string, error)
BeginPrepareNextCard(context.Context) error
@ -78,6 +78,7 @@ func (app *App) RegisterRoutes(mux *http.ServeMux) {
mux.HandleFunc("/ping-pdq", app.fetchChipDNAStatus)
mux.HandleFunc("/logerror", app.onChipDNAError)
mux.HandleFunc("/api/payment/sale", app.salePayment)
mux.HandleFunc("/api/payment/preauth", app.streamCreditCallPreauth)
}
func (app *App) takePreauthorization(w http.ResponseWriter, r *http.Request) {
@ -86,9 +87,6 @@ func (app *App) takePreauthorization(w http.ResponseWriter, r *http.Request) {
var (
theResponse cmstypes.ResponseRec
theRequest cmstypes.TransactionRec
trResult creditcall.TransactionResultXML
result creditcall.PaymentResult
save bool
)
theResponse.Status.Code = http.StatusInternalServerError
@ -149,39 +147,18 @@ func (app *App) takePreauthorization(w http.ResponseWriter, r *http.Request) {
theRequest.TransactionType,
)
client := app.creditCallClient()
// ---- START TRANSACTION ----
body, err = callChipDNA(client, types.LinkStartTransaction, body)
outcome := app.executeCreditCallPreauth(context.Background(), theRequest, func(client *http.Client) (creditcall.TransactionResultXML, error) {
var transaction creditcall.TransactionResultXML
response, err := callChipDNA(client, types.LinkStartTransaction, body)
if err != nil {
logging.Error(types.ServiceName, err.Error(), "Preauth processing error", string(op), "", "", 0)
theResponse.Data = creditcall.BuildFailureURL(types.ResultError, "No response from payment processor")
writeTransactionResult(w, http.StatusBadGateway, theResponse)
return
return transaction, err
}
if err := trResult.ParseTransactionResult(body); err != nil {
if err := transaction.ParseTransactionResult(response); err != nil {
logging.Error(types.ServiceName, err.Error(), "Parse transaction result error", string(op), "", "", 0)
}
result.FillFromTransactionResult(trResult)
// ---- PRINT RECEIPT ----
app.printCreditCallReceipt(result.CardholderReceipt)
// ---- REDIRECT ----
theResponse.Status = result.Status
theResponse.Data, save = creditcall.BuildPreauthRedirectURL(result.Fields)
if save {
go app.persistPreauth(context.Background(), result.Fields, theRequest.CheckoutDate)
}
writeTransactionResult(w, http.StatusOK, theResponse)
return transaction, nil
})
writeTransactionResult(w, outcome.HTTPStatus, outcome.legacyResponse())
}
func (app *App) takePayment(w http.ResponseWriter, r *http.Request) {
@ -314,6 +291,9 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
return
}
release := app.disp.BeginForeground()
defer release()
status, err := app.disp.PrepareCurrentCard(r.Context())
app.SetCardWellStatus(status)
if err != nil {
@ -322,7 +302,11 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
return
}
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispense error: "+err.Error())
if errors.Is(err, dispenser.ErrPreparationExhausted) {
errorhandlers.WriteError(w, http.StatusBadGateway, err.Error())
return
}
errorhandlers.WriteError(w, http.StatusBadGateway, "Dispense error: "+err.Error())
return
}
@ -330,8 +314,11 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
// build lock server command
app.lockserver.BuildCommand(doorReq, checkIn, checkOut)
// lock server sequence
// Each request performs at most one encoder operation.
encodingStarted := time.Now()
log.Info("LockSequence started")
encodingErr := app.lockserver.LockSequence()
log.Infof("LockSequence finished; success=%t duration=%s", encodingErr == nil, time.Since(encodingStarted))
if encodingErr != nil {
logging.Error(types.ServiceName, encodingErr.Error(), "Key encoding", string(op), "", "", 0)
}
@ -344,32 +331,10 @@ func (app *App) issueDoorCard(w http.ResponseWriter, r *http.Request) {
status, deliveryErr := app.disp.DeliverCurrentCard(finalizeCtx)
app.SetCardWellStatus(status)
if deliveryErr != nil {
if encodingErr != nil {
recoveryErr := fmt.Errorf("key encoding failed: %v; dispenser recovery failed: %w", encodingErr, deliveryErr)
logging.Error(types.ServiceName, recoveryErr.Error(), "Dispenser recovery", string(op), "", "", 0)
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispenser recovery failed; another encoding attempt is not safe")
return
}
logging.Error(types.ServiceName, deliveryErr.Error(), "Card delivery", string(op), "", "", 0)
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Card delivery could not be confirmed")
return
}
if encodingErr != nil {
status, preparationErr := app.disp.PrepareNextCard(finalizeCtx)
app.SetCardWellStatus(status)
if preparationErr != nil {
recoveryErr := fmt.Errorf("key encoding failed: %v; dispenser recovery failed: %w", encodingErr, preparationErr)
logging.Error(types.ServiceName, recoveryErr.Error(), "Dispenser recovery", string(op), "", "", 0)
if errors.Is(preparationErr, dispenser.ErrCardWellEmpty) {
errorhandlers.WriteError(w, http.StatusServiceUnavailable, dispenser.CardWellEmptyMessage)
return
}
errorhandlers.WriteError(w, http.StatusServiceUnavailable, "Dispenser recovery failed; another encoding attempt is not safe")
return
}
// FC0 is attempted once; the next UI request owns all further preparation.
errorhandlers.WriteError(w, http.StatusBadGateway, encodingErr.Error())
return
}

View File

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

View File

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

View File

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

View File

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

View File

@ -245,95 +245,174 @@ func printCardholderReceipt(cardholderReceipt string) error {
return nil
}
// receiptColumns follows the existing 44-column normal-size text convention.
const receiptColumns = 44
func BuildCardholderReceipt(entries []ReceiptEntryXML) ([]byte, error) {
var buf bytes.Buffer
rendered := make([]bool, len(entries))
take := func(id string) string {
for i, entry := range entries {
if !rendered[i] && entry.ReceiptEntryId == id && entry.Value != "" {
rendered[i] = true
return receiptEntryText(entry)
}
}
return ""
}
write := func(b []byte) { buf.Write(b) }
// writeStr := func(s string) { buf.WriteString(s) }
writeln := func(s string) {
buf.WriteString(s)
// Set and restore only text state; leave printer setup and transport alone.
normal := func() { buf.Write([]byte{ESC, 'a', 0, ESC, 'E', BOLD_OFF, GS, '!', NORMAL_FONT}) }
normal()
hasRows, newSection := false, false
beginLine := func(center bool) {
if hasRows && newSection {
buf.WriteString(strings.Repeat("-", receiptColumns) + "\n")
}
hasRows, newSection = true, false
if center {
buf.Write([]byte{ESC, 'a', CENTER})
}
}
text := func(value string, bold bool) {
if bold {
buf.Write([]byte{ESC, 'E', BOLD_ON})
}
buf.WriteString(value)
if bold {
buf.Write([]byte{ESC, 'E', BOLD_OFF})
}
}
line := func(value string, bold, center bool) {
if value == "" {
return
}
beginLine(center)
text(value, bold)
buf.WriteByte('\n')
normal()
}
pair := func(left, right string, boldRight bool) {
if gap, fits := receiptPairGap(left, right); fits {
beginLine(false)
text(left+gap, false)
text(right, boldRight)
buf.WriteByte('\n')
normal()
return
}
line(left, false, false)
line(right, boldRight, false)
}
// Build a lookup map by ReceiptEntryId
m := make(map[string]ReceiptEntryXML, len(entries))
for _, e := range entries {
m[e.ReceiptEntryId] = e
line(take("Recipient"), true, true)
line(take("MerchantName"), false, true)
newSection = true
line(take("CardScheme"), false, false)
line(take("PanMasked"), false, false)
pair(take("Aid"), take("PanSequence"), false)
pair(take("TransactionSource"), take("TransactionType"), false)
newSection = true
// Align the provider amount without parsing or modifying its value.
for i, entry := range entries {
if entry.ReceiptEntryId == "TotalAmount" && entry.Value != "" {
rendered[i] = true
label := entry.Label
if label == "" {
label = "TOTAL"
}
// Utility to center text
// center := func(s string) {
// write([]byte{ESC, 'a', CENTER})
// writeln(s)
// write([]byte{ESC, 'a', 0})
// }
// Utility for bold lines
// boldOn := func() { write([]byte{GS, '!', WIDER_FONT}) }
// boldOff := func() { write([]byte{GS, '!', NORMAL_FONT}) }
// boldOn()
// 1) Header: CARDHOLDER COPY
writeln(m["Recipient"].Value)
// writeStr("\n\n")
// 2) Merchant name
writeln(m["MerchantName"].Value)
// writeStr("\n\n")
// 3) AID
writeln("AID: " + m["Aid"].Value)
// 4) Card scheme & pan
writeln(fmt.Sprintf("%s Card: %s", m["CardScheme"].Value, m["PanMasked"].Value))
// 5) PAN Seq No
writeln("PAN Seq No: " + m["PanSequence"].Value)
// 6) Transaction source
writeln(m["TransactionSource"].Value)
// 7) Transaction type (Sale/Account Verification)
writeln(m["TransactionType"].Value)
// 8) Total
// assuming value like "GBP1.50" — insert space after currency
total := m["TotalAmount"].Value
if !strings.HasPrefix(total, "GBP") && len(total) > 3 {
total = total[:3] + " " + total[3:]
label = strings.TrimSuffix(label, ":") + ":"
if gap, fits := receiptPairGap(label, entry.Value); fits {
line(label+gap+entry.Value, true, false)
} else {
line(receiptEntryText(entry), true, false)
}
writeln("TOTAL: " + total)
// 9) Cardholder verification
writeln(m["CardholderVerification"].Value)
// 10) Approved/Declined
writeln(m["TransactionResult"].Value)
// 11) Auth code
writeln("Auth Code: " + m["AuthCode"].Value)
// 12) Reference
writeln("Ref: " + m["AuthReference"].Value)
// 13) Merchant & terminal IDs
writeln("MID: " + m["MerchantIdMasked"].Value)
writeln("TID: " + m["TerminalIdMasked"].Value)
// 14) Date/time
writeln(m["AuthDateTime"].Value)
// 15) Retention message
writeln(m["RetentionMessage"].Value)
// boldOff()
// finally feed & cut
write([]byte{ESC, 'd', 7}) // Feed 5 lines
write([]byte{GS, 'V', 1})
break
}
}
pair(take("CardholderVerification"), take("TransactionResult"), true)
newSection = true
line(take("AuthCode"), false, false)
line(take("AuthReference"), false, false)
line(take("TransactionSeqNumber"), false, false)
pair(take("MerchantIdMasked"), take("TerminalIdMasked"), false)
line(take("AuthDateTime"), false, false)
footer := take("RetentionMessage")
// Preserve every remaining occurrence, including unknown IDs, in provider order.
for i, entry := range entries {
if !rendered[i] && entry.Value != "" {
line(receiptEntryText(entry), false, false)
}
}
newSection = true
line(footer, false, true)
normal()
buf.Write([]byte{ESC, 'd', 7})
buf.Write([]byte{GS, 'V', 1})
return buf.Bytes(), nil
}
func receiptEntryText(entry ReceiptEntryXML) string {
label := entry.Label
if label == "" {
switch entry.ReceiptEntryId {
case "Recipient", "MerchantName", "CardScheme", "TransactionSource", "TransactionType",
"CardholderVerification", "TransactionResult", "AuthDateTime", "RetentionMessage":
return entry.Value
case "PanMasked":
label = "Card"
case "Aid":
label = "AID"
case "PanSequence":
label = "PAN Seq No"
case "TotalAmount":
label = "TOTAL"
case "AuthCode":
label = "Auth Code"
case "AuthReference":
label = "Ref"
case "TransactionSeqNumber":
label = "Transaction Seq. No"
case "MerchantIdMasked":
label = "MID"
case "TerminalIdMasked":
label = "TID"
default:
var readable strings.Builder
runes := []rune(entry.ReceiptEntryId)
for i, r := range runes {
if i > 0 && r >= 'A' && r <= 'Z' &&
((runes[i-1] >= 'a' && runes[i-1] <= 'z') ||
(i+1 < len(runes) && runes[i+1] >= 'a' && runes[i+1] <= 'z')) {
readable.WriteByte(' ')
}
if r == '_' || r == '-' {
r = ' '
}
readable.WriteRune(r)
}
label = strings.TrimSpace(readable.String())
}
}
if label == "" {
return entry.Value
}
return strings.TrimSuffix(label, ":") + ": " + entry.Value
}
func receiptPairGap(left, right string) (string, bool) {
if left == "" || right == "" || len(left)+2+len(right) > receiptColumns {
return "", false
}
// Only printable ASCII has a predictable single-column width here.
for _, r := range left + right {
if r < ' ' || r > '~' {
return "", false
}
}
return strings.Repeat(" ", receiptColumns-len(left)-len(right)), true
}
func printLogo(path string) ([]byte, error) {
const maxLogoWidth = 384
f, err := os.Open(path)

View File

@ -0,0 +1,280 @@
package printer
import (
"bytes"
"reflect"
"strings"
"testing"
)
type receiptTestChar struct {
value byte
center, bold bool
}
type receiptTestOutput struct {
lines []string
chars []receiptTestChar
feeds, cuts int
}
// readReceiptText understands only the commands emitted by this receipt builder.
func readReceiptText(t *testing.T, data []byte) receiptTestOutput {
t.Helper()
var out receiptTestOutput
var line strings.Builder
var center, bold bool
for i := 0; i < len(data); {
if data[i] == ESC || data[i] == GS {
if i+2 >= len(data) {
t.Fatalf("BuildCardholderReceipt control bytes = %v, want complete command", data[i:])
}
prefix, command, value := data[i], data[i+1], data[i+2]
switch {
case prefix == ESC && command == 'a':
if value != 0 && value != CENTER {
t.Errorf("receipt alignment = %d, want left or center", value)
}
center = value == CENTER
case prefix == ESC && command == 'E':
if value != BOLD_OFF && value != BOLD_ON {
t.Errorf("receipt bold = %d, want on or off", value)
}
bold = value == BOLD_ON
case prefix == GS && command == '!':
if value != NORMAL_FONT {
t.Errorf("receipt size = %d, want normal size", value)
}
case prefix == ESC && command == 'd':
out.feeds++
if value != 7 || center || bold || i != len(data)-6 {
t.Errorf("receipt feed = %d, center=%t bold=%t offset=%d, want final seven-line feed in normal state", value, center, bold, i)
}
case prefix == GS && command == 'V':
out.cuts++
if value != 1 || i != len(data)-3 {
t.Errorf("receipt cut = %d at %d, want final GS V 1", value, i)
}
default:
t.Fatalf("BuildCardholderReceipt command = %v, want supported text command", data[i:i+3])
}
i += 3
continue
}
if data[i] == '\n' {
out.lines = append(out.lines, line.String())
line.Reset()
} else {
line.WriteByte(data[i])
out.chars = append(out.chars, receiptTestChar{value: data[i], center: center, bold: bold})
}
i++
}
if line.Len() != 0 || center || bold || out.feeds != 1 || out.cuts != 1 {
t.Errorf("receipt termination: trailing=%q center=%t bold=%t feeds=%d cuts=%d, want normal state and one feed/cut", line.String(), center, bold, out.feeds, out.cuts)
}
return out
}
func buildReceiptText(t *testing.T, entries []ReceiptEntryXML) receiptTestOutput {
t.Helper()
before := append([]ReceiptEntryXML(nil), entries...)
data, err := BuildCardholderReceipt(entries)
if err != nil {
t.Fatalf("BuildCardholderReceipt(%v) error = %v, want nil", entries, err)
}
if !reflect.DeepEqual(entries, before) {
t.Errorf("BuildCardholderReceipt input = %v, want unchanged %v", entries, before)
}
if !bytes.HasSuffix(data, []byte{ESC, 'd', 7, GS, 'V', 1}) {
t.Errorf("BuildCardholderReceipt suffix = %v, want unchanged feed/cut", data)
}
return readReceiptText(t, data)
}
func sampleReceipt(recipient string) []ReceiptEntryXML {
return []ReceiptEntryXML{
{ReceiptEntryId: "Recipient", Value: recipient},
{ReceiptEntryId: "MerchantName", Value: "Standard Test Merchant"},
{ReceiptEntryId: "Aid", Value: "A0000000031010", Label: "AID"},
{ReceiptEntryId: "CardScheme", Value: "VISA DEBIT"},
{ReceiptEntryId: "PanMasked", Value: "************1133", Label: "Card"},
{ReceiptEntryId: "PanSequence", Value: "01", Label: "PAN Seq No"},
{ReceiptEntryId: "TransactionSource", Value: "ICC"},
{ReceiptEntryId: "TransactionType", Value: "SALE"},
{ReceiptEntryId: "TotalAmount", Value: "GBP120.00", Label: "TOTAL"},
{ReceiptEntryId: "CardholderVerification", Value: "PIN VERIFIED"},
{ReceiptEntryId: "TransactionResult", Value: "APPROVED"},
{ReceiptEntryId: "AuthCode", Value: "D0A35D", Label: "Auth Code"},
{ReceiptEntryId: "AuthReference", Value: "ChipDNA-Sale-20260908144731", Label: "Ref"},
{ReceiptEntryId: "MerchantIdMasked", Value: "******7897", Label: "MID"},
{ReceiptEntryId: "TerminalIdMasked", Value: "****9508", Label: "TID"},
{ReceiptEntryId: "TransactionSeqNumber", Value: "00001059", Label: "Transaction Seq. No"},
{ReceiptEntryId: "AuthDateTime", Value: "08/09/2026 14:48:06"},
{ReceiptEntryId: "RetentionMessage", Value: "Please retain for your records"},
}
}
func TestBuildCardholderReceiptCompleteLayout(t *testing.T) {
for _, recipient := range []string{"CARDHOLDER COPY", "MERCHANT COPY"} {
t.Run(recipient, func(t *testing.T) {
entries := sampleReceipt(recipient)
out := buildReceiptText(t, entries)
// Ignore padding used for left/right placement, not semantic row order.
var rows []string
for _, line := range out.lines {
rows = append(rows, strings.Join(strings.Fields(line), " "))
}
rule := strings.Repeat("-", 44)
want := []string{recipient, "Standard Test Merchant", rule, "VISA DEBIT", "Card: ************1133",
"AID: A0000000031010 PAN Seq No: 01", "ICC SALE", rule, "TOTAL: GBP120.00", "PIN VERIFIED APPROVED", rule,
"Auth Code: D0A35D", "Ref: ChipDNA-Sale-20260908144731", "Transaction Seq. No: 00001059",
"MID: ******7897 TID: ****9508", "08/09/2026 14:48:06", rule, "Please retain for your records"}
if !reflect.DeepEqual(rows, want) {
t.Errorf("BuildCardholderReceipt(%q) rows = %q, want %q", recipient, rows, want)
}
for _, entry := range entries {
if !strings.Contains(strings.Join(out.lines, "\n"), entry.Value) {
t.Errorf("BuildCardholderReceipt(%q) lost %s=%q", recipient, entry.ReceiptEntryId, entry.Value)
}
}
for _, line := range out.lines {
if line == "" || len(line) > 44 {
t.Errorf("BuildCardholderReceipt(%q) row = %q, want compact nonempty row within 44 columns", recipient, line)
}
}
if len(out.lines) > 19 {
t.Errorf("BuildCardholderReceipt(%q) rows = %d, want representative receipt at most 19", recipient, len(out.lines))
}
})
}
}
func TestBuildCardholderReceiptFormattingState(t *testing.T) {
out := buildReceiptText(t, sampleReceipt("CARDHOLDER COPY"))
var plain strings.Builder
for _, char := range out.chars {
plain.WriteByte(char.value)
}
for _, tc := range []struct {
text string
center, bold bool
}{
{"CARDHOLDER COPY", true, true}, {"Standard Test Merchant", true, false},
{"VISA DEBIT", false, false}, {"TOTAL:", false, true}, {"GBP120.00", false, true},
{"PIN VERIFIED", false, false}, {"APPROVED", false, true}, {"Auth Code:", false, false},
{"Please retain for your records", true, false},
} {
start := strings.Index(plain.String(), tc.text)
if start < 0 {
t.Fatalf("receipt text lacks %q", tc.text)
}
for _, char := range out.chars[start : start+len(tc.text)] {
if char.center != tc.center || char.bold != tc.bold {
t.Errorf("receipt style for %q = center:%t bold:%t, want center:%t bold:%t", tc.text, char.center, char.bold, tc.center, tc.bold)
break
}
}
}
}
func TestBuildCardholderReceiptMissingFields(t *testing.T) {
for _, tc := range []struct {
name string
entries []ReceiptEntryXML
want []string
}{
{name: "empty"},
{name: "empty values", entries: []ReceiptEntryXML{{ReceiptEntryId: "Aid", Label: "AID"}, {ReceiptEntryId: "Unknown", Label: "Unused"}}},
{name: "one partner", entries: []ReceiptEntryXML{{ReceiptEntryId: "PanSequence", Value: "02"}}, want: []string{"PAN Seq No: 02"}},
{name: "result only", entries: []ReceiptEntryXML{{ReceiptEntryId: "TransactionResult", Value: "DECLINED"}}, want: []string{"DECLINED"}},
} {
t.Run(tc.name, func(t *testing.T) {
out := buildReceiptText(t, tc.entries)
if !reflect.DeepEqual(out.lines, tc.want) {
t.Errorf("BuildCardholderReceipt(%v) rows = %q, want %q", tc.entries, out.lines, tc.want)
}
})
}
}
func TestBuildCardholderReceiptPreservesRemainingEntries(t *testing.T) {
entries := []ReceiptEntryXML{
{ReceiptEntryId: "AuthCode", Value: ""},
{ReceiptEntryId: "FooBar", Value: "first-extra", Priority: "9"},
{ReceiptEntryId: "AuthCode", Value: "primary", Label: "Provider authorization"},
{ReceiptEntryId: "AuthCode", Value: "duplicate", Label: "Second authorization"},
{ReceiptEntryId: "FooBar", Value: "second-extra", Label: "Foo", Priority: "1"},
{ReceiptEntryId: "RetentionMessage", Value: "Retain this"},
{ReceiptEntryId: "RetentionMessage", Value: "Extra retention"},
{ReceiptEntryId: "HTTPCode", Value: "provider-code"},
{Value: "unlabelled-value"},
}
out := buildReceiptText(t, entries)
want := []string{"Provider authorization: primary", "Foo Bar: first-extra", "Second authorization: duplicate",
"Foo: second-extra", "Extra retention", "HTTP Code: provider-code", "unlabelled-value", strings.Repeat("-", 44), "Retain this"}
if !reflect.DeepEqual(out.lines, want) {
t.Errorf("BuildCardholderReceipt remaining rows = %q, want %q", out.lines, want)
}
}
func TestBuildCardholderReceiptPairBoundaries(t *testing.T) {
for _, tc := range []struct {
name, left, right string
paired bool
}{
{"short", "ICC", "SALE", true},
{"exact width", strings.Repeat("L", 20), strings.Repeat("R", 22), true},
{"overflow", strings.Repeat("L", 21), strings.Repeat("R", 22), false},
{"unicode", "TAP \u00c9", "SALE", false},
{"multiline", "ICC\nFALLBACK", "SALE", false},
{"left missing", "", "SALE", false},
{"right missing", "ICC", "", false},
} {
t.Run(tc.name, func(t *testing.T) {
out := buildReceiptText(t, []ReceiptEntryXML{{ReceiptEntryId: "TransactionSource", Value: tc.left}, {ReceiptEntryId: "TransactionType", Value: tc.right}})
var want []string
if tc.paired {
want = []string{tc.left + strings.Repeat(" ", 44-len(tc.left)-len(tc.right)) + tc.right}
} else {
if tc.left != "" {
want = append(want, strings.Split(tc.left, "\n")...)
}
if tc.right != "" {
want = append(want, tc.right)
}
}
if !reflect.DeepEqual(out.lines, want) {
t.Errorf("BuildCardholderReceipt pair(%q,%q) rows = %q, want %q", tc.left, tc.right, out.lines, want)
}
})
}
}
func TestBuildCardholderReceiptLongValuesAndLabels(t *testing.T) {
ref := strings.Repeat("long-reference-", 8)
verify := "CONSUMER DEVICE VERIFICATION WITH ADDITIONAL PROVIDER TEXT"
out := buildReceiptText(t, []ReceiptEntryXML{
{ReceiptEntryId: "CardholderVerification", Value: verify},
{ReceiptEntryId: "TransactionResult", Value: "DECLINED"},
{ReceiptEntryId: "AuthReference", Label: "Provider reference:", Value: ref},
{ReceiptEntryId: "MerchantIdMasked", Label: strings.Repeat("Merchant", 6), Value: "******7897"},
{ReceiptEntryId: "TerminalIdMasked", Value: "****9508"},
})
want := []string{verify, "DECLINED", strings.Repeat("-", 44), "Provider reference: " + ref,
strings.Repeat("Merchant", 6) + ": ******7897", "TID: ****9508"}
if !reflect.DeepEqual(out.lines, want) {
t.Errorf("BuildCardholderReceipt long fields rows = %q, want %q", out.lines, want)
}
}
func TestBuildCardholderReceiptProviderAmounts(t *testing.T) {
for _, amount := range []string{"GBP120.00", "EUR 42,50", "USD1.23", "amount supplied verbatim", strings.Repeat("9", 50)} {
t.Run(amount, func(t *testing.T) {
out := buildReceiptText(t, []ReceiptEntryXML{{ReceiptEntryId: "TotalAmount", Label: "Provider total", Value: amount}})
if len(out.lines) != 1 || !strings.HasPrefix(out.lines[0], "Provider total:") || !strings.HasSuffix(out.lines[0], amount) {
t.Errorf("BuildCardholderReceipt amount(%q) rows = %q, want provider label and unchanged amount", amount, out.lines)
}
})
}
}

View File

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