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
 
@@ -112,6 +118,11 @@ Versioning](http://semver.org/spec/v2.0.0.html) except to the first release.
 * 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

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,50 @@
+package test_helpers
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+func TestLogTailBuffer_KeepsLastNLines(t *testing.T) {
+	b := newLogTailBuffer(3)
+	for i := 1; i <= 5; i++ {
+		_, _ = fmt.Fprintf(b, "line %d\n", i)
+	}
+	require.Equal(t, "line 3\nline 4\nline 5\n", b.Tail())
+}
+
+func TestLogTailBuffer_PartialLine(t *testing.T) {
+	b := newLogTailBuffer(5)
+	_, err := b.Write([]byte("hello "))
+	require.NoError(t, err)
+	_, err = b.Write([]byte("world"))
+	require.NoError(t, err)
+	require.Equal(t, "hello world\n", b.Tail())
+}
+
+func TestLogTailBuffer_SplitWrites(t *testing.T) {
+	b := newLogTailBuffer(5)
+	_, _ = b.Write([]byte("first\nsecon"))
+	_, _ = b.Write([]byte("d\nthird\n"))
+	require.Equal(t, "first\nsecond\nthird\n", b.Tail())
+}
+
+func TestLogTailBuffer_Empty(t *testing.T) {
+	b := newLogTailBuffer(5)
+	require.Empty(t, b.Tail())
+	require.Empty(t, formatLogTail(b))
+	require.Empty(t, formatLogTail(nil))
+}
+
+func TestFormatLogTail_Wraps(t *testing.T) {
+	b := newLogTailBuffer(5)
+	_, _ = b.Write([]byte("boom\n"))
+	got := formatLogTail(b)
+	require.Contains(t, got, "--- last tarantool log lines ---")
+	require.Contains(t, got, "boom")
+	require.True(t, strings.HasSuffix(got, "--- end of tarantool log ---"),
+		"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)
+}

test_helpers/log_dump_test.go

@@ -0,0 +1,63 @@
+package test_helpers
+
+import (
+	"fmt"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+)
+
+type fakeT struct {
+	failed bool
+	logs   []string
+	helped int
+}
+
+func (f *fakeT) Helper()      { f.helped++ }
+func (f *fakeT) Failed() bool { return f.failed }
+func (f *fakeT) Logf(format string, args ...any) {
+	f.logs = append(f.logs, fmt.Sprintf(format, args...))
+}
+
+func newInstWithLog(lines ...string) *TarantoolInstance {
+	inst := &TarantoolInstance{log: newLogTailBuffer(logTailLines)}
+	inst.Opts.Listen = "127.0.0.1:1234"
+	for _, l := range lines {
+		_, _ = fmt.Fprintln(inst.log, l)
+	}
+	return inst
+}
+
+func TestDumpLogsIfFailed_PassedTest(t *testing.T) {
+	ft := &fakeT{failed: false}
+	DumpLogsIfFailed(ft, newInstWithLog("oops"))
+	require.Empty(t, ft.logs, "expected no logs on passing test")
+}
+
+func TestDumpLogsIfFailed_FailedTest(t *testing.T) {
+	ft := &fakeT{failed: true}
+	DumpLogsIfFailed(ft, newInstWithLog("oops", "more context"))
+	require.Len(t, ft.logs, 1)
+	require.Contains(t, ft.logs[0], "oops")
+	require.Contains(t, ft.logs[0], "more context")
+	require.Contains(t, ft.logs[0], "127.0.0.1:1234")
+}
+
+func TestDumpLogsIfFailed_NilInstance(t *testing.T) {
+	ft := &fakeT{failed: true}
+	DumpLogsIfFailed(ft, nil)
+	require.Empty(t, ft.logs, "expected no logs for nil instance")
+}
+
+func TestDumpLogsIfFailed_EmptyLog(t *testing.T) {
+	ft := &fakeT{failed: true}
+	DumpLogsIfFailed(ft, newInstWithLog())
+	require.Empty(t, ft.logs, "expected no logs for empty buffer")
+}
+
+func TestTarantoolInstance_LogTail_Nil(t *testing.T) {
+	var inst *TarantoolInstance
+	require.Empty(t, inst.LogTail(), "nil receiver")
+	inst2 := &TarantoolInstance{}
+	require.Empty(t, inst2.LogTail(), "no buffer")
+}

test_helpers/main.go

@@ -99,7 +99,8 @@ type TarantoolInstance struct {
 	// Dialer to check that connection established.
 	Dialer tarantool.Dialer
 
-	st chan state
+	st  chan state
+	log *logTailBuffer
 }
 
 // T is a subset of testing.T interface used by test helpers.
@@ -201,6 +202,17 @@ func (t *TarantoolInstance) Signal(sig os.Signal) error {
 	return t.Cmd.Process.Signal(sig)
 }
 
+// LogTail returns the tail of the spawned tarantool's combined
+// stdout/stderr captured since the process was started — up to
+// the last 50 lines. Includes a partial trailing line if the
+// process did not flush a newline. Empty if no output was captured.
+func (t *TarantoolInstance) LogTail() string {
+	if t == nil || t.log == nil {
+		return ""
+	}
+	return t.log.Tail()
+}
+
 func isReady(dialer tarantool.Dialer, opts *tarantool.Opts) error {
 	var err error
 	var conn *tarantool.Connection
@@ -345,6 +357,7 @@ func RestartTarantool(inst *TarantoolInstance) error {
 
 	inst.Cmd.Process = startedInst.Cmd.Process
 	inst.st = startedInst.st
+	inst.log = startedInst.log
 
 	return err
 }
@@ -401,7 +414,8 @@ func prepareDir(workDir string) (string, error) {
 func StartTarantool(startOpts StartOpts) (*TarantoolInstance, error) {
 	// Prepare tarantool command.
 	inst := &TarantoolInstance{
-		st: make(chan state, 1),
+		st:  make(chan state, 1),
+		log: newLogTailBuffer(logTailLines),
 	}
 	init := state{
 		done: make(chan struct{}),
@@ -432,6 +446,8 @@ func StartTarantool(startOpts StartOpts) (*TarantoolInstance, error) {
 	}
 	inst.Cmd = commandKillOnExit(getTarantoolExec(), args...)
 	inst.Cmd.Dir = startOpts.WorkDir
+	inst.Cmd.Stdout = inst.log
+	inst.Cmd.Stderr = inst.log
 
 	inst.Cmd.Env = append(
 		os.Environ(),
@@ -485,15 +501,16 @@ func StartTarantool(startOpts StartOpts) (*TarantoolInstance, error) {
 	}
 
 	if inst.IsExit() && inst.result() != nil {
+		runErr := inst.result()
 		StopTarantool(inst)
-		return nil, fmt.Errorf("unexpected terminated Tarantool %q: %w",
-			inst.Opts.Listen, inst.result())
+		return nil, fmt.Errorf("unexpected terminated Tarantool %q: %w%s",
+			inst.Opts.Listen, runErr, formatLogTail(inst.log))
 	}
 
 	if err != nil {
 		StopTarantool(inst)
-		return nil, fmt.Errorf("failed to connect Tarantool %q: %w",
-			inst.Opts.Listen, err)
+		return nil, fmt.Errorf("failed to connect Tarantool %q: %w%s",
+			inst.Opts.Listen, err, formatLogTail(inst.log))
 	}
 
 	return inst, nil