Files
OpsLog/internal/winkeyer/hostopen_test.go
T
rouggy 3def789742 fix(winkeyer): send the probe the way a working client sends it
Logger32's WinKeyer debug against the K3NG that will not answer OpsLog is a
capture of the exchange working, on the same keyer and the same port:

    Sent: 13 13 13 00 04 55
    Rcvd: 55            (72 ms)
    Sent: 00 02  Host open
    Rcvd: 23            (WK2 v23)

That is the sequence I already send. The difference is the grouping: Logger32
puts the three nulls and the echo probe in ONE write, and we split them with a
50 ms pause and a buffer purge in between. On a keyer that reboots when the
port opens, that pause is a window for it to come up mid-sequence and swallow
half of it — and there was nothing to wait for, since a null produces no reply.

The handshake bytes are now logged unconditionally, not behind the diagnostic
option. "No WinKeyer answered" cannot be told apart from a wrong port, a wrong
baud rate, a keyer still booting, or another program holding the line. The
bytes can, and it is four lines per connect attempt.
2026-08-15 10:28:11 +02:00

219 lines
6.7 KiB
Go

package winkeyer
import (
"errors"
"sync"
"testing"
"time"
"go.bug.st/serial"
)
// fakeKeyer is a serial.Port that behaves like a WinKeyer: it answers the echo
// probe and Host Open, and records everything the host sent so the handshake
// can be checked byte for byte against K1EL's documented sequence.
type fakeKeyer struct {
mu sync.Mutex
written []byte
toRead []byte
version byte
// deaf drops every command — the keyer that is not there, or is not
// listening because RTS starved it.
deaf bool
// mute answers the echo but never returns a version.
mute bool
// needsResync ignores commands until three nulls have been seen, standing
// in for a keyer left mid-command by another program.
needsResync bool
nulls int
}
func (f *fakeKeyer) Write(p []byte) (int, error) {
f.mu.Lock()
defer f.mu.Unlock()
f.written = append(f.written, p...)
if f.deaf {
return len(p), nil
}
for i := 0; i < len(p); i++ {
switch {
case p[i] == cmdNull:
f.nulls++
case f.needsResync && f.nulls < 3:
// still confused — swallow it
case p[i] == cmdAdmin && i+1 < len(p):
i++
switch p[i] {
case adminEcho:
if i+1 < len(p) {
i++
f.toRead = append(f.toRead, p[i])
}
case adminOpen:
if !f.mute {
f.toRead = append(f.toRead, f.version)
}
}
}
}
return len(p), nil
}
func (f *fakeKeyer) Read(p []byte) (int, error) {
f.mu.Lock()
defer f.mu.Unlock()
if len(f.toRead) == 0 {
return 0, nil // a timeout, not an error — what a real port does
}
n := copy(p, f.toRead)
f.toRead = f.toRead[n:]
return n, nil
}
func (f *fakeKeyer) sent() []byte {
f.mu.Lock()
defer f.mu.Unlock()
return append([]byte(nil), f.written...)
}
func (f *fakeKeyer) Drain() error { return nil }
func (f *fakeKeyer) ResetInputBuffer() error { return nil }
func (f *fakeKeyer) ResetOutputBuffer() error { return nil }
func (f *fakeKeyer) SetDTR(bool) error { return nil }
func (f *fakeKeyer) SetRTS(bool) error { return nil }
func (f *fakeKeyer) GetModemStatusBits() (*serial.ModemStatusBits, error) {
return &serial.ModemStatusBits{}, nil
}
func (f *fakeKeyer) SetReadTimeout(time.Duration) error { return nil }
func (f *fakeKeyer) Close() error { return nil }
func (f *fakeKeyer) Break(time.Duration) error { return nil }
func (f *fakeKeyer) SetMode(*serial.Mode) error { return nil }
// TestHostOpenFollowsK1ELSequence checks the handshake against the order K1EL
// publishes: three nulls to resync the parser, an echo probe to prove there is
// a keyer, then Host Open. OpsLog used to send Host Open alone, which a keyer
// left mid-command simply absorbed.
func TestHostOpenFollowsK1ELSequence(t *testing.T) {
f := &fakeKeyer{version: 23}
ver, _, err := hostOpen(f, false)
if err != nil {
t.Fatalf("hostOpen: %v", err)
}
if ver != 23 {
t.Errorf("version = %d, want 23", ver)
}
// One write for the six probe bytes, then Host Open — the order and the
// grouping of a Logger32 capture against a real K3NG.
want := []byte{
cmdNull, cmdNull, cmdNull,
cmdAdmin, adminEcho, echoProbe,
cmdAdmin, adminOpen,
}
got := f.sent()
if len(got) != len(want) {
t.Fatalf("sent % X, want % X", got, want)
}
for i := range want {
if got[i] != want[i] {
t.Fatalf("sent % X, want % X", got, want)
}
}
}
// A keyer left part-way through a command by another program is the everyday
// cause of a silent WinKeyer. The nulls must recover it without the operator
// having to unplug anything.
func TestHostOpenRecoversAConfusedParser(t *testing.T) {
f := &fakeKeyer{version: 30, needsResync: true}
ver, _, err := hostOpen(f, false)
if err != nil {
t.Fatalf("hostOpen: %v", err)
}
if ver != 30 {
t.Errorf("version = %d, want 30", ver)
}
}
// Nothing on the port must FAIL the connection. Reporting success and then
// writing settings and text into the void is what produced a log full of
// commands and a keyer that never made a sound.
func TestHostOpenFailsWhenNothingAnswers(t *testing.T) {
f := &fakeKeyer{deaf: true}
if _, _, err := hostOpen(f, false); !errors.Is(err, errNoKeyer) {
t.Fatalf("want errNoKeyer, got %v", err)
}
}
// Echoing but not returning a version is a different fault and must not be
// reported as "no keyer".
func TestHostOpenReportsMissingVersion(t *testing.T) {
f := &fakeKeyer{mute: true}
_, _, err := hostOpen(f, false)
if err == nil {
t.Fatal("want an error")
}
if errors.Is(err, errNoKeyer) {
t.Fatalf("a keyer that echoed was reported as absent: %v", err)
}
}
// slowKeyer answers nothing until it has been "powered up" for d — a K3NG on an
// Arduino, which the DTR edge from opening the port drops into its bootloader.
type slowKeyer struct {
fakeKeyer
ready time.Time
}
func (s *slowKeyer) Write(p []byte) (int, error) {
if time.Now().Before(s.ready) {
return len(p), nil // still in the bootloader — the bytes are lost
}
return s.fakeKeyer.Write(p)
}
// TestHostOpenWaitsOutAnArduinoReboot is the case that started this: a K3NG
// keyer reboots when the port opens, so it misses a handshake sent 400 ms
// later. The retry has to wait long enough, and must not need the operator to
// press connect twice.
func TestHostOpenWaitsOutAnArduinoReboot(t *testing.T) {
f := &slowKeyer{ready: time.Now().Add(1500 * time.Millisecond)}
f.version = 23
ver, slow, err := hostOpen(f, false)
if err != nil {
t.Fatalf("hostOpen: %v", err)
}
if ver != 23 {
t.Errorf("version = %d, want 23", ver)
}
// This second value is what gets remembered for the port, and it is the
// whole reason the operator is never asked what kind of keyer they own.
// Lose it and every later connect pays the same doomed quick attempt.
if !slow {
t.Error("the long wait is what worked, but it was not reported as needed")
}
}
// A keyer that answers straight away must NOT be remembered as slow — that
// would add seconds to every connect for a K1EL that never needed them.
func TestHostOpenDoesNotMarkAFastKeyerSlow(t *testing.T) {
f := &fakeKeyer{version: 23}
if _, slow, err := hostOpen(f, false); err != nil || slow {
t.Fatalf("hostOpen = slow %v, err %v — want a fast keyer left alone", slow, err)
}
}
// A port already known to hold a slow keyer skips the doomed fast attempt, so
// the second connect is as quick as a K1EL's.
func TestHostOpenSlowBootSucceedsFirstTry(t *testing.T) {
f := &slowKeyer{ready: time.Now().Add(1500 * time.Millisecond)}
f.version = 23
if _, _, err := hostOpen(f, true); err != nil {
t.Fatalf("hostOpen: %v", err)
}
// One attempt: exactly one handshake on the wire, not two.
want := len([]byte{cmdNull, cmdNull, cmdNull, cmdAdmin, adminEcho, echoProbe, cmdAdmin, adminOpen})
if got := len(f.sent()); got != want {
t.Errorf("sent %d bytes, want %d — the fast attempt was not skipped", got, want)
}
}