path: root/integrationtests/dtail_test.go

package integrationtests

import (
	"context"
	"fmt"
	"os"
	"os/exec"
	"strings"
	"testing"
	"time"

	"github.com/mimecast/dtail/internal/config"
)

func TestDTailWithServer(t *testing.T) {
	testLogger := NewTestLogger("TestDTailWithServer")
	defer testLogger.WriteLogFile()
	cleanupTmpFiles(t)

	if !config.Env("DTAIL_INTEGRATION_TEST_RUN_MODE") {
		t.Log("Skipping")
		return
	}
	followFile := "dtail.follow.tmp"
	port := getUniquePortNumber()
	bindAddress := "localhost"
	greetings := []string{"World!", "Sol-System!", "Milky-Way!", "Universe!", "Multiverse!"}

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

	go func() {
		select {
		case <-time.After(time.Minute):
			t.Error("Max time for this test exceeded!")
			cancel()
		case <-ctx.Done():
			return
		}
	}()

	serverCh, _, _, err := startCommand(ctx, t,
		"", "../dserver",
		"--cfg", "none",
		"--logger", "stdout",
		"--logLevel", "info",
		"--bindAddress", bindAddress,
		"--port", fmt.Sprintf("%d", port),
	)
	if err != nil {
		t.Error(err)
		return
	}

	// MAYBETODO: In testmode, never read a config file (use none for all commands)
	clientCh, _, _, err := startCommand(ctx, t,
		"", "../dtail",
		"--cfg", "none",
		"--logger", "stdout",
		"--logLevel", "info",
		"--servers", fmt.Sprintf("%s:%d", bindAddress, port),
		"--files", followFile,
		"--grep", "Hello",
		"--trustAllHosts",
		"--noColor",
	)
	if err != nil {
		t.Error(err)
		return
	}
	// Write greetings to followFile
	fd, err := os.Create(followFile)
	if err != nil {
		t.Error(err)
	}
	defer fd.Close()

	go func() {
		var circular int
		for {
			select {
			case <-time.After(time.Second):
				_, _ = fd.WriteString(time.Now().String())
				_, _ = fd.WriteString(fmt.Sprintf(" - Hello %s\n", greetings[circular]))
				circular = (circular + 1) % len(greetings)
			case <-ctx.Done():
				return
			}
		}
	}()

	var greetingsRecv []string

readLoop:
	for len(greetingsRecv) < len(greetings) {
		select {
		case line := <-serverCh:
			t.Log("server:", line)
		case line := <-clientCh:
			t.Log("client:", line)
			if strings.Contains(line, "Hello ") {
				s := strings.Split(line, " ")
				greeting := s[len(s)-1]
				greetingsRecv = append(greetingsRecv, greeting)
				t.Log("Received greeting", greeting, len(greetingsRecv))
			}
		case <-ctx.Done():
			t.Log("Done reading client and server pipes")
			break readLoop
		}
	}

	// We expect to have received the greetings in the same order they were sent.`
	offset := -1
	for i, g := range greetings {
		if g == greetingsRecv[0] {
			offset = i
			break
		}
	}
	if offset == -1 {
		t.Error("Could not find first offset of greetings received")
		return
	}

	for i, g := range greetingsRecv {
		index := (i + offset) % len(greetings)
		if greetings[index] != g {
			t.Errorf("Expected '%s' but got '%s' at '%v' vs '%v'\n",
				g, greetings[index], greetings, greetingsRecv)
			return
		}
	}

	// File cleanup handled by cleanupTmpFiles
}

// TestDTailShutdownAfter is a regression guard for the follow-client shutdown
// bug (task 1v0): a `dtail --shutdownAfter N` follow session used to never
// return from client.Start, so the process hung until it was killed externally.
// With the fix the shutdownAfter deadline cancels the client context, which the
// reconnect and per-connection read loops honour, so the process exits shortly
// after N seconds. Pre-fix this test would block until the maxExit watchdog and
// fail; it must now pass well within that window.
func TestDTailShutdownAfter(t *testing.T) {
	testLogger := NewTestLogger("TestDTailShutdownAfter")
	defer testLogger.WriteLogFile()
	cleanupTmpFiles(t)

	if !config.Env("DTAIL_INTEGRATION_TEST_RUN_MODE") {
		t.Log("Skipping")
		return
	}

	const shutdownAfter = 3
	// Generous ceiling over shutdownAfter to absorb connection setup and
	// graceful teardown; the point is that the client returns at all, not that
	// it returns to the millisecond. Pre-fix it never returned.
	const maxExit = 15 * time.Second

	followFile := "dtail.shutdownafter.follow.tmp"
	port := getUniquePortNumber()
	bindAddress := "localhost"

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

	// Overall safety net so a genuine hang cannot wedge the whole suite.
	go func() {
		select {
		case <-time.After(time.Minute):
			t.Error("Max time for this test exceeded!")
			cancel()
		case <-ctx.Done():
		}
	}()

	// Start the server the follow client connects to.
	_, _, _, err := startCommand(ctx, t,
		"", "../dserver",
		"--cfg", "none",
		"--logger", "stdout",
		"--logLevel", "error",
		"--bindAddress", bindAddress,
		"--port", fmt.Sprintf("%d", port),
	)
	if err != nil {
		t.Error(err)
		return
	}
	if err := waitForServerReady(ctx, bindAddress, port); err != nil {
		t.Error(err)
		return
	}

	// Keep appending to the followed file so the session has live work to do,
	// exercising the streaming read path rather than an idle connection.
	fd, err := os.Create(followFile)
	if err != nil {
		t.Error(err)
		return
	}
	defer fd.Close()
	go func() {
		for i := 0; ; i++ {
			select {
			case <-time.After(200 * time.Millisecond):
				_, _ = fd.WriteString(fmt.Sprintf("%s - Hello line %d\n", time.Now().String(), i))
			case <-ctx.Done():
				return
			}
		}
	}()

	// Run the follow client with --shutdownAfter and measure that it returns.
	cmd := exec.CommandContext(ctx, "../dtail",
		"--cfg", "none",
		"--logger", "stdout",
		"--logLevel", "error",
		"--servers", fmt.Sprintf("%s:%d", bindAddress, port),
		"--files", followFile,
		"--grep", "Hello",
		"--trustAllHosts",
		"--noColor",
		"--shutdownAfter", fmt.Sprintf("%d", shutdownAfter),
	)
	start := time.Now()
	if err := cmd.Start(); err != nil {
		t.Error(err)
		return
	}

	waitErr := make(chan error, 1)
	go func() { waitErr <- cmd.Wait() }()

	select {
	case err := <-waitErr:
		elapsed := time.Since(start)
		t.Logf("dtail --shutdownAfter %d exited after %v (err=%v)", shutdownAfter, elapsed, err)
		// It must not exit meaningfully before the deadline (that would mean the
		// session failed rather than shut down on schedule).
		if elapsed < time.Duration(shutdownAfter)*time.Second-time.Second {
			t.Errorf("dtail exited after %v, before the %ds shutdownAfter deadline", elapsed, shutdownAfter)
		}
		if elapsed > maxExit {
			t.Errorf("dtail took %v to exit, want <= %v (follow shutdown regression)", elapsed, maxExit)
		}
	case <-time.After(maxExit):
		_ = cmd.Process.Kill()
		t.Errorf("dtail --shutdownAfter %d did not exit within %v: the follow client hung "+
			"(client.Start never returned)", shutdownAfter, maxExit)
	}
}

func TestDTailColorTable(t *testing.T) {
	if !config.Env("DTAIL_INTEGRATION_TEST_RUN_MODE") {
		t.Log("Skipping")
		return
	}

	cleanupTmpFiles(t)
	testLogger := NewTestLogger("TestDTailColorTable")
	defer testLogger.WriteLogFile()

	// Test in serverless mode
	t.Run("Serverless", func(t *testing.T) {
		testDTailColorTableServerless(t, testLogger)
	})

	// Test in server mode
	t.Run("ServerMode", func(t *testing.T) {
		testDTailColorTableWithServer(t, testLogger)
	})
}

func testDTailColorTableServerless(t *testing.T, logger *TestLogger) {
	ctx := WithTestLogger(context.Background(), logger)

	outFile := "dtailcolortable.stdout.tmp"
	expectedOutFile := "dtailcolortable.expected"

	_, err := runCommand(ctx, t, outFile, "../dtail", "--colorTable")
	if err != nil {
		t.Error(err)
		return
	}
	if err := compareFilesWithContext(ctx, t, outFile, expectedOutFile); err != nil {
		t.Error(err)
		return
	}
}

func testDTailColorTableWithServer(t *testing.T, logger *TestLogger) {
	outFile := "dtailcolortable.stdout.tmp"
	expectedOutFile := "dtailcolortable.expected"
	port := getUniquePortNumber()
	bindAddress := "localhost"

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

	// Start dserver
	_, _, _, err := startCommand(ctx, t,
		"", "../dserver",
		"--cfg", "none",
		"--logger", "stdout",
		"--logLevel", "error",
		"--bindAddress", bindAddress,
		"--port", fmt.Sprintf("%d", port),
	)
	if err != nil {
		t.Error(err)
		return
	}

	if err := waitForServerReady(ctx, bindAddress, port); err != nil {
		t.Error(err)
		return
	}

	_, err = runCommand(ctx, t, outFile, "../dtail",
		"--colorTable",
		"--servers", fmt.Sprintf("%s:%d", bindAddress, port),
		"--trustAllHosts")
	if err != nil {
		t.Error(err)
		return
	}

	cancel()

	if err := compareFilesWithContext(ctx, t, outFile, expectedOutFile); err != nil {
		t.Error(err)
		return
	}
}