cannon_test.go
1package log
2
3import (
4 "bytes"
5 "encoding/json"
6 "log"
7 "log/slog"
8 "testing"
9 "testing/slogtest"
10
11 "github.com/stretchr/testify/assert"
12)
13
14// Tests conformity with a slog handler for normal logging operation
15func TestHandler(t *testing.T) {
16 var buf bytes.Buffer
17 h := slog.NewJSONHandler(&buf, nil)
18 c := wrap(h)
19
20 results := func() []map[string]any {
21 return getJSONLines(buf.Bytes(), t)
22 }
23 err := slogtest.TestHandler(c, results)
24 if err != nil {
25 log.Fatal(err)
26 }
27}
28
29func getJSONLines(b []byte, t *testing.T) []map[string]any {
30 var ms []map[string]any
31 for _, line := range bytes.Split(b, []byte{'\n'}) {
32 if len(line) == 0 {
33 continue
34 }
35 var m map[string]any
36 if err := json.Unmarshal(line, &m); err != nil {
37 t.Fatal(err)
38 }
39 ms = append(ms, m)
40 }
41 return ms
42}
43
44func getJSON(b []byte, t *testing.T) map[string]any {
45 var m map[string]any
46 if err := json.Unmarshal(b, &m); err != nil {
47 t.Fatal(err)
48 }
49 return m
50}
51
52// log 2 lines then emit the canonical log line, should have all prior attributes
53func TestAttrs(t *testing.T) {
54 var buf bytes.Buffer
55 h := wrap(slog.NewJSONHandler(&buf, nil))
56 log := New(h)
57
58 log.Info("test 1", "a", "b", "c", "d")
59 result := getJSON(buf.Bytes(), t)
60 assert.Equal(t, result["a"], "b")
61 assert.Equal(t, result["c"], "d")
62 buf.Reset()
63
64 log.Info("test 2", "e", "z", "f", "x")
65 result = getJSON(buf.Bytes(), t)
66 assert.Equal(t, result["e"], "z")
67 assert.Equal(t, result["f"], "x")
68 buf.Reset()
69
70 assert.NoError(t, h.(*cannon).emit())
71 result = getJSON(buf.Bytes(), t)
72 assert.Equal(t, result["a"], "b")
73 assert.Equal(t, result["c"], "d")
74 assert.Equal(t, result["e"], "z")
75 assert.Equal(t, result["f"], "x")
76 assert.Equal(t, result["msg"], "canonical_log_line")
77 assert.Equal(t, result["level"], "INFO")
78}
79
80func TestGroup(t *testing.T) {
81 var buf bytes.Buffer
82 h := wrap(slog.NewJSONHandler(&buf, nil))
83 log := New(h)
84
85 log.WithGroup("test").Info("test 1", "a", "b", "c", "d")
86 result := getJSON(buf.Bytes(), t)
87 assert.Equal(t, result["test"], map[string]any{"a": "b", "c": "d"})
88 buf.Reset()
89
90 log.WithGroup("test2").Info("test 2", "e", "z", "f", "x")
91 result = getJSON(buf.Bytes(), t)
92 assert.Equal(t, result["test2"], map[string]any{"e": "z", "f": "x"})
93 buf.Reset()
94
95 assert.NoError(t, Emit(log))
96 result = getJSON(buf.Bytes(), t)
97 assert.Equal(t, result["test"], map[string]any{"a": "b", "c": "d"})
98 assert.Equal(t, result["test2"], map[string]any{"e": "z", "f": "x"})
99 assert.Equal(t, result["msg"], "canonical_log_line")
100 assert.Equal(t, result["level"], "INFO")
101}
102
103func TestWithAttrs(t *testing.T) {
104 var buf bytes.Buffer
105 h := wrap(slog.NewJSONHandler(&buf, nil))
106 log := New(h)
107
108 log.With("n", "m").Info("test 1", "a", "b", "c", "d")
109 result := getJSON(buf.Bytes(), t)
110 assert.Equal(t, result["a"], "b")
111 assert.Equal(t, result["c"], "d")
112 assert.Equal(t, result["n"], "m")
113 buf.Reset()
114
115 assert.NoError(t, Emit(log))
116 result = getJSON(buf.Bytes(), t)
117 assert.Equal(t, result["a"], "b")
118 assert.Equal(t, result["c"], "d")
119 assert.Equal(t, result["n"], "m")
120 assert.Equal(t, result["msg"], "canonical_log_line")
121 assert.Equal(t, result["level"], "INFO")
122}
123
124func TestWithAttrsNoLogCall(t *testing.T) {
125 var buf bytes.Buffer
126 h := wrap(slog.NewJSONHandler(&buf, nil))
127 log := New(h)
128
129 log.With("n", "m")
130
131 assert.NoError(t, Emit(log))
132 result := getJSON(buf.Bytes(), t)
133 assert.Equal(t, result["n"], "m")
134 assert.Equal(t, result["msg"], "canonical_log_line")
135 assert.Equal(t, result["level"], "INFO")
136}
137
138func TestEmit(t *testing.T) {
139 var buf bytes.Buffer
140 h := wrap(slog.NewJSONHandler(&buf, nil))
141 log := New(h)
142
143 assert.NoError(t, Emit(log, "a", "b", "c", "d", "n", "m"))
144 result := getJSON(buf.Bytes(), t)
145 assert.Equal(t, result["a"], "b")
146 assert.Equal(t, result["c"], "d")
147 assert.Equal(t, result["n"], "m")
148 assert.Equal(t, result["msg"], "canonical_log_line")
149 assert.Equal(t, result["level"], "INFO")
150}
151
152// tests that values that cannot be merged are last write wins
153func TestLWW(t *testing.T) {
154 var buf bytes.Buffer
155 h := wrap(slog.NewJSONHandler(&buf, nil))
156 log := New(h)
157
158 log.Info("test 1", "a", "b", "c", "d")
159 result := getJSON(buf.Bytes(), t)
160 assert.Equal(t, result["a"], "b")
161 assert.Equal(t, result["c"], "d")
162 buf.Reset()
163
164 // attribute c clobbers previous value when merging is not possible
165 log.Info("test 2", "c", "e")
166 result = getJSON(buf.Bytes(), t)
167 assert.Equal(t, result["c"], "e")
168 buf.Reset()
169
170 assert.NoError(t, h.(*cannon).emit())
171 result = getJSON(buf.Bytes(), t)
172 assert.Equal(t, result["a"], "b")
173 assert.Equal(t, result["c"], "e")
174 assert.Equal(t, result["msg"], "canonical_log_line")
175 assert.Equal(t, result["level"], "INFO")
176}
177
178func TestMergeGroup(t *testing.T) {
179 var buf bytes.Buffer
180 h := wrap(slog.NewJSONHandler(&buf, nil))
181 log := New(h)
182
183 log.WithGroup("test").Info("test 1", "a", "b", "c", "d")
184 result := getJSON(buf.Bytes(), t)
185 assert.Equal(t, result["test"], map[string]any{"a": "b", "c": "d"})
186 buf.Reset()
187
188 // another group with same key, should merge with first group
189 log.WithGroup("test").Info("test 2", "e", "f", "g", "h")
190 result = getJSON(buf.Bytes(), t)
191 assert.Equal(t, result["test"], map[string]any{"e": "f", "g": "h"})
192 buf.Reset()
193
194 assert.NoError(t, Emit(log))
195 result = getJSON(buf.Bytes(), t)
196 assert.Equal(t, result["test"], map[string]any{"a": "b", "c": "d", "e": "f", "g": "h"})
197 assert.Equal(t, result["msg"], "canonical_log_line")
198 assert.Equal(t, result["level"], "INFO")
199}
200
201func TestMergeGroupLWW(t *testing.T) {
202 var buf bytes.Buffer
203 h := wrap(slog.NewJSONHandler(&buf, nil))
204 log := New(h)
205
206 log.WithGroup("test").Info("test 1", "a", "b", "c", "d")
207 result := getJSON(buf.Bytes(), t)
208 assert.Equal(t, result["test"], map[string]any{"a": "b", "c": "d"})
209 buf.Reset()
210
211 // another group with same key, should merge with first group. Key "a" is overwritten, so LWW.
212 log.WithGroup("test").Info("test 2", "a", "z", "g", "h")
213 result = getJSON(buf.Bytes(), t)
214 assert.Equal(t, result["test"], map[string]any{"a": "z", "g": "h"})
215 buf.Reset()
216
217 assert.NoError(t, Emit(log))
218 result = getJSON(buf.Bytes(), t)
219 assert.Equal(t, result["test"], map[string]any{"a": "z", "c": "d", "g": "h"})
220 assert.Equal(t, result["msg"], "canonical_log_line")
221 assert.Equal(t, result["level"], "INFO")
222}
223
224type user string
225
226func (a user) Merge(b slog.Value) slog.Value {
227 previous := b.String()
228 return slog.StringValue(previous + "->" + string(a))
229}
230
231func TestMergeUserDefined(t *testing.T) {
232 var buf bytes.Buffer
233 h := wrap(slog.NewJSONHandler(&buf, nil))
234 log := New(h)
235
236 log.Info("test 1", "a", user("a"))
237 result := getJSON(buf.Bytes(), t)
238 assert.Equal(t, result["a"], "a")
239 buf.Reset()
240
241 // attribute c clobbers previous value when merging is not possible
242 log.Info("test 2", "a", user("b"))
243 result = getJSON(buf.Bytes(), t)
244 assert.Equal(t, result["a"], "b")
245 buf.Reset()
246
247 assert.NoError(t, h.(*cannon).emit())
248 result = getJSON(buf.Bytes(), t)
249 assert.Equal(t, result["a"], "a->b")
250 assert.Equal(t, result["msg"], "canonical_log_line")
251 assert.Equal(t, result["level"], "INFO")
252
253}
