1package logging
2
3import (
4 "bytes"
5 "context"
6 "encoding/json"
7 "io"
8 "os"
9 "path/filepath"
10 "testing"
11 "time"
12)
13
14func TestParseDebug(t *testing.T) {
15 for _, tc := range []struct {
16 input string
17 wantError bool
18 selected []string
19 }{
20 {"", false, nil}, {"core,app", false, []string{"core", "app"}},
21 {"all", false, []string{"all"}}, {"unknown", true, nil}, {"core,", true, nil},
22 {"all,input-motion", false, []string{"all", "input-motion"}},
23 } {
24 got, err := ParseDebug(tc.input)
25 if (err != nil) != tc.wantError {
26 t.Fatalf("ParseDebug(%q): %v", tc.input, err)
27 }
28 for _, name := range tc.selected {
29 if !got[name] {
30 t.Errorf("ParseDebug(%q) missing %s", tc.input, name)
31 }
32 }
33 }
34}
35
36func TestComponentLevelsAndRotation(t *testing.T) {
37 t.Setenv("XDG_STATE_HOME", t.TempDir())
38 dir := filepath.Join(os.Getenv("XDG_STATE_HOME"), "neferwl", "runs", "drm")
39 path := filepath.Join(dir, "latest.log")
40 for run := 0; run < keepRuns+2; run++ {
41 time.Sleep(2 * time.Millisecond) // distinct millisecond timestamps
42 ctx, closeLog, err := Open(context.Background(), "drm", "info", "core")
43 if err != nil {
44 t.Fatal(err)
45 }
46 core := For(ctx, "core")
47 app := For(ctx, "app")
48 core.Debug().Msg("visible")
49 app.Debug().Msg("hidden")
50 app.Info().Msg("startup")
51 if err := closeLog(false); err != nil {
52 t.Fatal(err)
53 }
54 data, err := os.ReadFile(path)
55 if err != nil {
56 t.Fatal(err)
57 }
58 lines := splitLines(data)
59 if len(lines) != 2 {
60 t.Fatalf("expected 2 entries, got %q", data)
61 }
62 for _, line := range lines {
63 var entry map[string]any
64 if err := json.Unmarshal(line, &entry); err != nil {
65 t.Fatal(err)
66 }
67 if entry["component"] != "core" && entry["component"] != "app" {
68 t.Fatalf("missing component: %v", entry)
69 }
70 }
71 }
72 runs, _ := filepath.Glob(filepath.Join(dir, "2*.log"))
73 if len(runs) != keepRuns {
74 t.Fatalf("kept %d runs, want %d", len(runs), keepRuns)
75 }
76 // A clean run leaves no empty crash file behind.
77 if crashes, _ := filepath.Glob(filepath.Join(dir, "2*.crash")); len(crashes) != 0 {
78 t.Fatalf("empty crash files kept: %v", crashes)
79 }
80}
81
82func splitLines(data []byte) [][]byte {
83 var lines [][]byte
84 for _, line := range bytes.Split(data, []byte("\n")) {
85 if len(line) > 0 {
86 lines = append(lines, line)
87 }
88 }
89 return lines
90}
91
92// Headless runs rotate in their own directory: they never prune a DRM run.
93func TestBackendsRotateSeparately(t *testing.T) {
94 t.Setenv("XDG_STATE_HOME", t.TempDir())
95 runs := filepath.Join(os.Getenv("XDG_STATE_HOME"), "neferwl", "runs")
96 open := func(backend string) {
97 time.Sleep(2 * time.Millisecond) // distinct millisecond timestamps
98 _, closeLog, err := Open(context.Background(), backend, "info", "")
99 if err != nil {
100 t.Fatal(err)
101 }
102 if err := closeLog(false); err != nil {
103 t.Fatal(err)
104 }
105 }
106 open("drm")
107 for range keepRuns + 2 {
108 open("headless")
109 }
110 if drm, _ := filepath.Glob(filepath.Join(runs, "drm", "2*.log")); len(drm) != 1 {
111 t.Fatalf("drm runs %v", drm)
112 }
113 if _, err := os.Stat(filepath.Join(runs, "drm", "latest.log")); err != nil {
114 t.Fatal(err)
115 }
116 if headless, _ := filepath.Glob(filepath.Join(runs, "headless", "2*.log")); len(headless) != keepRuns {
117 t.Fatalf("kept %d headless runs", len(headless))
118 }
119}
120
121// A category alone raises its component to debug, so its lines are written.
122func TestCategoryEnablesComponentDebug(t *testing.T) {
123 t.Setenv("XDG_STATE_HOME", t.TempDir())
124 ctx, closeLog, err := Open(context.Background(), "drm", "info", "input-motion")
125 if err != nil {
126 t.Fatal(err)
127 }
128 input, core := For(ctx, "input"), For(ctx, "core")
129 input.Debug().Msg("motion")
130 core.Debug().Msg("hidden")
131 if err := closeLog(false); err != nil {
132 t.Fatal(err)
133 }
134 data, err := os.ReadFile(filepath.Join(os.Getenv("XDG_STATE_HOME"), "neferwl", "runs", "drm", "latest.log"))
135 if err != nil {
136 t.Fatal(err)
137 }
138 if lines := splitLines(data); len(lines) != 1 || !bytes.Contains(lines[0], []byte(`"motion"`)) {
139 t.Fatalf("got %q", data)
140 }
141}
142
143// A disk that stops answering must not block the goroutine that logs:
144// input and outputs log from their own loops.
145func TestLogWriteNeverBlocksOnSlowDisk(t *testing.T) {
146 r, pw, err := os.Pipe() // nobody reads: writes block once the pipe is full
147 if err != nil {
148 t.Fatal(err)
149 }
150 defer r.Close()
151 w := newAsyncWriter(struct{ io.Writer }{pw}, pw, "")
152 line := bytes.Repeat([]byte{'x'}, 1024)
153 done := make(chan struct{})
154 go func() {
155 defer close(done)
156 for range 4 * logQueue { // far past the pipe buffer and the queue
157 _, _ = w.Write(line)
158 }
159 }()
160 select {
161 case <-done:
162 case <-time.After(5 * time.Second):
163 t.Fatal("log write blocked on a stuck disk")
164 }
165 r.Close() // unblock the writer so Close can drain and return
166 _ = w.Close()
167}
168
169// Narrow categories are on only when named, never through "all".
170func TestEnabledCategories(t *testing.T) {
171 // The component each narrow category logs under; "" is not asserted.
172 owners := map[string]string{"input-motion": "", "input-keys": "", "drm-flip": "", "wayland-damage": "wayland", "render-damage": "render"}
173 for category, owner := range owners {
174 component := categories[category]
175 if owner != "" && component != owner {
176 t.Errorf("%s belongs to %q, want %q", category, component, owner)
177 }
178 for _, tc := range []struct {
179 debug string
180 want bool
181 }{{"all", false}, {component, false}, {category, true}, {"all," + category, true}} {
182 sel, err := ParseDebug(tc.debug)
183 if err != nil {
184 t.Fatal(err)
185 }
186 ctx := context.WithValue(context.Background(), debugKey{}, debugSet(sel))
187 if got := Enabled(ctx, category); got != tc.want {
188 t.Errorf("%s with %q: %v", category, tc.debug, got)
189 }
190 }
191 }
192}