package orusapi_test import ( "bytes" "encoding/json" "fmt" "io" "os" "runtime/debug" "strings" "testing" "time" "github.com/getsentry/sentry-go" "github.com/rs/zerolog" "github.com/stretchr/testify/assert" "orus.io/orus-io/go-orusapi" ) func ExampleConsoleWriter() { log := zerolog.New(orusapi.ConsoleWriter{Out: os.Stdout, NoColor: true}) log.Info().Str("foo", "bar").Msg("Hello World") // Output: <nil> INF Hello World foo=bar } func ExampleConsoleWriter_customFormatters() { out := orusapi.ConsoleWriter{Out: os.Stdout, NoColor: true} out.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%-6s|", i)) } out.FormatFieldName = func(i interface{}) string { return fmt.Sprintf("%s:", i) } out.FormatFieldValue = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%s", i)) } log := zerolog.New(out) log.Info().Str("foo", "bar").Msg("Hello World") // Output: <nil> INFO | Hello World foo:BAR } func ExampleNewConsoleWriter() { out := zerolog.NewConsoleWriter() out.NoColor = true // For testing purposes only log := zerolog.New(out) log.Debug().Str("foo", "bar").Msg("Hello World") // Output: <nil> DBG Hello World foo=bar } func ExampleNewConsoleWriter_customFormatters() { out := orusapi.NewConsoleWriter( func(w *orusapi.ConsoleWriter) { // Customize time format w.TimeFormat = time.RFC822 // Customize level formatting w.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("[%-5s]", i)) } }, ) out.NoColor = true // For testing purposes only log := zerolog.New(out) log.Info().Str("foo", "bar").Msg("Hello World") // Output: <nil> [INFO ] Hello World foo=bar } func TestConsoleLogger(t *testing.T) { t.Run("Numbers", func(t *testing.T) { buf := &bytes.Buffer{} log := zerolog.New(orusapi.ConsoleWriter{Out: buf, NoColor: true}) log.Info(). Float64("float", 1.23). Uint64("small", 123). Uint64("big", 1152921504606846976). Msg("msg") if got, want := strings.TrimSpace(buf.String()), "<nil> INF msg big=1152921504606846976 float=1.23 small=123"; got != want { t.Errorf("\ngot:\n%s\nwant:\n%s", got, want) } }) } func TestConsoleWriter(t *testing.T) { t.Run("Default field formatter", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"foo"}} _, err := w.Write([]byte(`{"foo": "DEFAULT"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "DEFAULT foo=DEFAULT\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write colorized", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: false} _, err := w.Write([]byte(`{"level": "warn", "message": "Foobar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write fields", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} d := time.Unix(0, 0).UTC().Format(time.RFC3339) _, err := w.Write([]byte(`{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "12:00AM DBG Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Unix timestamp input format", func(t *testing.T) { of := zerolog.TimeFieldFormat defer func() { zerolog.TimeFieldFormat = of }() zerolog.TimeFieldFormat = zerolog.TimeFormatUnix buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true} _, err := w.Write([]byte(`{"time": 1234, "level": "debug", "message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "Jan 1 00:20:34.000 DBG Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Unix timestamp ms input format", func(t *testing.T) { of := zerolog.TimeFieldFormat defer func() { zerolog.TimeFieldFormat = of }() zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true} _, err := w.Write([]byte(`{"time": 1234567, "level": "debug", "message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "Jan 1 00:20:34.567 DBG Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Unix timestamp us input format", func(t *testing.T) { of := zerolog.TimeFieldFormat defer func() { zerolog.TimeFieldFormat = of }() zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMicro buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, TimeFormat: time.StampMicro, NoColor: true} _, err := w.Write([]byte(`{"time": 1234567891, "level": "debug", "message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "Jan 1 00:20:34.567891 DBG Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("No message field", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} _, err := w.Write([]byte(`{"level": "debug", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "<nil> DBG foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("No level field", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} _, err := w.Write([]byte(`{"message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "<nil> ??? Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write colorized fields", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: false} _, err := w.Write([]byte(`{"level": "warn", "message": "Foobar", "foo": "bar"}`)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar \x1b[36mfoo=\x1b[0mbar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write error field", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} d := time.Unix(0, 0).UTC().Format(time.RFC3339) evt := `{"time": "` + d + `", "level": "error", "message": "Foobar", "aaa": "bbb", "error": "Error"}` // t.Log(evt) _, err := w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "12:00AM ERR Foobar error=Error aaa=bbb\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write caller field", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} cwd, err := os.Getwd() if err != nil { t.Fatalf("Cannot get working directory: %s", err) } d := time.Unix(0, 0).UTC().Format(time.RFC3339) evt := `{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar", "caller": "` + cwd + `/foo/bar.go"}` // t.Log(evt) _, err = w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "12:00AM DBG foo/bar.go > Foobar foo=bar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write JSON field", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} evt := `{"level": "debug", "message": "Foobar", "foo": [1, 2, 3], "bar": true}` // t.Log(evt) _, err := w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "<nil> DBG Foobar bar=true foo=[1,2,3]\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Write exception", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true} b := debug.Stack() t.Log(string(b)) st := sentry.NewStacktrace() b, err := json.Marshal(st) if err != nil { t.Errorf("Unexpected error marshaling exception: %s", err) t.FailNow() } evt := `{"level": "error", "message": "Foobar", "exception": {"type": "any", "value": "error!", "stacktrace": ` + string(b) + `}}` _, err = w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } wd, err := os.Getwd() assert.NoError(t, err) expectedOutput := fmt.Sprintf(`<nil> ERR Foobar exception=error!(any) orus.io/orus-io/go-orusapi_test.TestConsoleWriter.func13 %s/log-console-writer_test.go:318 `, wd) actualOutput := buf.String() t.Log(actualOutput) if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) } func TestConsoleWriterConfiguration(t *testing.T) { t.Run("Sets TimeFormat", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true, TimeFormat: time.RFC3339} d := time.Unix(0, 0).UTC().Format(time.RFC3339) evt := `{"time": "` + d + `", "level": "info", "message": "Foobar"}` _, err := w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "1970-01-01T00:00:00Z INF Foobar\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) t.Run("Sets PartsOrder", func(t *testing.T) { buf := &bytes.Buffer{} w := orusapi.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"message", "level"}} evt := `{"level": "info", "message": "Foobar"}` _, err := w.Write([]byte(evt)) if err != nil { t.Errorf("Unexpected error when writing output: %s", err) } expectedOutput := "Foobar INF\n" actualOutput := buf.String() if actualOutput != expectedOutput { t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput) } }) } func BenchmarkConsoleWriter(b *testing.B) { b.ResetTimer() b.ReportAllocs() msg := []byte(`{"level": "info", "foo": "bar", "message": "HELLO", "time": "1990-01-01"}`) w := orusapi.ConsoleWriter{Out: io.Discard, NoColor: false} for range b.N { _, _ = w.Write(msg) } }