Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 7 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,13 @@
reconnected. The daemon now forwards the time a request has left, the seat takes its own waits off as
well, and a desktop operation is stopped a second before its time runs out, so one queued behind
another answers, or fails, in time.
- **A desktop action that runs out of time says so.** An action stopped at its deadline, such as a
`seat_wait` left with less time than its wait after queueing behind a long display change, answered
with a bare "TaskCanceledException: A task was canceled.", which said neither that time ran out nor
whether anything ran. It now fails with `errorCode: "timed_out"` and the time the request had,
and `started: false` and "Nothing was done" when it was still waiting for the desktop, or
`started: true` when it was stopped partway; a read-only action says that nothing changed. A request
whose time ran out before it was even sent also answers `timed_out` with `started: false`.
- **Typing keeps pace with the program.** `seat_type` and `anode type` sent characters as fast as
Windows took them, so a busy program, such as Chrome editing a long field, could drop and reorder
them while the call still reported success. Characters now go out 15 ms apart by default, timed
Expand Down
6 changes: 6 additions & 0 deletions docs/PROTOCOL.md
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,12 @@ daemon forwards a request with `timeoutMs` set to the time it has left after wai
operations on its one connection to the seat host (waits under 100 ms aren't counted), and the seat
host takes its own waits off as well. A desktop operation is stopped a second (or an eighth of a
shorter time) before that time runs out, so even one cut short answers before its caller gives up.
It fails with `errorCode: "timed_out"`, and `started` says how far it got: `false` when it was still
waiting for the desktop behind an earlier operation and did nothing, `true` when it was stopped
partway and may have done some of its work (one that only reads, such as `desktop.wait`, changed
nothing even then). A request whose time runs out before it is sent at all, in a client's queue or
the daemon's, fails the same way with `started: false`. Once started, operations that bound their own
work by the time, such as `input.text`, report their own failure instead.
Limits derived from the time, such as how much one `input.text` may type, shrink with it.

Desktop operations additionally require an `agentId` and live `leaseToken`, acquired through
Expand Down
10 changes: 7 additions & 3 deletions docs/TROUBLESHOOTING.md
Original file line number Diff line number Diff line change
Expand Up @@ -41,9 +41,13 @@ with an ordinary terminal. Only `anode setup` needs administrator approval.

### A command timed out and the viewer is still connected

The timed-out command may have executed. Check the seat before repeating it. Run `anode start`
to reconnect the seat host if the daemon reports it is not ready; Anode can recover that connection
without waiting for the viewer to reconnect. `anode kill` remains available to stop the seat.
The timed-out command may have executed. Check the seat before repeating it. A desktop action that
the seat stopped at its deadline says how far it got: `timed_out` with `started: false` did nothing,
since it was still waiting behind an earlier action; with `started: true` it was stopped partway (one
that only reads, such as `seat_wait`, changed nothing).
Run `anode start` to reconnect the seat host if the daemon reports it is not ready; Anode can
recover that connection without waiting for the viewer to reconnect. `anode kill` remains available
to stop the seat.

### "Remote Desktop host: fDenyTSConnections = 1"

Expand Down
70 changes: 70 additions & 0 deletions src/Anode/Cli/AgentChecks.cs
Original file line number Diff line number Diff line change
Expand Up @@ -337,6 +337,76 @@ async Task<JsonObject> Hold(JsonObject request, CancellationToken cancel)
return "an action queued behind another of its agent's runs in the time its caller has left, and stops before it";
}

