Files
summercms/modules/diary/daily_test.go
Jakub Zych 24f4643283 test(diary): config, channels, rotation, redaction and slogtest
- config rules name their key; env strings overlay defaults; D-08 defaults
- component floors, verbosity 1-3, quiet on the console only
- daily rotation, retention, 0640 files, unwritable dir, lazy open, path confinement
- redaction on every driver, console control-character stripping and prefix
- loggers before Setup, Reset, HideOnTTY, 100 concurrent writers
- testing/slogtest for the console handler and the JSON pipeline
- sunscreen InstallDefault still installs a redacting logfmt handler
2026-10-21 19:09:28 +02:00

271 lines
9.6 KiB
Go

//go:build unix
package diary_test
import (
"os"
"path/filepath"
"slices"
"strings"
"syscall"
"testing"
"git.golem15.com/golem15/summercms/modules/diary"
)
// dailyOnly is the environment of a configuration whose default channel is
// the daily file at info.
var dailyOnly = []string{"SUMMER_LOG__DEFAULT=daily", "SUMMER_LOG__CHANNELS__DAILY__LEVEL=info"}
// TestDailyRotation: a record before and one after local midnight land in
// two files named by their dates.
func TestDailyRotation(t *testing.T) {
root := t.TempDir()
clk := newClock(day(21, 23, 59, 59))
var buf lockedBuffer
setup(t, diary.Options{Stderr: &buf, Root: root, Now: clk.Now}, dailyOnly...)
blog := diary.For("blog")
blog.Info("before midnight")
clk.Set(day(22, 0, 0, 1))
blog.Info("after midnight")
dir := filepath.Join(root, "storage", "logs")
first := readDaily(t, filepath.Join(dir, "summer-2026-10-21.log"))
second := readDaily(t, filepath.Join(dir, "summer-2026-10-22.log"))
if len(first) != 1 || !strings.Contains(first[0], "before midnight") {
t.Errorf("2026-10-21 file = %q, want only the record before midnight", first)
}
if len(second) != 1 || !strings.Contains(second[0], "after midnight") {
t.Errorf("2026-10-22 file = %q, want only the record after midnight", second)
}
if buf.String() != "" {
t.Errorf("console written although the default channel is daily:\n%s", buf.String())
}
}
// TestDailyRetention: with days 2 the files of today and the day before are
// kept, older files of the same base are deleted, and every other file in
// the directory is left alone. days 0 keeps everything.
func TestDailyRetention(t *testing.T) {
keep := []string{
"summer-2026-10-20.log", "summer-2026-10-21.log",
"summer.log", "other-2026-10-01.log", "summer-2026-10-01.json",
"summer-latest.log", "summer-2026-1-1.log", "notes.txt", "xsummer-2026-10-01.log",
}
gone := []string{"summer-2026-10-19.log", "summer-2026-10-18.log", "summer-2025-01-01.log"}
prepare := func(t *testing.T) string {
t.Helper()
root := t.TempDir()
dir := filepath.Join(root, "storage", "logs")
if err := os.MkdirAll(filepath.Join(dir, "summer-2026-10-01.log"), 0o750); err != nil {
t.Fatal(err)
}
for _, name := range append(slices.Clone(keep), gone...) {
if err := os.WriteFile(filepath.Join(dir, name), []byte("old\n"), 0o640); err != nil {
t.Fatal(err)
}
}
return root
}
list := func(t *testing.T, root string) []string {
t.Helper()
entries, err := os.ReadDir(filepath.Join(root, "storage", "logs"))
if err != nil {
t.Fatal(err)
}
var names []string
for _, e := range entries {
names = append(names, e.Name())
}
return names
}
root := prepare(t)
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}},
append(slices.Clone(dailyOnly), "SUMMER_LOG__CHANNELS__DAILY__DAYS=2")...)
diary.For("blog").Info("today")
names := list(t, root)
for _, name := range append(slices.Clone(keep), "summer-2026-10-01.log") {
if !slices.Contains(names, name) {
t.Errorf("retention deleted %s; left %v", name, names)
}
}
for _, name := range gone {
if slices.Contains(names, name) {
t.Errorf("retention kept %s; left %v", name, names)
}
}
today := readDaily(t, filepath.Join(root, "storage", "logs", "summer-2026-10-21.log"))
if len(today) != 2 || today[0] != "old" || !strings.Contains(today[1], `"msg":"today"`) {
t.Errorf("today's file = %q, want the old line and the new record appended", today)
}
diary.Reset()
root = prepare(t)
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}},
append(slices.Clone(dailyOnly), "SUMMER_LOG__CHANNELS__DAILY__DAYS=0")...)
diary.For("blog").Info("today")
names = list(t, root)
for _, name := range append(slices.Clone(keep), gone...) {
if !slices.Contains(names, name) {
t.Errorf("days 0 deleted %s", name)
}
}
}
// TestDailyPermissions: a new daily file is 0640 whatever the umask, its
// directory 0750 under the usual umask, and an existing file keeps its mode.
func TestDailyPermissions(t *testing.T) {
old := syscall.Umask(0o022)
t.Cleanup(func() { syscall.Umask(old) })
root := t.TempDir()
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}}, dailyOnly...)
diary.For("blog").Info("first")
dir := filepath.Join(root, "storage", "logs")
file := filepath.Join(dir, "summer-2026-10-21.log")
readDaily(t, file)
assertMode(t, file, 0o640)
assertMode(t, dir, 0o750)
// A strict umask cannot strip the file's group read bit.
diary.Reset()
syscall.Umask(0o077)
root = t.TempDir()
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}}, dailyOnly...)
diary.For("blog").Info("strict umask")
file = filepath.Join(root, "storage", "logs", "summer-2026-10-21.log")
readDaily(t, file)
assertMode(t, file, 0o640)
// An existing file is appended to and keeps its mode.
diary.Reset()
syscall.Umask(0o022)
root = t.TempDir()
dir = filepath.Join(root, "storage", "logs")
if err := os.MkdirAll(dir, 0o750); err != nil {
t.Fatal(err)
}
file = filepath.Join(dir, "summer-2026-10-21.log")
if err := os.WriteFile(file, nil, 0o600); err != nil {
t.Fatal(err)
}
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}}, dailyOnly...)
diary.For("blog").Info("existing")
if lines := readDaily(t, file); len(lines) != 1 {
t.Errorf("existing file has %d lines, want 1", len(lines))
}
assertMode(t, file, 0o600)
}
func assertMode(t *testing.T, path string, want os.FileMode) {
t.Helper()
info, err := os.Stat(path)
if err != nil {
t.Fatal(err)
}
if got := info.Mode().Perm(); got != want {
t.Errorf("%s mode = %o, want %o", path, got, want)
}
}
// TestDailyUnwritable: a daily file that cannot be opened warns once (on a
// plain stderr handler when no console channel exists), never fails Setup,
// and later records are dropped silently.
func TestDailyUnwritable(t *testing.T) {
root := t.TempDir()
// A regular file where the log directory should be: MkdirAll fails for
// every user, root included.
if err := os.WriteFile(filepath.Join(root, "blocker"), []byte("x"), 0o600); err != nil {
t.Fatal(err)
}
var buf lockedBuffer
setup(t, diary.Options{Root: root, Stderr: &buf},
append(slices.Clone(dailyOnly), "SUMMER_LOG__CHANNELS__DAILY__PATH=blocker/logs/summer.log")...)
blog := diary.For("blog")
for i := range 5 {
blog.Info("record", "i", i)
}
out := buf.String()
if n := strings.Count(out, "daily log file disabled"); n != 1 {
t.Fatalf("warning appears %d times, want 1:\n%s", n, out)
}
for _, want := range []string{"level=WARN", "component=diary", filepath.Join(root, "blocker", "logs", "summer-2026-10-21.log")} {
if !strings.Contains(out, want) {
t.Errorf("warning lacks %q:\n%s", want, out)
}
}
if strings.Contains(out, "msg=record") {
t.Errorf("records reached stderr although the default channel is daily:\n%s", out)
}
if err := diary.Close(); err != nil {
t.Errorf("Close after a disabled daily file: %v", err)
}
}
// TestDailyLazyOpen: no file or directory exists until a record reaches the
// daily channel; a closed file opens again on the next record.
func TestDailyLazyOpen(t *testing.T) {
root := t.TempDir()
var buf lockedBuffer
setup(t, diary.Options{Root: root, Stderr: &buf})
storage := filepath.Join(root, "storage")
if _, err := os.Stat(storage); !os.IsNotExist(err) {
t.Fatalf("Setup created %s (err %v)", storage, err)
}
diary.For("blog").Info("below the daily level")
if _, err := os.Stat(storage); !os.IsNotExist(err) {
t.Fatalf("an info record created %s although the daily level is warn (err %v)", storage, err)
}
if !strings.Contains(buf.String(), "below the daily level") {
t.Errorf("console lacks the info record:\n%s", buf.String())
}
file := filepath.Join(storage, "logs", "summer-2026-10-21.log")
diary.For("blog").Warn("first warning")
if lines := readDaily(t, file); len(lines) != 1 {
t.Fatalf("daily file has %d lines after one warning, want 1", len(lines))
}
diary.For("blog").Warn("after close")
if lines := readDaily(t, file); len(lines) != 2 {
t.Fatalf("daily file has %d lines after reopening, want 2", len(lines))
}
}
// TestPathConfinement: a relative daily path may not leave the application
// root; a path that stays inside after cleaning and an absolute path are
// accepted, and relative paths resolve against Options.Root.
func TestPathConfinement(t *testing.T) {
for _, path := range []string{"../summer.log", "storage/../../summer.log", "./../logs/summer.log", ".."} {
_, err := diary.ParseConfig(openConfig(t, "SUMMER_LOG__CHANNELS__DAILY__PATH="+path))
if err == nil || !strings.Contains(err.Error(), "log.channels.daily.path") {
t.Errorf("path %q: err %v, want an error naming log.channels.daily.path", path, err)
}
}
abs := filepath.Join(t.TempDir(), "elsewhere", "app.log")
for _, path := range []string{"storage/../logs/summer.log", "logs/app.log", abs} {
if _, err := diary.ParseConfig(openConfig(t, "SUMMER_LOG__CHANNELS__DAILY__PATH="+path)); err != nil {
t.Errorf("path %q rejected: %v", path, err)
}
}
root := t.TempDir()
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}},
append(slices.Clone(dailyOnly), "SUMMER_LOG__CHANNELS__DAILY__PATH="+abs)...)
diary.For("blog").Info("absolute")
if lines := readDaily(t, filepath.Join(filepath.Dir(abs), "app-2026-10-21.log")); len(lines) != 1 {
t.Errorf("absolute path file has %d lines, want 1", len(lines))
}
diary.Reset()
setup(t, diary.Options{Root: root, Stderr: &lockedBuffer{}},
append(slices.Clone(dailyOnly), "SUMMER_LOG__CHANNELS__DAILY__PATH=storage/../logs/app.log")...)
diary.For("blog").Info("relative")
if lines := readDaily(t, filepath.Join(root, "logs", "app-2026-10-21.log")); len(lines) != 1 {
t.Errorf("relative path did not resolve against the root: %d lines", len(lines))
}
}