chore: add rotating log for audit data

Adds rotating audit log writer. Also minor improvements.

For siderolabs#37

Signed-off-by: Dmitriy Matrenichev <[email protected]>

internal/backend/runtime/omni/audit/audit.go

@@ -0,0 +1,21 @@
+// Copyright (c) 2024 Sidero Labs, Inc.
+//
+// Use of this software is governed by the Business Source License
+// included in the LICENSE file.
+
+// Package audit provides a state wrapper that logs audit events.
+package audit
+
+import (
+	"github.com/siderolabs/omni/internal/pkg/auth/role"
+)
+
+// Data contains the audit data.
+type Data struct {
+	UserAgent string    `json:"user_agent,omitempty"`
+	IPAddress string    `json:"ip_address,omitempty"`
+	UserID    string    `json:"user_id,omitempty"`
+	Identity  string    `json:"identity,omitempty"`
+	Role      role.Role `json:"role,omitempty"`
+	Email     string    `json:"email,omitempty"`
+}

internal/backend/runtime/omni/audit/export_test.go

@@ -0,0 +1,12 @@
+// Copyright (c) 2024 Sidero Labs, Inc.
+//
+// Use of this software is governed by the Business Source License
+// included in the LICENSE file.
+
+package audit
+
+import "time"
+
+func (l *LogFile) DumpAt(data any, at time.Time) error {
+	return l.dumpAt(data, at)
+}

internal/backend/runtime/omni/audit/log_file.go

@@ -0,0 +1,107 @@
+// Copyright (c) 2024 Sidero Labs, Inc.
+//
+// Use of this software is governed by the Business Source License
+// included in the LICENSE file.
+
+package audit
+
+import (
+	"bytes"
+	"encoding/json"
+	"io"
+	"os"
+	"path/filepath"
+	"sync"
+	"time"
+
+	"github.com/siderolabs/gen/pair/ordered"
+
+	"github.com/siderolabs/omni/internal/pkg/pool"
+)
+
+// LogFile is a rotating log file.
+//
+//nolint:govet
+type LogFile struct {
+	dir string
+
+	mu        sync.Mutex
+	f         *os.File
+	lastWrite time.Time
+
+	pool pool.Pool[bytes.Buffer]
+}
+
+// NewLogFile creates a new rotating log file.
+func NewLogFile(dir string) *LogFile {
+	return &LogFile{
+		dir: dir,
+		pool: pool.Pool[bytes.Buffer]{
+			New: func() *bytes.Buffer {
+				return &bytes.Buffer{}
+			},
+		},
+	}
+}
+
+// Dump writes data to the log file, creating new one on demand.
+func (l *LogFile) Dump(data any) error {
+	return l.dumpAt(data, time.Time{})
+}
+
+func (l *LogFile) dumpAt(data any, at time.Time) error {
+	b := l.pool.Get()
+	defer func() { b.Reset(); l.pool.Put(b) }()
+
+	err := json.NewEncoder(b).Encode(data)
+	if err != nil {
+		return err
+	}
+
+	l.mu.Lock()
+	defer l.mu.Unlock()
+
+	if at.IsZero() {
+		at = time.Now()
+	}
+
+	f, err := l.openFile(at)
+	if err != nil {
+		return err
+	}
+
+	_, err = io.Copy(f, b)
+	if err != nil {
+		return err
+	}
+
+	l.lastWrite = at
+
+	return nil
+}
+
+// openFile opens a file for the given date. It returns the file is date for at matches
+// the last write date. Otherwise, it opens a new file.
+func (l *LogFile) openFile(at time.Time) (*os.File, error) {
+	if l.f != nil && ordered.MakeTriple(at.Date()).Compare(ordered.MakeTriple(l.lastWrite.Date())) <= 0 {
+		return l.f, nil
+	}
+
+	if l.f != nil {
+		err := l.f.Close()
+		if err != nil {
+			return nil, err
+		}
+	}
+
+	logPath := filepath.Join(l.dir, at.Format("2006-01-02")) + ".jsonlog"
+
+	f, err := os.OpenFile(logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644)
+	if err != nil {
+		return nil, err
+	}
+
+	l.f = f
+
+	return f, nil
+}

internal/backend/runtime/omni/audit/log_file_test.go

