Lots of output causes hangs

qemu/qemu.go

@@ -528,6 +528,14 @@ func (v *VM) Waited() bool {
 func (v *VM) Wait() error {
 	v.waitCalled.Store(true)
 
+	// If there is a lot of output after the last user's Expect call (or
+	// there are no Expect calls at all), the pty buffer may fill up and
+	// the guest is blocked from writing anything and from continuing
+	// execution.
+	//
+	// Therefore, drain! EOF should happen when the guest exits.
+	_, _ = v.Console.ExpectEOF()
+
 	<-v.wait
 
 	v.waitMu.Lock()

qemu/qemu_test.go

@@ -276,13 +276,13 @@ func TestStartVM(t *testing.T) {
 	uopts := uroot.Opts{
 		Env:        env,
 		InitCmd:    "init",
-		UinitCmd:   "qemutest1",
+		UinitCmd:   "helloworld",
 		OutputFile: initrdWriter,
 		TempDir:    tmp,
 	}
 	uopts.AddBusyBoxCommands(
 		"github.com/u-root/u-root/cmds/core/init",
-		"github.com/hugelgupf/vmtest/tests/cmds/qemutest1",
+		"github.com/hugelgupf/vmtest/tests/cmds/helloworld",
 	)
 	if err := uroot.CreateInitramfs(logger, uopts); err != nil {
 		t.Fatalf("error creating initramfs: %v", err)
@@ -298,7 +298,7 @@ func TestStartVM(t *testing.T) {
 	}
 	t.Logf("cmdline: %#v", vm.CmdlineQuoted())
 
-	if _, err := vm.Console.ExpectString("I AM HERE"); err != nil {
+	if _, err := vm.Console.ExpectString("Hello world"); err != nil {
 		t.Errorf("Error expecting I AM HERE: %v", err)
 	}
 

tests/cmds/catfile/.gitignore

@@ -0,0 +1 @@
+catfile

tests/cmds/catfile/main_linux.go

@@ -0,0 +1,41 @@
+// Command catfile reads a file.
+package main
+
+import (
+	"flag"
+	"fmt"
+	"log"
+	"os"
+
+	"github.com/hugelgupf/vmtest/guest"
+	"golang.org/x/sys/unix"
+)
+
+var file = flag.String("file", "", "Filepath to read")
+
+func realMain() error {
+	cleanup, err := guest.MountSharedDir()
+	if err != nil {
+		return err
+	}
+	defer cleanup()
+
+	b, err := os.ReadFile(*file)
+	if err != nil {
+		return err
+	}
+
+	fmt.Println(string(b))
+	return nil
+}
+
+func main() {
+	flag.Parse()
+
+	if err := realMain(); err != nil {
+		// Don't Fatalf, so that we can shutdown properly below.
+		log.Printf("helloworld: %v", err)
+	}
+
+	_ = unix.Reboot(unix.LINUX_REBOOT_CMD_POWER_OFF)
+}

tests/cmds/helloworld/main_linux.go

@@ -1,42 +1,24 @@
-// Command httpdownload configures networking with DHCP and downloads one web
-// page.
+// Package helloworld prints hello world and shuts down.
 package main
 
 import (
 	"flag"
 	"fmt"
 	"log"
-	"os"
 
-	"github.com/hugelgupf/vmtest/guest"
 	"golang.org/x/sys/unix"
 )
 
-var file = flag.String("file", "", "Filepath to read")
-
-func realMain() error {
-	cleanup, err := guest.MountSharedDir()
-	if err != nil {
-		return err
-	}
-	defer cleanup()
-
-	b, err := os.ReadFile(*file)
-	if err != nil {
-		return err
-	}
-
-	fmt.Println(string(b))
-	return nil
-}
+var n = flag.Int("n", 1, "How many times to repeat Hello world")
 
 func main() {
 	flag.Parse()
 
-	if err := realMain(); err != nil {
-		// Don't Fatalf, so that we can shutdown properly below.
-		log.Printf("helloworld: %v", err)
+	for i := 0; i < *n; i++ {
+		fmt.Println("Hello world", i)
 	}
 
-	_ = unix.Reboot(unix.LINUX_REBOOT_CMD_POWER_OFF)
+	if err := unix.Reboot(unix.LINUX_REBOOT_CMD_POWER_OFF); err != nil {
+		log.Fatalf("Failed to shut down: %v", err)
+	}
 }

tests/startexample/vm_test.go

@@ -21,10 +21,10 @@ func TestStart(t *testing.T) {
 		Commands: uroot.BusyBoxCmds(
 			"github.com/u-root/u-root/cmds/core/init",
 			"github.com/u-root/u-root/cmds/core/elvish",
-			"github.com/hugelgupf/vmtest/tests/cmds/helloworld",
+			"github.com/hugelgupf/vmtest/tests/cmds/catfile",
 		),
 		InitCmd:   "init",
-		UinitCmd:  "helloworld",
+		UinitCmd:  "catfile",
 		UinitArgs: []string{"-file", "/testdata/hello"},
 		TempDir:   t.TempDir(),
 	}

uqemu/uqemu_test.go

@@ -73,11 +73,11 @@ func TestStartVM(t *testing.T) {
 
 	initramfs := uroot.Opts{
 		InitCmd:  "init",
-		UinitCmd: "qemutest1",
+		UinitCmd: "helloworld",
 		TempDir:  tmp,
 		Commands: uroot.BusyBoxCmds(
 			"github.com/u-root/u-root/cmds/core/init",
-			"github.com/hugelgupf/vmtest/tests/cmds/qemutest1",
+			"github.com/hugelgupf/vmtest/tests/cmds/helloworld",
 		),
 	}
 	vm, err := qemu.Start(qemu.ArchUseEnvv, WithUrootInitramfs(logger, initramfs, initrdPath), qemu.WithSerialOutput(w))
@@ -86,8 +86,8 @@ func TestStartVM(t *testing.T) {
 	}
 	t.Logf("cmdline: %#v", vm.CmdlineQuoted())
 
-	if _, err := vm.Console.ExpectString("I AM HERE"); err != nil {
-		t.Errorf("Error expecting I AM HERE: %v", err)
+	if _, err := vm.Console.ExpectString("Hello world"); err != nil {
+		t.Errorf("Error expecting Hello world: %v", err)
 	}
 
 	if err := vm.Wait(); err != nil {
@@ -104,16 +104,16 @@ func TestTask(t *testing.T) {
 	r, w := io.Pipe()
 
 	var taskGotCanceled bool
-	var taskSawIAmHere bool
+	var taskSawHelloWorld bool
 	var vmExitErr error
 
 	initramfs := uroot.Opts{
 		InitCmd:  "init",
-		UinitCmd: "qemutest1",
+		UinitCmd: "helloworld",
 		TempDir:  tmp,
 		Commands: uroot.BusyBoxCmds(
 			"github.com/u-root/u-root/cmds/core/init",
-			"github.com/hugelgupf/vmtest/tests/cmds/qemutest1",
+			"github.com/hugelgupf/vmtest/tests/cmds/helloworld",
 		),
 	}
 	vm, err := qemu.Start(
@@ -125,8 +125,8 @@ func TestTask(t *testing.T) {
 			s := bufio.NewScanner(r)
 			for s.Scan() {
 				line := string(replaceCtl(s.Bytes()))
-				if strings.Contains(line, "I AM HERE") {
-					taskSawIAmHere = true
+				if strings.Contains(line, "Hello world") {
+					taskSawHelloWorld = true
 				}
 				t.Logf("vm: %s", line)
 			}
@@ -159,8 +159,8 @@ func TestTask(t *testing.T) {
 	}
 	t.Logf("cmdline: %#v", vm.CmdlineQuoted())
 
-	if _, err := vm.Console.ExpectString("I AM HERE"); err != nil {
-		t.Errorf("Error expecting I AM HERE: %v", err)
+	if _, err := vm.Console.ExpectString("Hello world"); err != nil {
+		t.Errorf("Error expecting Hello world: %v", err)
 	}
 
 	werr := vm.Wait()
@@ -174,8 +174,8 @@ func TestTask(t *testing.T) {
 	if !taskGotCanceled {
 		t.Error("Error: Task did not get canceled")
 	}
-	if !taskSawIAmHere {
-		t.Error("Error: Serial console task didn't see I AM HERE")
+	if !taskSawHelloWorld {
+		t.Error("Error: Serial console task didn't see Hello world")
 	}
 }
 
@@ -450,3 +450,33 @@ func TestInvalidInitramfs(t *testing.T) {
 		})
 	}
 }
+
+func TestOutputFillsConsoleBuffers(t *testing.T) {
+	// 4000 repeats of Hello world fill the buffer of the pty used by the
+	// Expect library. Make sure this does not cause hangs.
+	initramfs := uroot.Opts{
+		InitCmd:   "init",
+		UinitCmd:  "helloworld",
+		UinitArgs: []string{"-n", "4000"},
+		TempDir:   t.TempDir(),
+		Commands: uroot.BusyBoxCmds(
+			"github.com/u-root/u-root/cmds/core/init",
+			"github.com/hugelgupf/vmtest/tests/cmds/helloworld",
+		),
+	}
+	vm, err := qemu.Start(
+		qemu.ArchUseEnvv,
+		WithUrootInitramfsT(t, initramfs),
+		qemu.LogSerialByLine(qemu.PrintLineWithPrefix("vm", t.Logf)),
+	)
+	if err != nil {
+		t.Fatalf("Failed to start VM: %v", err)
+	}
+	t.Logf("cmdline: %#v", vm.CmdlineQuoted())
+
+	// No calls to Expect means nothing is draining the Console pty buffer.
+
+	if err := vm.Wait(); err != nil {
+		t.Fatalf("Error waiting for VM to exit: %v", err)
+	}
+}