From 1b736272c9519f553d6ce61b92f1dacf6a51be56 Mon Sep 17 00:00:00 2001 From: Gregory Salaun Date: Fri, 14 Aug 2026 12:07:58 +0200 Subject: [PATCH] fix(winkeyer): perform K1EL's full opening handshake MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit An operator's log showed the whole fault in its first line: "connected on COM3 — no reply — the keyer did not answer Host Open", followed by seven configuration commands and two calls sent as Morse. Nothing was listening. Reporting a link as up and then writing to it regardless is the part worth fixing; the handshake is why it was down. K1EL's Application Interface Guide gives the sequence, and we did one step of it. Now all of it: - DTR on, RTS OFF. K1EL's own init sets DTR_CONTROL_ENABLE with RTS_CONTROL_DISABLE, and on a serial WinKeyer those lines ARE the power supply — DTR feeds the 3.3 V regulator, RTS provides the negative rail. go.bug.st/serial defaults both to true, so we drove RTS high on every connect without a line of code saying so. - 400 ms after the lines come up, for a WK1 still booting off DTR. - Three 0x13 nulls to resync the command parser. A keyer left part-way through a command by whoever spoke to it last would absorb Host Open as a parameter — the everyday cause of a silent WinKeyer, and one the operator can do nothing about from the outside. - An echo test (0x00 0x04 0x55) before trusting the port at all. This is the step that answers "is there a keyer here", and connecting now fails on it, with the byte that came back when something else replied. The whole handshake is retried once, since the first attempt's nulls are what clear a confused parser. Tested against a fake port that reproduces each failure: absent, mid-command, and echoing but versionless. --- changelog.json | 8 +- internal/winkeyer/hostopen.go | 132 ++++++++++++++++++++++++ internal/winkeyer/hostopen_test.go | 156 +++++++++++++++++++++++++++++ internal/winkeyer/winkeyer.go | 25 +++-- 4 files changed, 308 insertions(+), 13 deletions(-) create mode 100644 internal/winkeyer/hostopen.go create mode 100644 internal/winkeyer/hostopen_test.go diff --git a/changelog.json b/changelog.json index fc862a8..a74f4af 100644 --- a/changelog.json +++ b/changelog.json @@ -15,7 +15,9 @@ "ADIF import: QSL_SENT_VIA no longer lands in the manager field, and QSL_RCVD_VIA is no longer discarded. Both are exported.", "QSL: logs where a routing word sits in the manager field are counted at startup and corrected only if you accept.", "QSL designer: copying a design from another profile failed with \"hero photo not found\" — the pictures were never copied.", - "QSL designer: duplicating a profile cloned its card designs without their pictures, leaving designs that could not be printed." + "QSL designer: duplicating a profile cloned its card designs without their pictures, leaving designs that could not be printed.", + "WinKeyer: the opening handshake now follows K1EL’s own sequence (RTS off, parser resync, echo test), which fixes keyers that stayed silent.", + "WinKeyer: a port where no keyer answers now reports the failure instead of showing “connected” and sending everything into the void." ], "fr": [ "Amplificateurs : coche ceux qui partagent un combiner et ON, OFF et OPERATE agissent sur tous à la fois. Chacun garde ses mesures.", @@ -30,7 +32,9 @@ "Import ADIF : QSL_SENT_VIA ne se retrouve plus dans le champ manager, et QSL_RCVD_VIA n’est plus perdu. Les deux sont exportés.", "QSL : les logs où un mode d’envoi occupe le champ manager sont comptés au démarrage et corrigés seulement si vous acceptez.", "Concepteur QSL : copier un design depuis un autre profil échouait sur « photo introuvable » — les images n’étaient jamais copiées.", - "Concepteur QSL : dupliquer un profil clonait ses designs sans leurs images, donnant des cartes impossibles à imprimer." + "Concepteur QSL : dupliquer un profil clonait ses designs sans leurs images, donnant des cartes impossibles à imprimer.", + "WinKeyer : la séquence d’ouverture suit désormais celle de K1EL (RTS bas, resync, test d’écho), ce qui réveille les manipulateurs muets.", + "WinKeyer : un port où aucun manipulateur ne répond signale l’échec au lieu d’afficher « connecté » et d’émettre dans le vide." ] }, { diff --git a/internal/winkeyer/hostopen.go b/internal/winkeyer/hostopen.go new file mode 100644 index 0000000..0f7c66a --- /dev/null +++ b/internal/winkeyer/hostopen.go @@ -0,0 +1,132 @@ +package winkeyer + +import ( + "errors" + "fmt" + "time" + + "go.bug.st/serial" + + "hamlog/internal/applog" +) + +// The opening handshake, as K1EL specifies it in the WinKeyer2 Application +// Interface Guide ("WK Init Psuedo Code"). OpsLog used to send Host Open alone +// and carry on whatever came back, which is how an operator ended up with a +// keyer reported as connected, a full set of settings written to it, and not +// one character keyed — the log said "no reply" and then behaved as if there +// had been one. +// +// The steps exist for reasons that are not obvious from the byte values: +// +// 400 ms a WK1 is still powering up off the DTR line when the port opens; +// WK2 and later do not need it, and it costs nothing once. +// 0x13 ×3 null commands. WinKey's parser may be part-way through a command +// left over from whoever spoke to it last — another logger, or us +// before a crash. A command byte expecting parameters would swallow +// Host Open whole. Three nulls flush that state out. +// echo ask the keyer to send one known byte back. This is the only step +// that answers "is there really a WinKeyer on this port", and it is +// the one to fail on: everything after it assumes a listener. +// open 0x00 0x02, and the keyer returns its firmware version. +const ( + cmdNull = 0x13 + cmdAdmin = 0x00 + adminOpen = 0x02 + adminEcho = 0x04 + echoProbe = 0x55 // K1EL's own choice; any byte works, this one is 0b01010101 + bootDelay = 400 * time.Millisecond + echoTimeout = 2 * time.Second // K1EL: "if a WK doesn't respond within 2 seconds abort" + openTimeout = 2 * time.Second + handshakeTry = 2 +) + +// errNoKeyer is returned when nothing answers the echo probe. +var errNoKeyer = errors.New("no WinKeyer answered on this port — check the cable, the port, and that no other program holds the keyer") + +// hostOpen runs the full documented handshake and returns the firmware version +// byte. It is tried twice: a keyer left mid-command by another program is the +// common case, the nulls of the first attempt clear it, and the second then +// succeeds. +func hostOpen(p serial.Port) (int, error) { + var lastErr error + for attempt := 1; attempt <= handshakeTry; attempt++ { + ver, err := hostOpenOnce(p) + if err == nil { + return ver, nil + } + lastErr = err + if attempt < handshakeTry { + applog.Printf("winkeyer: handshake attempt %d failed (%v) — retrying", attempt, err) + } + } + return 0, lastErr +} + +func hostOpenOnce(p serial.Port) (int, error) { + // The keyer may still be booting off the DTR line we just raised. + time.Sleep(bootDelay) + drain(p) + + // Resync the command parser before asking it anything. + if _, err := p.Write([]byte{cmdNull, cmdNull, cmdNull}); err != nil { + return 0, fmt.Errorf("resync: %w", err) + } + time.Sleep(50 * time.Millisecond) + drain(p) + + // Is anything actually there? + if _, err := p.Write([]byte{cmdAdmin, adminEcho, echoProbe}); err != nil { + return 0, fmt.Errorf("echo test: %w", err) + } + b, ok := readByte(p, echoTimeout) + if !ok { + return 0, errNoKeyer + } + if b != echoProbe { + // Something replied, but not what we asked for. Say what came back — + // on a wrong port that byte is the only clue to what is on the other end. + return 0, fmt.Errorf("echo test: expected 0x%02X, got 0x%02X — is this the keyer's port?", echoProbe, b) + } + + if _, err := p.Write([]byte{cmdAdmin, adminOpen}); err != nil { + return 0, fmt.Errorf("host open: %w", err) + } + ver, ok := readByte(p, openTimeout) + if !ok { + return 0, errors.New("host open: the keyer echoed but did not return its firmware version") + } + return int(ver), nil +} + +// readByte waits up to d for one byte. The serial read timeout is per-call and +// can return 0 bytes without an error, so this loops until the deadline rather +// than trusting a single Read. +func readByte(p serial.Port, d time.Duration) (byte, bool) { + _ = p.SetReadTimeout(200 * time.Millisecond) + deadline := time.Now().Add(d) + buf := make([]byte, 1) + for time.Now().Before(deadline) { + n, err := p.Read(buf) + if n > 0 { + return buf[0], true + } + if err != nil { + return 0, false + } + } + return 0, false +} + +// drain throws away anything already waiting — a status byte from a previous +// session, or the tail of a reply we are no longer interested in. +func drain(p serial.Port) { + _ = p.SetReadTimeout(20 * time.Millisecond) + buf := make([]byte, 64) + for i := 0; i < 16; i++ { + n, err := p.Read(buf) + if n == 0 || err != nil { + return + } + } +} diff --git a/internal/winkeyer/hostopen_test.go b/internal/winkeyer/hostopen_test.go new file mode 100644 index 0000000..29b8364 --- /dev/null +++ b/internal/winkeyer/hostopen_test.go @@ -0,0 +1,156 @@ +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) + if err != nil { + t.Fatalf("hostOpen: %v", err) + } + if ver != 23 { + t.Errorf("version = %d, want 23", ver) + } + 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) + 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); !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) + 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) + } +} diff --git a/internal/winkeyer/winkeyer.go b/internal/winkeyer/winkeyer.go index 364a596..8e772b6 100644 --- a/internal/winkeyer/winkeyer.go +++ b/internal/winkeyer/winkeyer.go @@ -152,22 +152,22 @@ func (m *Manager) Connect(cfg Config) error { DataBits: 8, Parity: serial.NoParity, StopBits: serial.OneStopBit, + // DTR on, RTS OFF. K1EL's own init code sets exactly this + // (DTR_CONTROL_ENABLE / RTS_CONTROL_DISABLE), and on a serial WinKeyer + // the two lines are the chip's power supply: DTR feeds the 3.3 V + // regulator, RTS provides the negative rail for the RS-232 swing. + // Driving RTS high starves that rail. The serial library defaults BOTH + // to true, which is how this was wrong without anyone writing it. + InitialStatusBits: &serial.ModemOutputBits{DTR: true, RTS: false}, }) if err != nil { return fmt.Errorf("winkeyer: open %s: %w", cfg.Port, err) } - _ = p.SetReadTimeout(200 * time.Millisecond) - // Host Open: <0x00 0x02>. Device replies with its firmware version byte. - if _, err := p.Write([]byte{0x00, 0x02}); err != nil { + ver, err := hostOpen(p) + if err != nil { _ = p.Close() - return fmt.Errorf("winkeyer: host open: %w", err) - } - ver := 0 - buf := make([]byte, 16) - _ = p.SetReadTimeout(1 * time.Second) - if n, _ := p.Read(buf); n > 0 { - ver = int(buf[0]) + return fmt.Errorf("winkeyer: %s: %w", cfg.Port, err) } _ = p.SetReadTimeout(200 * time.Millisecond) @@ -515,7 +515,10 @@ func cmdName(b []byte) string { func firmwareFamily(ver int) string { switch { case ver == 0: - return "no reply — the keyer did not answer Host Open" + // Unreachable from a successful connect — the handshake fails rather + // than returning a version of zero. Kept so a future caller that skips + // hostOpen cannot print "WK1 (v0)" and be believed. + return "unknown firmware (no version returned)" case ver < 20: return fmt.Sprintf("WK1 (v%d)", ver) case ver < 30: