summaryrefslogtreecommitdiff
path: root/internal/io/dlog/loggers/file_test.go
diff options
context:
space:
mode:
authorPaul Buetow <paul@buetow.org>2026-07-22 23:51:18 +0300
committerPaul Buetow <paul@buetow.org>2026-07-22 23:51:18 +0300
commit849951be1d1a7ee9f9302006ccb187bf5b4e36f3 (patch)
tree496c924a03a9ea6212e29bb4699e268066ebad81 /internal/io/dlog/loggers/file_test.go
parentbf78b3abffee6d49c08ca2980156afc455994969 (diff)
feat: DTail fork — server/client feature development
Squashed development of the snonux/dtail fork's product code (internal/, cmd/) since diverging from mimecast/dtail. Major areas: - Read/output path: the former "turbo" channel-less path is now the single, default server-side read/output path for cat/grep/tail and MapReduce; the old channel-based path and its config/env toggles were removed. - MapReduce: single aggregate implementation (server + serverless) fed directly by a processor pipeline, with input-exhausted finalization via the shutdown coordinator; high-concurrency and data-race fixes. - Journal source reads (journal:unit.service) via journalctl, Linux-gated behind a journal-v1 capability. - Auth-key fast reconnect: in-memory per-user public-key cache with TTL/max-keys, registered over an authenticated session (AUTHKEY), checked before authorized_keys. - Interactive query reload (--interactive-query) with SESSION START/UPDATE generation boundaries and capability negotiation. - Client-side deadlines: --timeout / --shutdownAfter as context deadlines; follow shutdown handling. - Client logging: diagnostics-only daily log by default, opt-in payload tee via --log-payload. - Numerous correctness fixes (buffer-pool double-recycle races, EOF-sentinel leaks, glob-expansion cap, TOCTOU in CSV parsing) with accompanying unit tests. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
Diffstat (limited to 'internal/io/dlog/loggers/file_test.go')
-rw-r--r--internal/io/dlog/loggers/file_test.go183
1 files changed, 183 insertions, 0 deletions
diff --git a/internal/io/dlog/loggers/file_test.go b/internal/io/dlog/loggers/file_test.go
new file mode 100644
index 0000000..0436327
--- /dev/null
+++ b/internal/io/dlog/loggers/file_test.go
@@ -0,0 +1,183 @@
+package loggers
+
+import (
+ "context"
+ "os"
+ "path/filepath"
+ "strconv"
+ "strings"
+ "sync"
+ "testing"
+ "time"
+
+ "github.com/mimecast/dtail/internal/config"
+)
+
+// withTempLogDir points config.Common.LogDir at a fresh temp dir for the
+// duration of a test and restores the previous config afterwards. The file
+// logger resolves its output path from config.Common.LogDir at write time.
+func withTempLogDir(t *testing.T) string {
+ t.Helper()
+ dir := t.TempDir()
+ prev := config.Common
+ config.Common = &config.CommonConfig{LogDir: dir}
+ t.Cleanup(func() { config.Common = prev })
+ return dir
+}
+
+// startFileLogger starts f and returns a stop func that cancels the context and
+// JOINS the logger goroutine (wg.Wait). Tests must defer stop() so the goroutine
+// has fully exited before returning: withTempLogDir's t.Cleanup restores the
+// global config.Common, and a still-running goroutine reading config.Common.LogDir
+// would otherwise race that restore. For the same reason none of these tests may
+// call t.Parallel — they mutate the process-global config.Common.
+func startFileLogger(t *testing.T, f *file) func() {
+ t.Helper()
+ ctx, cancel := context.WithCancel(context.Background())
+ var wg sync.WaitGroup
+ wg.Add(1)
+ f.Start(ctx, &wg)
+ return func() {
+ cancel()
+ wg.Wait()
+ }
+}
+
+func readLogFile(t *testing.T, dir, base string) string {
+ t.Helper()
+ data, err := os.ReadFile(filepath.Join(dir, base+".log"))
+ if err != nil {
+ if os.IsNotExist(err) {
+ return ""
+ }
+ t.Fatalf("reading log file: %v", err)
+ }
+ return string(data)
+}
+
+// TestFileLoggerNothingLostOnClose verifies every logged line reaches disk when
+// the context is cancelled (clean shutdown): the goroutine drains the buffer
+// channel and flushes the 64KB writer before closing the fd.
+func TestFileLoggerNothingLostOnClose(t *testing.T) {
+ dir := withTempLogDir(t)
+ base := "close-test"
+ f := newFile(Strategy{Rotation: SignalRotation, FileBase: base})
+ stop := startFileLogger(t, f)
+
+ const n = 500
+ var want strings.Builder
+ for i := 0; i < n; i++ {
+ line := "line-" + strconv.Itoa(i)
+ f.Log(time.Now(), line)
+ want.WriteString(line + "\n")
+ }
+
+ // stop() cancels the context and joins the goroutine, which flushes and
+ // closes the fd on the way out — so all output must be on disk afterwards.
+ stop()
+
+ if got := readLogFile(t, dir, base); got != want.String() {
+ t.Fatalf("lost output on close: got %d bytes, want %d bytes",
+ len(got), want.Len())
+ }
+}
+
+// TestFileLoggerIdleFlush verifies a single low-volume line (follow/tail style)
+// is not stuck behind the 64KB buffer: the idle ticker flushes it to disk
+// promptly without any explicit Flush or shutdown. The logger goroutine is
+// joined via stop() before returning so it cannot outlive config.Common.
+func TestFileLoggerIdleFlush(t *testing.T) {
+ dir := withTempLogDir(t)
+ base := "idle-test"
+ f := newFile(Strategy{Rotation: SignalRotation, FileBase: base})
+ stop := startFileLogger(t, f)
+ defer stop()
+
+ f.Log(time.Now(), "follow-line")
+
+ deadline := time.Now().Add(2 * time.Second)
+ for time.Now().Before(deadline) {
+ if strings.Contains(readLogFile(t, dir, base), "follow-line") {
+ return
+ }
+ time.Sleep(5 * time.Millisecond)
+ }
+ t.Fatal("follow-style line stuck behind buffer; idle flush did not emit it")
+}
+
+// TestFileLoggerExplicitFlush verifies Flush() is SYNCHRONOUS: once it returns,
+// the buffered data is already on disk (no polling needed). This is the property
+// dlog.FatalPanic relies on to not drop Fatal diagnostics before panicking.
+func TestFileLoggerExplicitFlush(t *testing.T) {
+ dir := withTempLogDir(t)
+ base := "flush-test"
+ f := newFile(Strategy{Rotation: SignalRotation, FileBase: base})
+ stop := startFileLogger(t, f)
+ defer stop()
+
+ f.Log(time.Now(), "flush-me")
+ f.Flush()
+
+ if got := readLogFile(t, dir, base); !strings.Contains(got, "flush-me") {
+ t.Fatalf("synchronous Flush() did not persist data before returning; got %q", got)
+ }
+}
+
+// TestFileLoggerRotateDoesNotBlockWithoutWrites verifies that Rotate() does
+// not deadlock when no log messages have been produced. Previously rotateCh
+// was unbuffered and only drained opportunistically from write(), so a SIGHUP
+// before any Log() call would block the caller forever.
+func TestFileLoggerRotateDoesNotBlockWithoutWrites(t *testing.T) {
+ f := newFile(Strategy{Rotation: SignalRotation, FileBase: "unit-test"})
+
+ ctx, cancel := context.WithCancel(context.Background())
+ defer cancel()
+
+ var wg sync.WaitGroup
+ wg.Add(1)
+ f.Start(ctx, &wg)
+
+ done := make(chan struct{})
+ go func() {
+ f.Rotate()
+ close(done)
+ }()
+
+ select {
+ case <-done:
+ case <-time.After(500 * time.Millisecond):
+ t.Fatal("Rotate() blocked without any writes; expected prompt return")
+ }
+
+ cancel()
+ wg.Wait()
+}
+
+// TestFileLoggerCancelBeforeFirstWriteDoesNotPanic verifies that cancelling
+// the context before any write has happened does not panic. Previously the
+// goroutine called f.fd.Close() unconditionally, but f.fd is only populated
+// by the first getWriter() call, so a ctx cancel with no prior writes
+// panicked on a nil pointer.
+func TestFileLoggerCancelBeforeFirstWriteDoesNotPanic(t *testing.T) {
+ f := newFile(Strategy{Rotation: SignalRotation, FileBase: "unit-test"})
+
+ ctx, cancel := context.WithCancel(context.Background())
+
+ var wg sync.WaitGroup
+ wg.Add(1)
+ f.Start(ctx, &wg)
+
+ cancel()
+
+ doneCh := make(chan struct{})
+ go func() {
+ wg.Wait()
+ close(doneCh)
+ }()
+
+ select {
+ case <-doneCh:
+ case <-time.After(1 * time.Second):
+ t.Fatal("file logger goroutine did not exit after ctx cancel")
+ }
+}