...

Source file src/github.com/rs/zerolog/console_test.go

Documentation: github.com/rs/zerolog

     1  package zerolog_test
     2  
     3  import (
     4  	"bytes"
     5  	"fmt"
     6  	"io/ioutil"
     7  	"os"
     8  	"strings"
     9  	"testing"
    10  	"time"
    11  
    12  	"github.com/rs/zerolog"
    13  )
    14  
    15  func ExampleConsoleWriter() {
    16  	log := zerolog.New(zerolog.ConsoleWriter{Out: os.Stdout, NoColor: true})
    17  
    18  	log.Info().Str("foo", "bar").Msg("Hello World")
    19  	// Output: <nil> INF Hello World foo=bar
    20  }
    21  
    22  func ExampleConsoleWriter_customFormatters() {
    23  	out := zerolog.ConsoleWriter{Out: os.Stdout, NoColor: true}
    24  	out.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%-6s|", i)) }
    25  	out.FormatFieldName = func(i interface{}) string { return fmt.Sprintf("%s:", i) }
    26  	out.FormatFieldValue = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("%s", i)) }
    27  	log := zerolog.New(out)
    28  
    29  	log.Info().Str("foo", "bar").Msg("Hello World")
    30  	// Output: <nil> INFO  | Hello World foo:BAR
    31  }
    32  
    33  func ExampleNewConsoleWriter() {
    34  	out := zerolog.NewConsoleWriter()
    35  	out.NoColor = true // For testing purposes only
    36  	log := zerolog.New(out)
    37  
    38  	log.Debug().Str("foo", "bar").Msg("Hello World")
    39  	// Output: <nil> DBG Hello World foo=bar
    40  }
    41  
    42  func ExampleNewConsoleWriter_customFormatters() {
    43  	out := zerolog.NewConsoleWriter(
    44  		func(w *zerolog.ConsoleWriter) {
    45  			// Customize time format
    46  			w.TimeFormat = time.RFC822
    47  			// Customize level formatting
    48  			w.FormatLevel = func(i interface{}) string { return strings.ToUpper(fmt.Sprintf("[%-5s]", i)) }
    49  		},
    50  	)
    51  	out.NoColor = true // For testing purposes only
    52  
    53  	log := zerolog.New(out)
    54  
    55  	log.Info().Str("foo", "bar").Msg("Hello World")
    56  	// Output: <nil> [INFO ] Hello World foo=bar
    57  }
    58  
    59  func TestConsoleLogger(t *testing.T) {
    60  	t.Run("Numbers", func(t *testing.T) {
    61  		buf := &bytes.Buffer{}
    62  		log := zerolog.New(zerolog.ConsoleWriter{Out: buf, NoColor: true})
    63  		log.Info().
    64  			Float64("float", 1.23).
    65  			Uint64("small", 123).
    66  			Uint64("big", 1152921504606846976).
    67  			Msg("msg")
    68  		if got, want := strings.TrimSpace(buf.String()), "<nil> INF msg big=1152921504606846976 float=1.23 small=123"; got != want {
    69  			t.Errorf("\ngot:\n%s\nwant:\n%s", got, want)
    70  		}
    71  	})
    72  }
    73  
    74  func TestConsoleWriter(t *testing.T) {
    75  	t.Run("Default field formatter", func(t *testing.T) {
    76  		buf := &bytes.Buffer{}
    77  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"foo"}}
    78  
    79  		_, err := w.Write([]byte(`{"foo": "DEFAULT"}`))
    80  		if err != nil {
    81  			t.Errorf("Unexpected error when writing output: %s", err)
    82  		}
    83  
    84  		expectedOutput := "DEFAULT foo=DEFAULT\n"
    85  		actualOutput := buf.String()
    86  		if actualOutput != expectedOutput {
    87  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
    88  		}
    89  	})
    90  
    91  	t.Run("Write colorized", func(t *testing.T) {
    92  		buf := &bytes.Buffer{}
    93  		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
    94  
    95  		_, err := w.Write([]byte(`{"level": "warn", "message": "Foobar"}`))
    96  		if err != nil {
    97  			t.Errorf("Unexpected error when writing output: %s", err)
    98  		}
    99  
   100  		expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar\n"
   101  		actualOutput := buf.String()
   102  		if actualOutput != expectedOutput {
   103  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   104  		}
   105  	})
   106  
   107  	t.Run("Write fields", func(t *testing.T) {
   108  		buf := &bytes.Buffer{}
   109  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   110  
   111  		ts := time.Unix(0, 0)
   112  		d := ts.UTC().Format(time.RFC3339)
   113  		_, err := w.Write([]byte(`{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar"}`))
   114  		if err != nil {
   115  			t.Errorf("Unexpected error when writing output: %s", err)
   116  		}
   117  
   118  		expectedOutput := ts.Format(time.Kitchen) + " DBG Foobar foo=bar\n"
   119  		actualOutput := buf.String()
   120  		if actualOutput != expectedOutput {
   121  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   122  		}
   123  	})
   124  
   125  	t.Run("Unix timestamp input format", func(t *testing.T) {
   126  		of := zerolog.TimeFieldFormat
   127  		defer func() {
   128  			zerolog.TimeFieldFormat = of
   129  		}()
   130  		zerolog.TimeFieldFormat = zerolog.TimeFormatUnix
   131  
   132  		buf := &bytes.Buffer{}
   133  		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
   134  
   135  		_, err := w.Write([]byte(`{"time": 1234, "level": "debug", "message": "Foobar", "foo": "bar"}`))
   136  		if err != nil {
   137  			t.Errorf("Unexpected error when writing output: %s", err)
   138  		}
   139  
   140  		expectedOutput := time.Unix(1234, 0).Format(time.StampMilli) + " DBG Foobar foo=bar\n"
   141  		actualOutput := buf.String()
   142  		if actualOutput != expectedOutput {
   143  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   144  		}
   145  	})
   146  
   147  	t.Run("Unix timestamp ms input format", func(t *testing.T) {
   148  		of := zerolog.TimeFieldFormat
   149  		defer func() {
   150  			zerolog.TimeFieldFormat = of
   151  		}()
   152  		zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMs
   153  
   154  		buf := &bytes.Buffer{}
   155  		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMilli, NoColor: true}
   156  
   157  		_, err := w.Write([]byte(`{"time": 1234567, "level": "debug", "message": "Foobar", "foo": "bar"}`))
   158  		if err != nil {
   159  			t.Errorf("Unexpected error when writing output: %s", err)
   160  		}
   161  
   162  		expectedOutput := time.Unix(1234, 567000000).Format(time.StampMilli) + " DBG Foobar foo=bar\n"
   163  		actualOutput := buf.String()
   164  		if actualOutput != expectedOutput {
   165  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   166  		}
   167  	})
   168  
   169  	t.Run("Unix timestamp us input format", func(t *testing.T) {
   170  		of := zerolog.TimeFieldFormat
   171  		defer func() {
   172  			zerolog.TimeFieldFormat = of
   173  		}()
   174  		zerolog.TimeFieldFormat = zerolog.TimeFormatUnixMicro
   175  
   176  		buf := &bytes.Buffer{}
   177  		w := zerolog.ConsoleWriter{Out: buf, TimeFormat: time.StampMicro, NoColor: true}
   178  
   179  		_, err := w.Write([]byte(`{"time": 1234567891, "level": "debug", "message": "Foobar", "foo": "bar"}`))
   180  		if err != nil {
   181  			t.Errorf("Unexpected error when writing output: %s", err)
   182  		}
   183  
   184  		expectedOutput := time.Unix(1234, 567891000).Format(time.StampMicro) + " DBG Foobar foo=bar\n"
   185  		actualOutput := buf.String()
   186  		if actualOutput != expectedOutput {
   187  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   188  		}
   189  	})
   190  
   191  	t.Run("No message field", func(t *testing.T) {
   192  		buf := &bytes.Buffer{}
   193  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   194  
   195  		_, err := w.Write([]byte(`{"level": "debug", "foo": "bar"}`))
   196  		if err != nil {
   197  			t.Errorf("Unexpected error when writing output: %s", err)
   198  		}
   199  
   200  		expectedOutput := "<nil> DBG foo=bar\n"
   201  		actualOutput := buf.String()
   202  		if actualOutput != expectedOutput {
   203  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   204  		}
   205  	})
   206  
   207  	t.Run("No level field", func(t *testing.T) {
   208  		buf := &bytes.Buffer{}
   209  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   210  
   211  		_, err := w.Write([]byte(`{"message": "Foobar", "foo": "bar"}`))
   212  		if err != nil {
   213  			t.Errorf("Unexpected error when writing output: %s", err)
   214  		}
   215  
   216  		expectedOutput := "<nil> ??? Foobar foo=bar\n"
   217  		actualOutput := buf.String()
   218  		if actualOutput != expectedOutput {
   219  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   220  		}
   221  	})
   222  
   223  	t.Run("Write colorized fields", func(t *testing.T) {
   224  		buf := &bytes.Buffer{}
   225  		w := zerolog.ConsoleWriter{Out: buf, NoColor: false}
   226  
   227  		_, err := w.Write([]byte(`{"level": "warn", "message": "Foobar", "foo": "bar"}`))
   228  		if err != nil {
   229  			t.Errorf("Unexpected error when writing output: %s", err)
   230  		}
   231  
   232  		expectedOutput := "\x1b[90m<nil>\x1b[0m \x1b[31mWRN\x1b[0m Foobar \x1b[36mfoo=\x1b[0mbar\n"
   233  		actualOutput := buf.String()
   234  		if actualOutput != expectedOutput {
   235  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   236  		}
   237  	})
   238  
   239  	t.Run("Write error field", func(t *testing.T) {
   240  		buf := &bytes.Buffer{}
   241  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   242  
   243  		ts := time.Unix(0, 0)
   244  		d := ts.UTC().Format(time.RFC3339)
   245  		evt := `{"time": "` + d + `", "level": "error", "message": "Foobar", "aaa": "bbb", "error": "Error"}`
   246  		// t.Log(evt)
   247  
   248  		_, err := w.Write([]byte(evt))
   249  		if err != nil {
   250  			t.Errorf("Unexpected error when writing output: %s", err)
   251  		}
   252  
   253  		expectedOutput := ts.Format(time.Kitchen) + " ERR Foobar error=Error aaa=bbb\n"
   254  		actualOutput := buf.String()
   255  		if actualOutput != expectedOutput {
   256  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   257  		}
   258  	})
   259  
   260  	t.Run("Write caller field", func(t *testing.T) {
   261  		buf := &bytes.Buffer{}
   262  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   263  
   264  		cwd, err := os.Getwd()
   265  		if err != nil {
   266  			t.Fatalf("Cannot get working directory: %s", err)
   267  		}
   268  
   269  		ts := time.Unix(0, 0)
   270  		d := ts.UTC().Format(time.RFC3339)
   271  		evt := `{"time": "` + d + `", "level": "debug", "message": "Foobar", "foo": "bar", "caller": "` + cwd + `/foo/bar.go"}`
   272  		// t.Log(evt)
   273  
   274  		_, err = w.Write([]byte(evt))
   275  		if err != nil {
   276  			t.Errorf("Unexpected error when writing output: %s", err)
   277  		}
   278  
   279  		expectedOutput := ts.Format(time.Kitchen) + " DBG foo/bar.go > Foobar foo=bar\n"
   280  		actualOutput := buf.String()
   281  		if actualOutput != expectedOutput {
   282  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   283  		}
   284  	})
   285  
   286  	t.Run("Write JSON field", func(t *testing.T) {
   287  		buf := &bytes.Buffer{}
   288  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true}
   289  
   290  		evt := `{"level": "debug", "message": "Foobar", "foo": [1, 2, 3], "bar": true}`
   291  		// t.Log(evt)
   292  
   293  		_, err := w.Write([]byte(evt))
   294  		if err != nil {
   295  			t.Errorf("Unexpected error when writing output: %s", err)
   296  		}
   297  
   298  		expectedOutput := "<nil> DBG Foobar bar=true foo=[1,2,3]\n"
   299  		actualOutput := buf.String()
   300  		if actualOutput != expectedOutput {
   301  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   302  		}
   303  	})
   304  }
   305  
   306  func TestConsoleWriterConfiguration(t *testing.T) {
   307  	t.Run("Sets TimeFormat", func(t *testing.T) {
   308  		buf := &bytes.Buffer{}
   309  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, TimeFormat: time.RFC3339}
   310  
   311  		ts := time.Unix(0, 0)
   312  		d := ts.UTC().Format(time.RFC3339)
   313  		evt := `{"time": "` + d + `", "level": "info", "message": "Foobar"}`
   314  
   315  		_, err := w.Write([]byte(evt))
   316  		if err != nil {
   317  			t.Errorf("Unexpected error when writing output: %s", err)
   318  		}
   319  
   320  		expectedOutput := ts.Format(time.RFC3339) + " INF Foobar\n"
   321  		actualOutput := buf.String()
   322  		if actualOutput != expectedOutput {
   323  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   324  		}
   325  	})
   326  
   327  	t.Run("Sets PartsOrder", func(t *testing.T) {
   328  		buf := &bytes.Buffer{}
   329  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"message", "level"}}
   330  
   331  		evt := `{"level": "info", "message": "Foobar"}`
   332  		_, err := w.Write([]byte(evt))
   333  		if err != nil {
   334  			t.Errorf("Unexpected error when writing output: %s", err)
   335  		}
   336  
   337  		expectedOutput := "Foobar INF\n"
   338  		actualOutput := buf.String()
   339  		if actualOutput != expectedOutput {
   340  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   341  		}
   342  	})
   343  
   344  	t.Run("Sets PartsExclude", func(t *testing.T) {
   345  		buf := &bytes.Buffer{}
   346  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsExclude: []string{"time"}}
   347  
   348  		d := time.Unix(0, 0).UTC().Format(time.RFC3339)
   349  		evt := `{"time": "` + d + `", "level": "info", "message": "Foobar"}`
   350  		_, err := w.Write([]byte(evt))
   351  		if err != nil {
   352  			t.Errorf("Unexpected error when writing output: %s", err)
   353  		}
   354  
   355  		expectedOutput := "INF Foobar\n"
   356  		actualOutput := buf.String()
   357  		if actualOutput != expectedOutput {
   358  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   359  		}
   360  	})
   361  
   362  	t.Run("Sets FieldsExclude", func(t *testing.T) {
   363  		buf := &bytes.Buffer{}
   364  		w := zerolog.ConsoleWriter{Out: buf, NoColor: true, FieldsExclude: []string{"foo"}}
   365  
   366  		evt := `{"level": "info", "message": "Foobar", "foo":"bar", "baz":"quux"}`
   367  		_, err := w.Write([]byte(evt))
   368  		if err != nil {
   369  			t.Errorf("Unexpected error when writing output: %s", err)
   370  		}
   371  
   372  		expectedOutput := "<nil> INF Foobar baz=quux\n"
   373  		actualOutput := buf.String()
   374  		if actualOutput != expectedOutput {
   375  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   376  		}
   377  	})
   378  
   379  	t.Run("Sets FormatExtra", func(t *testing.T) {
   380  		buf := &bytes.Buffer{}
   381  		w := zerolog.ConsoleWriter{
   382  			Out: buf, NoColor: true, PartsOrder: []string{"level", "message"},
   383  			FormatExtra: func(evt map[string]interface{}, buf *bytes.Buffer) error {
   384  				buf.WriteString("\nAdditional stacktrace")
   385  				return nil
   386  			},
   387  		}
   388  
   389  		evt := `{"level": "info", "message": "Foobar"}`
   390  		_, err := w.Write([]byte(evt))
   391  		if err != nil {
   392  			t.Errorf("Unexpected error when writing output: %s", err)
   393  		}
   394  
   395  		expectedOutput := "INF Foobar\nAdditional stacktrace\n"
   396  		actualOutput := buf.String()
   397  		if actualOutput != expectedOutput {
   398  			t.Errorf("Unexpected output %q, want: %q", actualOutput, expectedOutput)
   399  		}
   400  	})
   401  }
   402  
   403  func BenchmarkConsoleWriter(b *testing.B) {
   404  	b.ResetTimer()
   405  	b.ReportAllocs()
   406  
   407  	var msg = []byte(`{"level": "info", "foo": "bar", "message": "HELLO", "time": "1990-01-01"}`)
   408  
   409  	w := zerolog.ConsoleWriter{Out: ioutil.Discard, NoColor: false}
   410  
   411  	for i := 0; i < b.N; i++ {
   412  		w.Write(msg)
   413  	}
   414  }
   415  

View as plain text