/// <summary>
/// A desktop action its deadline cuts short answers <c>timed_out</c> with the time it had and whether it started,
/// not a bare "A task was canceled.": one still queued did nothing. A stopping seat still cancels.
/// </summary>
public static async Task<string> DeadlineReplies()
{
var entered = Signal(); var finish = Signal();
var record = new System.Collections.Concurrent.ConcurrentQueue<string>();
var lease = new DesktopLease(record: record.Enqueue);
int dispatched = 0;
async Task<JsonObject> Dispatch(JsonObject request, CancellationToken cancel)
{
Interlocked.Increment(ref dispatched);
if (request.Str("text") == "first")
{
entered.TrySetResult();
await finish.Task;
return JsonLine.Ok();
}
await Task.Delay(Timeout.Infinite, cancel); // An action that doesn't size its work by its time.
return JsonLine.Ok();
}
string token = (await lease.HandleAsync(Lease("A", "acquire"), Dispatch)).Obj("result")!.Str("leaseToken")!;
Task<JsonObject> first = lease.HandleAsync(Input("A", token, "first"), Dispatch);
JsonObject queued;
try
{
await entered.Task.WaitAsync(TimeSpan.FromSeconds(2));
var waiting = Input("A", token, "queued");
waiting["timeoutMs"] = 800;
queued = await lease.HandleAsync(waiting, Dispatch).WaitAsync(TimeSpan.FromSeconds(5));
}
finally { finish.TrySetResult(); }
Require((await first.WaitAsync(TimeSpan.FromSeconds(2))).Bool("ok") == true, "the action in front failed");
Require(dispatched == 1, $"a request that never got the desktop was dispatched ({dispatched} dispatches)");
Require(queued.Bool("ok") == false && queued.Str("errorCode") == "timed_out" && queued.Bool("started") == false
&& queued.Str("error") is { } never && never.Contains("800 ms") && never.Contains("Nothing was done"),
"a request that ran out of time in the queue did not say so: " + queued.ToJsonString());

var held = Input("A", token, "held");
held["timeoutMs"] = 1500;
var stopped = await lease.HandleAsync(held, Dispatch).WaitAsync(TimeSpan.FromSeconds(5));
Require(stopped.Bool("ok") == false && stopped.Str("errorCode") == "timed_out" && stopped.Bool("started") == true
&& stopped.Str("error") is { } partway && partway.Contains("1.5 s") && partway.Contains("may have run"),
"an action stopped partway did not say so: " + stopped.ToJsonString());
var look = new JsonObject { ["op"] = "desktop.wait", ["agentId"] = "A", ["leaseToken"] = token, ["windowId"] = "w_1", ["textContains"] = "never", ["timeoutMs"] = 1000 };
var read = await lease.HandleAsync(look, Dispatch).WaitAsync(TimeSpan.FromSeconds(5));
Require(read.Str("errorCode") == "timed_out" && read.Bool("started") == true && read.Str("error") is { } safe
&& safe.Contains("nothing changed") && !safe.Contains("may have run"), "a read-only action stopped partway was said to have acted: " + read.ToJsonString());
var start = new JsonObject { ["op"] = "exec.start", ["agentId"] = "A", ["leaseToken"] = token, ["path"] = "unused-test-command", ["timeoutMs"] = 1000 };
var started = await lease.HandleAsync(start, Dispatch).WaitAsync(TimeSpan.FromSeconds(5));
Require(started.Str("errorCode") == "timed_out" && started.Bool("started") == true && started.Str("error") is { } job
&& job.Contains("seat_job action=list"), "a command start cut short didn't point at the job list: " + started.ToJsonString());
Require(record.Any(line => line == "'input.text' ran out of its 800 ms before it got the desktop")
&& record.Any(line => line == "'input.text' ran out of its 1.5 s and was stopped"), "a timeout left no log line: " + string.Join(" | ", record));
Require((await lease.HandleAsync(Input("A", token, "first"), Dispatch).WaitAsync(TimeSpan.FromSeconds(2))).Bool("ok") == true,
"a timed-out action kept the desktop from the next one");

using var stopping = new CancellationTokenSource();
Task<JsonObject> during = lease.HandleAsync(Input("A", token, "held"), Dispatch, stopping.Token);
stopping.Cancel();
try
{
var reply = await during.WaitAsync(TimeSpan.FromSeconds(2));
throw new InvalidOperationException("a stopping seat's cancellation was answered as a timeout: " + reply.ToJsonString());
}
catch (OperationCanceledException) { }
return "an action cut short by its deadline answers timed_out with its time and how far it got: nothing done, nothing changed, a job to find, or input that may have run";
}

