From 86264e4e20af3eb9f90ae65487a5b5e91eb8a28d Mon Sep 17 00:00:00 2001 From: Anton Nikiforov Date: Tue, 4 Feb 2025 09:11:36 +0300 Subject: [PATCH] [#1619] logger: Add benchmark Change-Id: I49e90e8a3689a755755afd0638b327a6b1884795 Signed-off-by: Anton Nikiforov --- pkg/util/logger/logger_test.go | 118 +++++++++++++++++++++++++++++ pkg/util/logger/logger_test.result | 46 +++++++++++ 2 files changed, 164 insertions(+) create mode 100644 pkg/util/logger/logger_test.go create mode 100644 pkg/util/logger/logger_test.result diff --git a/pkg/util/logger/logger_test.go b/pkg/util/logger/logger_test.go new file mode 100644 index 000000000..b867ee6cc --- /dev/null +++ b/pkg/util/logger/logger_test.go @@ -0,0 +1,118 @@ +package logger + +import ( + "context" + "testing" + + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "go.uber.org/zap/zaptest/observer" +) + +func BenchmarkLogger(b *testing.B) { + ctx := context.Background() + m := map[string]Prm{} + + prm := Prm{} + require.NoError(b, prm.SetLevelString("debug")) + m["logging enabled"] = prm + + prm = Prm{} + require.NoError(b, prm.SetLevelString("error")) + m["logging disabled"] = prm + + prm = Prm{} + require.NoError(b, prm.SetLevelString("error")) + require.NoError(b, prm.SetTags([][]string{{"main", "debug"}, {"morph", "debug"}})) + m["logging enabled via tags"] = prm + + prm = Prm{} + require.NoError(b, prm.SetLevelString("debug")) + require.NoError(b, prm.SetTags([][]string{{"main", "error"}, {"morph", "debug"}})) + m["logging disabled via tags"] = prm + + for k, v := range m { + b.Run(k, func(b *testing.B) { + logger, err := createLogger(v) + require.NoError(b, err) + UpdateLevelForTags(v) + b.ResetTimer() + b.ReportAllocs() + for range b.N { + logger.Info(ctx, "test info") + } + }) + } +} + +type testCore struct { + core zapcore.Core +} + +func (c *testCore) Enabled(lvl zapcore.Level) bool { + return c.core.Enabled(lvl) +} + +func (c *testCore) With(fields []zapcore.Field) zapcore.Core { + c.core = c.core.With(fields) + return c +} + +func (c *testCore) Check(e zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry { + return ce.AddCore(e, c) +} + +func (c *testCore) Write(zapcore.Entry, []zapcore.Field) error { + return nil +} + +func (c *testCore) Sync() error { + return c.core.Sync() +} + +func createLogger(prm Prm) (*Logger, error) { + prm.Options = []zap.Option{zap.WrapCore(func(core zapcore.Core) zapcore.Core { + tc := testCore{core: core} + return &tc + })} + return NewLogger(prm) +} + +func TestLoggerOutput(t *testing.T) { + obs, logs := observer.New(zap.NewAtomicLevelAt(zap.DebugLevel)) + + prm := Prm{} + require.NoError(t, prm.SetLevelString("debug")) + prm.Options = []zap.Option{zap.WrapCore(func(zapcore.Core) zapcore.Core { + return obs + })} + loggerMain, err := NewLogger(prm) + require.NoError(t, err) + UpdateLevelForTags(prm) + + loggerMainWith := loggerMain.With(zap.String("key", "value")) + + require.Panics(t, func() { + loggerMainWith.WithTag(TagShard) + }) + loggerShard := loggerMain.WithTag(TagShard) + loggerShard = loggerShard.With(zap.String("key1", "value1")) + + loggerMorph := loggerMain.WithTag(TagMorph) + loggerMorph = loggerMorph.With(zap.String("key2", "value2")) + + ctx := context.Background() + loggerMain.Debug(ctx, "main") + loggerMainWith.Debug(ctx, "main with") + loggerShard.Debug(ctx, "shard") + loggerMorph.Debug(ctx, "morph") + + require.Len(t, logs.All(), 4) + require.Len(t, logs.FilterFieldKey("key").All(), 1) + require.Len(t, logs.FilterFieldKey("key1").All(), 1) + require.Len(t, logs.FilterFieldKey("key2").All(), 1) + require.Len(t, logs.FilterField(zap.String("tag", TagMain.String())).All(), 2) + require.Len(t, logs.FilterField(zap.String("tag", TagShard.String())).All(), 1) + require.Len(t, logs.FilterField(zap.String("tag", TagMorph.String())).All(), 1) +} diff --git a/pkg/util/logger/logger_test.result b/pkg/util/logger/logger_test.result new file mode 100644 index 000000000..612fa2967 --- /dev/null +++ b/pkg/util/logger/logger_test.result @@ -0,0 +1,46 @@ +goos: linux +goarch: amd64 +pkg: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger +cpu: 11th Gen Intel(R) Core(TM) i5-1135G7 @ 2.40GHz +BenchmarkLogger/logging_enabled-8 10000 1156 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1124 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1106 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1096 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1071 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1081 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1074 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1134 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1123 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled-8 10000 1144 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.15 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.54 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.22 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.22 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 17.01 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.31 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.61 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.17 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 16.26 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled-8 10000 21.02 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1146 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1086 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1113 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1157 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1069 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1073 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1096 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1092 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1060 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_enabled_via_tags-8 10000 1153 ns/op 240 B/op 1 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.23 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.39 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.47 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.62 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.53 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.53 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.74 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.20 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 17.06 ns/op 0 B/op 0 allocs/op +BenchmarkLogger/logging_disabled_via_tags-8 10000 16.60 ns/op 0 B/op 0 allocs/op +PASS +ok git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger 0.260s