Nonemm/tools/Nonemm.EngineProbe/EngineProbe.cs

using System.Text;
using Nonemm.Digital;

namespace Nonemm.EngineProbe;

/// Questions about MMTTY that cannot be answered without MMTTY running, asked
/// in order and written to the report:
///
/// 1. Does the control answer `TxBufLen`, and is a name it does not know
///    distinguishable from one it does?
/// 2. While a message is going out, does that number count down at the
///    character rate? If it does, it says exactly how much of the message is
///    still in the engine and can still be taken back.
/// 3. Does the engine hold a word until the space after it? That is MMTTY's
///    Option ▸ Way to send, and Word out is what its help calls the usual
///    setting.
/// 4. Does `{RX}` — `SetMmttyPTT(1)`, stop once the buffer is empty — send a
///    word the engine is holding, or drop it? A macro whose last word has no
///    space after it hangs on the answer.
/// 5. What comes back on the receive side while transmitting, and when? With
///    the sound loopback off that is MMTTY echoing its transmit window; with it
///    on it is the demodulator hearing the transmission.
///
/// A backspace is not on the list any more: pushed in as a character, MMTTY
/// counted it as one more character to transmit and sent the text unchanged.
/// It is not an edit.
///
/// The answers decide whether the transmit buffer can be handed to MMTTY
/// instead of being paced from here. `docs/unfinished.md` states what each one
/// means.
public sealed class EngineProbe
{
    /// Long enough for a character at 45.45 baud, short enough to see the count
    /// move.
    private static readonly TimeSpan PollInterval = TimeSpan.FromMilliseconds(50);

    /// A message at 45.45 baud takes a few seconds; this is well past the end
    /// of one.
    private static readonly TimeSpan Patience = TimeSpan.FromSeconds(30);

    /// A count that has not moved for this long is not going to move.
    private static readonly TimeSpan Still = TimeSpan.FromSeconds(5);

    /// How long after a push the count is written down every time it is read,
    /// and an empty answer is not believed. The count runs behind the engine,
    /// and this is where the report says by how much.
    private static readonly TimeSpan Settling = TimeSpan.FromSeconds(2);

    /// How long the engine is given to key up and to drop again.
    private static readonly TimeSpan Keying = TimeSpan.FromSeconds(3);

    /// One character at 45.45 baud, which is the rate the window feeds at.
    private static readonly TimeSpan CharacterTime = TimeSpan.FromMilliseconds(165);

    private const string Message = "CQ TEST DE OM5M OM5M ";
    private const string Word = "ABCD";

    private readonly MmttyEngine engine;
    private readonly ProbeLog log;
    private readonly StringBuilder received = new();
    private readonly Lock gate = new();
    private TaskCompletionSource<int>? asking;
    private TaskCompletionSource<bool>? keying;

    public EngineProbe(MmttyEngine engine, ProbeLog log)
    {
        this.engine = engine;
        this.log = log;
        engine.Reported += (_, what) => log.Write($"bridge: {what}");
        engine.TransmitChanged += WhenTransmitChanged;
        engine.Buffered += WhenBuffered;
        engine.Received += WhenReceived;
    }