public static async Task<string> Line()
{
long now = 0;
Expand Down
1 change: 1 addition & 0 deletions src/Anode/Cli/SelfTest.cs
Original file line number Diff line number Diff line change
Expand Up @@ -144,6 +144,7 @@ public static int Run(string[] args)
Check(results, "MCP lease client process", () => McpChecks.LeaseClientProcess().GetAwaiter().GetResult());
Check(results, "agent queue and disconnect", () => AgentChecks.QueueAndDisconnect().GetAwaiter().GetResult());
Check(results, "agent queue time", () => AgentChecks.QueueTime().GetAwaiter().GetResult());
Check(results, "agent deadline replies", () => AgentChecks.DeadlineReplies().GetAwaiter().GetResult());
Check(results, "agent line", () => AgentChecks.Line().GetAwaiter().GetResult());
Check(results, "agent names", () => AgentChecks.Names().GetAwaiter().GetResult());
Check(results, "MCP ownership", () => AgentChecks.McpOwnership().GetAwaiter().GetResult());
Expand Down
8 changes: 6 additions & 2 deletions src/Anode/Cli/TransportChecks.cs
Original file line number Diff line number Diff line change
Expand Up @@ -44,7 +44,8 @@ public static async Task<string> QueueDeadline()
{
await entered.Task.WaitAsync(TimeSpan.FromSeconds(3));
var queued = await client.RequestAsync("queued", timeoutMs: 100).WaitAsync(TimeSpan.FromSeconds(2));
Require(queued.Bool("ok") == false && queued.Str("error")!.Contains("timed out"), "queued request did not time out");
Require(queued.Bool("ok") == false && queued.Str("error")!.Contains("timed out")
&& queued.Str("errorCode") == "timed_out" && queued.Bool("started") == false, "queued request did not time out as never sent: " + queued.ToJsonString());
Require(!first.IsCompleted && client.IsConnected, "queue timeout interrupted the active request");
}
finally { release.TrySetResult(); }
Expand Down Expand Up @@ -109,7 +110,8 @@ public static async Task<string> ForwardTimeLeft()
finally { release.TrySetResult(); }
var unsent = await starved.WaitAsync(TimeSpan.FromSeconds(3));
Require((await first.WaitAsync(TimeSpan.FromSeconds(3))).Bool("ok") == true && unsent.Bool("ok") == false
&& !given.ContainsKey("starved") && seat.IsConnected, "a request with almost no time left was sent, or cost the connection: " + unsent.ToJsonString());
&& !given.ContainsKey("starved") && seat.IsConnected && unsent.Str("errorCode") == "timed_out" && unsent.Bool("started") == false,
"a request with almost no time left was sent, cost the connection, or didn't say it never started: " + unsent.ToJsonString());
return "the daemon forwards each request with its caller's time left, so time queued behind another isn't counted twice";
}

Expand All @@ -126,6 +128,8 @@ public static async Task<string> LateReply()
?? throw new InvalidOperationException("could not connect to the test pipe");
var timedOut = await client.RequestAsync("slow", timeoutMs: 100);
Require(timedOut.Bool("ok") == false && !client.IsConnected, "timed-out connection stayed reusable");
// It was sent, so it may have run: it must not claim, as an unsent request does, that it never started.
Require(timedOut["started"] is null, "a request timed out after it was sent claimed it never started: " + timedOut.ToJsonString());
var next = await client.RequestAsync("next", timeoutMs: 4000);
Require(next.Bool("ok") == false, "a late reply was accepted as the next result");
using var fresh = await JsonPipeClient.TryConnectAsync(name, 4000)
Expand Down
34 changes: 31 additions & 3 deletions src/Anode/Core/Agents/DesktopLease.cs
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
using System.Diagnostics;
using System.Globalization;
using System.Text.Json.Nodes;
using Anode.Core.Bridge;

Expand Down Expand Up @@ -36,7 +37,7 @@ private sealed class Waiter(string agent, string? name, long seen)
private long _clientStarted;
private bool _active;

