How to view current terminal contents?

Hi there.

I've spent a good bit of time over the past few weeks trying to make this library work with a legacy application we have. Invariably, it goes off the rails sometimes in weird ways. I suspect it's our app, and not your library, but I wonder what the best way to view the contents of the virtual terminal is?

It appears to me that I should be able state.String(), but this doesn't actually get flushed to until a match happens as far as I can tell. What I want to do is troubleshoot the contents of the terminal if a match doesn't happen. Am I correct in my understanding that the only true way to get the current state of the terminal is to match something?

Thanks in advance.

Sorry...better stated, it doesn't get flushed until Expect is called, and Expect won't return until a match happens. So, there's no way to say "read the contents of the terminal, even if a match doesn't occur, and tell me what they are"....this would be tremendously useful for debugging, so I'm hoping I'm missing something obvious.

Hi @d1rewolf, you can get the current state of the terminal without matching something. Here's a small example of how we use it internally:

package program

import (
	"context"
	"fmt"
	"os/exec"
	"runtime/debug"
	"strings"
	"testing"
	"time"

	expect "github.com/Netflix/go-expect"
	"github.com/hinshun/vt10x"
	"github.com/kr/pty"
	"golang.org/x/sync/errgroup"
)

func NewVTConsole(t *testing.T, opts ...expect.ConsoleOpt) (*expect.Console, *vt10x.State, error) {
	ptm, pts, err := pty.Open()
	if err != nil {
		return nil, nil, err
	}

	var screen vt10x.State
	term, err := vt10x.Create(&screen, pts)
	if err != nil {
		return nil, nil, err
	}

	opts = append([]expect.ConsoleOpt{
		expectNoError(t),
		sendNoError(t),
		expect.WithDefaultTimeout(5 * time.Second),
		expect.WithStdin(ptm),
		expect.WithStdout(term),
		expect.WithCloser(pts, ptm, term),
	}, opts...)

	c, err := expect.NewConsole(opts...)
	if err != nil {
		return nil, nil, err
	}

	return c, &screen, nil
}

func expectNoError(t *testing.T) expect.ConsoleOpt {
	return expect.WithExpectObserver(
		func(matchers []expect.Matcher, buf string, err error) {
			if err == nil {
				return
			}

			if len(matchers) == 0 {
				t.Errorf("Error occurred while matching %q: %s\n%s", buf, err, string(debug.Stack()))
			} else {
				var criteria []string
				for _, matcher := range matchers {
					criteria = append(criteria, fmt.Sprintf("%q", matcher.Criteria()))
				}
				t.Errorf("Failed to find [%s] in %q: %s\n%s", strings.Join(criteria, ", "), buf, err, string(debug.Stack()))
			}
		},
	)
}

func sendNoError(t *testing.T) expect.ConsoleOpt {
	return expect.WithSendObserver(
		func(msg string, n int, err error) {
			if err != nil {
				t.Errorf("Failed to send %q: %s\n%s", msg, err, string(debug.Stack()))
			}
			if len(msg) != n {
				t.Errorf("Only sent %d of %d bytes for %q\n%s", n, len(msg), msg, string(debug.Stack()))
			}
		},
	)
}

func TestProgram(t *testing.T) {
	c, screen, err := NewVTConsole(t)
	if err != nil {
		t.Fatalf("err: %s", err)
	}

	defer c.Close()
	defer func() {
		t.Logf("\n%s", expect.StripTrailingEmptyLines(screen.String()))
	}()

	cmd := exec.Command("echo", "hello")
	cmd.Stdin = c.Tty()
	cmd.Stdout = c.Tty()
	cmd.Stderr = c.Tty()

	eg, _ := errgroup.WithContext(context.Background())

	eg.Go(func() error {
		c.ExpectString("hello")
		c.Tty().Close()
		c.ExpectEOF()
		return nil
	})

	eg.Go(func() error {
		return cmd.Run()
	})

	err = eg.Wait()
	if err != nil {
		t.Fatalf("err: %s", err)
	}
}

When running go test -v . we see this:

❯ go test -v .
=== RUN   TestProgram
--- PASS: TestProgram (0.00s)
    program_test.go:88:
        hello
PASS
ok  	github.com/hinshun/expectfoo	0.005s

Changing c.ExpectString("hello") to c.ExpectString("world") will cause to test to timeout after 5 seconds, so we attach a ExpectObserver to write out what match was failing:

