diff --git a/README.md b/README.md index 9de08927b..eed14c598 100644 --- a/README.md +++ b/README.md @@ -66,41 +66,44 @@ Log a message and 10 fields: | Package | Time | Time % to zap | Objects Allocated | | :------ | :--: | :-----------: | :---------------: | -| :zap: zap | 1744 ns/op | +0% | 5 allocs/op -| :zap: zap (sugared) | 2483 ns/op | +42% | 10 allocs/op -| zerolog | 918 ns/op | -47% | 1 allocs/op -| go-kit | 5590 ns/op | +221% | 57 allocs/op -| slog | 5640 ns/op | +223% | 40 allocs/op -| apex/log | 21184 ns/op | +1115% | 63 allocs/op -| logrus | 24338 ns/op | +1296% | 79 allocs/op -| log15 | 26054 ns/op | +1394% | 74 allocs/op +| :zap: zap | 626 ns/op | +0% | 5 allocs/op +| :zap: zap (sugared) | 982 ns/op | +57% | 11 allocs/op +| zerolog | 236 ns/op | -62% | 1 allocs/op +| go-kit | 2174 ns/op | +247% | 58 allocs/op +| slog | 2175 ns/op | +247% | 40 allocs/op +| fortio log | 5659 ns/op | +804% | 140 allocs/op +| apex/log | 9934 ns/op | +1487% | 64 allocs/op +| log15 | 11288 ns/op | +1703% | 75 allocs/op +| logrus | 12118 ns/op | +1836% | 80 allocs/op Log a message with a logger that already has 10 fields of context: | Package | Time | Time % to zap | Objects Allocated | | :------ | :--: | :-----------: | :---------------: | -| :zap: zap | 193 ns/op | +0% | 0 allocs/op -| :zap: zap (sugared) | 227 ns/op | +18% | 1 allocs/op -| zerolog | 81 ns/op | -58% | 0 allocs/op -| slog | 322 ns/op | +67% | 0 allocs/op -| go-kit | 5377 ns/op | +2686% | 56 allocs/op -| apex/log | 19518 ns/op | +10013% | 53 allocs/op -| log15 | 19812 ns/op | +10165% | 70 allocs/op -| logrus | 21997 ns/op | +11297% | 68 allocs/op +| :zap: zap | 63 ns/op | +0% | 0 allocs/op +| :zap: zap (sugared) | 82 ns/op | +30% | 1 allocs/op +| zerolog | 18 ns/op | -71% | 0 allocs/op +| slog | 242 ns/op | +284% | 0 allocs/op +| go-kit | 2341 ns/op | +3616% | 56 allocs/op +| fortio log | 5162 ns/op | +8094% | 131 allocs/op +| log15 | 9321 ns/op | +14695% | 70 allocs/op +| apex/log | 9421 ns/op | +14854% | 53 allocs/op +| logrus | 10950 ns/op | +17281% | 68 allocs/op Log a static string, without any context or `printf`-style templating: | Package | Time | Time % to zap | Objects Allocated | | :------ | :--: | :-----------: | :---------------: | -| :zap: zap | 165 ns/op | +0% | 0 allocs/op -| :zap: zap (sugared) | 212 ns/op | +28% | 1 allocs/op -| zerolog | 95 ns/op | -42% | 0 allocs/op -| slog | 296 ns/op | +79% | 0 allocs/op -| go-kit | 415 ns/op | +152% | 9 allocs/op -| standard library | 422 ns/op | +156% | 2 allocs/op -| apex/log | 1601 ns/op | +870% | 5 allocs/op -| logrus | 3017 ns/op | +1728% | 23 allocs/op -| log15 | 3469 ns/op | +2002% | 20 allocs/op +| :zap: zap | 52 ns/op | +0% | 0 allocs/op +| :zap: zap (sugared) | 80 ns/op | +54% | 1 allocs/op +| zerolog | 17 ns/op | -67% | 0 allocs/op +| slog | 230 ns/op | +342% | 0 allocs/op +| go-kit | 243 ns/op | +367% | 9 allocs/op +| standard library | 309 ns/op | +494% | 2 allocs/op +| apex/log | 787 ns/op | +1413% | 5 allocs/op +| fortio log | 827 ns/op | +1490% | 2 allocs/op +| logrus | 1495 ns/op | +2775% | 23 allocs/op +| log15 | 2030 ns/op | +3804% | 20 allocs/op ## Development Status: Stable diff --git a/benchmarks/fortio_test.go b/benchmarks/fortio_test.go new file mode 100644 index 000000000..e09708d72 --- /dev/null +++ b/benchmarks/fortio_test.go @@ -0,0 +1,79 @@ +// Copyright (c) 2016 Uber Technologies, Inc. +// +// Permission is hereby granted, free of charge, to any person obtaining a copy +// of this software and associated documentation files (the "Software"), to deal +// in the Software without restriction, including without limitation the rights +// to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +// copies of the Software, and to permit persons to whom the Software is +// furnished to do so, subject to the following conditions: +// +// The above copyright notice and this permission notice shall be included in +// all copies or substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +// IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +// FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +// AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +// LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +// OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN +// THE SOFTWARE. + +package benchmarks + +import ( + "io" + + "fortio.org/log" +) + +type shmLogger struct { + fields []log.KeyVal +} + +var fLog = &shmLogger{} + +func (l *shmLogger) Infof(msg string, fields ...interface{}) { + log.Infof(msg, fields...) +} + +func (l *shmLogger) InfoS(msg string, fields ...log.KeyVal) { + log.S(log.Info, msg, fields...) +} + +func (l *shmLogger) InfoContext(msg string) { + log.S(log.Info, msg, l.fields...) +} + +func newFortiolog(fields ...log.KeyVal) *shmLogger { + log.Config = log.DefaultConfig() + log.Config.LogFileAndLine = false // file/line extraction implies bad perf + log.Config.JSON = true // structured logging comparison + log.Config.GoroutineID = false // other loggers don't have that + log.SetOutput(io.Discard) + log.Color = false // should already be but just in case + fLog.fields = fields + log.SetLogLevel(log.Info) + return fLog +} + +func newDisabledFortiolog(fields ...log.KeyVal) *shmLogger { + logger := newFortiolog() + log.SetLogLevel(log.Error) + logger.fields = fields + return logger +} + +func fakeFortiologFields() []log.KeyVal { + return []log.KeyVal{ + log.Attr("int", _tenInts[0]), + log.Attr("ints", _tenInts), + log.Str("string", _tenStrings[0]), + log.Attr("strings", _tenStrings), + log.Attr("time", _tenTimes[0]), + log.Attr("times", _tenTimes), + log.Attr("user1", _oneUser), + log.Attr("user2", _oneUser), + log.Attr("users", _tenUsers), + log.Attr("error", errExample), + } +} diff --git a/benchmarks/go.mod b/benchmarks/go.mod index 8024e66b2..95d9dac48 100644 --- a/benchmarks/go.mod +++ b/benchmarks/go.mod @@ -4,7 +4,10 @@ go 1.19 replace go.uber.org/zap => ../ +// replace fortio.org/log => ../../../fortio.org/log // remove this before any merging + require ( + fortio.org/log v1.11.0 github.com/apex/log v1.9.0 github.com/go-kit/log v0.2.1 github.com/rs/zerolog v1.28.0 diff --git a/benchmarks/go.sum b/benchmarks/go.sum index 4ae6da835..1c0c0e1fd 100644 --- a/benchmarks/go.sum +++ b/benchmarks/go.sum @@ -1,3 +1,5 @@ +fortio.org/log v1.11.0 h1:w7ueGPGbXz0A3+ApMz/5Q9gwEMrwSo/ohTlLo2Um6dU= +fortio.org/log v1.11.0/go.mod h1:u/8/2lyczXq52aT5Nw6reD+3cR6m/EbS2jBiIYhgiTU= github.com/apex/log v1.9.0 h1:FHtw/xuaM8AgmvDDTI9fiwoAL25Sq2cxojnZICUU8l0= github.com/apex/log v1.9.0/go.mod h1:m82fZlWIuiWzWP04XCTXmnX0xRkYYbCdYn8jbJeLBEA= github.com/apex/logs v1.0.0/go.mod h1:XzxuLZ5myVHDy9SAmYpamKKRNApGj54PfYLcFrXqDwo= diff --git a/benchmarks/scenario_bench_test.go b/benchmarks/scenario_bench_test.go index b41b1b50e..61f84d4a3 100644 --- a/benchmarks/scenario_bench_test.go +++ b/benchmarks/scenario_bench_test.go @@ -104,6 +104,15 @@ func BenchmarkDisabledWithoutFields(b *testing.B) { } }) }) + b.Run("fortio.org/log", func(b *testing.B) { + logger := newDisabledFortiolog() + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.InfoS(getMessage(0)) + } + }) + }) } @@ -183,7 +192,15 @@ func BenchmarkDisabledAccumulatedContext(b *testing.B) { } }) }) - + b.Run("fortio.org/log", func(b *testing.B) { + logger := newDisabledFortiolog(fakeFortiologFields()...) + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.InfoContext(getMessage(0)) + } + }) + }) } func BenchmarkDisabledAddingFields(b *testing.B) { @@ -253,7 +270,15 @@ func BenchmarkDisabledAddingFields(b *testing.B) { } }) }) - + b.Run("fortio.org/log", func(b *testing.B) { + logger := newDisabledFortiolog() + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.InfoS(getMessage(0), fakeFortiologFields()...) + } + }) + }) } func BenchmarkWithoutFields(b *testing.B) { @@ -401,7 +426,15 @@ func BenchmarkWithoutFields(b *testing.B) { } }) }) - + b.Run("fortio.org/log", func(b *testing.B) { + logger := newFortiolog() + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.Infof(getMessage(0)) + } + }) + }) } func BenchmarkAccumulatedContext(b *testing.B) { @@ -531,6 +564,15 @@ func BenchmarkAccumulatedContext(b *testing.B) { } }) }) + b.Run("fortio.org/log", func(b *testing.B) { + logger := newFortiolog(fakeFortiologFields()...) + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.InfoContext(getMessage(0)) + } + }) + }) } @@ -643,5 +685,13 @@ func BenchmarkAddingFields(b *testing.B) { } }) }) - + b.Run("fortio.org/log", func(b *testing.B) { + logger := newFortiolog() + b.ResetTimer() + b.RunParallel(func(pb *testing.PB) { + for pb.Next() { + logger.InfoS(getMessage(0), fakeFortiologFields()...) + } + }) + }) } diff --git a/benchmarks/slog_test.go b/benchmarks/slog_test.go index 36a5a6077..f059e6ab3 100644 --- a/benchmarks/slog_test.go +++ b/benchmarks/slog_test.go @@ -21,17 +21,16 @@ package benchmarks import ( - "io" - + "go.uber.org/zap/internal/ztest" "golang.org/x/exp/slog" ) func newSlog(fields ...slog.Attr) *slog.Logger { - return slog.New(slog.NewJSONHandler(io.Discard).WithAttrs(fields)) + return slog.New(slog.NewJSONHandler(&ztest.Discarder{}).WithAttrs(fields)) } func newDisabledSlog(fields ...slog.Attr) *slog.Logger { - return slog.New(slog.HandlerOptions{Level: slog.LevelError}.NewJSONHandler(io.Discard).WithAttrs(fields)) + return slog.New(slog.HandlerOptions{Level: slog.LevelError}.NewJSONHandler(&ztest.Discarder{}).WithAttrs(fields)) } func fakeSlogFields() []slog.Attr { diff --git a/benchmarks/zap_test.go b/benchmarks/zap_test.go index 84784152c..314ede4c3 100644 --- a/benchmarks/zap_test.go +++ b/benchmarks/zap_test.go @@ -34,20 +34,21 @@ import ( var ( errExample = errors.New("fail") - _messages = fakeMessages(1000) - _tenInts = []int{1, 2, 3, 4, 5, 6, 7, 8, 9, 0} + _messages = fakeMessages(1000) + // Go optimizes away allocations for numbers below 256 + _tenInts = []int{1001, 1002, 1003, 1004, 1005, 1006, 1007, 1008, 1009, 1010} _tenStrings = []string{"a", "b", "c", "d", "e", "f", "g", "h", "i", "j"} _tenTimes = []time.Time{ - time.Unix(0, 0), - time.Unix(1, 0), - time.Unix(2, 0), - time.Unix(3, 0), - time.Unix(4, 0), - time.Unix(5, 0), - time.Unix(6, 0), - time.Unix(7, 0), - time.Unix(8, 0), - time.Unix(9, 0), + time.Unix(1000, 0), + time.Unix(1001, 0), + time.Unix(1002, 0), + time.Unix(1003, 0), + time.Unix(1004, 0), + time.Unix(1005, 0), + time.Unix(1006, 0), + time.Unix(1007, 0), + time.Unix(1008, 0), + time.Unix(1009, 0), } _oneUser = &user{ Name: "Jane Doe", @@ -110,6 +111,7 @@ func newZapLogger(lvl zapcore.Level) *zap.Logger { enc := zapcore.NewJSONEncoder(ec) return zap.New(zapcore.NewCore( enc, + // os.Stderr, // for real/checking the output &ztest.Discarder{}, lvl, )) diff --git a/internal/readme/readme.go b/internal/readme/readme.go index 148765908..7be150ce9 100644 --- a/internal/readme/readme.go +++ b/internal/readme/readme.go @@ -46,6 +46,7 @@ var ( "apex/log": "apex/log", "rs/zerolog": "zerolog", "slog": "slog", + "fortio.org/log": "fortio log", } )