From cbd7422ea75aafc0f474491f09c7adb7b93c439f Mon Sep 17 00:00:00 2001 From: Matthias Frei Date: Wed, 27 May 2020 11:11:25 +0200 Subject: [PATCH] Write stdout to file in integration tests, check exit code --- .circleci/config.yml | 2 + .../helloworld/helloworld_integration_test.go | 10 +- netcat/netcat_integration_test.go | 13 +- pkg/integration/apps.go | 115 ++++++++---------- 4 files changed, 57 insertions(+), 83 deletions(-) diff --git a/.circleci/config.yml b/.circleci/config.yml index 788d189d..a15f0155 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -97,6 +97,8 @@ jobs: name: Integration tests command: | make integration + - store_artifacts: + path: /tmp/scion-apps-integration/ - save_cache: key: v1-pkg-cache-{{ checksum "~/scion/go.sum" }}-{{ checksum "go.sum" }} paths: diff --git a/_examples/helloworld/helloworld_integration_test.go b/_examples/helloworld/helloworld_integration_test.go index 736156ed..82e615a4 100644 --- a/_examples/helloworld/helloworld_integration_test.go +++ b/_examples/helloworld/helloworld_integration_test.go @@ -32,7 +32,7 @@ func TestHelloworldSample(t *testing.T) { if err := integration.Init(name); err != nil { t.Fatalf("Failed to init: %s\n", err) } - cmd := integration.AppBinPath(bin) + cmd := integration.AppBinPath(bin) // Common arguments cmnArgs := []string{} // Server @@ -59,14 +59,6 @@ func TestHelloworldSample(t *testing.T) { integration.Contains("Done. Wrote 11 bytes."), nil, }, - { - "client_error", - append([]string{"-remote", "1-ff00:0:bad,[127.0.0.1]:" + serverPort}, cmnArgs...), - nil, - nil, - nil, - integration.RegExp("^Fatal error.*err_code=\"No paths available\"$"), - }, } for _, tc := range testCases { diff --git a/netcat/netcat_integration_test.go b/netcat/netcat_integration_test.go index 2ef24478..a8b315d4 100644 --- a/netcat/netcat_integration_test.go +++ b/netcat/netcat_integration_test.go @@ -80,7 +80,7 @@ func TestIntegrationScionNetcat(t *testing.T) { }, { "client_hello", - append(cmnArgs, integration.DstAddrPattern + ":" + serverPort), + append(cmnArgs, integration.DstAddrPattern+":"+serverPort), integration.RegExp(fmt.Sprintf("^%s$", testMessage)), nil, nil, @@ -100,7 +100,7 @@ func TestIntegrationScionNetcat(t *testing.T) { IAPairs := integration.IAPairs(hostAddr) IAPairs = IAPairs[:5] - if err := integration.RunTests(in, IAPairs, integration.DefaultClientTimeout, 250 * time.Millisecond); err != nil { + if err := integration.RunTests(in, IAPairs, integration.DefaultClientTimeout, 250*time.Millisecond); err != nil { t.Fatalf("Error during tests err: %v", err) } } @@ -140,7 +140,7 @@ func TestIntegrationScionNetcatUDP(t *testing.T) { }{ { "client_hello_UDP", - append(cmnArgs, integration.DstAddrPattern + ":" + serverPort), + append(cmnArgs, integration.DstAddrPattern+":"+serverPort), nil, nil, nil, @@ -160,14 +160,13 @@ func TestIntegrationScionNetcatUDP(t *testing.T) { IAPairs := integration.IAPairs(hostAddr) IAPairs = IAPairs[:5] - if err := integration.RunTests(in, IAPairs, integration.DefaultClientTimeout, 250 * time.Millisecond); err != nil { + if err := integration.RunTests(in, IAPairs, integration.DefaultClientTimeout, 250*time.Millisecond); err != nil { t.Fatalf("Error during tests err: %v", err) } } } - -func wrapperCommand(tmpDir string, inputSource string, command string) (wrapperCmd string, err error){ +func wrapperCommand(tmpDir string, inputSource string, command string) (wrapperCmd string, err error) { wrapperCmd = path.Join(tmpDir, fmt.Sprintf("%s_wrapper.sh", serverBin)) f, err := os.OpenFile(wrapperCmd, os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0777) if err != nil { @@ -176,7 +175,7 @@ func wrapperCommand(tmpDir string, inputSource string, command string) (wrapperC defer f.Close() w := bufio.NewWriter(f) defer w.Flush() - _, _ = w.WriteString(fmt.Sprintf("#!/bin/bash\ntimeout 5 /bin/bash -c \"%s | %s $1 $2 $3 $4\"", + _, _ = w.WriteString(fmt.Sprintf("#!/bin/bash\ntimeout 5 /bin/bash -c \"%s | %s $1 $2 $3 $4\" || true", inputSource, command)) return wrapperCmd, nil } diff --git a/pkg/integration/apps.go b/pkg/integration/apps.go index 2e533b66..c943a39b 100644 --- a/pkg/integration/apps.go +++ b/pkg/integration/apps.go @@ -23,6 +23,7 @@ import ( "io/ioutil" "os" "os/exec" + "path" "regexp" "strings" "time" @@ -107,14 +108,17 @@ func (sai *ScionAppsIntegration) StartServer(ctx context.Context, return nil, err } + logfile := fmt.Sprintf("server_%s", dst.IA.FileFmt(false)) + startInfo := dst.IA.FileFmt(false) + ready := make(chan struct{}) signal := ReadySignal init := true // parse stdout until we have the ready signal // and check the output with serverOutMatchFun. + sp = sai.pipeLog(logfile+".log", startInfo, sp) go func() { defer log.HandlePanic() - defer sp.Close() var stdoutMatch bool scanner := bufio.NewScanner(sp) @@ -131,7 +135,6 @@ func (sai *ScionAppsIntegration) StartServer(ctx context.Context, if sai.serverOutMatchFun != nil { stdoutMatch = sai.serverOutMatchFun(stdoutMatch, line) } - log.Debug("Server stdout", "log line", line) } if sai.serverOutMatchFun != nil { r.stdoutMatch <- stdoutMatch @@ -140,25 +143,10 @@ func (sai *ScionAppsIntegration) StartServer(ctx context.Context, } }() - var logPipeR *io.PipeReader - var logPipeW *io.PipeWriter - if sai.logDir != "" { - // log stderr to file - logPipeR, logPipeW = io.Pipe() - go func() { - sai.writeLog("server", dst.IA.FileFmt(false), dst.IA.FileFmt(false), logPipeR) - }() - } - // Check the stderr with serverErrMatchFun. + ep = sai.pipeLog(logfile+".err", startInfo, ep) go func() { defer log.HandlePanic() - defer ep.Close() - defer func() { - if logPipeW != nil { - _ = logPipeW.Close() - } - }() var stderrMatch bool scanner := bufio.NewScanner(ep) for scanner.Scan() { @@ -174,11 +162,6 @@ func (sai *ScionAppsIntegration) StartServer(ctx context.Context, if sai.serverErrMatchFun != nil { stderrMatch = sai.serverErrMatchFun(stderrMatch, line) } - log.Debug("Server stderr", "log line", line) - if logPipeW != nil { - // Propagate to file logger - _, _ = fmt.Fprint(logPipeW, fmt.Sprintf("%s\n", line)) - } } if sai.serverErrMatchFun != nil { r.stderrMatch <- stderrMatch @@ -230,6 +213,10 @@ func (sai *ScionAppsIntegration) StartClient(ctx context.Context, return nil, err } + logfile := fmt.Sprintf("client_%s", clientID(src, dst)) + startInfo := fmt.Sprintf("%s -> %s", src.IA, dst.IA) + + sp = sai.pipeLog(logfile+".log", startInfo, sp) // check the output with clientOutMatchFun go func() { var stdoutMatch bool @@ -242,7 +229,6 @@ func (sai *ScionAppsIntegration) StartClient(ctx context.Context, if sai.clientOutMatchFun != nil { stdoutMatch = sai.clientOutMatchFun(stdoutMatch, line) } - log.Debug("Client stdout", "msg", line) } if sai.clientOutMatchFun != nil { r.stdoutMatch <- stdoutMatch @@ -251,23 +237,9 @@ func (sai *ScionAppsIntegration) StartClient(ctx context.Context, } }() - var logPipeR *io.PipeReader - var logPipeW *io.PipeWriter - if sai.logDir != "" { - // log stderr to file - logPipeR, logPipeW = io.Pipe() - go func() { - sai.writeLog("client", clientID(src, dst), fmt.Sprintf("%s -> %s", src.IA, dst.IA), logPipeR) - }() - } - // Check the stderr with clientErrMatchFun + ep = sai.pipeLog(logfile+".err", startInfo, ep) go func() { - defer func() { - if logPipeW != nil { - _ = logPipeW.Close() - } - }() var stderrMatch bool scanner := bufio.NewScanner(ep) for scanner.Scan() { @@ -278,11 +250,6 @@ func (sai *ScionAppsIntegration) StartClient(ctx context.Context, if sai.clientErrMatchFun != nil { stderrMatch = sai.clientErrMatchFun(stderrMatch, line) } - log.Debug("Client stderr", "msg", line) - if logPipeW != nil { - // Propagate to file logger - _, _ = fmt.Fprint(logPipeW, fmt.Sprintf("%s\n", line)) - } } if sai.clientErrMatchFun != nil { r.stderrMatch <- stderrMatch @@ -311,7 +278,12 @@ func (sai *ScionAppsIntegration) ClientStderr(errMatch func(bool, string) bool) } func (sai *ScionAppsIntegration) initLogDir(name string) error { - logDir, err := ioutil.TempDir("", name) + tmpDir := path.Join(os.TempDir(), "scion-apps-integration") + err := os.MkdirAll(tmpDir, 0777) + if err != nil { + log.Error("Failed to create log folder for testrun", "dir", tmpDir, "err", err) + } + logDir, err := ioutil.TempDir(tmpDir, name) if err != nil { log.Error("Failed to create log folder for testrun", "dir", name, "err", err) return err @@ -321,32 +293,34 @@ func (sai *ScionAppsIntegration) initLogDir(name string) error { return nil } -func (sai *ScionAppsIntegration) writeLog(name, id, startInfo string, ep io.ReadCloser) { - defer ep.Close() - f, err := os.OpenFile(fmt.Sprintf("%s/%s_%s.log", sai.logDir, name, id), - os.O_CREATE|os.O_WRONLY, os.FileMode(0644)) +func (sai *ScionAppsIntegration) pipeLog(name, startInfo string, r io.ReadCloser) io.ReadCloser { + if sai.logDir != "" { + // tee to log + pipeR, pipeW := io.Pipe() + tee := io.TeeReader(r, pipeW) + go func() { + sai.writeLog(name, startInfo, tee) + pipeW.Close() + }() + return pipeR + } + return r +} + +func (sai *ScionAppsIntegration) writeLog(name, startInfo string, pipe io.Reader) { + file := path.Join(sai.logDir, name) + f, err := os.OpenFile(file, os.O_CREATE|os.O_APPEND|os.O_WRONLY, os.FileMode(0644)) if err != nil { log.Error("Failed to create log file for test run (create)", - "name", name, "id", id, "err", err) + "file", file, "err", err) return } defer f.Close() - // seek to end of file. - if _, err := f.Seek(0, 2); err != nil { - log.Error("Failed to create log file for test run (seek)", - "name", name, "id", id, "err", err) - return - } - w := bufio.NewWriter(f) - defer w.Flush() - _, _ = w.WriteString(sintegration.WithTimestamp(fmt.Sprintf("Starting %s %s\n", name, startInfo))) + _, _ = f.WriteString(sintegration.WithTimestamp(fmt.Sprintf("Starting %s %s\n", name, startInfo))) defer func() { - _, _ = w.WriteString(sintegration.WithTimestamp(fmt.Sprintf("Finished %s %s\n", name, startInfo))) + _, _ = f.WriteString(sintegration.WithTimestamp(fmt.Sprintf("Finished %s %s\n", name, startInfo))) }() - scanner := bufio.NewScanner(ep) - for scanner.Scan() { - _, _ = w.WriteString(fmt.Sprintf("%s\n", scanner.Text())) - } + _, _ = io.Copy(f, pipe) } func clientID(src, dst *snet.UDPAddr) string { @@ -361,14 +335,21 @@ type appsWaiter struct { stderrMatch chan bool } -func (aw *appsWaiter) Wait() (err error) { - _, _ = aw.Process.Wait() +func (aw *appsWaiter) Wait() error { + state, err := aw.Process.Wait() + if err != nil { + return err + } + if state.ExitCode() > 0 { // Ignore servers killed by the framework + return fmt.Errorf("the program under test returned non-zero exit code:\n%s [exit code=%d]", + aw.Cmd.String(), state.ExitCode()) + } err = checkOutputMatches(aw.stdoutMatch, aw.stderrMatch) if err != nil { return err } _ = aw.Cmd.Wait() - return + return nil } func checkOutputMatches(stdoutRes chan bool, stderrRes chan bool) error {