blob: b903e41448726281398e3482738e5f596d9e1995 [file] [log] [blame]
// Copyright 2015 The Vanadium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style
// license that can be found in the LICENSE file.
package exec_test
import (
"fmt"
"io"
"log"
"os"
"os/exec"
"runtime"
"strings"
"sync"
"syscall"
"testing"
"time"
"unicode/utf8"
"v.io/v23/verror"
vexec "v.io/x/ref/lib/exec"
// Use mock timekeeper to avoid actually sleeping during the test.
"v.io/x/ref/test/timekeeper"
)
// We always expect there to be exactly three open file descriptors
// when the test starts out: STDIN, STDOUT, and STDERR. This
// assumption is tested in init below, and in the rare cases where it
// is wrong, we try to close all additional file descriptors, and bail
// out if that fails.
const baselineOpenFiles = 3
func init() {
if os.Getenv("GOMAXPROCS") == "" {
// Set the number of logical processors to 1 if GOMAXPROCS is
// not set in the environment.
//
// TODO(caprita): the default in Go 1.5 is num cpus, which
// causes flakiness. Figure out why.
runtime.GOMAXPROCS(1)
}
if os.Getenv("GO_WANT_HELPER_PROCESS_EXEC") == "1" {
return
}
want, got := baselineOpenFiles, openFiles()
if want == got {
return
}
for i := want; i < got; i++ {
syscall.Close(i)
}
if want, got = baselineOpenFiles, openFiles(); want != got {
message := `Test expected to start with %d open files, found %d instead.
This can happen if parent process has any open file descriptors,
e.g. pipes, that are being inherited.`
panic(fmt.Errorf(message, want, got))
}
}
// These tests need to run a subprocess and we reuse this same test
// binary to do so. A fake test 'TestHelperProcess' contains the code
// we need to run in the child and we simply run this same binary with
// a test.run= arg that runs just that test. This idea was taken from
// the tests for os/exec.
func helperCommand(s ...string) *exec.Cmd {
cs := []string{"-test.run=TestHelperProcess", "--"}
cs = append(cs, s...)
cmd := exec.Command(os.Args[0], cs...)
cmd.Env = append([]string{"GO_WANT_HELPER_PROCESS_EXEC=1"}, os.Environ()...)
return cmd
}
func openFiles() int {
f, err := os.Open("/dev/null")
if err != nil {
panic("Failed to open /dev/null\n")
}
n := f.Fd()
f.Close()
return int(n)
}
func clean(t *testing.T, ph ...*vexec.ParentHandle) {
for _, p := range ph {
alreadyClean := !p.Exists()
p.Clean()
if !alreadyClean && p.Exists() {
t.Errorf("child process left behind even after calling Clean")
}
}
if want, got := baselineOpenFiles, openFiles(); want != got {
t.Errorf("Leaking file descriptors: expect %d, got %d", want, got)
}
}
func read(ch chan bool, r io.Reader, m string) {
buf := make([]byte, 4096*4)
n, err := r.Read(buf)
if err != nil {
log.Printf("failed to read message: error %s, expecting '%s'\n",
err, m)
ch <- false
return
}
g := string(buf[:n])
b := g == m
if !b {
log.Printf("read '%s', not '%s'\n", g, m)
}
ch <- b
}
func expectMessage(r io.Reader, m string) bool {
ch := make(chan bool, 1)
go read(ch, r, m)
select {
case b := <-ch:
return b
case <-time.After(5 * time.Second):
log.Printf("expectMessage: timeout\n")
return false
}
}
func TestConfigExchange(t *testing.T) {
cmd := helperCommand("testConfig")
stderr, _ := cmd.StderrPipe()
cfg := vexec.NewConfig()
cfg.Set("foo", "bar")
ph := vexec.NewParentHandle(cmd, vexec.ConfigOpt{Config: cfg})
err := ph.Start()
if err != nil {
t.Fatalf("testConfig: start: %v", err)
}
serialized, err := cfg.Serialize()
if err != nil {
t.Fatalf("testConfig: failed to serialize config: %v", err)
}
if !expectMessage(stderr, serialized) {
t.Errorf("unexpected output from child")
} else {
if err = cmd.Wait(); err != nil {
t.Errorf("testConfig: wait: %v", err)
}
}
clean(t, ph)
}
func TestSecretExchange(t *testing.T) {
cmd := helperCommand("testSecret")
stderr, _ := cmd.StderrPipe()
ph := vexec.NewParentHandle(cmd, vexec.SecretOpt("dummy_secret"))
err := ph.Start()
if err != nil {
t.Fatalf("testSecretTest: start: %v", err)
}
if !expectMessage(stderr, "dummy_secret") {
t.Errorf("unexpected output from child")
} else {
if err = cmd.Wait(); err != nil {
t.Errorf("testSecretTest: wait: %v", err)
}
}
clean(t, ph)
}
func TestNoVersion(t *testing.T) {
// Make sure that Init correctly tests for the presence of VEXEC_VERSION
_, err := vexec.GetChildHandle()
if verror.ErrorID(err) != vexec.ErrNoVersion.ID {
t.Errorf("Should be missing Version")
}
}
func waitForReady(t *testing.T, cmd *exec.Cmd, name string, delay int, ph *vexec.ParentHandle) error {
err := ph.Start()
if err != nil {
t.Fatalf("%s: start: %v", name, err)
return err
}
return ph.WaitForReady(time.Duration(delay) * time.Second)
}
func readyHelperCmd(t *testing.T, cmd *exec.Cmd, name, result string) *vexec.ParentHandle {
stderr, err := cmd.StderrPipe()
if err != nil {
t.Fatalf("%s: failed to get stderr pipe\n", name)
}
ph := vexec.NewParentHandle(cmd)
if err := waitForReady(t, cmd, name, 4, ph); err != nil {
t.Errorf("%s: WaitForReady: %v (%v)", name, err, ph)
return nil
}
if !expectMessage(stderr, result) {
t.Errorf("%s: failed to read '%s' from child\n", name, result)
}
return ph
}
func readyHelper(t *testing.T, name, test, result string) *vexec.ParentHandle {
cmd := helperCommand(test)
return readyHelperCmd(t, cmd, name, result)
}
func testMany(t *testing.T, name, test, result string) []*vexec.ParentHandle {
nprocs := 10
ph := make([]*vexec.ParentHandle, nprocs)
cmd := make([]*exec.Cmd, nprocs)
stderr := make([]io.ReadCloser, nprocs)
controlReaders := make([]io.ReadCloser, nprocs)
var done sync.WaitGroup
for i := 0; i < nprocs; i++ {
cmd[i] = helperCommand(test)
// The control pipe is used to signal the child when to wake up.
controlRead, controlWrite, err := os.Pipe()
if err != nil {
t.Errorf("Failed to create control pipe: %v", err)
return nil
}
controlReaders[i] = controlRead
cmd[i].ExtraFiles = append(cmd[i].ExtraFiles, controlRead)
stderr[i], _ = cmd[i].StderrPipe()
tk := timekeeper.NewManualTime()
ph[i] = vexec.NewParentHandle(cmd[i], vexec.TimeKeeperOpt{TimeKeeper: tk})
done.Add(1)
go func() {
// For simulated slow children, wait until the parent
// starts waiting, and then wake up the child.
if test == "testReadySlow" {
<-tk.Requests()
tk.AdvanceTime(3 * time.Second)
if _, err = controlWrite.Write([]byte("wake")); err != nil {
t.Errorf("Failed to write to control pipe: %v", err)
}
}
controlWrite.Close()
done.Done()
}()
if err := ph[i].Start(); err != nil {
t.Errorf("%s: Failed to start child %d: %s\n", name, i, err)
}
}
for i := 0; i < nprocs; i++ {
if err := ph[i].WaitForReady(5 * time.Second); err != nil {
t.Errorf("%s: Failed to wait for child %d: %s\n", name, i, err)
}
controlReaders[i].Close()
}
for i := 0; i < nprocs; i++ {
if !expectMessage(stderr[i], result) {
t.Errorf("%s: Failed to read message from child %d\n", name, i)
}
}
done.Wait()
return ph
}
func TestToReadyMany(t *testing.T) {
clean(t, testMany(t, "TestToReadyMany", "testReady", ".")...)
}
func TestToReadySlowMany(t *testing.T) {
clean(t, testMany(t, "TestToReadySlowMany", "testReadySlow", "..")...)
}
func TestToReady(t *testing.T) {
ph := readyHelper(t, "TestToReady", "testReady", ".")
clean(t, ph)
}
func TestToFail(t *testing.T) {
name := "testFail"
cmd := helperCommand(name, "failed", "to", "start")
ph := vexec.NewParentHandle(cmd)
err := waitForReady(t, cmd, name, 4, ph)
if err == nil || !strings.Contains(err.Error(), "failed to start") {
t.Errorf("unexpected error: %v", err)
}
}
func TestToFailInvalidUTF8(t *testing.T) {
name := "testFail"
cmd := helperCommand(name, "invalid", "utf8", string([]byte{0xFF}), "in", string([]byte{0xFC}), "error", "message")
ph := vexec.NewParentHandle(cmd)
err := waitForReady(t, cmd, name, 4, ph)
if err == nil || !strings.Contains(err.Error(), "invalid utf8 "+string(utf8.RuneError)+" in "+string(utf8.RuneError)+" error message") {
t.Errorf("unexpected error: %v", err)
}
}
func TestNeverReady(t *testing.T) {
name := "testNeverReady"
result := "never ready"
cmd := helperCommand(name)
stderr, _ := cmd.StderrPipe()
ph := vexec.NewParentHandle(cmd)
err := waitForReady(t, cmd, name, 1, ph)
if verror.ErrorID(err) != vexec.ErrTimeout.ID {
t.Errorf("Failed to get timeout: got %v\n", err)
} else {
// block waiting for error from child
if !expectMessage(stderr, result) {
t.Errorf("%s: failed to read '%s' from child\n", name, result)
}
}
clean(t, ph)
}
func TestTooSlowToReady(t *testing.T) {
name := "testTooSlowToReady"
result := "write status_wr: broken pipe"
cmd := helperCommand(name)
// The control pipe is used to signal the child when to wake up.
controlRead, controlWrite, err := os.Pipe()
if err != nil {
t.Errorf("Failed to create control pipe: %v", err)
return
}
cmd.ExtraFiles = append(cmd.ExtraFiles, controlRead)
stderr, _ := cmd.StderrPipe()
tk := timekeeper.NewManualTime()
ph := vexec.NewParentHandle(cmd, vexec.TimeKeeperOpt{TimeKeeper: tk})
defer clean(t, ph)
defer controlWrite.Close()
defer controlRead.Close()
// Wait for the parent to start waiting, then simulate a timeout.
go func() {
toWait := <-tk.Requests()
tk.AdvanceTime(toWait)
}()
err = waitForReady(t, cmd, name, 1, ph)
if verror.ErrorID(err) != vexec.ErrTimeout.ID {
t.Errorf("Failed to get timeout: got %v\n", err)
} else {
// After the parent timed out, wake up the child and let it
// proceed.
if _, err = controlWrite.Write([]byte("wake")); err != nil {
t.Errorf("Failed to write to control pipe: %v", err)
} else {
// block waiting for error from child
if !expectMessage(stderr, result) {
t.Errorf("%s: failed to read '%s' from child\n", name, result)
}
}
}
}
func TestToReadySlow(t *testing.T) {
name := "TestToReadySlow"
cmd := helperCommand("testReadySlow")
// The control pipe is used to signal the child when to wake up.
controlRead, controlWrite, err := os.Pipe()
if err != nil {
t.Errorf("Failed to create control pipe: %v", err)
return
}
cmd.ExtraFiles = append(cmd.ExtraFiles, controlRead)
stderr, err := cmd.StderrPipe()
if err != nil {
t.Fatalf("%s: failed to get stderr pipe", name)
}
tk := timekeeper.NewManualTime()
ph := vexec.NewParentHandle(cmd, vexec.TimeKeeperOpt{TimeKeeper: tk})
defer clean(t, ph)
defer controlWrite.Close()
defer controlRead.Close()
// Wait for the parent to start waiting, simulate a short wait (but not
// enough to timeout the parent), then wake up the child.
go func() {
<-tk.Requests()
tk.AdvanceTime(2 * time.Second)
if _, err = controlWrite.Write([]byte("wake")); err != nil {
t.Errorf("Failed to write to control pipe: %v", err)
}
}()
if err := waitForReady(t, cmd, name, 4, ph); err != nil {
t.Errorf("%s: WaitForReady: %v (%v)", name, err, ph)
return
}
// After the child has replied, simulate a timeout on the server by
// advacing the time more; at this point, however, the timeout should no
// longer occur since the child already replied.
tk.AdvanceTime(2 * time.Second)
if result := ".."; !expectMessage(stderr, result) {
t.Errorf("%s: failed to read '%s' from child\n", name, result)
}
}
func TestToCompletion(t *testing.T) {
ph := readyHelper(t, "TestToCompletion", "testSuccess", "...ok")
e := ph.Wait(10 * time.Second)
if e != nil {
t.Errorf("Wait failed: err %s\n", e)
}
clean(t, ph)
}
func TestToCompletionError(t *testing.T) {
ph := readyHelper(t, "TestToCompletionError", "testError", "...err")
e := ph.Wait(time.Second)
if e == nil {
t.Errorf("Wait failed: err %s\n", e)
}
clean(t, ph)
}
func TestExtraFiles(t *testing.T) {
cmd := helperCommand("testExtraFiles")
rd, wr, err := os.Pipe()
if err != nil {
t.Fatalf("Failed to create pipe: %s\n", err)
}
cmd.ExtraFiles = append(cmd.ExtraFiles, rd)
msg := "hello there..."
fmt.Fprintf(wr, msg)
ph := readyHelperCmd(t, cmd, "TestExtraFiles", "child: "+msg)
if ph == nil {
t.Fatalf("Failed to get vexec.ParentHandle\n")
}
e := ph.Wait(10 * time.Second)
if e != nil {
t.Errorf("Wait failed: err %s\n", e)
}
rd.Close()
wr.Close()
clean(t, ph)
}
func TestExitEarly(t *testing.T) {
name := "exitEarly"
cmd := helperCommand(name)
tk := timekeeper.NewManualTime()
ph := vexec.NewParentHandle(cmd, vexec.TimeKeeperOpt{TimeKeeper: tk})
err := ph.Start()
if err != nil {
t.Fatalf("%s: start: %v", name, err)
}
e := ph.Wait(time.Second)
if e == nil || e.Error() != "exit status 1" {
t.Errorf("Unexpected value for error: %v\n", e)
}
clean(t, ph)
}
func TestWaitAndCleanRace(t *testing.T) {
name := "testReadyAndHang"
cmd := helperCommand(name)
tk := timekeeper.NewManualTime()
ph := vexec.NewParentHandle(cmd, vexec.TimeKeeperOpt{TimeKeeper: tk})
if err := waitForReady(t, cmd, name, 1, ph); err != nil {
t.Errorf("%s: WaitForReady: %v (%v)", name, err, ph)
}
// Drain the tk.Requests() channel since waitForReady can leave something in it.
select {
case <-tk.Requests():
default:
}
go func() {
// Wait for the ph.Wait below to block, then advance the time
// s.t. the Wait times out.
<-tk.Requests()
tk.AdvanceTime(2 * time.Second)
}()
if got, want := ph.Wait(time.Second), vexec.ErrTimeout.ID; got == nil || verror.ErrorID(got) != want {
t.Errorf("Wait returned %v, wanted %v instead", got, want)
}
if got, want := ph.Clean(), "signal: killed"; got == nil || got.Error() != want {
t.Errorf("Wait returned %v, wanted %v instead", got, want)
}
}
func verifyNoExecVariable() {
version := os.Getenv(vexec.ExecVersionVariable)
if len(version) != 0 {
log.Fatalf("Version variable %q has a value: %s", vexec.ExecVersionVariable, version)
}
}
// TestHelperProcess isn't a real test; it's used as a helper process
// for the other tests.
func TestHelperProcess(*testing.T) {
// Return immediately if this is not run as the child helper
// for the other tests.
if os.Getenv("GO_WANT_HELPER_PROCESS_EXEC") != "1" {
return
}
defer os.Exit(0)
version := os.Getenv(vexec.ExecVersionVariable)
if len(version) == 0 {
log.Fatalf("Version variable %q has no value", vexec.ExecVersionVariable)
}
// Write errors to stderr or using log. since the parent
// process is reading stderr.
args := os.Args
for len(args) > 0 {
if args[0] == "--" {
args = args[1:]
break
}
args = args[1:]
}
if len(args) == 0 {
log.Fatal("No command")
}
cmd, args := args[0], args[1:]
switch cmd {
case "exitEarly":
_, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
os.Exit(1)
case "testNeverReady":
_, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
fmt.Fprintf(os.Stderr, "never ready")
case "testTooSlowToReady":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
// Wait for the parent to tell us when it's ok to proceed.
controlPipe := ch.NewExtraFile(0, "control_rd")
for {
buf := make([]byte, 100)
n, err := controlPipe.Read(buf)
if err != nil {
log.Fatal(err)
}
if n > 0 {
break
}
}
// SetReady should return an error since the parent has
// timed out on us and we'd be writing to a closed pipe.
if err := ch.SetReady(); err != nil {
fmt.Fprintf(os.Stderr, "%s", err)
} else {
fmt.Fprintf(os.Stderr, "didn't get the expected error")
}
case "testFail":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
err = ch.SetFailed(fmt.Errorf("%s", strings.Join(args, " ")))
if err != nil {
fmt.Fprintf(os.Stderr, "%s\n", err)
}
// It's fine to call SetFailed multiple times.
if err2 := ch.SetFailed(fmt.Errorf("dummy")); err != err2 {
fmt.Fprintf(os.Stderr, "Received new error got: %v, want %v\n", err2, err)
}
case "testReady":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
err = ch.SetReady()
if err != nil {
fmt.Fprintf(os.Stderr, "%s\n", err)
}
// It's fine to call SetReady multiple times.
if err2 := ch.SetReady(); err != err2 {
fmt.Fprintf(os.Stderr, "Received new error got: %v, want %v\n", err2, err)
}
fmt.Fprintf(os.Stderr, ".")
case "testReadySlow":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
// Wait for the parent to tell us when it's ok to proceed.
controlPipe := ch.NewExtraFile(0, "control_rd")
for {
buf := make([]byte, 100)
n, err := controlPipe.Read(buf)
if err != nil {
log.Fatal(err)
}
if n > 0 {
break
}
}
ch.SetReady()
fmt.Fprintf(os.Stderr, "..")
case "testReadyAndHang":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
ch.SetReady()
<-time.After(time.Minute)
case "testSuccess", "testError":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatal(err)
}
verifyNoExecVariable()
ch.SetReady()
rc := make(chan int)
go func() {
if cmd == "testError" {
fmt.Fprintf(os.Stderr, "...err")
rc <- 1
} else {
fmt.Fprintf(os.Stderr, "...ok")
rc <- 0
}
}()
r := <-rc
os.Exit(r)
case "testConfig":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatalf("%v", err)
} else {
verifyNoExecVariable()
serialized, err := ch.Config.Serialize()
if err != nil {
log.Fatalf("%v", err)
}
fmt.Fprintf(os.Stderr, "%s", serialized)
}
case "testSecret":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatalf("%s", err)
} else {
verifyNoExecVariable()
fmt.Fprintf(os.Stderr, "%s", ch.Secret)
}
case "testExtraFiles":
ch, err := vexec.GetChildHandle()
if err != nil {
log.Fatalf("error.... %s\n", err)
}
verifyNoExecVariable()
err = ch.SetReady()
rd := ch.NewExtraFile(0, "read")
buf := make([]byte, 1024)
if n, err := rd.Read(buf); err != nil {
fmt.Fprintf(os.Stderr, "child: error %s\n", err)
} else {
fmt.Fprintf(os.Stderr, "child: %s", string(buf[:n]))
}
}
}