OpsLog/internal/winkeyer/hostopen.go

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

	// resetDelay is the second attempt's wait, and it is not there for a K1EL.
	//
	// Plenty of "WinKeyers" are a K3NG keyer — an Arduino running an emulation
	// of the same protocol. On an Arduino, DTR is wired to the reset pin through
	// a capacitor: raising it when the port opens REBOOTS the board, which then
	// sits in its bootloader before the sketch even starts. K3NG's own options
	// file says as much ("disabling Automatic Software Reset is highly
	// recommended", and an option to "discard errant serial port bytes at
	// startup" for when it is not). 400 ms is nowhere near long enough, so the
	// keyer misses the whole handshake and looks absent.
	//
	// Rather than make every operator wait for the slowest possible device, the
	// first attempt stays quick and only the retry allows for a reboot.
	resetDelay   = 2500 * time.Millisecond
	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, and the two attempts cover the two ways a keyer that
// is plugged in and working can miss being spoken to: a parser left mid-command
// by whoever talked to it last (the first attempt's nulls clear that), and an
// Arduino-based keyer still rebooting from the DTR edge (the second attempt
// waits long enough for it).
// slowBoot skips straight to the long wait, set when this port has already been
// seen to need it. The second return value says whether the long wait is what
// worked, so the caller can remember it and open quickly next time.
func hostOpen(p serial.Port, slowBoot bool) (ver int, needsSlowBoot bool, err error) {
	var lastErr error
	for attempt := 1; attempt <= handshakeTry; attempt++ {
		wait := bootDelay
		if attempt > 1 || slowBoot {
			wait = resetDelay
		}
		ver, err := hostOpenOnce(p, wait)
		if err == nil {
			if attempt > 1 {
				applog.Printf("winkeyer: answered on attempt %d — this keyer needs %s to boot (a K3NG or another Arduino keyer with auto-reset on); remembering that for this port", attempt, wait)
			}
			return ver, wait == resetDelay, nil
		}
		lastErr = err
		if attempt < handshakeTry {
			applog.Printf("winkeyer: handshake attempt %d failed (%v) — retrying after %s in case the keyer is rebooting", attempt, err, resetDelay)
		}
	}
	return 0, false, lastErr
}

func hostOpenOnce(p serial.Port, boot time.Duration) (int, error) {
	// The keyer may still be booting off the DTR line we just raised.
	time.Sleep(boot)
	drain(p)

	// The resync nulls and the echo probe go out as ONE write.
	//
	// Copied byte for byte from a Logger32 capture against the K3NG keyer that
	// would not answer OpsLog: "Sent: 13 13 13 00 04 55 / Rcvd: 55". Same keyer,
	// same port, same six bytes — the only difference was that we sent them as
	// two writes with a pause and a buffer purge in between, and Logger32 sends
	// them as one. 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.
	//
	// There is nothing to wait for between the two halves anyway: a null produces
	// no reply, so the pause was only ever giving the keyer a chance to change
	// its mind.
	probe := []byte{cmdNull, cmdNull, cmdNull, cmdAdmin, adminEcho, echoProbe}
	traceHandshake("TX", probe, 0, false)
	if _, err := p.Write(probe); err != nil {
		return 0, fmt.Errorf("echo test: %w", err)
	}
	b, ok := readByte(p, echoTimeout)
	traceHandshake("RX", nil, b, ok)
	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)
	}

	open := []byte{cmdAdmin, adminOpen}
	traceHandshake("TX", open, 0, false)
	if _, err := p.Write(open); err != nil {
		return 0, fmt.Errorf("host open: %w", err)
	}
	ver, ok := readByte(p, openTimeout)
	traceHandshake("RX", nil, ver, ok)
	if !ok {
		return 0, errors.New("host open: the keyer echoed but did not return its firmware version")
	}
	return int(ver), nil
}

// traceHandshake puts the opening exchange in the log, ALWAYS — unlike the
// running trace beside it, which is behind the diagnostic option.
//
// A failure that says only "no WinKeyer answered" cannot be told apart from a
// wrong port, a wrong baud rate, a keyer still rebooting, or another program
// holding the line. The bytes can. It is four lines per connect, and only when
// the connect is attempted.
func traceHandshake(dir string, b []byte, got byte, ok bool) {
	switch {
	case dir == "TX":
		applog.Printf("winkeyer: handshake TX % 02X", b)
	case ok:
		applog.Printf("winkeyer: handshake RX %02X", got)
	default:
		applog.Printf("winkeyer: handshake RX — nothing came back")
	}
}

// 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
		}
	}
}