diff --git a/Makefile b/Makefile index 60449e2..90433f8 100644 --- a/Makefile +++ b/Makefile @@ -20,7 +20,7 @@ mock-handler: test: @echo "Running runner unit tests..." - go test ./runner/... + go test -v ./runner/... @echo "Running conformance tests with mock handler..." $(RUNNER_BIN) -handler $(MOCK_HANDLER_BIN) diff --git a/README.md b/README.md index 9f075c8..62f81f3 100644 --- a/README.md +++ b/README.md @@ -52,8 +52,20 @@ make runner # Run the test runner against your handler binary ./build/runner --handler + +# Configure timeouts (optional) +./build/runner --handler \ + --handler-timeout 30s \ # Max wait per test case (default: 10s) + --timeout 2m # Total execution limit (default: 30s) ``` +#### Timeout Flags + +- **`--handler-timeout`** (default: 10s): Maximum time to wait for handler response to each test case. Prevents hangs on unresponsive handlers. +- **`--timeout`** (default: 30s): Total execution time limit across all test suites. Ensures bounded test runs. + +The runner automatically detects and recovers from crashed/unresponsive handlers, allowing remaining tests to continue. + ### Testing the Runner Build and test the runner: diff --git a/cmd/runner/main.go b/cmd/runner/main.go index 77a5729..fa756d7 100644 --- a/cmd/runner/main.go +++ b/cmd/runner/main.go @@ -1,11 +1,13 @@ package main import ( + "context" "flag" "fmt" "io/fs" "os" "strings" + "time" "github.com/stringintech/kernel-bindings-tests/runner" "github.com/stringintech/kernel-bindings-tests/testdata" @@ -13,6 +15,8 @@ import ( func main() { handlerPath := flag.String("handler", "", "Path to handler binary") + handlerTimeout := flag.Duration("handler-timeout", 10*time.Second, "Max time to wait for handler to respond to each test case (e.g., 10s, 500ms)") + timeout := flag.Duration("timeout", 30*time.Second, "Total timeout for executing all test suites (e.g., 30s, 1m)") flag.Parse() if *handlerPath == "" { @@ -33,6 +37,18 @@ func main() { os.Exit(1) } + // Create test runner + testRunner, err := runner.NewTestRunner(*handlerPath, *handlerTimeout, *timeout) + if err != nil { + fmt.Fprintf(os.Stderr, "Error creating test runner: %v\n", err) + os.Exit(1) + } + defer testRunner.CloseHandler() + + // Create context with total execution timeout + ctx, cancel := context.WithTimeout(context.Background(), *timeout) + defer cancel() + // Run tests totalPassed := 0 totalFailed := 0 @@ -48,17 +64,8 @@ func main() { continue } - // Create test runner - testRunner, err := runner.NewTestRunner(*handlerPath) - if err != nil { - fmt.Fprintf(os.Stderr, "Error creating test runner: %v\n", err) - continue - } - // Run suite - result := testRunner.RunTestSuite(*suite) - testRunner.Close() - + result := testRunner.RunTestSuite(ctx, *suite) printResults(suite, result) totalPassed += result.PassedTests diff --git a/runner/handler.go b/runner/handler.go new file mode 100644 index 0000000..2239e76 --- /dev/null +++ b/runner/handler.go @@ -0,0 +1,158 @@ +package runner + +import ( + "bufio" + "bytes" + "errors" + "fmt" + "io" + "log/slog" + "os/exec" + "time" +) + +var ( + // ErrHandlerTimeout indicates the handler did not respond within the timeout + ErrHandlerTimeout = errors.New("handler timeout") + // ErrHandlerClosed indicates the handler closed stdout unexpectedly + ErrHandlerClosed = errors.New("handler closed unexpectedly") +) + +// HandlerConfig configures a handler process +type HandlerConfig struct { + Path string + Args []string + Env []string + // Timeout specifies the maximum duration to wait when reading from the handler's + // stdout. If zero, defaults to 10 seconds. The handler is killed if it fails to + // write output within this timeout. + Timeout time.Duration +} + +// Handler manages a conformance handler process communicating via stdin/stdout +type Handler struct { + cmd *exec.Cmd + stdin io.WriteCloser + stdout *bufio.Scanner + stderr io.ReadCloser + timeout time.Duration +} + +// NewHandler spawns a new handler process with the given configuration +func NewHandler(cfg *HandlerConfig) (*Handler, error) { + cmd := exec.Command(cfg.Path, cfg.Args...) + if cfg.Env != nil { + cmd.Env = append(cmd.Environ(), cfg.Env...) + } + + stdin, err := cmd.StdinPipe() + if err != nil { + return nil, fmt.Errorf("failed to create stdin pipe: %w", err) + } + + stdout, err := cmd.StdoutPipe() + if err != nil { + return nil, fmt.Errorf("failed to create stdout pipe: %w", err) + } + + stderr, err := cmd.StderrPipe() + if err != nil { + return nil, fmt.Errorf("failed to create stderr pipe: %w", err) + } + + // Start() automatically closes all pipes on failure, no manual cleanup needed + if err := cmd.Start(); err != nil { + return nil, fmt.Errorf("failed to start handler: %w", err) + } + + timeout := cfg.Timeout + if timeout == 0 { + timeout = 10 * time.Second + } + + return &Handler{ + cmd: cmd, + stdin: stdin, + stdout: bufio.NewScanner(stdout), + stderr: stderr, + timeout: timeout, + }, nil +} + +// SendLine writes a line to the handler's stdin +func (h *Handler) SendLine(line []byte) error { + _, err := h.stdin.Write(append(line, '\n')) + return err +} + +// ReadLine reads a line from the handler's stdout with a configurable timeout +func (h *Handler) ReadLine() ([]byte, error) { + // Use a timeout for Scan() in case the handler hangs + scanDone := make(chan bool, 1) + go func() { + scanDone <- h.stdout.Scan() + }() + + var baseErr error + select { + case ok := <-scanDone: + if ok { + return h.stdout.Bytes(), nil + } + if err := h.stdout.Err(); err != nil { + return nil, err + } + // EOF - handler closed stdout prematurely, fall through to kill and capture stderr + baseErr = ErrHandlerClosed + case <-time.After(h.timeout): + // Timeout - handler didn't respond, fall through to kill and capture stderr + baseErr = ErrHandlerTimeout + } + + // Kill the process immediately to force stderr to close. + // Without this, there's a rare scenario where stdout closes but stderr remains open, + // causing io.ReadAll(h.stderr) below to block indefinitely waiting for stderr EOF. + if h.cmd.Process != nil { + h.cmd.Process.Kill() + } + + // Capture stderr to provide diagnostic information when the handler fails. + if stderrOut, err := io.ReadAll(h.stderr); err == nil && len(stderrOut) > 0 { + return nil, fmt.Errorf("%w: %s", baseErr, bytes.TrimSpace(stderrOut)) + } + return nil, baseErr +} + +// Close closes stdin and waits for the handler to exit with a 5-second timeout. +// If the handler doesn't exit within the timeout, it is killed. +func (h *Handler) Close() { + if h.stdin != nil { + // Close stdin to signal the handler that we're done sending requests. + // Per the handler specification, the handler should exit cleanly when stdin closes. + h.stdin.Close() + } + if h.cmd != nil { + // Wait for the handler to exit cleanly in response to stdin closing. + // Wait() automatically closes all remaining pipes after the process exits. + // Use a timeout in case the handler doesn't respect the protocol. + done := make(chan error, 1) + go func() { + done <- h.cmd.Wait() + }() + + select { + case err := <-done: + if err != nil { + slog.Warn("Handler exit with error", "error", err) + } + case <-time.After(5 * time.Second): + slog.Warn("Handler did not exit within a 5-second timeout, killing process") + if h.cmd.Process != nil { + h.cmd.Process.Kill() + // Call Wait() again to let the process finish cleanup (closing pipes, etc.) + // No timeout needed since Kill() should guarantee the process will exit + h.cmd.Wait() + } + } + } +} diff --git a/runner/handler_test.go b/runner/handler_test.go new file mode 100644 index 0000000..228ebff --- /dev/null +++ b/runner/handler_test.go @@ -0,0 +1,196 @@ +package runner + +import ( + "bufio" + "errors" + "fmt" + "os" + "strings" + "testing" + "time" +) + +const ( + // envTestAsSubprocess signals the binary to run as a subprocess helper. + envTestAsSubprocess = "TEST_AS_SUBPROCESS" + + // envTestHelperName specifies which helper function to execute in subprocess mode. + envTestHelperName = "TEST_HELPER_NAME" + + // Handler simulation test identifiers. + helperNameNormal = "normal" + helperNameUnresponsive = "unresponsive" + helperNameCrash = "crash" +) + +// testHelpers maps helper names to functions that simulate different handler behaviors. +var testHelpers = map[string]func(){ + helperNameNormal: helperNormal, + helperNameUnresponsive: helperUnresponsive, + helperNameCrash: helperCrash, +} + +// TestMain allows the test binary to serve two purposes: +// 1. Normal mode: runs tests when TEST_AS_SUBPROCESS != "1" +// 2. Subprocess mode: executes a helper function when TEST_AS_SUBPROCESS == "1" +// +// This enables tests to spawn the binary itself as a mock handler subprocess, +// avoiding the need for separate test fixture binaries. +func TestMain(m *testing.M) { + if os.Getenv(envTestAsSubprocess) != "1" { + // Run tests normally + os.Exit(m.Run()) + } + + // Run as subprocess helper based on which helper is requested + helperName := os.Getenv(envTestHelperName) + if helper, ok := testHelpers[helperName]; ok { + helper() + } else { + fmt.Fprintf(os.Stderr, "Unknown test helper: %s\n", helperName) + os.Exit(1) + } +} + +// TestHandler_NormalOperation tests that a well-behaved handler works correctly +func TestHandler_NormalOperation(t *testing.T) { + h, err := newHandlerForTest(t, helperNameNormal, 0) + if err != nil { + t.Fatalf("Failed to create handler: %v", err) + } + defer h.Close() + + // Send a request to the handler + request := `{"id":1,"method":"test"}` + if err := h.SendLine([]byte(request)); err != nil { + t.Fatalf("Failed to send request: %v", err) + } + + // Read the response + line, err := h.ReadLine() + if err != nil { + t.Fatalf("Failed to read line: %v", err) + } + + expected := `{"id":1,"result":true}` + if string(line) != expected { + t.Errorf("Expected %q, got %q", expected, string(line)) + } +} + +// helperNormal simulates a normal well-behaved handler that reads a request, +// validates it, and sends a response. +func helperNormal() { + // Read requests from stdin and respond with expected results + scanner := bufio.NewScanner(os.Stdin) + for scanner.Scan() { + request := scanner.Text() + expected := `{"id":1,"method":"test"}` + if request != expected { + fmt.Fprintf(os.Stderr, "Expected request %q, got %q\n", expected, request) + os.Exit(1) + } + fmt.Println(`{"id":1,"result":true}`) + } +} + +// TestHandler_Unresponsive tests that the runner correctly handles an unresponsive handler +func TestHandler_Unresponsive(t *testing.T) { + h, err := newHandlerForTest(t, helperNameUnresponsive, 100*time.Millisecond) + if err != nil { + t.Fatalf("Failed to create handler: %v", err) + } + defer h.Close() + + // Send a request to the handler + request := `{"id":1,"method":"test"}` + if err := h.SendLine([]byte(request)); err != nil { + t.Fatalf("Failed to send request: %v", err) + } + + // Try to read the response - should Timeout + start := time.Now() + _, err = h.ReadLine() + elapsed := time.Since(start) + + if err == nil { + t.Fatal("Expected error from unresponsive handler, got nil") + } + + // Verify it's the Timeout error we expect + if !errors.Is(err, ErrHandlerTimeout) { + t.Errorf("Expected ErrHandlerTimeout, got: %v", err) + } + + // Verify Timeout happened quickly (within reasonable margin) + if elapsed > 200*time.Millisecond { + t.Errorf("Timeout took too long: %v (expected ~100ms)", elapsed) + } +} + +// helperUnresponsive simulates a handler that receives requests but never responds, +// triggering the Timeout mechanism in the runner. +func helperUnresponsive() { + // Read from stdin to prevent broken pipe, but never write responses + scanner := bufio.NewScanner(os.Stdin) + for scanner.Scan() { + // Sleep indefinitely to simulate unresponsiveness + time.Sleep(1 * time.Hour) + } +} + +// TestHandler_Crash tests that the runner correctly handles a handler that crashes +// while processing a request +func TestHandler_Crash(t *testing.T) { + h, err := newHandlerForTest(t, helperNameCrash, 0) + if err != nil { + t.Fatalf("Failed to create handler: %v", err) + } + defer h.Close() + + // Send a request to the handler + request := `{"id":1,"method":"test"}` + if err := h.SendLine([]byte(request)); err != nil { + t.Fatalf("Failed to send request: %v", err) + } + + // Try to read the response - should get ErrHandlerClosed + _, err = h.ReadLine() + + if err == nil { + t.Fatal("Expected error from crashed handler, got nil") + } + + // Verify it's the handler closed error we expect + if !errors.Is(err, ErrHandlerClosed) { + t.Errorf("Expected ErrHandlerClosed, got: %v", err) + } + + // Verify the error message contains the panic string from stderr + if !strings.Contains(err.Error(), "simulated handler crash") { + t.Errorf("Expected error to contain 'simulated handler crash', got: %v", err) + } +} + +// helperCrash simulates a handler that crashes while processing a request, +// triggering the ErrHandlerClosed error in the runner. +func helperCrash() { + // Read requests from stdin but panic instead of responding + scanner := bufio.NewScanner(os.Stdin) + for scanner.Scan() { + panic("simulated handler crash") + } +} + +// newHandlerForTest creates a Handler that runs a test helper as a subprocess. +// The helperName identifies which helper to run (e.g., "normal", "crash", "hang"). +// The timeout parameter sets the per-request timeout (0 uses default). +func newHandlerForTest(t *testing.T, helperName string, timeout time.Duration) (*Handler, error) { + t.Helper() + + return NewHandler(&HandlerConfig{ + Path: os.Args[0], + Env: []string{"TEST_AS_SUBPROCESS=1", "TEST_HELPER_NAME=" + helperName}, + Timeout: timeout, + }) +} diff --git a/runner/runner.go b/runner/runner.go index 11fed46..3c2c441 100644 --- a/runner/runner.go +++ b/runner/runner.go @@ -1,126 +1,113 @@ package runner import ( - "bufio" - "bytes" + "context" "embed" "encoding/json" "fmt" - "io" "io/fs" + "log/slog" "os" - "os/exec" "path/filepath" + "time" ) // TestRunner executes test suites against a handler binary type TestRunner struct { - handlerPath string - cmd *exec.Cmd - stdin io.WriteCloser - stdout *bufio.Scanner - stderr io.ReadCloser + handler *Handler + handlerConfig *HandlerConfig + timeout time.Duration } -// NewTestRunner creates a new test runner -func NewTestRunner(handlerPath string) (*TestRunner, error) { +// NewTestRunner creates a new test runner for executing test suites against a handler binary. +// The handlerTimeout parameter specifies the maximum duration to wait for the handler to +// respond to each test case. If zero, defaults to 10 seconds. +// The timeout parameter specifies the total duration allowed for running all tests +// across all test suites. If zero, defaults to 30 seconds. +func NewTestRunner(handlerPath string, handlerTimeout time.Duration, timeout time.Duration) (*TestRunner, error) { if _, err := os.Stat(handlerPath); os.IsNotExist(err) { return nil, fmt.Errorf("handler binary not found: %s", handlerPath) } - cmd := exec.Command(handlerPath) - - stdin, err := cmd.StdinPipe() - if err != nil { - return nil, fmt.Errorf("failed to create stdin pipe: %w", err) - } - - stdout, err := cmd.StdoutPipe() - if err != nil { - return nil, fmt.Errorf("failed to create stdout pipe: %w", err) - } - - stderr, err := cmd.StderrPipe() + handler, err := NewHandler(&HandlerConfig{ + Path: handlerPath, + Timeout: handlerTimeout, + }) if err != nil { - return nil, fmt.Errorf("failed to create stderr pipe: %w", err) + return nil, err } - if err := cmd.Start(); err != nil { - return nil, fmt.Errorf("failed to start handler: %w", err) + if timeout == 0 { + timeout = 30 * time.Second } return &TestRunner{ - handlerPath: handlerPath, - cmd: cmd, - stdin: stdin, - stdout: bufio.NewScanner(stdout), - stderr: stderr, + handler: handler, + handlerConfig: &HandlerConfig{ + Path: handlerPath, + Timeout: handlerTimeout, + }, + timeout: timeout, }, nil } -// Close terminates the handler process -func (tr *TestRunner) Close() error { - if tr.stdin != nil { - tr.stdin.Close() - } - if tr.cmd != nil { - return tr.cmd.Wait() +// SendRequest sends a request to the handler, spawning a new handler if needed +func (tr *TestRunner) SendRequest(req Request) error { + if tr.handler == nil { + handler, err := NewHandler(tr.handlerConfig) + if err != nil { + return fmt.Errorf("failed to spawn new handler: %w", err) + } + tr.handler = handler } - return nil -} -// SendRequest sends a request and reads the response -func (tr *TestRunner) SendRequest(req Request) (*Response, error) { reqData, err := json.Marshal(req) if err != nil { - return nil, fmt.Errorf("failed to marshal request: %w", err) + return fmt.Errorf("failed to marshal request: %w", err) } - if _, err := tr.stdin.Write(append(reqData, '\n')); err != nil { - return nil, fmt.Errorf("failed to write request: %w", err) + if err := tr.handler.SendLine(reqData); err != nil { + slog.Warn("Failed to write request, cleaning up handler (will spawn new one for remaining tests)", "error", err) + tr.CloseHandler() + return fmt.Errorf("failed to write request: %w", err) } + return nil +} - // Read response - if !tr.stdout.Scan() { - if err := tr.stdout.Err(); err != nil { - return nil, fmt.Errorf("failed to read response: %w", err) - } - // Handler closed stdout prematurely. - // Kill the process immediately to force stderr to close. - // Without this, there's a rare scenario where stdout closes but stderr remains open, - // causing io.ReadAll(tr.stderr) below to block indefinitely waiting for stderr EOF. - if tr.cmd.Process != nil { - tr.cmd.Process.Kill() - } - if stderrOut, err := io.ReadAll(tr.stderr); err == nil && len(stderrOut) > 0 { - return nil, fmt.Errorf("handler closed unexpectedly: %s", bytes.TrimSpace(stderrOut)) - } - return nil, fmt.Errorf("handler closed unexpectedly") +// ReadResponse reads and unmarshals a response from the handler +func (tr *TestRunner) ReadResponse() (*Response, error) { + line, err := tr.handler.ReadLine() + if err != nil { + slog.Warn("Failed to read response, cleaning up handler (will spawn new one for remaining tests)", "error", err) + tr.CloseHandler() + return nil, err } - respLine := tr.stdout.Text() + var resp Response - if err := json.Unmarshal([]byte(respLine), &resp); err != nil { - return nil, fmt.Errorf("failed to parse response: %w", err) + if err := json.Unmarshal(line, &resp); err != nil { + return nil, err } return &resp, nil } -// RunTestSuite executes a test suite -func (tr *TestRunner) RunTestSuite(suite TestSuite) TestResult { +// CloseHandler closes the handler and sets it to nil +func (tr *TestRunner) CloseHandler() { + if tr.handler == nil { + return + } + tr.handler.Close() + tr.handler = nil +} + +// RunTestSuite executes a test suite. The context can be used to enforce a total +// execution timeout across all test suites. +func (tr *TestRunner) RunTestSuite(ctx context.Context, suite TestSuite) TestResult { result := TestResult{ SuiteName: suite.Name, TotalTests: len(suite.Tests), } for _, test := range suite.Tests { - err := tr.runTest(test) - testResult := SingleTestResult{ - TestID: test.ID, - Passed: err == nil, - } - if err != nil { - testResult.Message = err.Error() - } - + testResult := tr.runTest(ctx, test) result.TestResults = append(result.TestResults, testResult) if testResult.Passed { result.PassedTests++ @@ -132,21 +119,55 @@ func (tr *TestRunner) RunTestSuite(suite TestSuite) TestResult { return result } -// runTest executes a single test case and validates the response. -// Returns an error if communication with the handler fails or validation fails. -func (tr *TestRunner) runTest(test TestCase) error { +// runTest executes a single test case by sending a request, reading the response, +// and validating the result matches expected output +func (tr *TestRunner) runTest(ctx context.Context, test TestCase) SingleTestResult { + // Check if context is already cancelled + select { + case <-ctx.Done(): + return SingleTestResult{ + TestID: test.ID, + Passed: false, + Message: fmt.Sprintf("Total execution timeout exceeded (%v)", tr.timeout), + } + default: + } + req := Request{ ID: test.ID, Method: test.Method, Params: test.Params, } - resp, err := tr.SendRequest(req) + err := tr.SendRequest(req) if err != nil { - return err + return SingleTestResult{ + TestID: test.ID, + Passed: false, + Message: fmt.Sprintf("Failed to send request: %v", err), + } } - return validateResponse(test, resp) + resp, err := tr.ReadResponse() + if err != nil { + return SingleTestResult{ + TestID: test.ID, + Passed: false, + Message: fmt.Sprintf("Failed to read response: %v", err), + } + } + + if err := validateResponse(test, resp); err != nil { + return SingleTestResult{ + TestID: test.ID, + Passed: false, + Message: fmt.Sprintf("Invalid response: %s", err.Error()), + } + } + return SingleTestResult{ + TestID: test.ID, + Passed: true, + } } // validateResponse validates that a response matches the expected test outcome.