1 package logrus
2
3 import (
4 "bytes"
5 "errors"
6 "fmt"
7 "os"
8 "runtime"
9 "sort"
10 "strings"
11 "testing"
12 "time"
13
14 "github.com/stretchr/testify/assert"
15 "github.com/stretchr/testify/require"
16 )
17
18 func TestFormatting(t *testing.T) {
19 tf := &TextFormatter{DisableColors: true}
20
21 testCases := []struct {
22 value string
23 expected string
24 }{
25 {`foo`, "time=\"0001-01-01T00:00:00Z\" level=panic test=foo\n"},
26 }
27
28 for _, tc := range testCases {
29 b, _ := tf.Format(WithField("test", tc.value))
30
31 if string(b) != tc.expected {
32 t.Errorf("formatting expected for %q (result was %q instead of %q)", tc.value, string(b), tc.expected)
33 }
34 }
35 }
36
37 func TestQuoting(t *testing.T) {
38 tf := &TextFormatter{DisableColors: true}
39
40 checkQuoting := func(q bool, value interface{}) {
41 b, _ := tf.Format(WithField("test", value))
42 idx := bytes.Index(b, ([]byte)("test="))
43 cont := bytes.Contains(b[idx+5:], []byte("\""))
44 if cont != q {
45 if q {
46 t.Errorf("quoting expected for: %#v", value)
47 } else {
48 t.Errorf("quoting not expected for: %#v", value)
49 }
50 }
51 }
52
53 checkQuoting(false, "")
54 checkQuoting(false, "abcd")
55 checkQuoting(false, "v1.0")
56 checkQuoting(false, "1234567890")
57 checkQuoting(false, "/foobar")
58 checkQuoting(false, "foo_bar")
59 checkQuoting(false, "foo@bar")
60 checkQuoting(false, "foobar^")
61 checkQuoting(false, "+/-_^@f.oobar")
62 checkQuoting(true, "foobar$")
63 checkQuoting(true, "&foobar")
64 checkQuoting(true, "x y")
65 checkQuoting(true, "x,y")
66 checkQuoting(false, errors.New("invalid"))
67 checkQuoting(true, errors.New("invalid argument"))
68
69
70 tf.QuoteEmptyFields = true
71 checkQuoting(true, "")
72 checkQuoting(false, "abcd")
73 checkQuoting(true, errors.New("invalid argument"))
74 }
75
76 func TestEscaping(t *testing.T) {
77 tf := &TextFormatter{DisableColors: true}
78
79 testCases := []struct {
80 value string
81 expected string
82 }{
83 {`ba"r`, `ba\"r`},
84 {`ba'r`, `ba'r`},
85 }
86
87 for _, tc := range testCases {
88 b, _ := tf.Format(WithField("test", tc.value))
89 if !bytes.Contains(b, []byte(tc.expected)) {
90 t.Errorf("escaping expected for %q (result was %q instead of %q)", tc.value, string(b), tc.expected)
91 }
92 }
93 }
94
95 func TestEscaping_Interface(t *testing.T) {
96 tf := &TextFormatter{DisableColors: true}
97
98 ts := time.Now()
99
100 testCases := []struct {
101 value interface{}
102 expected string
103 }{
104 {ts, fmt.Sprintf("\"%s\"", ts.String())},
105 {errors.New("error: something went wrong"), "\"error: something went wrong\""},
106 }
107
108 for _, tc := range testCases {
109 b, _ := tf.Format(WithField("test", tc.value))
110 if !bytes.Contains(b, []byte(tc.expected)) {
111 t.Errorf("escaping expected for %q (result was %q instead of %q)", tc.value, string(b), tc.expected)
112 }
113 }
114 }
115
116 func TestTimestampFormat(t *testing.T) {
117 checkTimeStr := func(format string) {
118 customFormatter := &TextFormatter{DisableColors: true, TimestampFormat: format}
119 customStr, _ := customFormatter.Format(WithField("test", "test"))
120 timeStart := bytes.Index(customStr, ([]byte)("time="))
121 timeEnd := bytes.Index(customStr, ([]byte)("level="))
122 timeStr := customStr[timeStart+5+len("\"") : timeEnd-1-len("\"")]
123 if format == "" {
124 format = time.RFC3339
125 }
126 _, e := time.Parse(format, (string)(timeStr))
127 if e != nil {
128 t.Errorf("time string \"%s\" did not match provided time format \"%s\": %s", timeStr, format, e)
129 }
130 }
131
132 checkTimeStr("2006-01-02T15:04:05.000000000Z07:00")
133 checkTimeStr("Mon Jan _2 15:04:05 2006")
134 checkTimeStr("")
135 }
136
137 func TestDisableLevelTruncation(t *testing.T) {
138 entry := &Entry{
139 Time: time.Now(),
140 Message: "testing",
141 }
142 keys := []string{}
143 timestampFormat := "Mon Jan 2 15:04:05 -0700 MST 2006"
144 checkDisableTruncation := func(disabled bool, level Level) {
145 tf := &TextFormatter{DisableLevelTruncation: disabled}
146 var b bytes.Buffer
147 entry.Level = level
148 tf.printColored(&b, entry, keys, nil, timestampFormat)
149 logLine := (&b).String()
150 if disabled {
151 expected := strings.ToUpper(level.String())
152 if !strings.Contains(logLine, expected) {
153 t.Errorf("level string expected to be %s when truncation disabled", expected)
154 }
155 } else {
156 expected := strings.ToUpper(level.String())
157 if len(level.String()) > 4 {
158 if strings.Contains(logLine, expected) {
159 t.Errorf("level string %s expected to be truncated to %s when truncation is enabled", expected, expected[0:4])
160 }
161 } else {
162 if !strings.Contains(logLine, expected) {
163 t.Errorf("level string expected to be %s when truncation is enabled and level string is below truncation threshold", expected)
164 }
165 }
166 }
167 }
168
169 checkDisableTruncation(true, DebugLevel)
170 checkDisableTruncation(true, InfoLevel)
171 checkDisableTruncation(false, ErrorLevel)
172 checkDisableTruncation(false, InfoLevel)
173 }
174
175 func TestDisableTimestampWithColoredOutput(t *testing.T) {
176 tf := &TextFormatter{DisableTimestamp: true, ForceColors: true}
177
178 b, _ := tf.Format(WithField("test", "test"))
179 if strings.Contains(string(b), "[0000]") {
180 t.Error("timestamp not expected when DisableTimestamp is true")
181 }
182 }
183
184 func TestNewlineBehavior(t *testing.T) {
185 tf := &TextFormatter{ForceColors: true}
186
187
188 e := NewEntry(StandardLogger())
189 e.Message = "test message\n"
190 b, _ := tf.Format(e)
191 if bytes.Contains(b, []byte("test message\n")) {
192 t.Error("first newline at end of Entry.Message resulted in unexpected 2 newlines in output. Expected newline to be removed.")
193 }
194
195
196 e = NewEntry(StandardLogger())
197 e.Message = "test message\n\n"
198 b, _ = tf.Format(e)
199 if bytes.Contains(b, []byte("test message\n\n")) {
200 t.Error("Double newline at end of Entry.Message resulted in unexpected 2 newlines in output. Expected single newline")
201 }
202 if !bytes.Contains(b, []byte("test message\n")) {
203 t.Error("Double newline at end of Entry.Message did not result in a single newline after formatting")
204 }
205 }
206
207 func TestTextFormatterFieldMap(t *testing.T) {
208 formatter := &TextFormatter{
209 DisableColors: true,
210 FieldMap: FieldMap{
211 FieldKeyMsg: "message",
212 FieldKeyLevel: "somelevel",
213 FieldKeyTime: "timeywimey",
214 },
215 }
216
217 entry := &Entry{
218 Message: "oh hi",
219 Level: WarnLevel,
220 Time: time.Date(1981, time.February, 24, 4, 28, 3, 100, time.UTC),
221 Data: Fields{
222 "field1": "f1",
223 "message": "messagefield",
224 "somelevel": "levelfield",
225 "timeywimey": "timeywimeyfield",
226 },
227 }
228
229 b, err := formatter.Format(entry)
230 if err != nil {
231 t.Fatal("Unable to format entry: ", err)
232 }
233
234 assert.Equal(t,
235 `timeywimey="1981-02-24T04:28:03Z" `+
236 `somelevel=warning `+
237 `message="oh hi" `+
238 `field1=f1 `+
239 `fields.message=messagefield `+
240 `fields.somelevel=levelfield `+
241 `fields.timeywimey=timeywimeyfield`+"\n",
242 string(b),
243 "Formatted output doesn't respect FieldMap")
244 }
245
246 func TestTextFormatterIsColored(t *testing.T) {
247 params := []struct {
248 name string
249 expectedResult bool
250 isTerminal bool
251 disableColor bool
252 forceColor bool
253 envColor bool
254 clicolorIsSet bool
255 clicolorForceIsSet bool
256 clicolorVal string
257 clicolorForceVal string
258 }{
259
260 {
261 name: "testcase1",
262 expectedResult: false,
263 isTerminal: false,
264 disableColor: false,
265 forceColor: false,
266 envColor: false,
267 clicolorIsSet: false,
268 clicolorForceIsSet: false,
269 },
270
271 {
272 name: "testcase2",
273 expectedResult: true,
274 isTerminal: true,
275 disableColor: false,
276 forceColor: false,
277 envColor: false,
278 clicolorIsSet: false,
279 clicolorForceIsSet: false,
280 },
281
282 {
283 name: "testcase3",
284 expectedResult: false,
285 isTerminal: true,
286 disableColor: true,
287 forceColor: false,
288 envColor: false,
289 clicolorIsSet: false,
290 clicolorForceIsSet: false,
291 },
292
293 {
294 name: "testcase4",
295 expectedResult: false,
296 isTerminal: false,
297 disableColor: true,
298 forceColor: false,
299 envColor: false,
300 clicolorIsSet: false,
301 clicolorForceIsSet: false,
302 },
303
304 {
305 name: "testcase5",
306 expectedResult: true,
307 isTerminal: false,
308 disableColor: false,
309 forceColor: true,
310 envColor: false,
311 clicolorIsSet: false,
312 clicolorForceIsSet: false,
313 },
314
315 {
316 name: "testcase6",
317 expectedResult: false,
318 isTerminal: true,
319 disableColor: false,
320 forceColor: false,
321 envColor: true,
322 clicolorIsSet: true,
323 clicolorForceIsSet: false,
324 clicolorVal: "0",
325 },
326
327 {
328 name: "testcase7",
329 expectedResult: true,
330 isTerminal: true,
331 disableColor: false,
332 forceColor: false,
333 envColor: true,
334 clicolorIsSet: true,
335 clicolorForceIsSet: false,
336 clicolorVal: "1",
337 },
338
339 {
340 name: "testcase8",
341 expectedResult: false,
342 isTerminal: false,
343 disableColor: false,
344 forceColor: false,
345 envColor: true,
346 clicolorIsSet: true,
347 clicolorForceIsSet: false,
348 clicolorVal: "0",
349 },
350
351 {
352 name: "testcase9",
353 expectedResult: false,
354 isTerminal: false,
355 disableColor: false,
356 forceColor: false,
357 envColor: true,
358 clicolorIsSet: true,
359 clicolorForceIsSet: false,
360 clicolorVal: "1",
361 },
362
363 {
364 name: "testcase10",
365 expectedResult: true,
366 isTerminal: false,
367 disableColor: false,
368 forceColor: true,
369 envColor: true,
370 clicolorIsSet: true,
371 clicolorForceIsSet: false,
372 clicolorVal: "1",
373 },
374
375 {
376 name: "testcase11",
377 expectedResult: false,
378 isTerminal: false,
379 disableColor: false,
380 forceColor: true,
381 envColor: true,
382 clicolorIsSet: true,
383 clicolorForceIsSet: false,
384 clicolorVal: "0",
385 },
386
387 {
388 name: "testcase12",
389 expectedResult: true,
390 isTerminal: false,
391 disableColor: false,
392 forceColor: false,
393 envColor: true,
394 clicolorIsSet: false,
395 clicolorForceIsSet: true,
396 clicolorForceVal: "1",
397 },
398
399 {
400 name: "testcase13",
401 expectedResult: false,
402 isTerminal: false,
403 disableColor: false,
404 forceColor: false,
405 envColor: true,
406 clicolorIsSet: false,
407 clicolorForceIsSet: true,
408 clicolorForceVal: "0",
409 },
410
411 {
412 name: "testcase14",
413 expectedResult: false,
414 isTerminal: true,
415 disableColor: false,
416 forceColor: false,
417 envColor: true,
418 clicolorIsSet: false,
419 clicolorForceIsSet: true,
420 clicolorForceVal: "0",
421 },
422 }
423
424 cleanenv := func() {
425 os.Unsetenv("CLICOLOR")
426 os.Unsetenv("CLICOLOR_FORCE")
427 }
428
429 defer cleanenv()
430
431 for _, val := range params {
432 t.Run("textformatter_"+val.name, func(subT *testing.T) {
433 tf := TextFormatter{
434 isTerminal: val.isTerminal,
435 DisableColors: val.disableColor,
436 ForceColors: val.forceColor,
437 EnvironmentOverrideColors: val.envColor,
438 }
439 cleanenv()
440 if val.clicolorIsSet {
441 os.Setenv("CLICOLOR", val.clicolorVal)
442 }
443 if val.clicolorForceIsSet {
444 os.Setenv("CLICOLOR_FORCE", val.clicolorForceVal)
445 }
446 res := tf.isColored()
447 if runtime.GOOS == "windows" && !tf.ForceColors && !val.clicolorForceIsSet {
448 assert.Equal(subT, false, res)
449 } else {
450 assert.Equal(subT, val.expectedResult, res)
451 }
452 })
453 }
454 }
455
456 func TestCustomSorting(t *testing.T) {
457 formatter := &TextFormatter{
458 DisableColors: true,
459 SortingFunc: func(keys []string) {
460 sort.Slice(keys, func(i, j int) bool {
461 if keys[j] == "prefix" {
462 return false
463 }
464 if keys[i] == "prefix" {
465 return true
466 }
467 return strings.Compare(keys[i], keys[j]) == -1
468 })
469 },
470 }
471
472 entry := &Entry{
473 Message: "Testing custom sort function",
474 Time: time.Now(),
475 Level: InfoLevel,
476 Data: Fields{
477 "test": "testvalue",
478 "prefix": "the application prefix",
479 "blablabla": "blablabla",
480 },
481 }
482 b, err := formatter.Format(entry)
483 require.NoError(t, err)
484 require.True(t, strings.HasPrefix(string(b), "prefix="), "format output is %q", string(b))
485 }
486
View as plain text