From 2aaaec020beabf16a154e3364039d1cc90638c26 Mon Sep 17 00:00:00 2001 From: Spike Curtis Date: Tue, 19 Sep 2023 11:23:44 +0400 Subject: [PATCH 1/5] Add more pty diagnostics for terminal parsing Signed-off-by: Spike Curtis --- testutil/pty.go | 15 ++++++++------- 1 file changed, 8 insertions(+), 7 deletions(-) diff --git a/testutil/pty.go b/testutil/pty.go index 956a77813adae..dd3a499266b50 100644 --- a/testutil/pty.go +++ b/testutil/pty.go @@ -21,20 +21,20 @@ func ReadUntilString(ctx context.Context, t *testing.T, want string, r io.Reader // ReadUntil emulates a terminal and reads one byte at a time until the matcher // returns true or the context expires. If the matcher is nil, read until EOF. // The PTY must be sized to 80x80 or there could be unexpected results. -func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line string) bool) error { +func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line string) bool) (retErr error) { // output can contain virtual terminal sequences, so we need to parse these // to correctly interpret getting what we want. + readBytes := make([]byte, 0) term := vt10x.New(vt10x.WithSize(80, 80)) readErrs := make(chan error, 1) defer func() { // Dump the terminal contents since they can be helpful for debugging, but - // skip empty lines since much of the terminal will usually be blank. + // trim empty lines since much of the terminal will usually be blank. got := term.String() - lines := strings.Split(got, "\n") - for _, line := range lines { - if strings.TrimSpace(line) != "" { - t.Logf("got: %v", line) - } + trimmed := strings.Trim(got, "\n") + t.Logf("Terminal contents:\n%s", trimmed) + if retErr != nil { + t.Logf("Bytes Read: %s", string(readBytes)) } }() for { @@ -48,6 +48,7 @@ func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line if err != nil { return err } + readBytes = append(readBytes, b...) _, err = term.Write(b) if err != nil { return err From e0c3f9b810ed2a9c899391231c4088fa05319ea8 Mon Sep 17 00:00:00 2001 From: Spike Curtis Date: Tue, 19 Sep 2023 11:37:10 +0400 Subject: [PATCH 2/5] print escaped strings Signed-off-by: Spike Curtis --- testutil/pty.go | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/testutil/pty.go b/testutil/pty.go index dd3a499266b50..59240c2360afb 100644 --- a/testutil/pty.go +++ b/testutil/pty.go @@ -31,10 +31,10 @@ func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line // Dump the terminal contents since they can be helpful for debugging, but // trim empty lines since much of the terminal will usually be blank. got := term.String() - trimmed := strings.Trim(got, "\n") - t.Logf("Terminal contents:\n%s", trimmed) + //trimmed := strings.Trim(got, "\n") + t.Logf("Terminal contents:\n%q", got) if retErr != nil { - t.Logf("Bytes Read: %s", string(readBytes)) + t.Logf("Bytes Read: %q", string(readBytes)) } }() for { From 1864a78b6fbd32c1d97f16adc1bfb203925fa8ab Mon Sep 17 00:00:00 2001 From: Spike Curtis Date: Tue, 19 Sep 2023 14:45:58 +0400 Subject: [PATCH 3/5] Only log on failure - heisenbug? Signed-off-by: Spike Curtis --- testutil/pty.go | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/testutil/pty.go b/testutil/pty.go index 59240c2360afb..1de041aad0dcf 100644 --- a/testutil/pty.go +++ b/testutil/pty.go @@ -28,12 +28,12 @@ func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line term := vt10x.New(vt10x.WithSize(80, 80)) readErrs := make(chan error, 1) defer func() { - // Dump the terminal contents since they can be helpful for debugging, but - // trim empty lines since much of the terminal will usually be blank. - got := term.String() - //trimmed := strings.Trim(got, "\n") - t.Logf("Terminal contents:\n%q", got) if retErr != nil { + // Dump the terminal contents since they can be helpful for debugging, but + // trim empty lines since much of the terminal will usually be blank. + got := term.String() + // trimmed := strings.Trim(got, "\n") + t.Logf("Terminal contents:\n%q", got) t.Logf("Bytes Read: %q", string(readBytes)) } }() From 01c3b0213e6ba80684a39f8b6a9affa2154da3c9 Mon Sep 17 00:00:00 2001 From: Spike Curtis Date: Tue, 19 Sep 2023 15:46:51 +0400 Subject: [PATCH 4/5] use the terminal across matches to keep cursor & contents state Signed-off-by: Spike Curtis --- agent/agent_test.go | 26 ++++++----- coderd/workspaceapps/apptest/apptest.go | 11 ++--- pty/start_test.go | 4 +- testutil/pty.go | 57 ++++++++++++++++++------- 4 files changed, 65 insertions(+), 33 deletions(-) diff --git a/agent/agent_test.go b/agent/agent_test.go index 80fa7435c7437..57cd14fd5da76 100644 --- a/agent/agent_test.go +++ b/agent/agent_test.go @@ -1669,13 +1669,15 @@ func TestAgent_ReconnectingPTY(t *testing.T) { } // Once for typing the command... - require.NoError(t, testutil.ReadUntil(ctx, t, netConn1, matchEchoCommand), "find echo command") + tr1 := testutil.NewTerminalReader(t, netConn1) + require.NoError(t, tr1.ReadUntil(ctx, matchEchoCommand), "find echo command") // And another time for the actual output. - require.NoError(t, testutil.ReadUntil(ctx, t, netConn1, matchEchoOutput), "find echo output") + require.NoError(t, tr1.ReadUntil(ctx, matchEchoOutput), "find echo output") // Same for the other connection. - require.NoError(t, testutil.ReadUntil(ctx, t, netConn2, matchEchoCommand), "find echo command") - require.NoError(t, testutil.ReadUntil(ctx, t, netConn2, matchEchoOutput), "find echo output") + tr2 := testutil.NewTerminalReader(t, netConn2) + require.NoError(t, tr2.ReadUntil(ctx, matchEchoCommand), "find echo command") + require.NoError(t, tr2.ReadUntil(ctx, matchEchoOutput), "find echo output") _ = netConn1.Close() _ = netConn2.Close() @@ -1684,8 +1686,9 @@ func TestAgent_ReconnectingPTY(t *testing.T) { defer netConn3.Close() // Same output again! - require.NoError(t, testutil.ReadUntil(ctx, t, netConn3, matchEchoCommand), "find echo command") - require.NoError(t, testutil.ReadUntil(ctx, t, netConn3, matchEchoOutput), "find echo output") + tr3 := testutil.NewTerminalReader(t, netConn3) + require.NoError(t, tr3.ReadUntil(ctx, matchEchoCommand), "find echo command") + require.NoError(t, tr3.ReadUntil(ctx, matchEchoOutput), "find echo output") // Exit should cause the connection to close. data, err = json.Marshal(codersdk.ReconnectingPTYRequest{ @@ -1696,19 +1699,20 @@ func TestAgent_ReconnectingPTY(t *testing.T) { require.NoError(t, err) // Once for the input and again for the output. - require.NoError(t, testutil.ReadUntil(ctx, t, netConn3, matchExitCommand), "find exit command") - require.NoError(t, testutil.ReadUntil(ctx, t, netConn3, matchExitOutput), "find exit output") + require.NoError(t, tr3.ReadUntil(ctx, matchExitCommand), "find exit command") + require.NoError(t, tr3.ReadUntil(ctx, matchExitOutput), "find exit output") // Wait for the connection to close. - require.ErrorIs(t, testutil.ReadUntil(ctx, t, netConn3, nil), io.EOF) + require.ErrorIs(t, tr3.ReadUntil(ctx, nil), io.EOF) // Try a non-shell command. It should output then immediately exit. netConn4, err := conn.ReconnectingPTY(ctx, uuid.New(), 80, 80, "echo test") require.NoError(t, err) defer netConn4.Close() - require.NoError(t, testutil.ReadUntil(ctx, t, netConn4, matchEchoOutput), "find echo output") - require.ErrorIs(t, testutil.ReadUntil(ctx, t, netConn3, nil), io.EOF) + tr4 := testutil.NewTerminalReader(t, netConn4) + require.NoError(t, tr4.ReadUntil(ctx, matchEchoOutput), "find echo output") + require.ErrorIs(t, tr4.ReadUntil(ctx, nil), io.EOF) }) } } diff --git a/coderd/workspaceapps/apptest/apptest.go b/coderd/workspaceapps/apptest/apptest.go index 05486695bd09a..38ffc56fa2c82 100644 --- a/coderd/workspaceapps/apptest/apptest.go +++ b/coderd/workspaceapps/apptest/apptest.go @@ -1428,8 +1428,9 @@ func testReconnectingPTY(ctx context.Context, t *testing.T, client *codersdk.Cli _, err = conn.Write(data) require.NoError(t, err) - require.NoError(t, testutil.ReadUntil(ctx, t, conn, matchEchoCommand), "find echo command") - require.NoError(t, testutil.ReadUntil(ctx, t, conn, matchEchoOutput), "find echo output") + tr := testutil.NewTerminalReader(t, conn) + require.NoError(t, tr.ReadUntil(ctx, matchEchoCommand), "find echo command") + require.NoError(t, tr.ReadUntil(ctx, matchEchoOutput), "find echo output") // Exit should cause the connection to close. data, err = json.Marshal(codersdk.ReconnectingPTYRequest{ @@ -1440,9 +1441,9 @@ func testReconnectingPTY(ctx context.Context, t *testing.T, client *codersdk.Cli require.NoError(t, err) // Once for the input and again for the output. - require.NoError(t, testutil.ReadUntil(ctx, t, conn, matchExitCommand), "find exit command") - require.NoError(t, testutil.ReadUntil(ctx, t, conn, matchExitOutput), "find exit output") + require.NoError(t, tr.ReadUntil(ctx, matchExitCommand), "find exit command") + require.NoError(t, tr.ReadUntil(ctx, matchExitOutput), "find exit output") // Ensure the connection closes. - require.ErrorIs(t, testutil.ReadUntil(ctx, t, conn, nil), io.EOF) + require.ErrorIs(t, tr.ReadUntil(ctx, nil), io.EOF) } diff --git a/pty/start_test.go b/pty/start_test.go index 4c077650e3814..dd3c8564a0ab0 100644 --- a/pty/start_test.go +++ b/pty/start_test.go @@ -67,11 +67,11 @@ func Test_Start_truncation(t *testing.T) { readDone := make(chan struct{}) go func() { defer close(readDone) - // avoid buffered IO so that we can precisely control how many bytes to read. + terminalReader := testutil.NewTerminalReader(t, pc.OutputReader()) n := 1 for n <= countEnd { want := fmt.Sprintf("%d", n) - err := testutil.ReadUntilString(ctx, t, want, pc.OutputReader()) + err := terminalReader.ReadUntilString(ctx, want) assert.NoError(t, err, "want: %s", want) if err != nil { return diff --git a/testutil/pty.go b/testutil/pty.go index 1de041aad0dcf..9edd553f10ea1 100644 --- a/testutil/pty.go +++ b/testutil/pty.go @@ -9,11 +9,28 @@ import ( "github.com/hinshun/vt10x" ) +// TerminalReader emulates a terminal and allows matching output. It's important in cases where we +// can get control sequences to parse them correctly, and keep the state of the terminal across the +// lifespan of the PTY, since some control sequences are relative to the current cursor position. +type TerminalReader struct { + t *testing.T + r io.Reader + term vt10x.Terminal +} + +func NewTerminalReader(t *testing.T, r io.Reader) *TerminalReader { + return &TerminalReader{ + t: t, + r: r, + term: vt10x.New(vt10x.WithSize(80, 80)), + } +} + // ReadUntilString emulates a terminal and reads one byte at a time until we // either see the string we want, or the context expires. The PTY must be sized // to 80x80 or there could be unexpected results. -func ReadUntilString(ctx context.Context, t *testing.T, want string, r io.Reader) error { - return ReadUntil(ctx, t, r, func(line string) bool { +func (tr *TerminalReader) ReadUntilString(ctx context.Context, want string) error { + return tr.ReadUntil(ctx, func(line string) bool { return strings.TrimSpace(line) == want }) } @@ -21,26 +38,36 @@ func ReadUntilString(ctx context.Context, t *testing.T, want string, r io.Reader // ReadUntil emulates a terminal and reads one byte at a time until the matcher // returns true or the context expires. If the matcher is nil, read until EOF. // The PTY must be sized to 80x80 or there could be unexpected results. -func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line string) bool) (retErr error) { - // output can contain virtual terminal sequences, so we need to parse these - // to correctly interpret getting what we want. +func (tr *TerminalReader) ReadUntil(ctx context.Context, matcher func(line string) bool) (retErr error) { readBytes := make([]byte, 0) - term := vt10x.New(vt10x.WithSize(80, 80)) readErrs := make(chan error, 1) defer func() { + // Dump the terminal contents since they can be helpful for debugging, but + // trim empty lines since much of the terminal will usually be blank. + got := tr.term.String() + lines := strings.Split(got, "\n") + for i := range lines { + if strings.TrimSpace(lines[i]) != "" { + lines = lines[i:] + break + } + } + for i := len(lines) - 1; i >= 0; i-- { + if strings.TrimSpace(lines[i]) != "" { + lines = lines[:i+1] + break + } + } + gotTrimmed := strings.Join(lines, "\n") + tr.t.Logf("Terminal contents:\n%s", gotTrimmed) if retErr != nil { - // Dump the terminal contents since they can be helpful for debugging, but - // trim empty lines since much of the terminal will usually be blank. - got := term.String() - // trimmed := strings.Trim(got, "\n") - t.Logf("Terminal contents:\n%q", got) - t.Logf("Bytes Read: %q", string(readBytes)) + tr.t.Logf("Bytes Read: %q", string(readBytes)) } }() for { b := make([]byte, 1) go func() { - _, err := r.Read(b) + _, err := tr.r.Read(b) readErrs <- err }() select { @@ -49,7 +76,7 @@ func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line return err } readBytes = append(readBytes, b...) - _, err = term.Write(b) + _, err = tr.term.Write(b) if err != nil { return err } @@ -60,7 +87,7 @@ func ReadUntil(ctx context.Context, t *testing.T, r io.Reader, matcher func(line // A nil matcher means to read until EOF. continue } - got := term.String() + got := tr.term.String() lines := strings.Split(got, "\n") for _, line := range lines { if matcher(line) { From 8bd27739ee4e4ac5cccb8479192cca54f60cf948 Mon Sep 17 00:00:00 2001 From: Spike Curtis Date: Tue, 19 Sep 2023 21:50:06 +0400 Subject: [PATCH 5/5] Only log bytes if we're not expecting EOF Signed-off-by: Spike Curtis --- testutil/pty.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/testutil/pty.go b/testutil/pty.go index 9edd553f10ea1..3ada3408a6b5e 100644 --- a/testutil/pty.go +++ b/testutil/pty.go @@ -6,6 +6,8 @@ import ( "strings" "testing" + "golang.org/x/xerrors" + "github.com/hinshun/vt10x" ) @@ -60,7 +62,8 @@ func (tr *TerminalReader) ReadUntil(ctx context.Context, matcher func(line strin } gotTrimmed := strings.Join(lines, "\n") tr.t.Logf("Terminal contents:\n%s", gotTrimmed) - if retErr != nil { + // EOF is expected when matcher == nil + if retErr != nil && !(xerrors.Is(retErr, io.EOF) && matcher == nil) { tr.t.Logf("Bytes Read: %q", string(readBytes)) } }()