Capture boot panics in debug log.

Docker and Containerd both eat the boot processes stderr, making it difficult
to track down panics (which are always written to stderr).

This CL makes the boot process dup its debug log FD to stderr, so that panics
will be captured in the debug log, which is better than nothing.

This is the 3rd try at this CL.  Previous attempts were foiled because Docker
expects the 'create' command to pass its stdio directly to the container, so
duping stderr in 'create' caused the applications stderr to go to the log file,
which breaks many applications (including our mysql test).

I added a new image_test that makes sure stdout and stderr are handled
correctly.

PiperOrigin-RevId: 215767328
Change-Id: Icebac5a5dcf39b623b79d7a0e2f968e059130059

runsc/main.go

@@ -175,14 +175,30 @@ func main() {
 		cmd.Fatalf("invalid log format %q, must be 'json' or 'text'", *logFormat)
 	}
 
+	subcommand := flag.CommandLine.Arg(0)
 	if *debugLogFD > -1 {
 		f := os.NewFile(uintptr(*debugLogFD), "debug log file")
+
+		// Quick sanity check to make sure no other commands get passed
+		// a log fd (they should use log dir instead).
+		if subcommand != "boot" {
+			cmd.Fatalf("flag --debug-log-fd should only be passed to 'boot' command, but was passed to %q", subcommand)
+		}
+
+		// If we are the boot process, then we own our stdio FDs and
+		// can do what we want with them. Since Docker and Containerd
+		// both eat boot's stderr, we dup our stderr to the provided
+		// log FD so that panics will appear in the logs, rather than
+		// just disappear.
+		if err := syscall.Dup2(int(f.Fd()), int(os.Stderr.Fd())); err != nil {
+			cmd.Fatalf("error dup'ing fd %d to stderr: %v", f.Fd(), err)
+		}
+
 		e = log.MultiEmitter{e, log.GoogleEmitter{&log.Writer{Next: f}}}
 	} else if *debugLogDir != "" {
 		if err := os.MkdirAll(*debugLogDir, 0775); err != nil {
 			cmd.Fatalf("error creating dir %q: %v", *debugLogDir, err)
 		}
-		subcommand := flag.CommandLine.Arg(0)
 		f, err := specutils.DebugLogFile(*debugLogDir, subcommand)
 		if err != nil {
 			cmd.Fatalf("error opening debug log file in %q: %v", *debugLogDir, err)

runsc/test/image/image_test.go

@@ -303,6 +303,27 @@ func TestRuby(t *testing.T) {
 	}
 }
 
+func TestStdio(t *testing.T) {
+	if err := testutil.Pull("alpine"); err != nil {
+		t.Fatalf("docker pull failed: %v", err)
+	}
+	d := testutil.MakeDocker("stdio-test")
+
+	wantStdout := "hello stdout"
+	wantStderr := "bonjour stderr"
+	cmd := fmt.Sprintf("echo %q; echo %q 1>&2;", wantStdout, wantStderr)
+	if err := d.Run("alpine", "/bin/sh", "-c", cmd); err != nil {
+		t.Fatalf("docker run failed: %v", err)
+	}
+	defer d.CleanUp()
+
+	for _, want := range []string{wantStdout, wantStderr} {
+		if _, err := d.WaitForOutput(want, 5*time.Second); err != nil {
+			t.Fatalf("docker didn't get output %q : %v", want, err)
+		}
+	}
+}
+
 func TestMain(m *testing.M) {
 	testutil.EnsureSupportedDockerVersion()
 	os.Exit(m.Run())