codifier/fxtest.go

// Copyright 2021 The Fuchsia 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 codifier

import (
	"context"
	"errors"
	"fmt"
	"log"
	"os/exec"
	"time"

	"golang.org/x/sync/errgroup"
)

const (
	// The maximum time allowed for `fx emu -N` and `fx serve` to start and emit
	// their ready strings.
	fxServersStartTimeout = 2 * time.Minute

	// The maximum time allowed for `fx emu -N` and `fx serve` to stop.
	fxServersStopTimeout = 30 * time.Second

	// This is the string that the command runner will watch for that indicates
	// that the `fx serve` command is ready. If this string has changes in the
	// serve command, the symptom here will be that the waiting-for-server step
	// times out.
	fxServeReadyString = "Ready to push packages!"

	// This is the string that the command runner will watch for that indicates
	// that the `fx emu -N` command is ready. If this string has changes in the
	// emu command, the symptom here will be that the waiting-for-server step
	// times out.
	fxEmuReadyString = "mDNS: Using unique host name"
)

// fxTest maintains the live the commands for running the testing servers and
// the directory in which they're run. The required commands are: `fx emu -N` and
// `fx serve`.
type fxTest struct {
	dir                  string
	fxServeCmd, fxEmuCmd *exec.Cmd
}

func newFxTest(dir string) *fxTest {
	return &fxTest{dir: dir}
}

func (f *fxTest) close() error {
	var emuErr, serveErr error
	if f.fxEmuCmd != nil {
		emuErr = terminateProcessesGroup(f.fxEmuCmd)
		f.fxEmuCmd = nil
	}
	if f.fxServeCmd != nil {
		serveErr = terminateProcessesGroup(f.fxServeCmd)
		f.fxServeCmd = nil
	}
	if emuErr != nil {
		return emuErr
	}
	return serveErr
}

// runTest runs the given test, first starting the emulator and fx server and
// ensuring that they are running and ready.
func (f *fxTest) runTest(testname string, chatty bool) error {
	ctx, cancel := context.WithCancel(context.Background())
	defer cancel()
	eg, ctx := errgroup.WithContext(ctx)
	readyC := make(chan int)
	defer close(readyC)

	// Start `fx serve`.
	log.Printf("runTest() starting `fx serve` for test %q", testname)
	srvCmd, servSigC, srvResC, err := startCommand(context.Background(), f.dir,
		fxServeReadyString, "fx", "serve")
	if err != nil {
		return err
	}
	f.fxServeCmd = srvCmd

	// Start `fx emu -N`.
	log.Printf("runTest() starting `fx emu -N` for test %q", testname)
	emuCmd, emuSigC, emuResC, err := startCommand(context.Background(), f.dir,
		fxEmuReadyString, "xvfb-run", "fx", "emu", "-N")
	if err != nil {
		return err
	}
	f.fxEmuCmd = emuCmd

	eg.Go(func() error {
		return f.runServer(ctx, srvCmd, servSigC, srvResC, readyC, "fx serve")
	})

	eg.Go(func() error {
		return f.runServer(ctx, emuCmd, emuSigC, emuResC, readyC, "xvfb-run fx emu -N")
	})

	if err := f.waitForServerStarts(ctx, readyC); err != nil {
		return err
	}

	log.Printf("runTest() starting test %q", testname)
	if _, err := runLoggedCommand(ctx, f.dir, "fx", "test", testname); err != nil {
		return err
	}
	cancel()
	return eg.Wait()
}

// waitForServerStarts waits for both the emulator and the fx server to emit
// their ready strings.
func (f *fxTest) waitForServerStarts(ctx context.Context, readyC chan int) error {
	serversReady := 2
	ticker := time.NewTicker(2 * time.Second)
	timeouter := time.After(fxServersStartTimeout)
	startTime := time.Now()
	for {
		select {
		case <-readyC:
			serversReady--
			if serversReady == 0 {
				return nil
			}
		case <-ticker.C:
			line := fmt.Sprintf("[waiting %s for %d servers to be ready]", time.Since(startTime).Round(time.Second), serversReady)
			logMessage(line, false)
		case <-timeouter:
			return errors.New("timed out waiting for servers to ge ready")
		}
	}
}

// runServer manages the running server, reacting to signals and terminations,
// ensuring that all child processes are terminated if the context is done.
func (f *fxTest) runServer(ctx context.Context, cmd *exec.Cmd, sigC, resC chan error, readyC chan int, command string) error {
	// Wait for the signal that it's ready to serve.
	for {
		select {
		case err := <-sigC:
			if err == nil { // nil indicates that the keyString was seen.
				log.Printf("==> `%s` started and ready to serve", command)
				readyC <- 1
			}
			msg := fmt.Sprintf("`%s` stderr>> %v", command, err)
			logMessage(msg, false)
		case err := <-resC:
			if err == nil { // nil indicates that exit code was 0.
				log.Printf("`%s` completed", command)
				return nil
			}
			log.Printf("`%s` completed with error: %v", command, err)
			return err
		case <-ctx.Done():
			// Ensure child processes are also termincated.
			return terminateProcessesGroup(cmd)
		}
	}
}

// logMessage writes the given msg to either the terminal or log. If chatty, it
// is written to the log. If not, it is are written to the terminal with a
// limited length and on the same line. So not chatty -> the errors appear, but
// in a limited space. chatty -> the errors spew out of the terminal like a
// mewing cat that claims to have never been fed.
func logMessage(line string, chatty bool) {
	if chatty {
		log.Printf(line)
		return
	}
	line = flattenString(line, maxLineWidth)
	// Note fmt here, not log, so written to stdout.
	fmt.Printf("\r%s%s", line, ansiClearToEOL)
}