❯ go test -v .
=== RUN   TestProgram
--- FAIL: TestProgram (5.00s)
    program_test.go:61: Failed to find ["world"] in "hello\r\n": read |0: i/o timeout
        goroutine 10 [running]:
        runtime/debug.Stack(0xc000112010, 0x1, 0x1)
        	/usr/local/go/src/runtime/debug/stack.go:24 +0x9d
        github.com/hinshun/expectfoo.expectNoError.func1(0xc0000fe020, 0x1, 0x1, 0xc000110007, 0x7, 0x5977e0, 0xc00010e000)
        	/home/edgarl/code/expectfoo/program_test.go:61 +0x1ba
        github.com/Netflix/go-expect.(*Console).Expect.func1(0xc0000ca000, 0xc00008ce18, 0xc000102000, 0xc00008ce28, 0xc000100020)
        	/home/edgarl/go/pkg/mod/github.com/!netflix/go-expect@v0.0.0-20200312175327-da48e75238e2/expect.go:76 +0xad
        github.com/Netflix/go-expect.(*Console).Expect(0xc0000ca000, 0xc00008ced8, 0x1, 0x1, 0xc000110000, 0x7, 0x5977e0, 0xc00010e000)
        	/home/edgarl/go/pkg/mod/github.com/!netflix/go-expect@v0.0.0-20200312175327-da48e75238e2/expect.go:96 +0x87d
        github.com/Netflix/go-expect.(*Console).ExpectString(0xc0000ca000, 0x56ca69, 0x5, 0x0, 0x0, 0x0, 0x0)
        	/home/edgarl/go/pkg/mod/github.com/!netflix/go-expect@v0.0.0-20200312175327-da48e75238e2/expect.go:35 +0xac
        github.com/hinshun/expectfoo.TestProgram.func2(0xc000047f68, 0x0)
        	/home/edgarl/code/expectfoo/program_test.go:99 +0x48
        golang.org/x/sync/errgroup.(*Group).Go.func1(0xc0000865d0, 0xc00005a590)
        	/home/edgarl/go/pkg/mod/golang.org/x/sync@v0.0.0-20200625203802-6e8e738ad208/errgroup/errgroup.go:57 +0x64
        created by golang.org/x/sync/errgroup.(*Group).Go
        	/home/edgarl/go/pkg/mod/golang.org/x/sync@v0.0.0-20200625203802-6e8e738ad208/errgroup/errgroup.go:54 +0x66
    program_test.go:88:
        hello
FAIL
FAIL	github.com/hinshun/expectfoo	5.004s
FAIL

Note how at the bottom we still see the screen output. Format that however you wish:

    program_test.go:88:
        hello
FAIL
FAIL	github.com/hinshun/expectfoo	5.004s
FAIL

Wow...thank you so much for the quick response and helpful example! I'll digest this and adjust my approach.

Thanks again!!!

Hello @hinshun...I think part of our problem may be that the match is occurring before the entire screen has finished drawing. Is it possible to defer a match until the screen is fully rendered?

And if you're referring to access the console contents from screen.String() above, this is how I've been trying this as well. However, I find that this "screen" is only updated if Expect is called. For example, I can do something like:

  log.Printf("Contents: %v", screen.String())
  console.Send("U")
  log.Printf("Contents: %v", screen.String())
  console.Send("W")
  log.Printf("Contents: %v", screen.String()) 
  console.Send("X")

What's logged as the output of screen.String() doesn't change between these Sends, even though our application should definitely be responding to these keystrokes. I think Expect has to be called, specifically this block:

go-expect/expect.go

Line 80 in da48e75

for {

...in order to have the console updated appropriately. Is this correct?

@d1rewolf , The stdout is only read when something is Expected, so it makes sense that the screen hasn't finished drawing. Yes you need to call Expect for the console to read anything.

When you send characters, the program stdout doesn't progress until you read. So if you're interacting with a shell, you need to match something to know when you can send more characters, for example a new-lined shell prompt \n#:

c.ExpectString("\n#")
c.SendLine("cd subdir")
c.ExpectString("\n#")
c.SendLine("cat myfile")
contents, _ := c.ExpectString("\n#")
c.SendLine("exit")
c.ExpectEOF()

Ok, @hinshun, thank you for your response. Because our application is a curses-based application, it's be nice to be able to inspect the screen before we do an expect for troubleshooting. However, I'm glad I properly understood the limitation and will adjust our plans accordingly. Thanks again!