/// <param name="record">Receives a line each time the desktop changes hands, for the log.</param>
/// <param name="record">Receives a line for the log each time the desktop changes hands or an action runs out of time.</param>
public DesktopLease(Action? invalidateReferences = null, Func<string, int>? cancelJobs = null, Func<long>? milliseconds = null,
Action<string>? record = null, Func<int, long, bool>? clientAlive = null)
{
Expand Down Expand Up @@ -204,6 +205,28 @@ private JsonObject Manage(JsonObject request)
/// </summary>
internal static int StopAfterMs(int timeoutMs) => Math.Max(1, timeoutMs - Math.Min(1000, timeoutMs / 8));

/// <summary>
/// The failure for a desktop action its deadline cut short. It names the time the request had and says whether
/// the action had started: one still waiting for the desktop did nothing, one stopped partway may have done some,
/// unless it only reads.
/// </summary>
private JsonObject TimedOut(string op, int timeoutMs, bool started)
{
string time = timeoutMs < 1000 ? $"{timeoutMs} ms" : (timeoutMs / 1000.0).ToString("0.#", CultureInfo.InvariantCulture) + " s";
string message = !started
? $"The request ran out of its {time} while it waited behind an earlier desktop action, so it never started. Nothing was done."
: $"The desktop action ran out of its {time} and was stopped. " + (Mcp.Tools.ReadsOnly(op)
? "It only reads the desktop, so nothing changed, and it is safe to repeat."
: op == "exec.start"
? "The command may have started: look for it with seat_job action=list before starting it again."
: "Part of it may have run: observe the desktop before acting again, and don't repeat it unseen.");
_record($"'{op}' ran out of its {time}" + (started ? " and was stopped" : " before it got the desktop"));
var failure = JsonLine.Fail(message);
failure["errorCode"] = "timed_out";
failure["started"] = started;
return failure;
}

public async Task<JsonObject> HandleAsync(JsonObject request,
Func<JsonObject, CancellationToken, Task<JsonObject>> dispatch, CancellationToken cancel = default)
{
Expand All @@ -216,9 +239,13 @@ public async Task<JsonObject> HandleAsync(JsonObject request,
if (!AgentAccess.RequiresLease(op)) return await dispatch(request, cancel).ConfigureAwait(false);
lock (_state) { if (Check(request) is { } error) return error; }

int timeoutMs = request.Int("timeoutMs") ?? 60000;
using var deadline = CancellationTokenSource.CreateLinkedTokenSource(cancel);
deadline.CancelAfter(StopAfterMs(request.Int("timeoutMs") ?? 60000));
await _interaction.WaitAsync(deadline.Token).ConfigureAwait(false);
deadline.CancelAfter(StopAfterMs(timeoutMs));
// Only the deadline's own cancellation is a timeout; a stopping seat still cancels as before.
bool OutOfTime() => deadline.IsCancellationRequested && !cancel.IsCancellationRequested;
try { await _interaction.WaitAsync(deadline.Token).ConfigureAwait(false); }
catch (OperationCanceledException) when (OutOfTime()) { return TimedOut(op, timeoutMs, started: false); }
bool admitted = false;
try
{
Expand All @@ -239,6 +266,7 @@ public async Task<JsonObject> HandleAsync(JsonObject request,
lock (_state) { if (_line.Count > 0) response["waitingAgents"] = _line.Count; }
return response;
}
catch (OperationCanceledException) when (OutOfTime()) { return TimedOut(op, timeoutMs, admitted); }
finally
{
try { if (admitted) lock (_state) { _active = false; Expire(); } }
Expand Down
17 changes: 14 additions & 3 deletions src/Anode/Core/Bridge/Pipes.cs
Original file line number Diff line number Diff line change
Expand Up @@ -296,8 +296,7 @@ public async Task<JsonObject> RequestAsync(string op, JsonObject? args = null, i
{
long left = timeoutMs - (Environment.TickCount64 - started);
// With almost no time left, any reply would come too late, and a late reply costs the connection.
if (deadline.IsCancellationRequested || left < Math.Min(100, timeoutMs / 8))
return JsonLine.Fail($"'{op}' timed out after {timeoutMs} ms while it waited; nothing was sent");
if (deadline.IsCancellationRequested || left < Math.Min(100, timeoutMs / 8)) return NotSent(op, timeoutMs);
request["timeoutMs"] = TimeLeft(timeoutMs, timeoutMs - left);
}
sent = true;
Expand All @@ -315,7 +314,7 @@ public async Task<JsonObject> RequestAsync(string op, JsonObject? args = null, i
// the command: it may already have changed something in the seat.
if (sent) Close();
cancel.ThrowIfCancellationRequested();
return JsonLine.Fail($"'{op}' timed out after {timeoutMs} ms");
return sent ? JsonLine.Fail($"'{op}' timed out after {timeoutMs} ms") : NotSent(op, timeoutMs);
}
catch (IOException ex)
{
Expand All @@ -333,6 +332,18 @@ public async Task<JsonObject> RequestAsync(string op, JsonObject? args = null, i
}
}

/// <summary>
/// A request whose time ran out before it went out. It carries the seat host's <c>timed_out</c> failure for an
/// action that never got the desktop, so a caller can tell that nothing ran.
/// </summary>
private static JsonObject NotSent(string op, int timeoutMs)
{
var failure = JsonLine.Fail($"'{op}' timed out after {timeoutMs} ms while it waited; nothing was sent");
failure["errorCode"] = "timed_out";
failure["started"] = false;
return failure;
}

/// <summary>
/// What is left of a request's time after a wait. Waits under 100 ms (a sixteenth of a shorter time) are the
/// ordinary cost of passing a request on and aren't counted, so limits derived from the time, such as how much
Expand Down
3 changes: 3 additions & 0 deletions src/Anode/Mcp/Tools.cs
Original file line number Diff line number Diff line change
Expand Up @@ -446,6 +446,9 @@ public static JsonArray Definitions()
/// </summary>
internal static bool ActsOnScreen(string op) => op.StartsWith("input.", StringComparison.Ordinal) || op is "gamepad.set" or "gamepad.tap";

/// <summary>Whether an operation only reads, as its tool's read-only hint says: stopping it partway changed nothing.</summary>
internal static bool ReadsOnly(string op) => All.Any(tool => tool.Op == op && tool.Effect == Effect.ReadOnly);

public static bool TryResolve(string name, out string op, out bool startsDaemon)
{
foreach (var tool in All)
Expand Down
Loading