Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,9 @@ and this project adheres to [Semantic Versioning](http://semver.org/spec/v2.0.0.

### Fixed

- `tt log -f`: fixed possible line loss/duplication on rename and hanging
after a watched log directory is removed.

## [2.13.0] - 2026-05-21

This release adds cluster worker configuration management and fixes
Expand Down
53 changes: 51 additions & 2 deletions cli/cmd/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,9 @@ import (
"fmt"
"os"
"os/signal"
"path/filepath"
"sync"
"time"

"github.com/spf13/cobra"
"github.com/tarantool/tt/cli/cmd/internal"
Expand All @@ -20,6 +22,8 @@ var logOpts struct {
follow bool // Follow logs output.
}

const logRootCheckInterval = 100 * time.Millisecond

// NewLogCmd creates log command.
func NewLogCmd() *cobra.Command {
logCmd := &cobra.Command{
Expand Down Expand Up @@ -60,10 +64,46 @@ func printLines(ctx context.Context, in <-chan string) error {
}
}

type logRootContext struct {
ctx context.Context
cancel context.CancelFunc
}

func logRoot(inst running.InstanceCtx) string {
if inst.SingleApp {
return inst.LogDir
}
return filepath.Dir(inst.LogDir)
}

func monitorLogRoot(ctx context.Context, root string, cancel context.CancelFunc) {
ticker := time.NewTicker(logRootCheckInterval)
defer ticker.Stop()

for {
select {
case <-ctx.Done():
return
case <-ticker.C:
if _, err := os.Stat(root); errors.Is(err, os.ErrNotExist) {
cancel()
return
}
}
}
}

func follow(instances []running.InstanceCtx, n int) error {
ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt)
defer stop()

rootContexts := make(map[string]logRootContext)
defer func() {
for _, rootCtx := range rootContexts {
rootCtx.cancel()
}
}()

nextColor := tail.DefaultColorPicker()
color := nextColor()
const logLinesChannelCapacity = 64
Expand All @@ -72,9 +112,18 @@ func follow(instances []running.InstanceCtx, n int) error {
// Wait group to wait for completion of all log reading routines to close the channel once.
var wg sync.WaitGroup
for _, inst := range instances {
if err := tail.Follow(ctx, logLines,
root := logRoot(inst)
rootCtx, ok := rootContexts[root]
if !ok {
rootCtx.ctx, rootCtx.cancel = context.WithCancel(ctx)
rootContexts[root] = rootCtx
go monitorLogRoot(rootCtx.ctx, root, rootCtx.cancel)
}

err := tail.Follow(rootCtx.ctx, logLines,
tail.NewLogFormatter(running.GetAppInstanceName(inst)+": ", color),
inst.Log, n, &wg); err != nil {
inst.Log, n, &wg)
if err != nil {
if errors.Is(err, os.ErrNotExist) {
continue
}
Expand Down
51 changes: 51 additions & 0 deletions cli/cmd/log_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
package cmd

import (
"context"
"os"
"path/filepath"
"testing"
"time"

"github.com/tarantool/tt/cli/running"
)

func TestLogRoot(t *testing.T) {
t.Run("multi-instance application", func(t *testing.T) {
inst := running.InstanceCtx{
LogDir: filepath.Join("app", "var", "log", "instance"),
}
expected := filepath.Join("app", "var", "log")
if actual := logRoot(inst); actual != expected {
t.Fatalf("Unexpected log root: got %q, want %q", actual, expected)
}
})

t.Run("single-instance application", func(t *testing.T) {
inst := running.InstanceCtx{
LogDir: filepath.Join("var", "log"),
SingleApp: true,
}
if actual := logRoot(inst); actual != inst.LogDir {
t.Fatalf("Unexpected log root: got %q, want %q", actual, inst.LogDir)
}
})
}

func TestMonitorLogRoot(t *testing.T) {
root := t.TempDir()
ctx, cancel := context.WithCancel(context.Background())
defer cancel()

go monitorLogRoot(ctx, root, cancel)

if err := os.Remove(root); err != nil {
t.Fatalf("Failed to remove log root: %v", err)
}

select {
case <-ctx.Done():
case <-time.After(time.Second):
t.Fatal("Log root removal did not cancel the follow context")
}
}
2 changes: 1 addition & 1 deletion cli/tail/follow.go
Original file line number Diff line number Diff line change
Expand Up @@ -10,7 +10,7 @@ import (
"time"

"github.com/apex/log"
"github.com/nxadm/tail"
"github.com/tarantool/go-tail"
)

const (
Expand Down
142 changes: 79 additions & 63 deletions cli/tail/follow_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,10 +11,13 @@ import (
)

const (
linesPerStep = 3
channelCapacity = 100
logLineFormat = "%03d: line"
logNewLineFormat = "%03d: new line added"
linesPerStep = 3
channelCapacity = 100
lineReadTimeout = 5 * time.Second
reopenWatchDelay = 500 * time.Millisecond
watcherStartDelay = 100 * time.Millisecond
logLineFormat = "%03d: line"
logNewLineFormat = "%03d: new line added"
)

// readWithTimeout Helper to read from channel with timeout.
Expand All @@ -25,7 +28,10 @@ func readWithTimeout(t *testing.T, ch <-chan string, timeout time.Duration) (str
defer timer.Stop()

select {
case s := <-ch:
case s, ok := <-ch:
if !ok {
return "", fmt.Errorf("channel closed while waiting for data")
}
return s, nil
case <-timer.C:
return "", fmt.Errorf("timeout waiting for data")
Expand Down Expand Up @@ -60,13 +66,30 @@ func createTmpLogFile(t *testing.T, count int, line_fmt string) string {
return f.Name()
}

func appendSyncedLine(t *testing.T, path, line string) {
t.Helper()

file, err := os.OpenFile(path, os.O_APPEND|os.O_WRONLY, 0o644)
if err != nil {
t.Fatalf("Failed to open log file for append: %v", err)
}
defer file.Close()

if _, err := fmt.Fprintln(file, line); err != nil {
t.Fatalf("Failed to append log line: %v", err)
}
if err := file.Sync(); err != nil {
t.Fatalf("Failed to flush log line: %v", err)
}
}

func checksLinesInFile(t *testing.T, lines int, ch <-chan string, exp_fmt string) error {
t.Helper()

for i := range lines {
n := i + 1

line, err := readWithTimeout(t, ch, time.Second)
line, err := readWithTimeout(t, ch, lineReadTimeout)
if err != nil {
return fmt.Errorf("failed to read line %d: %w", n, err)
}
Expand Down Expand Up @@ -103,10 +126,6 @@ func TestFollow2_ReadExistingContent(t *testing.T) {
}

func TestFollow2_FollowNewContent(t *testing.T) {
if os.Getenv("CI") != "" {
t.Skip("Skipping flaky test on CI until issue #TNTP-3131 is fixed")
}

lf := createTmpLogFile(t, linesPerStep, logLineFormat)

ctx, cancel := context.WithCancel(context.Background())
Expand All @@ -124,6 +143,10 @@ func TestFollow2_FollowNewContent(t *testing.T) {
t.Fatalf("Failed to check lines in file: %v", err)
}

// TailFile starts its filesystem watcher asynchronously. Keep that startup
// outside the append scenario this test exercises.
time.Sleep(watcherStartDelay)

// Append new content
appendFile, err := os.OpenFile(lf, os.O_APPEND|os.O_WRONLY, 0o644)
if err != nil {
Expand Down Expand Up @@ -195,89 +218,82 @@ func TestFollow2_NonExistentFile(t *testing.T) {
}
}

func rotationTest(t *testing.T, use_delay bool) {
func TestFollow2_FileRotation(t *testing.T) {
lf := createTmpLogFile(t, linesPerStep, logLineFormat)

ctx, cancel := context.WithCancel(context.Background())
defer cancel()

f := tail.NewTailFollower(lf)

outCh, err := f.Follow(ctx, linesPerStep)
if err != nil {
t.Skipf("Failed to follow: %v", err)
cancel()
t.Fatalf("Failed to follow: %v", err)
}
defer func() {
cancel()
f.Wait()
}()

err = checksLinesInFile(t, linesPerStep, outCh, logLineFormat)
if err != nil {
t.Skipf("Failed to check initial lines in file: %v", err)
return
t.Fatalf("Failed to check initial lines in file: %v", err)
}

err = os.Rename(lf, lf+".bak")
// TailFile starts its filesystem watcher asynchronously. Keep that startup
// outside the write-plus-rename scenario this test exercises.
time.Sleep(watcherStartDelay)

const readinessLine = "watcher is ready"
appendSyncedLine(t, lf, readinessLine)
line, err := readWithTimeout(t, outCh, lineReadTimeout)
if err != nil {
t.Fatalf("Failed to rotate log file: %v", err)
t.Fatalf("Failed to read watcher readiness line: %v", err)
}

if use_delay {
time.Sleep(500 * time.Millisecond) // Add delay to avoid flaky fails.
if line != readinessLine {
t.Fatalf("Watcher readiness line mismatch: got %q, want %q", line, readinessLine)
}

newFile, err := os.Create(lf)
if err != nil {
t.Fatalf("Failed to create new log file: %v", err)
const replacementLine = "line in replacement file"
replacementPath := lf + ".new"
if err := os.WriteFile(replacementPath, []byte(replacementLine+"\n"), 0o644); err != nil {
t.Fatalf("Failed to prepare replacement log file: %v", err)
}

err = writeLogLines(t, newFile, linesPerStep, logNewLineFormat)

newFile.Close()
const lineBeforeRotation = "line written immediately before rotation"
appendSyncedLine(t, lf, lineBeforeRotation)
if err := os.Rename(lf, lf+".bak"); err != nil {
t.Fatalf("Failed to rotate log file: %v", err)
}

line, err = readWithTimeout(t, outCh, lineReadTimeout)
if err != nil {
t.Skipf("Failed to write new log lines after rotation: %v", err)
return
t.Fatalf("Failed to read line written before rotation: %v", err)
}
if line != lineBeforeRotation {
t.Fatalf("Line written before rotation mismatch: got %q, want %q",
line, lineBeforeRotation)
}

newFile.Close()
// Let the asynchronous reopen path start watching for the replacement.
// The loss assertion above remains adjacent to the rename.
time.Sleep(reopenWatchDelay)
if err := os.Rename(replacementPath, lf); err != nil {
t.Fatalf("Failed to install replacement log file: %v", err)
}

err = checksLinesInFile(t, linesPerStep, outCh, logNewLineFormat)
line, err = readWithTimeout(t, outCh, lineReadTimeout)
if err != nil {
t.Skipf("Failed to check appended lines in file: %v", err)
return
t.Fatalf("Failed to read line from replacement file: %v", err)
}
if line != replacementLine {
t.Fatalf("Replacement line mismatch: got %q, want %q", line, replacementLine)
}

cancel()
f.Wait()
}

// TestFollow2_FileRotation_Flaky tests the file rotation with flaky retries.
// It retries the test multiple times to handle potential flakiness in the tail library.
// This is a workaround for the issue #TNTP-3131, where the tail library
// does not handle file rotation correctly.
// - TODO: Need fix `tail` library, see #TNTP-3131 for more details.
func TestFollow2_FileRotation_Flaky(t *testing.T) {
if os.Getenv("CI") != "" {
t.Skip("Skipping flaky test on CI until issue #TNTP-3131 is fixed")
}

const flakyRepeatCount = 3

test_pass := false

for i := range flakyRepeatCount {
t.Run(fmt.Sprintf("Rotation-%d", i+1), func(t *testing.T) {
rotationTest(t, i > 0)

test_pass = !t.Skipped()
})

if test_pass {
break
}

t.Logf("FLAKY test %s failed, retrying flaky test iteration", t.Name())
}

if !test_pass {
t.Fatalf("Test failed after all flaky iterations")
for line := range outCh {
t.Fatalf("Unexpected line after rotation: %q", line)
}
}
Loading
Loading