588 lines
15 KiB
Go
588 lines
15 KiB
Go
// 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/ioutil"
|
|
"log"
|
|
"testing"
|
|
|
|
"go.uber.org/zap"
|
|
)
|
|
|
|
func BenchmarkDisabledWithoutFields(b *testing.B) {
|
|
b.Logf("Logging at a disabled level without any structured context.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if m := logger.Check(zap.InfoLevel, getMessage(0)); m != nil {
|
|
m.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.SugarFormatting", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infof("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newDisabledApexLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newDisabledLogrus()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := newDisabledZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func BenchmarkDisabledAccumulatedContext(b *testing.B) {
|
|
b.Logf("Logging at a disabled level with some accumulated context.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).With(fakeFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).With(fakeFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if m := logger.Check(zap.InfoLevel, getMessage(0)); m != nil {
|
|
m.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).With(fakeFields()...).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.SugarFormatting", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).With(fakeFields()...).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infof("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newDisabledApexLog().WithFields(fakeApexFields())
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newDisabledLogrus().WithFields(fakeLogrusFields())
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := fakeZerologContext(newDisabledZerolog().With()).Logger()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func BenchmarkDisabledAddingFields(b *testing.B) {
|
|
b.Logf("Logging at a disabled level, adding context at each log site.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0), fakeFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if m := logger.Check(zap.InfoLevel, getMessage(0)); m != nil {
|
|
m.Write(fakeFields()...)
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.ErrorLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infow(getMessage(0), fakeSugarFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newDisabledApexLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.WithFields(fakeApexFields()).Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newDisabledLogrus()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.WithFields(fakeLogrusFields()).Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := newDisabledZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
fakeZerologFields(logger.Info()).Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func BenchmarkWithoutFields(b *testing.B) {
|
|
b.Logf("Logging without any structured context.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(0)); ce != nil {
|
|
ce.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.CheckSampled", func(b *testing.B) {
|
|
logger := newSampledLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
i := 0
|
|
for pb.Next() {
|
|
i++
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(i)); ce != nil {
|
|
ce.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.SugarFormatting", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infof("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newApexLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("go-kit/kit/log", func(b *testing.B) {
|
|
logger := newKitLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Log(getMessage(0), getMessage(1))
|
|
}
|
|
})
|
|
})
|
|
b.Run("inconshreveable/log15", func(b *testing.B) {
|
|
logger := newLog15()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newLogrus()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("stdlib.Println", func(b *testing.B) {
|
|
logger := log.New(ioutil.Discard, "", log.LstdFlags)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Println(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("stdlib.Printf", func(b *testing.B) {
|
|
logger := log.New(ioutil.Discard, "", log.LstdFlags)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Printf("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := newZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog.Formatting", func(b *testing.B) {
|
|
logger := newZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msgf("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog.Check", func(b *testing.B) {
|
|
logger := newZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if e := logger.Info(); e.Enabled() {
|
|
e.Msg(getMessage(0))
|
|
}
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func BenchmarkAccumulatedContext(b *testing.B) {
|
|
b.Logf("Logging with some accumulated context.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).With(fakeFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).With(fakeFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(0)); ce != nil {
|
|
ce.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.CheckSampled", func(b *testing.B) {
|
|
logger := newSampledLogger(zap.DebugLevel).With(fakeFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
i := 0
|
|
for pb.Next() {
|
|
i++
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(i)); ce != nil {
|
|
ce.Write()
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).With(fakeFields()...).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.SugarFormatting", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).With(fakeFields()...).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infof("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newApexLog().WithFields(fakeApexFields())
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("go-kit/kit/log", func(b *testing.B) {
|
|
logger := newKitLog(fakeSugarFields()...)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Log(getMessage(0), getMessage(1))
|
|
}
|
|
})
|
|
})
|
|
b.Run("inconshreveable/log15", func(b *testing.B) {
|
|
logger := newLog15().New(fakeSugarFields())
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newLogrus().WithFields(fakeLogrusFields())
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := fakeZerologContext(newZerolog().With()).Logger()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog.Check", func(b *testing.B) {
|
|
logger := fakeZerologContext(newZerolog().With()).Logger()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if e := logger.Info(); e.Enabled() {
|
|
e.Msg(getMessage(0))
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog.Formatting", func(b *testing.B) {
|
|
logger := fakeZerologContext(newZerolog().With()).Logger()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info().Msgf("%v %v %v %s %v %v %v %v %v %s\n", fakeFmtArgs()...)
|
|
}
|
|
})
|
|
})
|
|
}
|
|
|
|
func BenchmarkAddingFields(b *testing.B) {
|
|
b.Logf("Logging with additional context at each log site.")
|
|
b.Run("Zap", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0), fakeFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Check", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(0)); ce != nil {
|
|
ce.Write(fakeFields()...)
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.CheckSampled", func(b *testing.B) {
|
|
logger := newSampledLogger(zap.DebugLevel)
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
i := 0
|
|
for pb.Next() {
|
|
i++
|
|
if ce := logger.Check(zap.InfoLevel, getMessage(i)); ce != nil {
|
|
ce.Write(fakeFields()...)
|
|
}
|
|
}
|
|
})
|
|
})
|
|
b.Run("Zap.Sugar", func(b *testing.B) {
|
|
logger := newZapLogger(zap.DebugLevel).Sugar()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Infow(getMessage(0), fakeSugarFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("apex/log", func(b *testing.B) {
|
|
logger := newApexLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.WithFields(fakeApexFields()).Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("go-kit/kit/log", func(b *testing.B) {
|
|
logger := newKitLog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Log(fakeSugarFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("inconshreveable/log15", func(b *testing.B) {
|
|
logger := newLog15()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.Info(getMessage(0), fakeSugarFields()...)
|
|
}
|
|
})
|
|
})
|
|
b.Run("sirupsen/logrus", func(b *testing.B) {
|
|
logger := newLogrus()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
logger.WithFields(fakeLogrusFields()).Info(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog", func(b *testing.B) {
|
|
logger := newZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
fakeZerologFields(logger.Info()).Msg(getMessage(0))
|
|
}
|
|
})
|
|
})
|
|
b.Run("rs/zerolog.Check", func(b *testing.B) {
|
|
logger := newZerolog()
|
|
b.ResetTimer()
|
|
b.RunParallel(func(pb *testing.PB) {
|
|
for pb.Next() {
|
|
if e := logger.Info(); e.Enabled() {
|
|
fakeZerologFields(e).Msg(getMessage(0))
|
|
}
|
|
}
|
|
})
|
|
})
|
|
}
|