1package logging
2
3import (
4 "encoding/json"
5 "log/slog"
6 "os"
7 "os/exec"
8 "path/filepath"
9 "strings"
10 "sync"
11 "testing"
12)
13
14func privateDir(t *testing.T) string {
15 t.Helper()
16 return filepath.Join(t.TempDir(), "vev")
17}
18
19func TestParseLevelAndEnvLevel(t *testing.T) {
20 tests := []struct {
21 in string
22 want slog.Level
23 }{
24 {"debug", slog.LevelDebug},
25 {" DEBUG ", slog.LevelDebug},
26 {"info", slog.LevelInfo},
27 {"", slog.LevelInfo},
28 {"warn", slog.LevelWarn},
29 {"warning", slog.LevelWarn},
30 {"error", slog.LevelError},
31 {"bogus", slog.LevelInfo},
32 }
33 for _, tt := range tests {
34 if got := ParseLevel(tt.in); got != tt.want {
35 t.Fatalf("ParseLevel(%q) = %v, want %v", tt.in, got, tt.want)
36 }
37 }
38
39 t.Setenv("VEV_LOG", "debug")
40 if got := EnvLevel(); got != slog.LevelDebug {
41 t.Fatalf("EnvLevel() = %v, want %v", got, slog.LevelDebug)
42 }
43}
44
45func TestSetupWritesJSONWithComponent(t *testing.T) {
46 dir := privateDir(t)
47 logger, closer, err := Setup(Config{Dir: dir, Component: Client, Level: slog.LevelDebug})
48 if err != nil {
49 t.Fatalf("Setup() error = %v", err)
50 }
51 defer func() {
52 if err := closer.Close(); err != nil {
53 t.Errorf("Close() error = %v", err)
54 }
55 }()
56
57 logger.Info("hello", "answer", 42)
58
59 data, err := os.ReadFile(filepath.Join(dir, "vev-client.log"))
60 if err != nil {
61 t.Fatalf("ReadFile() error = %v", err)
62 }
63 var entry map[string]any
64 if err := json.Unmarshal(data, &entry); err != nil {
65 t.Fatalf("log entry is not JSON: %v; data=%q", err, data)
66 }
67 if entry["component"] != "client" {
68 t.Fatalf("component = %v, want client; entry=%v", entry["component"], entry)
69 }
70 if entry["msg"] != "hello" || entry["answer"] != float64(42) {
71 t.Fatalf("unexpected entry fields: %v", entry)
72 }
73 if _, err := os.Stat(filepath.Join(dir, "vev-client-crash.log")); err != nil {
74 t.Fatalf("crash log not created: %v", err)
75 }
76}
77
78func TestRuntimeRotation(t *testing.T) {
79 dir := t.TempDir()
80 path := filepath.Join(dir, "vev-daemon.log")
81 w, err := newRotatingWriter(path, 10, true)
82 if err != nil {
83 t.Fatalf("newRotatingWriter() error = %v", err)
84 }
85 defer func() {
86 if err := w.Close(); err != nil {
87 t.Errorf("Close() error = %v", err)
88 }
89 }()
90
91 if _, err := w.Write([]byte("0123456789")); err != nil {
92 t.Fatalf("Write() error = %v", err)
93 }
94 if _, err := os.Stat(path + ".old"); err != nil {
95 t.Fatalf("rotated file missing: %v", err)
96 }
97 live, err := os.ReadFile(path)
98 if err != nil {
99 t.Fatalf("read live file: %v", err)
100 }
101 if len(live) != 0 {
102 t.Fatalf("live file length = %d, want 0 after rotation", len(live))
103 }
104 old, err := os.ReadFile(path + ".old")
105 if err != nil {
106 t.Fatalf("read old file: %v", err)
107 }
108 if string(old) != "0123456789" {
109 t.Fatalf("old file = %q, want original write", old)
110 }
111}
112
113func TestStartupOnlyRotation(t *testing.T) {
114 dir := t.TempDir()
115 path := filepath.Join(dir, "vev-client.log")
116 if err := os.WriteFile(path, []byte("already-too-large"), 0o600); err != nil {
117 t.Fatalf("seed log: %v", err)
118 }
119 w, err := newRotatingWriter(path, 5, false)
120 if err != nil {
121 t.Fatalf("newRotatingWriter() error = %v", err)
122 }
123 defer func() {
124 if err := w.Close(); err != nil {
125 t.Errorf("Close() error = %v", err)
126 }
127 }()
128
129 if old, err := os.ReadFile(path + ".old"); err != nil || string(old) != "already-too-large" {
130 t.Fatalf("startup rotation old = %q, err = %v", old, err)
131 }
132 if _, err := w.Write([]byte("first")); err != nil {
133 t.Fatalf("Write(first) error = %v", err)
134 }
135 if _, err := w.Write([]byte("second")); err != nil {
136 t.Fatalf("Write(second) error = %v", err)
137 }
138 if old, err := os.ReadFile(path + ".old"); err != nil || string(old) != "already-too-large" {
139 t.Fatalf("startup-only mode rotated during writes; old = %q, err = %v", old, err)
140 }
141 live, err := os.ReadFile(path)
142 if err != nil {
143 t.Fatalf("read live file: %v", err)
144 }
145 if string(live) != "firstsecond" {
146 t.Fatalf("live file = %q, want appended writes", live)
147 }
148}
149
150func TestCrashOutputCapturesPanicStack(t *testing.T) {
151 dir := privateDir(t)
152 cmd := exec.Command(os.Args[0], "-test.run=TestCrashOutputHelper")
153 cmd.Env = append(os.Environ(), "VEV_CRASH_HELPER=1", "VEV_CRASH_DIR="+dir)
154 if err := cmd.Run(); err == nil {
155 t.Fatal("crash helper exited successfully, want panic failure")
156 }
157
158 data, err := os.ReadFile(filepath.Join(dir, "vev-daemon-crash.log"))
159 if err != nil {
160 t.Fatalf("read crash log: %v", err)
161 }
162 if !strings.Contains(string(data), "intentional crash for SetCrashOutput test") || !strings.Contains(string(data), "goroutine") {
163 t.Fatalf("crash log did not contain panic stack; data=%q", data)
164 }
165}
166
167func TestCrashOutputHelper(t *testing.T) {
168 if os.Getenv("VEV_CRASH_HELPER") != "1" {
169 return
170 }
171 if _, _, err := Setup(Config{Dir: os.Getenv("VEV_CRASH_DIR"), Component: Daemon, Level: slog.LevelInfo}); err != nil {
172 panic(err)
173 }
174 panic("intentional crash for SetCrashOutput test")
175}
176
177func TestStartupOnlyConcurrentRotationRaceIsIgnored(t *testing.T) {
178 dir := t.TempDir()
179 path := filepath.Join(dir, "vev-client.log")
180 if err := os.WriteFile(path, []byte("already-too-large"), 0o600); err != nil {
181 t.Fatalf("seed log: %v", err)
182 }
183
184 var wg sync.WaitGroup
185 errCh := make(chan error, 8)
186 for i := 0; i < cap(errCh); i++ {
187 wg.Add(1)
188 go func() {
189 defer wg.Done()
190 w, err := newRotatingWriter(path, 5, false)
191 if err != nil {
192 errCh <- err
193 return
194 }
195 if _, err := w.Write([]byte("x")); err != nil {
196 errCh <- err
197 }
198 if err := w.Close(); err != nil {
199 errCh <- err
200 }
201 }()
202 }
203 wg.Wait()
204 close(errCh)
205 for err := range errCh {
206 if err != nil {
207 t.Fatalf("concurrent startup writer failed: %v", err)
208 }
209 }
210 if _, err := os.Stat(path); err != nil {
211 t.Fatalf("live log missing after concurrent startup rotation: %v", err)
212 }
213 if _, err := os.Stat(path + ".old"); err != nil {
214 t.Fatalf("rotated log missing after concurrent startup rotation: %v", err)
215 }
216}
217
218func TestDoubleClose(t *testing.T) {
219 _, closer, err := Setup(Config{Dir: privateDir(t), Component: Stdio, Level: slog.LevelInfo})
220 if err != nil {
221 t.Fatalf("Setup() error = %v", err)
222 }
223 if err := closer.Close(); err != nil {
224 t.Fatalf("first Close() error = %v", err)
225 }
226 if err := closer.Close(); err != nil {
227 t.Fatalf("second Close() error = %v", err)
228 }
229}
230
231func TestRotationRenameFailureIsNonFatal(t *testing.T) {
232 dir := t.TempDir()
233 path := filepath.Join(dir, "vev-daemon.log")
234 if err := os.WriteFile(path, nil, 0o600); err != nil {
235 t.Fatalf("seed log: %v", err)
236 }
237 if err := os.Mkdir(path+".old", 0o700); err != nil {
238 t.Fatalf("make rename obstacle: %v", err)
239 }
240 if err := os.WriteFile(filepath.Join(path+".old", "child"), []byte("x"), 0o600); err != nil {
241 t.Fatalf("make non-empty obstacle: %v", err)
242 }
243
244 w, err := newRotatingWriter(path, 4, true)
245 if err != nil {
246 t.Fatalf("newRotatingWriter() error = %v", err)
247 }
248 defer func() {
249 if err := w.Close(); err != nil {
250 t.Errorf("Close() error = %v", err)
251 }
252 }()
253
254 if _, err := w.Write([]byte("exceeds")); err != nil {
255 t.Fatalf("Write() error = %v", err)
256 }
257 live, err := os.ReadFile(path)
258 if err != nil {
259 t.Fatalf("read live file: %v", err)
260 }
261 if !strings.Contains(string(live), "exceeds") {
262 t.Fatalf("write was not preserved after failed rename: %q", live)
263 }
264}