package logging import ( "bytes" "errors" "fmt" "io" "os" "path/filepath" "strings" "sync" "sync/atomic" "testing" "time" log "github.com/sirupsen/logrus" ) func TestWeeklyLogRotationShiftsAndRetainsExactGenerations(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "active") for generation := 1; generation <= 14; generation++ { writeLogTestFile(t, weeklyLogTestGeneration(path, generation), fmt.Sprintf("generation-%d", generation)) } writeLogTestFile(t, weeklyLogTestGeneration(path, 19), "generation-19") for name, contents := range map[string]string{ "hardlink.backup.14.log": "related-looking backup", "another.14.log": "unrelated log", "hardlink.14.log.bak": "different extension", } { writeLogTestFile(t, filepath.Join(directory, name), contents) } sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC) setLogTestModTime(t, path, sunday) writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{}) writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC)) if err := writer.Close(); err != nil { t.Fatal(err) } requireLogTestContents(t, path, "") requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "active") requireLogTestContents(t, weeklyLogTestGeneration(path, 2), "generation-1") requireLogTestContents(t, weeklyLogTestGeneration(path, 13), "generation-12") for _, generation := range []int{14, 19} { if _, err := os.Stat(weeklyLogTestGeneration(path, generation)); !errors.Is(err, os.ErrNotExist) { t.Errorf("generation %d exists after rotation, want removed: %v", generation, err) } } for name, contents := range map[string]string{ "hardlink.backup.14.log": "related-looking backup", "another.14.log": "unrelated log", "hardlink.14.log.bak": "different extension", } { requireLogTestContents(t, filepath.Join(directory, name), contents) } } func TestWeeklyLogRotationOccursOncePerWeek(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "week-zero\n") sunday := time.Date(2026, time.January, 4, 18, 0, 0, 0, time.UTC) setLogTestModTime(t, path, sunday) writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{}) writer.rotateIfNeeded(time.Date(2026, time.January, 4, 23, 59, 59, 0, time.UTC)) if _, err := os.Stat(weeklyLogTestGeneration(path, 1)); !errors.Is(err, os.ErrNotExist) { t.Fatalf("rotation before Monday: %v, want no generation", err) } writer.rotateIfNeeded(time.Date(2026, time.January, 5, 0, 0, 0, 0, time.UTC)) if _, err := writer.Write([]byte("week-one\n")); err != nil { t.Fatal(err) } writer.rotateIfNeeded(time.Date(2026, time.January, 6, 12, 0, 0, 0, time.UTC)) if err := writer.Close(); err != nil { t.Fatal(err) } requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "week-zero\n") requireLogTestContents(t, path, "week-one\n") if _, err := os.Stat(weeklyLogTestGeneration(path, 2)); !errors.Is(err, os.ErrNotExist) { t.Errorf("same-week rotation created generation 2: %v", err) } } func TestWeeklyLogStartupRotatesOnceAfterSeveralMissedWeeks(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "old active") writeLogTestFile(t, weeklyLogTestGeneration(path, 1), "older history") setLogTestModTime(t, path, time.Date(2026, time.January, 5, 12, 0, 0, 0, time.UTC)) now := time.Date(2026, time.February, 23, 9, 0, 0, 0, time.UTC) writer := newLogTestWriter(t, path, now, weeklyLogRuntime{}) if err := writer.Close(); err != nil { t.Fatal(err) } requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "old active") requireLogTestContents(t, weeklyLogTestGeneration(path, 2), "older history") if _, err := os.Stat(weeklyLogTestGeneration(path, 3)); !errors.Is(err, os.ErrNotExist) { t.Errorf("missed weeks created generation 3: %v", err) } } func TestWeeklyLogSchedulerUsesLocalMondayBoundary(t *testing.T) { location, err := time.LoadLocation("Europe/London") if err != nil { t.Fatal(err) } directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "sunday") sunday := time.Date(2026, time.March, 29, 0, 0, 0, 0, location) setLogTestModTime(t, path, sunday) clock := &atomic.Pointer[time.Time]{} clock.Store(&sunday) created := make(chan *logTestTimer, 2) rotated := make(chan struct{}) runtime := weeklyLogRuntime{ now: func() time.Time { return *clock.Load() }, newTimer: func(duration time.Duration) logRotationTimer { timer := &logTestTimer{duration: duration, ch: make(chan time.Time, 1)} created <- timer return timer }, rename: func(oldPath, newPath string) error { err := os.Rename(oldPath, newPath) if oldPath == path && err == nil { close(rotated) } return err }, } writer, err := newWeeklyLogWriter(path, location, runtime) if err != nil { t.Fatal(err) } timer := <-created if timer.duration != 23*time.Hour { t.Fatalf("timer duration = %v, want 23h across DST boundary", timer.duration) } monday := time.Date(2026, time.March, 30, 0, 0, 0, 0, location) clock.Store(&monday) timer.ch <- monday <-rotated if err := writer.Close(); err != nil { t.Fatal(err) } requireLogTestContents(t, weeklyLogTestGeneration(path, 1), "sunday") } func TestWeeklyLogConcurrentWritesRemainCompleteAcrossRotation(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC) writer := newLogTestWriter(t, path, sunday, weeklyLogRuntime{}) const goroutines = 8 const recordsPerGoroutine = 100 writeErrors := make(chan error, goroutines) var writers sync.WaitGroup writers.Add(goroutines) for worker := 0; worker < goroutines; worker++ { go func() { defer writers.Done() for record := 0; record < recordsPerGoroutine; record++ { if _, err := writer.Write([]byte(fmt.Sprintf("%d:%d\n", worker, record))); err != nil { writeErrors <- err return } } }() } writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC)) writers.Wait() close(writeErrors) for err := range writeErrors { t.Errorf("weeklyLogWriter.Write() error = %v, want nil", err) } if err := writer.Close(); err != nil { t.Fatal(err) } contents := readLogTestFile(t, weeklyLogTestGeneration(path, 1)) + readLogTestFile(t, path) lines := strings.Split(strings.TrimSpace(contents), "\n") if len(lines) != goroutines*recordsPerGoroutine { t.Fatalf("record count = %d, want %d", len(lines), goroutines*recordsPerGoroutine) } seen := make(map[string]bool, len(lines)) for _, line := range lines { if _, _, ok := strings.Cut(line, ":"); !ok { t.Fatalf("record %q has no separator", line) } seen[line] = true } if len(seen) != goroutines*recordsPerGoroutine { t.Errorf("unique record count = %d, want %d", len(seen), goroutines*recordsPerGoroutine) } } func TestWeeklyLogCloseWaitsForRotationAndIsIdempotent(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "active") sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC) setLogTestModTime(t, path, sunday) started := make(chan struct{}) release := make(chan struct{}) runtime := weeklyLogRuntime{rename: func(oldPath, newPath string) error { if oldPath == path { close(started) <-release } return os.Rename(oldPath, newPath) }} writer := newLogTestWriter(t, path, sunday, runtime) rotationDone := make(chan struct{}) go func() { writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC)) close(rotationDone) }() <-started closeDone := make(chan error, 1) go func() { closeDone <- writer.Close() }() select { case err := <-closeDone: t.Fatalf("weeklyLogWriter.Close() during rotation returned %v, want blocked", err) case <-time.After(20 * time.Millisecond): } close(release) <-rotationDone if err := <-closeDone; err != nil { t.Fatal(err) } if err := writer.Close(); err != nil { t.Errorf("second weeklyLogWriter.Close() error = %v, want nil", err) } if _, err := writer.Write([]byte("after close")); !errors.Is(err, os.ErrClosed) { t.Errorf("weeklyLogWriter.Write() after close error = %v, want os.ErrClosed", err) } } func TestWeeklyLogRotationFailureIsNonRecursiveAndPreservesWrites(t *testing.T) { directory := t.TempDir() path := filepath.Join(directory, "hardlink.log") writeLogTestFile(t, path, "before\n") sunday := time.Date(2026, time.August, 9, 12, 0, 0, 0, time.UTC) setLogTestModTime(t, path, sunday) var diagnostics bytes.Buffer runtime := weeklyLogRuntime{ rename: func(oldPath, newPath string) error { if oldPath == path { return errors.New("injected rename failure") } return os.Rename(oldPath, newPath) }, diagnostic: &diagnostics, } writer := newLogTestWriter(t, path, sunday, runtime) writer.rotateIfNeeded(time.Date(2026, time.August, 10, 0, 0, 0, 0, time.UTC)) if _, err := writer.Write([]byte("after\n")); err != nil { t.Fatalf("weeklyLogWriter.Write() after failed rotation error = %v, want nil", err) } if err := writer.Close(); err != nil { t.Fatal(err) } requireLogTestContents(t, path, "before\nafter\n") if !strings.Contains(diagnostics.String(), "weekly_log_rotation_failed") || !strings.Contains(diagnostics.String(), "injected rename failure") { t.Errorf("rotation diagnostic = %q, want action and injected error", diagnostics.String()) } if strings.Contains(readLogTestFile(t, path), "weekly log rotation failed") { t.Error("rotation diagnostic recursively entered active log") } } func TestSetupLoggingKeepsFilenameAndJSONFormat(t *testing.T) { logger := log.StandardLogger() previousOutput := logger.Out previousFormatter := logger.Formatter previousLevel := logger.Level t.Cleanup(func() { logger.SetOutput(previousOutput) logger.SetFormatter(previousFormatter) logger.SetLevel(previousLevel) }) directory := filepath.Join(t.TempDir(), "nested", "logs") writer, err := SetupLogging(directory, "hardlink", "v-test") if err != nil { t.Fatal(err) } log.WithField("probe", "value").Info("test record") if err := writer.Close(); err != nil { t.Fatal(err) } contents := readLogTestFile(t, filepath.Join(directory, "hardlink.log")) for _, want := range []string{`"buildVersion":"v-test"`, `"msg":"Logging initialized"`, `"probe":"value"`, `"msg":"test record"`} { if !strings.Contains(contents, want) { t.Errorf("hardlink.log contents missing %q: %s", want, contents) } } if _, err := os.Stat(filepath.Join(directory, "hardlink.1.log")); !errors.Is(err, os.ErrNotExist) { t.Errorf("SetupLogging() created archive during current week: %v", err) } } type logTestTimer struct { duration time.Duration ch chan time.Time stopped atomic.Bool } func (t *logTestTimer) C() <-chan time.Time { return t.ch } func (t *logTestTimer) Stop() bool { return !t.stopped.Swap(true) } func newLogTestWriter(t *testing.T, path string, now time.Time, overrides weeklyLogRuntime) *weeklyLogWriter { t.Helper() runtime := defaultWeeklyLogRuntime() runtime.now = func() time.Time { return now } if overrides.now != nil { runtime.now = overrides.now } if overrides.newTimer != nil { runtime.newTimer = overrides.newTimer } if overrides.rename != nil { runtime.rename = overrides.rename } if overrides.diagnostic != nil { runtime.diagnostic = overrides.diagnostic } writer, err := newWeeklyLogWriter(path, now.Location(), runtime) if err != nil { t.Fatal(err) } return writer } func weeklyLogTestGeneration(path string, generation int) string { extension := filepath.Ext(path) return fmt.Sprintf("%s.%d%s", strings.TrimSuffix(path, extension), generation, extension) } func writeLogTestFile(t *testing.T, path, contents string) { t.Helper() if err := os.WriteFile(path, []byte(contents), 0o600); err != nil { t.Fatal(err) } } func setLogTestModTime(t *testing.T, path string, value time.Time) { t.Helper() if err := os.Chtimes(path, value, value); err != nil { t.Fatal(err) } } func readLogTestFile(t *testing.T, path string) string { t.Helper() contents, err := os.ReadFile(path) if err != nil { t.Fatal(err) } return string(contents) } func requireLogTestContents(t *testing.T, path, want string) { t.Helper() if got := readLogTestFile(t, path); got != want { t.Errorf("%s contents = %q, want %q", filepath.Base(path), got, want) } } var _ io.WriteCloser = (*weeklyLogWriter)(nil)