@@ -0,0 +1,163 @@
+// Copyright (c) 2024 Sidero Labs, Inc.
+//
+// Use of this software is governed by the Business Source License
+// included in the LICENSE file.
+
+package audit_test
+
+import (
+	"embed"
+	"fmt"
+	"io/fs"
+	"os"
+	"path/filepath"
+	"slices"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/siderolabs/gen/xtesting/must"
+	"github.com/stretchr/testify/require"
+
+	"github.com/siderolabs/omni/internal/backend/runtime/omni/audit"
+)
+
+//go:embed testdata/currentday
+var currentDay embed.FS
+
+func TestLogFile_CurrentDay(t *testing.T) {
+	dir := must.Value(os.MkdirTemp("", "log_file_test"))(t)
+
+	t.Cleanup(func() { os.RemoveAll(dir) }) //nolint:errcheck
+
+	entries := []entry{
+		{shift: time.Second, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.1", Email: "[email protected]"}},
+		{shift: time.Minute, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.2", Email: "[email protected]"}},
+		{shift: 30 * time.Minute, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.3", Email: "[email protected]"}},
+	}
+
+	start := time.Date(2012, 1, 1, 23, 0, 0, 0, time.Local)
+	now := start
+	file := audit.NewLogFile(dir)
+
+	for _, e := range entries {
+		now = now.Add(e.shift)
+
+		require.NoError(t, file.DumpAt(e.data, now))
+	}
+
+	checkFiles(t, basicLoader(dir), fsSub(t, currentDay, "currentday"))
+}
+
+//go:embed testdata/nextday
+var nextDay embed.FS
+
+func TestLogFile_CurrentAndNewDay(t *testing.T) {
+	dir := must.Value(os.MkdirTemp("", "log_file_test"))(t)
+
+	t.Cleanup(func() { os.RemoveAll(dir) }) //nolint:errcheck
+
+	entries := []entry{
+		{shift: 0, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.1", Email: "[email protected]"}},
+		{shift: 55 * time.Minute, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.2", Email: "[email protected]"}},
+		{shift: 5 * time.Minute, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: "10.10.0.3", Email: "[email protected]"}},
+	}
+
+	start := time.Date(2012, 1, 1, 23, 0, 0, 0, time.Local)
+	now := start
+	file := audit.NewLogFile(dir)
+
+	for _, e := range entries {
+		now = now.Add(e.shift)
+
+		require.NoError(t, file.DumpAt(e.data, now))
+	}
+
+	checkFiles(t, basicLoader(dir), fsSub(t, nextDay, "nextday"))
+}
+
+//go:embed testdata/concurrent
+var concurrent embed.FS
+
+func TestLogFile_CurrentDayConcurrent(t *testing.T) {
+	dir := must.Value(os.MkdirTemp("", "log_file_test"))(t)
+
+	t.Cleanup(func() { os.RemoveAll(dir) }) //nolint:errcheck
+
+	entries := make([]entry, 0, 250)
+
+	for i := range 250 {
+		address := fmt.Sprintf("10.10.0.%d", i+1)
+		email := fmt.Sprintf("random_email_%[email protected]", i+1)
+
+		entries = append(entries, entry{shift: time.Second, data: audit.Data{UserAgent: "Mozilla/5.0", IPAddress: address, Email: email}})
+	}
+
+	start := time.Date(2012, 1, 1, 23, 0, 0, 0, time.Local)
+	now := start
+	file := audit.NewLogFile(dir)
+
+	t.Run("concurrent", func(t *testing.T) {
+		for _, e := range entries {
+			now = now.Add(e.shift)
+			nowCopy := now
+
+			t.Run("", func(t *testing.T) {
+				t.Parallel()
+
+				require.NoError(t, file.DumpAt(e.data, nowCopy))
+			})
+		}
+	})
+
+	checkFiles(t, sortedLoader(basicLoader(dir)), fsSub(t, concurrent, "concurrent"))
+}
+
+//nolint:govet
+type entry struct {
+	shift time.Duration
+	data  audit.Data
+}
+
+type subFS interface {
+	fs.ReadFileFS
+	fs.ReadDirFS
+}
+
+func checkFiles(t *testing.T, loader fileLoader, expectedFS subFS) {
+	expectedFiles := must.Value(expectedFS.ReadDir("."))(t)
+
+	for _, expectedFile := range expectedFiles {
+		if expectedFile.IsDir() {
+			t.Fatal("unexpected directory", expectedFile.Name())
+		}
+
+		expectedData := string(must.Value(expectedFS.ReadFile(expectedFile.Name()))(t))
+		actualData := loader(t, expectedFile.Name())
+
+		require.Equal(t, expectedData, actualData, "file %s", expectedFile.Name())
+	}
+}
+
+func fsSub(t *testing.T, subFs subFS, folder string) subFS {
+	return must.Value(fs.Sub(subFs, filepath.Join("testdata", folder)))(t).(subFS) //nolint:forcetypeassert
+}
+
+type fileLoader func(t *testing.T, filename string) string
+
+func basicLoader(dir string) func(t *testing.T, filename string) string {
+	return func(t *testing.T, filename string) string {
+		return string(must.Value(os.ReadFile(filepath.Join(dir, filename)))(t))
+	}
+}
+
+func sortedLoader(loader fileLoader) fileLoader {
+	return func(t *testing.T, filename string) string {
+		data := strings.TrimRight(loader(t, filename), "\n")
+		slc := strings.Split(data, "\n")
+
+		slices.Sort(slc)
+
+		return strings.Join(slc, "\n") + "\n"
+	}
+}