From 6302e396da5105f15e7cf15b42a07acb09082b10 Mon Sep 17 00:00:00 2001 From: Alessandro Rinaldi Date: Sat, 5 Sep 2026 21:25:55 +0200 Subject: [PATCH] shell: say what a long command line's timeout probably means MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Past a limit of its own a remote shell truncates the typed line and says nothing; the exit-code marker goes with it, so -c waits for output that cannot come and eventually reports a bare "timed out waiting for command to finish", which explains nothing. The limits differ by shell — a megabyte with bash, 4094 characters under dash, 8190 on cmd.exe — and dwshell cannot know which shell answers, so it cannot predict this. What it can do is read two things it already has: how long the line it sent was, and whether anything ran at all. Past 4000 characters, the lowest point any measured shell truncates at, the timeout now names truncation as a possible cause and points at `dwshell put`. It stays a possibility, never a diagnosis: a command still running looks the same from here, which is why the hint is gated on a length that could actually have been cut. Below that length the message is unchanged. Nothing is added to the wire and nothing is typed at the remote — the lesson of the reverted probe (v1.3.9), whose extra typed line was eaten by commands reading stdin. Verified live: a 12000-character line on a Windows agent gets the hint, while `sleep 60` against an 8s timeout still gets the plain message. Closes #3. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01MvidAFW9a2r4hTgHPW9ywG --- internal/app/shell/run.go | 29 ++++++++++++++++++++++-- internal/app/shell/timeout_test.go | 36 ++++++++++++++++++++++++++++++ 2 files changed, 63 insertions(+), 2 deletions(-) create mode 100644 internal/app/shell/timeout_test.go diff --git a/internal/app/shell/run.go b/internal/app/shell/run.go index 0727809..2aed4f3 100644 --- a/internal/app/shell/run.go +++ b/internal/app/shell/run.go @@ -38,6 +38,29 @@ func wrapCommand(cmd string, os remote.OS) string { return fmt.Sprintf("echo __DWSH_BEGIN__; ( %s ); echo __DWSH_RC_$?_END__\r", cmd) } +// truncationHintLength is the point past which a remote shell could have +// truncated the command line. The lowest limit measured is a shell reading in +// canonical mode, cut by the tty at 4094 characters; below that no remote is +// known to truncate, so the hint could only mislead. +const truncationHintLength = 4000 + +// timeoutErr explains a timeout, adding what a truncated command line looks +// like when the line was long enough for that to be possible — past its limit a +// remote shell cuts the line silently and the exit-code marker goes with it, so +// the wait can never end. +// +// It stays a possibility, never a diagnosis: a command that is simply still +// running looks exactly the same from here. Seeing the BEGIN marker only rules +// out the case where nothing ran at all, not the slow one. +func timeoutErr(out []byte, lineLen int) error { + if lineLen > truncationHintLength && reBegin.Match(out) { + return fmt.Errorf("timed out waiting for command to finish; the command line was %d characters, "+ + "and past a limit of its own the remote shell truncates the line silently, losing the exit-code "+ + "marker — if that is what happened here, upload it with `dwshell put` and run it by path", lineLen) + } + return fmt.Errorf("timed out waiting for command to finish") +} + // Run executes a single command non-interactively and returns its output and // exit code. It opens a fresh shell, sends the wrapped command, and reads until // the RC sentinel (or ctx/timeout fires). @@ -54,7 +77,8 @@ func Run(ctx context.Context, sess *session.Session, os remote.OS, command strin return nil, err } - if err := sh.Input(wrapCommand(command, os)); err != nil { + wrapped := wrapCommand(command, os) + if err := sh.Input(wrapped); err != nil { return nil, err } @@ -74,7 +98,8 @@ func Run(ctx context.Context, sess *session.Session, os remote.OS, command strin case <-ctx.Done(): return nil, ctx.Err() case <-timeoutCh: - return nil, fmt.Errorf("timed out waiting for command to finish") + // The line as typed, minus the Enter that submits it. + return nil, timeoutErr(buf.Bytes(), len(wrapped)-1) case chunk, ok := <-sh.Output(): if !ok { if sh.Err() != nil { diff --git a/internal/app/shell/timeout_test.go b/internal/app/shell/timeout_test.go new file mode 100644 index 0000000..32da72a --- /dev/null +++ b/internal/app/shell/timeout_test.go @@ -0,0 +1,36 @@ +package shell + +import ( + "strings" + "testing" +) + +// A short command line cannot have been truncated by any remote shell, so the +// timeout must not speculate about it. +func TestTimeoutErrStaysPlainForAShortLine(t *testing.T) { + err := timeoutErr([]byte("__DWSH_BEGIN__\r\nsome output\r\n"), 120) + if got := err.Error(); got != "timed out waiting for command to finish" { + t.Fatalf("expected the plain timeout message, got %q", got) + } +} + +// Long enough to have been cut, and something did run: offer truncation as a +// possibility, with the way around it. +func TestTimeoutErrHintsTruncationForALongLine(t *testing.T) { + err := timeoutErr([]byte("__DWSH_BEGIN__\r\nsome output\r\n"), 9000) + got := err.Error() + for _, want := range []string{"timed out", "9000", "truncate", "dwshell put"} { + if !strings.Contains(got, want) { + t.Errorf("message %q does not mention %q", got, want) + } + } +} + +// Nothing ran at all — the marker never came back — so truncation is not the +// story and the hint would mislead. +func TestTimeoutErrStaysPlainWhenNothingRan(t *testing.T) { + err := timeoutErr([]byte("no marker here"), 9000) + if got := err.Error(); got != "timed out waiting for command to finish" { + t.Fatalf("expected the plain timeout message, got %q", got) + } +}