diff --git a/README.md b/README.md index afa61569..5b1ab730 100644 --- a/README.md +++ b/README.md @@ -60,7 +60,7 @@ func main() { // Output: {"time":1516134303,"level":"debug","message":"hello world"} ``` > Note: By default log writes to `os.Stderr` -> Note: The default log level for `log.Print` is *debug* +> Note: The default log level for `log.Print` is *trace* ### Contextual Logging @@ -412,15 +412,7 @@ Equivalent of `Lshortfile`: ```go zerolog.CallerMarshalFunc = func(pc uintptr, file string, line int) string { - short := file - for i := len(file) - 1; i > 0; i-- { - if file[i] == '/' { - short = file[i+1:] - break - } - } - file = short - return file + ":" + strconv.Itoa(line) + return filepath.Base(file) + ":" + strconv.Itoa(line) } log.Logger = log.With().Caller().Logger() log.Info().Msg("hello world") diff --git a/console.go b/console.go index 423d6879..3c6258b0 100644 --- a/console.go +++ b/console.go @@ -57,6 +57,10 @@ type ConsoleWriter struct { // TimeFormat specifies the format for timestamp in output. TimeFormat string + // TimeLocation tells ConsoleWriter’s default FormatTimestamp + // how to localize the time. + TimeLocation *time.Location + // PartsOrder defines the order of parts in output. PartsOrder []string @@ -88,9 +92,9 @@ type ConsoleWriter struct { // NewConsoleWriter creates and initializes a new ConsoleWriter. func NewConsoleWriter(options ...func(w *ConsoleWriter)) ConsoleWriter { w := ConsoleWriter{ - Out: os.Stdout, - TimeFormat: consoleDefaultTimeFormat, - PartsOrder: consoleDefaultPartsOrder(), + Out: os.Stdout, + TimeFormat: consoleDefaultTimeFormat, + PartsOrder: consoleDefaultPartsOrder(), } for _, opt := range options { @@ -294,7 +298,7 @@ func (w ConsoleWriter) writePart(buf *bytes.Buffer, evt map[string]interface{}, } case TimestampFieldName: if w.FormatTimestamp == nil { - f = consoleDefaultFormatTimestamp(w.TimeFormat, w.NoColor) + f = consoleDefaultFormatTimestamp(w.TimeFormat, w.TimeLocation, w.NoColor) } else { f = w.FormatTimestamp } @@ -390,19 +394,23 @@ func consoleDefaultPartsOrder() []string { } } -func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter { +func consoleDefaultFormatTimestamp(timeFormat string, location *time.Location, noColor bool) Formatter { if timeFormat == "" { timeFormat = consoleDefaultTimeFormat } + if location == nil { + location = time.Local + } + return func(i interface{}) string { t := "" switch tt := i.(type) { case string: - ts, err := time.ParseInLocation(TimeFieldFormat, tt, time.Local) + ts, err := time.ParseInLocation(TimeFieldFormat, tt, location) if err != nil { t = tt } else { - t = ts.Local().Format(timeFormat) + t = ts.In(location).Format(timeFormat) } case json.Number: i, err := tt.Int64() @@ -423,7 +431,7 @@ func consoleDefaultFormatTimestamp(timeFormat string, noColor bool) Formatter { } ts := time.Unix(sec, nsec) - t = ts.Format(timeFormat) + t = ts.In(location).Format(timeFormat) } } return colorize(t, colorDarkGray, noColor) diff --git a/console_test.go b/console_test.go index 6945ffe9..32b6c3f5 100644 --- a/console_test.go +++ b/console_test.go @@ -343,6 +343,35 @@ func TestConsoleWriterConfiguration(t *testing.T) { } }) + t.Run("Sets TimeFormat and TimeLocation", func(t *testing.T) { + locs := []*time.Location{ time.Local, time.UTC } + + for _, location := range locs { + buf := &bytes.Buffer{} + w := zerolog.ConsoleWriter{ + Out: buf, + NoColor: true, + TimeFormat: time.RFC3339, + TimeLocation: location, + } + + ts := time.Unix(0, 0) + d := ts.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 := ts.In(location).Format(time.RFC3339) + " INF Foobar\n" + actualOutput := buf.String() + if actualOutput != expectedOutput { + t.Errorf("Unexpected output %q, want: %q (location=%s)", actualOutput, expectedOutput, location) + } + } + }) + t.Run("Sets PartsOrder", func(t *testing.T) { buf := &bytes.Buffer{} w := zerolog.ConsoleWriter{Out: buf, NoColor: true, PartsOrder: []string{"message", "level"}} diff --git a/globals.go b/globals.go index b38a7fce..ac1d9c48 100644 --- a/globals.go +++ b/globals.go @@ -1,6 +1,7 @@ package zerolog import ( + "bytes" "encoding/json" "strconv" "sync/atomic" @@ -81,8 +82,22 @@ var ( } // InterfaceMarshalFunc allows customization of interface marshaling. - // Default: "encoding/json.Marshal" - InterfaceMarshalFunc = json.Marshal + // Default: "encoding/json.Marshal" with disabled HTML escaping + InterfaceMarshalFunc = func(v interface{}) ([]byte, error) { + var buf bytes.Buffer + encoder := json.NewEncoder(&buf) + encoder.SetEscapeHTML(false) + err := encoder.Encode(v) + if err != nil { + return nil, err + } + b := buf.Bytes() + if len(b) > 0 { + // Remove trailing \n which is added by Encode. + return b[:len(b)-1], nil + } + return b, nil + } // TimeFieldFormat defines the time format of the Time field type. If set to // TimeFormatUnix, TimeFormatUnixMs, TimeFormatUnixMicro or TimeFormatUnixNano, the time is formatted as a UNIX diff --git a/internal/json/types.go b/internal/json/types.go index ef3a2a7a..43feaaa8 100644 --- a/internal/json/types.go +++ b/internal/json/types.go @@ -311,7 +311,25 @@ func appendFloat(dst []byte, val float64, bitSize int) []byte { case math.IsInf(val, -1): return append(dst, `"-Inf"`...) } - return strconv.AppendFloat(dst, val, 'f', -1, bitSize) + // convert as if by es6 number to string conversion + // see also https://cs.opensource.google/go/go/+/refs/tags/go1.20.3:src/encoding/json/encode.go;l=573 + strFmt := byte('f') + // Use float32 comparisons for underlying float32 value to get precise cutoffs right. + if abs := math.Abs(val); abs != 0 { + if bitSize == 64 && (abs < 1e-6 || abs >= 1e21) || bitSize == 32 && (float32(abs) < 1e-6 || float32(abs) >= 1e21) { + strFmt = 'e' + } + } + dst = strconv.AppendFloat(dst, val, strFmt, -1, bitSize) + if strFmt == 'e' { + // Clean up e-09 to e-9 + n := len(dst) + if n >= 4 && dst[n-4] == 'e' && dst[n-3] == '-' && dst[n-2] == '0' { + dst[n-2] = dst[n-1] + dst = dst[:n-1] + } + } + return dst } // AppendFloat32 converts the input float32 to a string and diff --git a/internal/json/types_test.go b/internal/json/types_test.go index 26dc3e80..350affef 100644 --- a/internal/json/types_test.go +++ b/internal/json/types_test.go @@ -1,7 +1,9 @@ package json import ( + "encoding/json" "math" + "math/rand" "net" "reflect" "testing" @@ -44,7 +46,7 @@ func TestAppendType(t *testing.T) { {"AppendFloat32(0)", "AppendFloat32", float32(0), []byte(`0`)}, {"AppendFloat32(-1.1)", "AppendFloat32", float32(-1.1), []byte(`-1.1`)}, {"AppendFloat32(1e20)", "AppendFloat32", float32(1e20), []byte(`100000000000000000000`)}, - {"AppendFloat32(1e21)", "AppendFloat32", float32(1e21), []byte(`1000000000000000000000`)}, + {"AppendFloat32(1e21)", "AppendFloat32", float32(1e21), []byte(`1e+21`)}, {"AppendFloat64(-Inf)", "AppendFloat64", float64(math.Inf(-1)), []byte(`"-Inf"`)}, {"AppendFloat64(+Inf)", "AppendFloat64", float64(math.Inf(1)), []byte(`"+Inf"`)}, @@ -52,7 +54,7 @@ func TestAppendType(t *testing.T) { {"AppendFloat64(0)", "AppendFloat64", float64(0), []byte(`0`)}, {"AppendFloat64(-1.1)", "AppendFloat64", float64(-1.1), []byte(`-1.1`)}, {"AppendFloat64(1e20)", "AppendFloat64", float64(1e20), []byte(`100000000000000000000`)}, - {"AppendFloat64(1e21)", "AppendFloat64", float64(1e21), []byte(`1000000000000000000000`)}, + {"AppendFloat64(1e21)", "AppendFloat64", float64(1e21), []byte(`1e+21`)}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { @@ -207,3 +209,340 @@ func Test_appendObjectData(t *testing.T) { }) } } + +var float64Tests = []struct { + Name string + Val float64 + Want string +}{ + { + Name: "Positive integer", + Val: 1234.0, + Want: "1234", + }, + { + Name: "Negative integer", + Val: -5678.0, + Want: "-5678", + }, + { + Name: "Positive decimal", + Val: 12.3456, + Want: "12.3456", + }, + { + Name: "Negative decimal", + Val: -78.9012, + Want: "-78.9012", + }, + { + Name: "Large positive number", + Val: 123456789.0, + Want: "123456789", + }, + { + Name: "Large negative number", + Val: -987654321.0, + Want: "-987654321", + }, + { + Name: "Zero", + Val: 0.0, + Want: "0", + }, + { + Name: "Smallest positive value", + Val: math.SmallestNonzeroFloat64, + Want: "5e-324", + }, + { + Name: "Largest positive value", + Val: math.MaxFloat64, + Want: "1.7976931348623157e+308", + }, + { + Name: "Smallest negative value", + Val: -math.SmallestNonzeroFloat64, + Want: "-5e-324", + }, + { + Name: "Largest negative value", + Val: -math.MaxFloat64, + Want: "-1.7976931348623157e+308", + }, + { + Name: "NaN", + Val: math.NaN(), + Want: `"NaN"`, + }, + { + Name: "+Inf", + Val: math.Inf(1), + Want: `"+Inf"`, + }, + { + Name: "-Inf", + Val: math.Inf(-1), + Want: `"-Inf"`, + }, + { + Name: "Clean up e-09 to e-9 case 1", + Val: 1e-9, + Want: "1e-9", + }, + { + Name: "Clean up e-09 to e-9 case 2", + Val: -2.236734e-9, + Want: "-2.236734e-9", + }, +} + +func TestEncoder_AppendFloat64(t *testing.T) { + for _, tc := range float64Tests { + t.Run(tc.Name, func(t *testing.T) { + var b []byte + b = (Encoder{}).AppendFloat64(b, tc.Val) + if s := string(b); tc.Want != s { + t.Errorf("%q", s) + } + }) + } +} + +func FuzzEncoder_AppendFloat64(f *testing.F) { + for _, tc := range float64Tests { + f.Add(tc.Val) + } + f.Fuzz(func(t *testing.T, val float64) { + actual := (Encoder{}).AppendFloat64(nil, val) + if len(actual) == 0 { + t.Fatal("empty buffer") + } + + if actual[0] == '"' { + switch string(actual) { + case `"NaN"`: + if !math.IsNaN(val) { + t.Fatalf("expected %v got NaN", val) + } + case `"+Inf"`: + if !math.IsInf(val, 1) { + t.Fatalf("expected %v got +Inf", val) + } + case `"-Inf"`: + if !math.IsInf(val, -1) { + t.Fatalf("expected %v got -Inf", val) + } + default: + t.Fatalf("unexpected string: %s", actual) + } + return + } + + if expected, err := json.Marshal(val); err != nil { + t.Error(err) + } else if string(actual) != string(expected) { + t.Errorf("expected %s, got %s", expected, actual) + } + + var parsed float64 + if err := json.Unmarshal(actual, &parsed); err != nil { + t.Fatal(err) + } + + if parsed != val { + t.Fatalf("expected %v, got %v", val, parsed) + } + }) +} + +var float32Tests = []struct { + Name string + Val float32 + Want string +}{ + { + Name: "Positive integer", + Val: 1234.0, + Want: "1234", + }, + { + Name: "Negative integer", + Val: -5678.0, + Want: "-5678", + }, + { + Name: "Positive decimal", + Val: 12.3456, + Want: "12.3456", + }, + { + Name: "Negative decimal", + Val: -78.9012, + Want: "-78.9012", + }, + { + Name: "Large positive number", + Val: 123456789.0, + Want: "123456790", + }, + { + Name: "Large negative number", + Val: -987654321.0, + Want: "-987654340", + }, + { + Name: "Zero", + Val: 0.0, + Want: "0", + }, + { + Name: "Smallest positive value", + Val: math.SmallestNonzeroFloat32, + Want: "1e-45", + }, + { + Name: "Largest positive value", + Val: math.MaxFloat32, + Want: "3.4028235e+38", + }, + { + Name: "Smallest negative value", + Val: -math.SmallestNonzeroFloat32, + Want: "-1e-45", + }, + { + Name: "Largest negative value", + Val: -math.MaxFloat32, + Want: "-3.4028235e+38", + }, + { + Name: "NaN", + Val: float32(math.NaN()), + Want: `"NaN"`, + }, + { + Name: "+Inf", + Val: float32(math.Inf(1)), + Want: `"+Inf"`, + }, + { + Name: "-Inf", + Val: float32(math.Inf(-1)), + Want: `"-Inf"`, + }, + { + Name: "Clean up e-09 to e-9 case 1", + Val: 1e-9, + Want: "1e-9", + }, + { + Name: "Clean up e-09 to e-9 case 2", + Val: -2.236734e-9, + Want: "-2.236734e-9", + }, +} + +func TestEncoder_AppendFloat32(t *testing.T) { + for _, tc := range float32Tests { + t.Run(tc.Name, func(t *testing.T) { + var b []byte + b = (Encoder{}).AppendFloat32(b, tc.Val) + if s := string(b); tc.Want != s { + t.Errorf("%q", s) + } + }) + } +} + +func FuzzEncoder_AppendFloat32(f *testing.F) { + for _, tc := range float32Tests { + f.Add(tc.Val) + } + f.Fuzz(func(t *testing.T, val float32) { + actual := (Encoder{}).AppendFloat32(nil, val) + if len(actual) == 0 { + t.Fatal("empty buffer") + } + + if actual[0] == '"' { + val := float64(val) + switch string(actual) { + case `"NaN"`: + if !math.IsNaN(val) { + t.Fatalf("expected %v got NaN", val) + } + case `"+Inf"`: + if !math.IsInf(val, 1) { + t.Fatalf("expected %v got +Inf", val) + } + case `"-Inf"`: + if !math.IsInf(val, -1) { + t.Fatalf("expected %v got -Inf", val) + } + default: + t.Fatalf("unexpected string: %s", actual) + } + return + } + + if expected, err := json.Marshal(val); err != nil { + t.Error(err) + } else if string(actual) != string(expected) { + t.Errorf("expected %s, got %s", expected, actual) + } + + var parsed float32 + if err := json.Unmarshal(actual, &parsed); err != nil { + t.Fatal(err) + } + + if parsed != val { + t.Fatalf("expected %v, got %v", val, parsed) + } + }) +} + +func generateFloat32s(n int) []float32 { + floats := make([]float32, n) + for i := 0; i < n; i++ { + floats[i] = rand.Float32() + } + return floats +} + +func generateFloat64s(n int) []float64 { + floats := make([]float64, n) + for i := 0; i < n; i++ { + floats[i] = rand.Float64() + } + return floats +} + +// this is really just for the memory allocation characteristics +func BenchmarkEncoder_AppendFloat32(b *testing.B) { + floats := append(generateFloat32s(5000), float32(math.NaN()), float32(math.Inf(1)), float32(math.Inf(-1))) + dst := make([]byte, 0, 128) + + b.ResetTimer() + + for i := 0; i < b.N; i++ { + for _, f := range floats { + dst = (Encoder{}).AppendFloat32(dst[:0], f) + } + } +} + +// this is really just for the memory allocation characteristics +func BenchmarkEncoder_AppendFloat64(b *testing.B) { + floats := append(generateFloat64s(5000), math.NaN(), math.Inf(1), math.Inf(-1)) + dst := make([]byte, 0, 128) + + b.ResetTimer() + + for i := 0; i < b.N; i++ { + for _, f := range floats { + dst = (Encoder{}).AppendFloat64(dst[:0], f) + } + } +} diff --git a/log_test.go b/log_test.go index 4d0d93b1..e51eb8fb 100644 --- a/log_test.go +++ b/log_test.go @@ -1013,3 +1013,12 @@ func TestUnmarshalTextLevel(t *testing.T) { }) } } + +func TestHTMLNoEscaping(t *testing.T) { + out := &bytes.Buffer{} + log := New(out) + log.Log().Interface("head", "").Send() + if got, want := decodeIfBinaryToString(out.Bytes()), `{"head":""}`+"\n"; got != want { + t.Errorf("invalid log output:\ngot: %v\nwant: %v", got, want) + } +}