tests: capture tarantool log tail in startup errors

CHANGELOG.md

@@ -36,6 +36,12 @@ Versioning](http://semver.org/spec/v2.0.0.html) except to the first release.
 * New `MockRequestNamed` type for verifying specific requests in tests.
 * New `test_helpers.ExecuteOnAll` function to execute operations on all
   instances in parallel with context support.
+* New `(*test_helpers.TarantoolInstance).LogTail()` method that returns
+  the last 50 lines of captured tarantool stdout/stderr (#147).
+* New `test_helpers.DumpLogsIfFailed(t, inst)` helper that prints the
+  captured tarantool log via `t.Logf` when the test failed — intended
+  for `defer test_helpers.DumpLogsIfFailed(t, inst)` after a successful
+  `StartTarantool` (#147).
 
 ### Changed
 
@@ -109,6 +115,18 @@ Versioning](http://semver.org/spec/v2.0.0.html) except to the first release.
 
 * Fixed the fluctuating behavior of the TestConnectionHandlerOpenUpdateClose
   test by increasing the waiting time (#502).
+* On Linux, tarantool processes started by `test_helpers.StartTarantool`
+  are now terminated when the parent test process dies, preventing leaked
+  instances after a panic (#147).
+* `test_helpers.StartTarantool` now captures the last lines of the
+  spawned tarantool's stdout/stderr and includes them in the returned
+  error when startup fails, so test failures show the underlying
+  tarantool error directly instead of just "exit status 1" or a
+  connection timeout (#147).
+* Reordered tests to defer `test_helpers.StopTarantoolWithCleanup` only
+  after asserting `StartTarantool` did not return an error, so a failed
+  start no longer panics with a nil-pointer dereference in the deferred
+  cleanup (#147).
 
 ## [v2.4.1] - 2025-10-16
 

arrow/tarantool_test.go

@@ -108,12 +108,11 @@ func runTestMain(m *testing.M) int {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(instance)
-
 	if err != nil {
 		log.Printf("Failed to prepare test Tarantool: %s", err)
 		return 1
 	}
+	defer test_helpers.StopTarantoolWithCleanup(instance)
 
 	return m.Run()
 }

crud/tarantool_test.go

@@ -1446,12 +1446,11 @@ func TestYieldEveryOption(t *testing.T) {
 // https://stackoverflow.com/questions/27629380/how-to-exit-a-go-program-honoring-deferred-calls
 func runTestMain(m *testing.M) int {
 	inst, err := test_helpers.StartTarantool(startOpts)
-	defer test_helpers.StopTarantoolWithCleanup(inst)
-
 	if err != nil {
 		log.Printf("Failed to prepare test tarantool: %s", err)
 		return 1
 	}
+	defer test_helpers.StopTarantoolWithCleanup(inst)
 
 	return m.Run()
 }

datetime/datetime_test.go

@@ -981,12 +981,11 @@ func runTestMain(m *testing.M) int {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(instance)
-
 	if err != nil {
 		log.Printf("Failed to prepare test Tarantool: %s", err)
 		return 1
 	}
+	defer test_helpers.StopTarantoolWithCleanup(instance)
 
 	return m.Run()
 }

decimal/decimal_test.go

@@ -599,12 +599,11 @@ func runTestMain(m *testing.M) int {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(instance)
-
 	if err != nil {
 		log.Printf("Failed to prepare test Tarantool: %s", err)
 		return 1
 	}
+	defer test_helpers.StopTarantoolWithCleanup(instance)
 
 	return m.Run()
 }

tarantool_test.go

@@ -2762,8 +2762,8 @@ func newWatcherReconnectionPrepareTestConnection(t *testing.T) (*Connection, con
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	t.Cleanup(func() { test_helpers.StopTarantoolWithCleanup(inst) })
 	require.NoErrorf(t, err, "Unable to start Tarantool")
+	t.Cleanup(func() { test_helpers.StopTarantoolWithCleanup(inst) })
 
 	ctx, cancel := test_helpers.GetConnectContext()
 
@@ -2843,8 +2843,8 @@ func TestConnection_NewWatcher_reconnect(t *testing.T) {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(inst)
 	require.NoErrorf(t, err, "Unable to start Tarantool")
+	defer test_helpers.StopTarantoolWithCleanup(inst)
 
 	reconnectOpts := opts
 	reconnectOpts.Reconnect = 100 * time.Millisecond
@@ -3097,8 +3097,8 @@ func TestConnection_named_index_after_reconnect(t *testing.T) {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(inst)
 	require.NoErrorf(t, err, "Unable to start Tarantool")
+	defer test_helpers.StopTarantoolWithCleanup(inst)
 
 	reconnectOpts := opts
 	reconnectOpts.Reconnect = 100 * time.Millisecond
@@ -3205,8 +3205,8 @@ func TestConnectIsBlocked(t *testing.T) {
 		ConnectRetry: 10,
 		RetryTimeout: 500 * time.Millisecond,
 	})
-	defer test_helpers.StopTarantoolWithCleanup(inst)
 	require.NoErrorf(t, err, "Unable to start Tarantool")
+	defer test_helpers.StopTarantoolWithCleanup(inst)
 
 	var counter int
 	mockDialer := mockSlowDialer{original: testDialer, counter: &counter}

test_helpers/cmd_linux.go

@@ -0,0 +1,21 @@
+//go:build linux
+
+package test_helpers
+
+import (
+	"os/exec"
+	"syscall"
+)
+
+// commandKillOnExit returns an *exec.Cmd that will be terminated by the
+// kernel when the parent process dies, see
+// https://github.com/golang/go/issues/37206. Without this, a panic in a
+// test leaves the spawned tarantool process running and blocking the TCP
+// port for subsequent runs (issue #147).
+func commandKillOnExit(name string, arg ...string) *exec.Cmd {
+	cmd := exec.Command(name, arg...)
+	cmd.SysProcAttr = &syscall.SysProcAttr{
+		Pdeathsig: syscall.SIGTERM,
+	}
+	return cmd
+}

test_helpers/cmd_other.go

@@ -0,0 +1,14 @@
+//go:build !linux
+
+package test_helpers
+
+import (
+	"os/exec"
+)
+
+// commandKillOnExit is a fallback for platforms without a Pdeathsig
+// equivalent. It just delegates to exec.Command, so a parent panic may
+// leave the tarantool child alive (issue #147).
+func commandKillOnExit(name string, arg ...string) *exec.Cmd {
+	return exec.Command(name, arg...)
+}

test_helpers/log_buffer.go

@@ -0,0 +1,87 @@
+package test_helpers
+
+import (
+	"bytes"
+	"strings"
+	"sync"
+)
+
+// logTailLines is the number of trailing log lines kept for a started
+// tarantool instance. Shown in the StartTarantool error to help diagnose
+// failures from CI logs without re-running the test.
+const logTailLines = 50
+
+// logTailBuffer is an io.Writer that keeps the last logTailLines lines
+// written to it. Safe for concurrent writes from exec.Cmd's stdout and
+// stderr copy goroutines.
+type logTailBuffer struct {
+	mu      sync.Mutex
+	lines   []string
+	pending []byte
+	max     int
+}
+
+func newLogTailBuffer(maxLines int) *logTailBuffer {
+	return &logTailBuffer{max: maxLines}
+}
+
+func (b *logTailBuffer) Write(p []byte) (int, error) {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+
+	b.pending = append(b.pending, p...)
+	for {
+		i := bytes.IndexByte(b.pending, '\n')
+		if i < 0 {
+			break
+		}
+		b.appendLine(string(b.pending[:i]))
+		b.pending = b.pending[i+1:]
+	}
+	return len(p), nil
+}
+
+func (b *logTailBuffer) appendLine(line string) {
+	if len(b.lines) >= b.max {
+		copy(b.lines, b.lines[1:])
+		b.lines = b.lines[:len(b.lines)-1]
+	}
+	b.lines = append(b.lines, line)
+}
+
+// formatLogTail returns a "\n--- last N lines of tarantool log ---\n..."
+// suffix suitable for appending to a StartTarantool error. Returns an
+// empty string when the buffer captured nothing.
+func formatLogTail(b *logTailBuffer) string {
+	if b == nil {
+		return ""
+	}
+	tail := b.Tail()
+	if tail == "" {
+		return ""
+	}
+	return "\n--- last tarantool log lines ---\n" + tail + "--- end of tarantool log ---"
+}
+
+// Tail returns the buffered output as a single string with a trailing
+// newline if non-empty, including any partial line that was not yet
+// terminated by '\n'.
+func (b *logTailBuffer) Tail() string {
+	b.mu.Lock()
+	defer b.mu.Unlock()
+
+	if len(b.lines) == 0 && len(b.pending) == 0 {
+		return ""
+	}
+
+	var sb strings.Builder
+	for _, l := range b.lines {
+		sb.WriteString(l)
+		sb.WriteByte('\n')
+	}
+	if len(b.pending) > 0 {
+		sb.Write(b.pending)
+		sb.WriteByte('\n')
+	}
+	return sb.String()
+}

test_helpers/log_buffer_test.go

@@ -0,0 +1,72 @@
+package test_helpers
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+)
+
+func TestLogTailBuffer_KeepsLastNLines(t *testing.T) {
+	b := newLogTailBuffer(3)
+	for i := 1; i <= 5; i++ {
+		_, _ = fmt.Fprintf(b, "line %d\n", i)
+	}
+	got := b.Tail()
+	want := "line 3\nline 4\nline 5\n"
+	if got != want {
+		t.Fatalf("Tail mismatch:\n got: %q\nwant: %q", got, want)
+	}
+}
+
+func TestLogTailBuffer_PartialLine(t *testing.T) {
+	b := newLogTailBuffer(5)
+	if _, err := b.Write([]byte("hello ")); err != nil {
+		t.Fatalf("Write: %v", err)
+	}
+	if _, err := b.Write([]byte("world")); err != nil {
+		t.Fatalf("Write: %v", err)
+	}
+	got := b.Tail()
+	if got != "hello world\n" {
+		t.Fatalf("Tail mismatch: got %q", got)
+	}
+}
+
+func TestLogTailBuffer_SplitWrites(t *testing.T) {
+	b := newLogTailBuffer(5)
+	_, _ = b.Write([]byte("first\nsecon"))
+	_, _ = b.Write([]byte("d\nthird\n"))
+	got := b.Tail()
+	want := "first\nsecond\nthird\n"
+	if got != want {
+		t.Fatalf("Tail mismatch:\n got: %q\nwant: %q", got, want)
+	}
+}
+
+func TestLogTailBuffer_Empty(t *testing.T) {
+	b := newLogTailBuffer(5)
+	if got := b.Tail(); got != "" {
+		t.Fatalf("expected empty, got %q", got)
+	}
+	if got := formatLogTail(b); got != "" {
+		t.Fatalf("expected empty formatLogTail, got %q", got)
+	}
+	if got := formatLogTail(nil); got != "" {
+		t.Fatalf("expected empty formatLogTail(nil), got %q", got)
+	}
+}
+
+func TestFormatLogTail_Wraps(t *testing.T) {
+	b := newLogTailBuffer(5)
+	_, _ = b.Write([]byte("boom\n"))
+	got := formatLogTail(b)
+	if !strings.Contains(got, "--- last tarantool log lines ---") {
+		t.Fatalf("missing header: %q", got)
+	}
+	if !strings.Contains(got, "boom") {
+		t.Fatalf("missing line: %q", got)
+	}
+	if !strings.HasSuffix(got, "--- end of tarantool log ---") {
+		t.Fatalf("missing footer: %q", got)
+	}
+}

test_helpers/log_dump.go

@@ -0,0 +1,29 @@
+package test_helpers
+
+// failedLogger is the subset of *testing.T needed by DumpLogsIfFailed.
+// Kept separate from T so adding Failed/Logf does not change the public
+// T interface contract.
+type failedLogger interface {
+	Helper()
+	Failed() bool
+	Logf(format string, args ...any)
+}
+
+// DumpLogsIfFailed prints the tail of the tarantool instance's captured
+// stdout/stderr via t.Logf when the test has already failed. Intended
+// for use as `defer test_helpers.DumpLogsIfFailed(t, inst)` right after
+// a successful StartTarantool, so an assertion failure later in the
+// test surfaces the corresponding tarantool log alongside the failure.
+//
+// No-op when the test passed, the instance is nil, or no log was captured.
+func DumpLogsIfFailed(t failedLogger, inst *TarantoolInstance) {
+	t.Helper()
+	if !t.Failed() || inst == nil {
+		return
+	}
+	tail := inst.LogTail()
+	if tail == "" {
+		return
+	}
+	t.Logf("tarantool %q log tail:\n%s", inst.Opts.Listen, tail)
+}