    public async Task RunAsync(CancellationToken cancellation)
    {
        await NamesAsync(cancellation).ConfigureAwait(false);
        await IdleAsync(cancellation).ConfigureAwait(false);
        if (!await KeyingAsync(cancellation).ConfigureAwait(false))
        {
            return;
        }
        await MessageAsync(cancellation).ConfigureAwait(false);
        await WordAsync(cancellation).ConfigureAwait(false);
        await UnfinishedWordAsync(cancellation).ConfigureAwait(false);
        await FedSlowlyAsync(cancellation).ConfigureAwait(false);
        await PoliteStopAsync(cancellation).ConfigureAwait(false);
        await StopCharacterAsync('\\', cancellation).ConfigureAwait(false);
        await StopCharacterAsync('~', cancellation).ConfigureAwait(false);
        await SentWholeAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 11. N1MM hands MMTTY the whole message with `SendString` and
    /// calls `SetMmttyPTT(1)` 400 ms later, and MMTTY ends the transmission
    /// itself. This program hands the message over one character at a time with
    /// `PostMmttyMessage(4, ...)` and the same stop does nothing. Is it the way
    /// the text arrives that makes the difference?
    private async Task SentWholeAsync(CancellationToken cancellation)
    {
        log.Step("11. the whole message with SendString, then SetMmttyPTT(1) as N1MM sends it");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        await engine.SendAsync(Message, cancellation).ConfigureAwait(false);
        log.Write($"pushed {Message.Length} characters in one call");
        await Task.Delay(TimeSpan.FromMilliseconds(400), cancellation).ConfigureAwait(false);
        await engine.SetPttAsync(false, cancellation).ConfigureAwait(false);
        log.Write("SetMmttyPTT(1) sent 400 ms after the push, which is N1MM's wait");
        TimeSpan waited = await WatchAsync(TimeSpan.FromSeconds(10), cancellation).ConfigureAwait(false);
        log.Write(waited >= TimeSpan.Zero
            ? $"the transmitter dropped {waited.TotalMilliseconds:0} ms after the stop"
            : "the transmitter stayed up");
        log.Write($"received: \"{TakeReceived()}\"");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 10. MMTTY's macro language ends a transmission with `\` at the
    /// end of a macro, and `~` stops the carrier. The only way into the engine
    /// from here is `PostMmttyMessage(4, ...)`, one typed character, so the
    /// question is whether a character typed that way is read as a command or
    /// transmitted as text. A stop that travels with the text is worth far more
    /// than one timed from outside: it lands exactly at the end of the message
    /// with nothing held on after it.
    private async Task StopCharacterAsync(char candidate, CancellationToken cancellation)
    {
        log.Step($"10. \"{Word}\" and then '{candidate}' typed as a character");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        await TypeAsync(Word, cancellation).ConfigureAwait(false);
        await engine.TypeAsync(candidate, cancellation).ConfigureAwait(false);
        TimeSpan waited = await WatchAsync(TimeSpan.FromSeconds(5), cancellation).ConfigureAwait(false);
        log.Write(waited >= TimeSpan.Zero
            ? $"'{candidate}' dropped the transmitter after {waited.TotalMilliseconds:0} ms"
            : $"'{candidate}' did not drop the transmitter");
        log.Write($"received: \"{TakeReceived()}\"");
        await engine.ReleaseKeyAsync(cancellation).ConfigureAwait(false);
        await StoppedAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 9. Does `SetMmttyPTT(1)` drop the transmitter at all? The
    /// window sends it at the end of every message and the engine went on
    /// transmitting, so the abort that follows it a second and a half later is
    /// what unkeys, and it cut the last character off a message once. Nothing
    /// is aborted here until the question is answered, and if the polite stop
    /// does nothing the `PTT` property is put back to false to see whether that
    /// does.
    private async Task PoliteStopAsync(CancellationToken cancellation)
    {
        log.Step($"9. \"{Message}\" fed slowly, then SetMmttyPTT(1) and nothing else");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        foreach (char character in Message)
        {
            await engine.TypeAsync(character, cancellation).ConfigureAwait(false);
            await Task.Delay(CharacterTime, cancellation).ConfigureAwait(false);
        }
        await engine.SetPttAsync(false, cancellation).ConfigureAwait(false);
        log.Write("SetMmttyPTT(1) sent with the message fed");
        TimeSpan waited = await WatchAsync(TimeSpan.FromSeconds(8), cancellation).ConfigureAwait(false);
        if (waited >= TimeSpan.Zero)
        {
            log.Write($"the polite stop dropped the transmitter after {waited.TotalMilliseconds:0} ms");
            return;
        }
        log.Write("the polite stop did not drop the transmitter");
        await engine.ReleaseKeyAsync(cancellation).ConfigureAwait(false);
        log.Write("PTT property put back to false");
        waited = await WatchAsync(TimeSpan.FromSeconds(3), cancellation).ConfigureAwait(false);
        log.Write(waited >= TimeSpan.Zero
            ? $"the property dropped the transmitter after {waited.TotalMilliseconds:0} ms"
            : "the property did not drop the transmitter either");
        log.Write($"received: \"{TakeReceived()}\"");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
    }

    /// Watches the transmit state and the count until the engine says it has
    /// stopped. Returns how long that took, or -1 when it never did.
    private async Task<TimeSpan> WatchAsync(TimeSpan patience, CancellationToken cancellation)
    {
        DateTime from = DateTime.UtcNow;
        DateTime giveUp = from + patience;
        while (DateTime.UtcNow < giveUp)
        {
            int left = await AskAsync("", cancellation).ConfigureAwait(false);
            if (!engine.IsTransmitting)
            {
                return DateTime.UtcNow - from;
            }
            log.Write($"{(DateTime.UtcNow - from).TotalMilliseconds,6:0} ms  transmitting, TxBufLen: {Answer(left)}");
            await Task.Delay(TimeSpan.FromMilliseconds(250), cancellation).ConfigureAwait(false);
        }
        return TimeSpan.FromMilliseconds(-1);
    }

    /// Question 6. The window feeds the engine one character every character
    /// time and keeps it nearly empty, so the engine sits with an empty buffer
    /// between characters. Does it drop the transmitter there, and does it
    /// hold it when the feeding stops altogether? The pane is drawn on the
    /// answer: a transmitter that drops by itself is not the end of a message.
    private async Task FedSlowlyAsync(CancellationToken cancellation)
    {
        log.Step($"7. \"{Message}\" fed one character every {CharacterTime.TotalMilliseconds:0} ms");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        foreach (char character in Message)
        {
            await engine.TypeAsync(character, cancellation).ConfigureAwait(false);
            await Task.Delay(CharacterTime, cancellation).ConfigureAwait(false);
        }
        log.Write($"fed {Message.Length} characters; transmitting: {engine.IsTransmitting}");
        log.Write("an unkey above this line is the engine dropping between two characters");
        log.Step("8. keyed with nothing more to feed");
        for (int look = 0; look < 12; look++)
        {
            await Task.Delay(TimeSpan.FromMilliseconds(250), cancellation).ConfigureAwait(false);
            log.Write($"transmitting: {engine.IsTransmitting}, TxBufLen: {Answer(await AskAsync("", cancellation).ConfigureAwait(false))}");
        }
        log.Write($"received: \"{TakeReceived()}\"");
        log.Write("still transmitting after three idle seconds means the engine holds the transmitter itself");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 1. `DISP_E_UNKNOWNNAME` is 0x80020006; a name the control knows
    /// answers with a number instead.
    private async Task NamesAsync(CancellationToken cancellation)
    {
        log.Step("1. does the control answer TxBufLen");
        log.Write($"TxBufLen: {Answer(await AskAsync("TxBufLen", cancellation).ConfigureAwait(false))}");
        log.Write($"NotAProperty: {Answer(await AskAsync("NotAProperty", cancellation).ConfigureAwait(false))}");
        log.Write("a number for the first and no answer for the second is what makes the count usable");
    }

    /// The number with nothing to transmit, which is what the count has to
    /// start and end at.
    private async Task IdleAsync(CancellationToken cancellation)
    {
        log.Step("2. TxBufLen with nothing to send");
        for (int look = 0; look < 3; look++)
        {
            log.Write($"TxBufLen: {Answer(await AskAsync("", cancellation).ConfigureAwait(false))}");
            await Task.Delay(PollInterval, cancellation).ConfigureAwait(false);
        }
    }

    /// Nothing else in the report means anything until the engine keys, so this
    /// stops the run rather than letting the rest measure an engine that is
    /// sitting still.
    private async Task<bool> KeyingAsync(CancellationToken cancellation)
    {
        log.Step("3. does the engine key up");
        if (!await KeyAsync(cancellation).ConfigureAwait(false))
        {
            log.Write("the engine did not key: nothing below this would mean anything, so stopping");
            log.Write("keying is the control's PTT property; SetMmttyPTT only stops a transmission");
            return false;
        }
        log.Write($"TxBufLen while keyed and idle: {Answer(await AskAsync("", cancellation).ConfigureAwait(false))}");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
        return true;
    }

    /// Questions 2 and 5. The whole message is pushed as fast as the bridge
    /// takes it, so what the count does afterwards is the engine transmitting
    /// rather than the probe feeding.
    private async Task MessageAsync(CancellationToken cancellation)
    {
        log.Step($"4. \"{Message}\" pushed in one go, then TxBufLen every {PollInterval.TotalMilliseconds} ms");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        await TypeAsync(Message, cancellation).ConfigureAwait(false);
        log.Write($"pushed {Message.Length} characters");
        log.Write("every reading for the next two seconds: the first one that is not 0 says how far behind the count is");
        await DrainAsync(cancellation).ConfigureAwait(false);
        log.Write($"received while transmitting: \"{TakeReceived()}\"");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 3. A word with no space after it is what MMTTY holds back when
    /// it is set to Word out, and that changes what "still in the buffer"
    /// means.
    private async Task WordAsync(CancellationToken cancellation)
    {
        log.Step($"5. \"{Word}\" with no space after it, then the space");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        await TypeAsync(Word, cancellation).ConfigureAwait(false);
        await Task.Delay(TimeSpan.FromSeconds(3), cancellation).ConfigureAwait(false);
        log.Write($"TxBufLen three seconds after the word: {Answer(await AskAsync("", cancellation).ConfigureAwait(false))}");
        log.Write($"received so far: \"{TakeReceived()}\"");
        log.Write("nothing received here means the engine is set to Word out and is holding it");
        await TypeAsync(" ", cancellation).ConfigureAwait(false);
        await DrainAsync(cancellation).ConfigureAwait(false);
        log.Write($"received after the space: \"{TakeReceived()}\"");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
    }

    /// Question 4. The word has no space after it, so an engine set to Word
    /// out is still holding it when the transmission is told to stop.
    private async Task UnfinishedWordAsync(CancellationToken cancellation)
    {
        log.Step($"6. \"{Word}\" with no space after it, then {{RX}}");
        TakeReceived();
        await KeyAsync(cancellation).ConfigureAwait(false);
        await TypeAsync(Word, cancellation).ConfigureAwait(false);
        await Task.Delay(TimeSpan.FromSeconds(2), cancellation).ConfigureAwait(false);
        log.Write($"TxBufLen before {{RX}}: {Answer(await AskAsync("", cancellation).ConfigureAwait(false))}");
        await UnkeyAsync(cancellation).ConfigureAwait(false);
        log.Write($"received: \"{TakeReceived()}\"");
        log.Write($"\"{Word}\" here means SetMmttyPTT(1) sends a held word before it stops");
    }

    /// Polls until the engine says it has nothing left, until the count stops
    /// moving, or until the patience runs out.
    ///
    /// The engine counts what it has been given a moment after it is given it,
    /// so a single empty answer straight after a push means the push has not
    /// registered, not that the message has gone.
    private async Task DrainAsync(CancellationToken cancellation)
    {
        DateTime started = DateTime.UtcNow;
        DateTime giveUp = started + Patience;
        DateTime moved = started;
        int last = int.MinValue;
        bool wasEmpty = false;
        while (DateTime.UtcNow < giveUp)
        {
            int left = await AskAsync("", cancellation).ConfigureAwait(false);
            bool settling = DateTime.UtcNow - started < Settling;
            if (left != last || settling)
            {
                log.Write($"TxBufLen: {Answer(left)}");
                moved = left != last ? DateTime.UtcNow : moved;
                last = left;
            }
            if (left == 0 && wasEmpty && !settling)
            {
                return;
            }
            wasEmpty = left == 0;
            if (DateTime.UtcNow - moved > Still)
            {
                log.Write($"the count has not moved for {Still.TotalSeconds} s, so it is not counting down");
                return;
            }
            await Task.Delay(PollInterval, cancellation).ConfigureAwait(false);
        }
        log.Write($"gave up waiting after {Patience.TotalSeconds} s");
    }

    /// Waits until the engine holds no more than `wanted` characters, so the
    /// next thing the probe does lands at a known point in the message.
    private async Task<int> WaitForAsync(int wanted, CancellationToken cancellation)
    {
        DateTime giveUp = DateTime.UtcNow + Still;
        while (DateTime.UtcNow < giveUp)
        {
            int left = await AskAsync("", cancellation).ConfigureAwait(false);
            if (left <= wanted)
            {
                return left;
            }
            await Task.Delay(PollInterval, cancellation).ConfigureAwait(false);
        }
        log.Write($"the count never came down to {wanted}, so the backspaces go in wherever it is");
        return await AskAsync("", cancellation).ConfigureAwait(false);
    }

    /// N1MM's `{TX}`: the control's PTT property, then wait for the engine to
    /// say it is transmitting.
    private async Task<bool> KeyAsync(CancellationToken cancellation)
    {
        if (engine.IsTransmitting)
        {
            return true;
        }
        TaskCompletionSource<bool> keyed = new(TaskCreationOptions.RunContinuationsAsynchronously);
        lock (gate)
        {
            keying = keyed;
        }
        await engine.SetPttAsync(true, cancellation).ConfigureAwait(false);
        try
        {
            await keyed.Task.WaitAsync(Keying, cancellation).ConfigureAwait(false);
            log.Write("keyed");
            return true;
        }
        catch (TimeoutException)
        {
            log.Write($"no transmit report {Keying.TotalSeconds} s after keying");
            return false;
        }
    }

    /// N1MM's `{RX}`: stop once the buffer is empty. Waits for the engine to
    /// say it has stopped, because the next step keys again and would otherwise
    /// see the old state and skip it.
    private async Task UnkeyAsync(CancellationToken cancellation)
    {
        await engine.SetPttAsync(false, cancellation).ConfigureAwait(false);
        if (await StoppedAsync(cancellation).ConfigureAwait(false))
        {
            return;
        }
        log.Write("still transmitting, stopping it the hard way");
        await engine.AbortAsync(cancellation).ConfigureAwait(false);
        if (!await StoppedAsync(cancellation).ConfigureAwait(false))
        {
            log.Write("the engine is still reporting a transmission after the abort");
        }
    }

    private async Task<bool> StoppedAsync(CancellationToken cancellation)
    {
        DateTime giveUp = DateTime.UtcNow + Keying;
        while (engine.IsTransmitting && DateTime.UtcNow < giveUp)
        {
            await Task.Delay(PollInterval, cancellation).ConfigureAwait(false);
        }
        return !engine.IsTransmitting;
    }

    private async Task TypeAsync(string text, CancellationToken cancellation)
    {
        foreach (char character in text)
        {
            await engine.TypeAsync(character, cancellation).ConfigureAwait(false);
        }
    }

    /// Sends one question and waits for the answer. The bridge answers every
    /// question, with -1 when the control would not, so this cannot hang while
    /// the bridge is alive.
    private async Task<int> AskAsync(string property, CancellationToken cancellation)
    {
        TaskCompletionSource<int> answer = new(TaskCreationOptions.RunContinuationsAsynchronously);
        lock (gate)
        {
            asking = answer;
        }
        await engine.AskBufferedAsync(property, cancellation).ConfigureAwait(false);
        return await answer.Task.WaitAsync(Keying, cancellation).ConfigureAwait(false);
    }

    private static string Answer(int left) => left < 0 ? "no answer" : left.ToString();

    private void WhenBuffered(object? sender, int left)
    {
        lock (gate)
        {
            asking?.TrySetResult(left);
        }
    }

    private void WhenTransmitChanged(object? sender, bool transmitting)
    {
        log.Write(transmitting ? "engine keyed" : "engine unkeyed");
        if (!transmitting)
        {
            return;
        }
        lock (gate)
        {
            keying?.TrySetResult(true);
        }
    }

    /// While the engine is not transmitting this is the demodulator hearing
    /// whatever is on the band, which is noise on a quiet frequency. Only what
    /// arrives while transmitting is about the transmission.
    private void WhenReceived(object? sender, string text)
    {
        foreach (char character in text)
        {
            log.Write($"{(engine.IsTransmitting ? "rx" : "noise")} {Printable(character)}");
        }
        if (!engine.IsTransmitting)
        {
            return;
        }
        lock (received)
        {
            received.Append(text);
        }
    }

    private string TakeReceived()
    {
        lock (received)
        {
            string text = received.ToString();
            received.Clear();
            return text;
        }
    }

    /// Control codes matter here: a backspace coming back is the engine saying
    /// it removed a character.
    private static string Printable(char character) => character switch
    {
        '\b' => "\\b (backspace)",
        '\r' => "\\r",
        '\n' => "\\n",
        _ when char.IsControl(character) => $"\\x{(int)character:x2}",
        _ => character.ToString(),
    };
}