Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perf(log): use sonic json lib #22233

Merged
merged 5 commits into from
Oct 22, 2024
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 7 additions & 3 deletions log/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -3,14 +3,18 @@ module cosmossdk.io/log
go 1.20

require (
github.com/pkg/errors v0.9.1
github.com/bytedance/sonic v1.12.3
github.com/rs/zerolog v1.33.0
gotest.tools/v3 v3.5.1
)

require (
github.com/google/go-cmp v0.6.0 // indirect
github.com/bytedance/sonic/loader v0.2.0 // indirect
github.com/cloudwego/base64x v0.1.4 // indirect
github.com/cloudwego/iasm v0.2.0 // indirect
github.com/klauspost/cpuid/v2 v2.0.9 // indirect
github.com/mattn/go-colorable v0.1.13 // indirect
github.com/mattn/go-isatty v0.0.20 // indirect
github.com/twitchyliquid64/golang-asm v0.15.1 // indirect
golang.org/x/arch v0.0.0-20210923205945-b76863e36670 // indirect
golang.org/x/sys v0.22.0 // indirect
)
39 changes: 34 additions & 5 deletions log/go.sum
Original file line number Diff line number Diff line change
@@ -1,22 +1,51 @@
github.com/bytedance/sonic v1.12.3 h1:W2MGa7RCU1QTeYRTPE3+88mVC0yXmsRQRChiyVocVjU=
github.com/bytedance/sonic v1.12.3/go.mod h1:B8Gt/XvtZ3Fqj+iSKMypzymZxw/FVwgIGKzMzT9r/rk=
github.com/bytedance/sonic/loader v0.1.1/go.mod h1:ncP89zfokxS5LZrJxl5z0UJcsk4M4yY2JpfqGeCtNLU=
github.com/bytedance/sonic/loader v0.2.0 h1:zNprn+lsIP06C/IqCHs3gPQIvnvpKbbxyXQP1iU4kWM=
github.com/bytedance/sonic/loader v0.2.0/go.mod h1:ncP89zfokxS5LZrJxl5z0UJcsk4M4yY2JpfqGeCtNLU=
github.com/cloudwego/base64x v0.1.4 h1:jwCgWpFanWmN8xoIUHa2rtzmkd5J2plF/dnLS6Xd/0Y=
github.com/cloudwego/base64x v0.1.4/go.mod h1:0zlkT4Wn5C6NdauXdJRhSKRlJvmclQ1hhJgA0rcu/8w=
github.com/cloudwego/iasm v0.2.0 h1:1KNIy1I1H9hNNFEEH3DVnI4UujN+1zjpuk6gwHLTssg=
github.com/cloudwego/iasm v0.2.0/go.mod h1:8rXZaNYT2n95jn+zTI1sDr+IgcD2GVs0nlbbQPiEFhY=
github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
github.com/google/go-cmp v0.6.0 h1:ofyhxvXcZhMsU5ulbFiLKl/XBFqE1GSq7atu8tAmTRI=
github.com/google/go-cmp v0.6.0/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
github.com/klauspost/cpuid/v2 v2.0.9 h1:lgaqFMSdTdQYdZ04uHyN2d/eKdOMyi2YLSvlQIBFYa4=
github.com/klauspost/cpuid/v2 v2.0.9/go.mod h1:FInQzS24/EEf25PyTYn52gqo7WaD8xa0213Md/qVLRg=
github.com/knz/go-libedit v1.10.1/go.mod h1:MZTVkCWyz0oBc7JOWP3wNAzd002ZbM/5hgShxwh4x8M=
github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY=
github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
github.com/pkg/errors v0.9.1 h1:FEBLx1zS214owpjy7qsBeixbURkuhQAwrK5UwLGTwt4=
github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
github.com/rs/zerolog v1.33.0 h1:1cU2KZkvPxNyfgEmhHAz/1A9Bz+llsdYzklWFzgp0r8=
github.com/rs/zerolog v1.33.0/go.mod h1:/7mN4D5sKwJLZQ2b/znpjC3/GQWY/xaDXUM0kKWRHss=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk=
github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
github.com/twitchyliquid64/golang-asm v0.15.1 h1:SU5vSMR7hnwNxj24w34ZyCi/FmDZTkS4MhqMhdFk5YI=
github.com/twitchyliquid64/golang-asm v0.15.1/go.mod h1:a1lVb/DtPvCB8fslRZhAngC2+aY1QWCk3Cedj/Gdt08=
golang.org/x/arch v0.0.0-20210923205945-b76863e36670 h1:18EFjUmQOcUvxNYSkA6jO9VAiXCnxFY6NyDX0bHDmkU=
golang.org/x/arch v0.0.0-20210923205945-b76863e36670/go.mod h1:5om86z9Hs0C8fWVUuoMHwpExlXzs5Tkyp9hOrfG7pp8=
golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.12.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.22.0 h1:RI27ohtqKCnwULzJLqkv897zojh5/DwS/ENaMzUOaWI=
golang.org/x/sys v0.22.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
gotest.tools/v3 v3.5.1 h1:EENdUnS3pdur5nybKYIh2Vfgc8IUNBjxDPSjtiJcOzU=
gotest.tools/v3 v3.5.1/go.mod h1:isy3WKz7GK6uNw/sbHzfKBLvlvXwUyV06n6brMxxopU=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
nullprogram.com/x/optparse v1.0.0/go.mod h1:KdyPE+Igbe0jQUrVfMqDMeJQIJZEuyV7pjYmp6pbG50=
94 changes: 68 additions & 26 deletions log/level_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,46 +3,88 @@ package log_test
import (
"testing"

"gotest.tools/v3/assert"

"cosmossdk.io/log"
)

func TestParseLogLevel(t *testing.T) {
_, err := log.ParseLogLevel("")
assert.Error(t, err, "empty log level")
if err == nil {
t.Errorf("expected error for empty log level, got nil")
}

level := "consensus:foo,mempool:debug,*:error"
_, err = log.ParseLogLevel(level)
assert.Error(t, err, "invalid log level foo in log level list [consensus:foo mempool:debug *:error]")
if err == nil {
t.Errorf("expected error for invalid log level foo in log level list [consensus:foo mempool:debug *:error], got nil")
}

level = "consensus:debug,mempool:debug,*:error"
filter, err := log.ParseLogLevel(level)
assert.NilError(t, err)
assert.Assert(t, filter != nil)

assert.Assert(t, !filter("consensus", "debug"))
assert.Assert(t, !filter("consensus", "info"))
assert.Assert(t, !filter("consensus", "error"))
assert.Assert(t, !filter("mempool", "debug"))
assert.Assert(t, !filter("mempool", "info"))
assert.Assert(t, !filter("mempool", "error"))
assert.Assert(t, !filter("state", "error"))
assert.Assert(t, !filter("server", "panic"))

assert.Assert(t, filter("server", "debug"))
assert.Assert(t, filter("state", "debug"))
assert.Assert(t, filter("state", "info"))
if err != nil {
t.Errorf("unexpected error: %v", err)
}
if filter == nil {
t.Fatalf("expected non-nil filter, got nil")
}

if filter("consensus", "debug") {
t.Errorf("expected filter to return false for consensus:debug")
}
if filter("consensus", "info") {
t.Errorf("expected filter to return false for consensus:info")
}
if filter("consensus", "error") {
t.Errorf("expected filter to return false for consensus:error")
}
if filter("mempool", "debug") {
t.Errorf("expected filter to return false for mempool:debug")
}
if filter("mempool", "info") {
t.Errorf("expected filter to return false for mempool:info")
}
if filter("mempool", "error") {
t.Errorf("expected filter to return false for mempool:error")
}
if filter("state", "error") {
t.Errorf("expected filter to return false for state:error")
}
if filter("server", "panic") {
t.Errorf("expected filter to return false for server:panic")
}

if !filter("server", "debug") {
t.Errorf("expected filter to return true for server:debug")
}
if !filter("state", "debug") {
t.Errorf("expected filter to return true for state:debug")
}
if !filter("state", "info") {
t.Errorf("expected filter to return true for state:info")
}

level = "error"
filter, err = log.ParseLogLevel(level)
assert.NilError(t, err)
assert.Assert(t, filter != nil)
if err != nil {
t.Errorf("unexpected error: %v", err)
}
if filter == nil {
t.Fatalf("expected non-nil filter, got nil")
}

assert.Assert(t, !filter("state", "error"))
assert.Assert(t, !filter("consensus", "error"))
if filter("state", "error") {
t.Errorf("expected filter to return false for state:error")
}
if filter("consensus", "error") {
t.Errorf("expected filter to return false for consensus:error")
}

assert.Assert(t, filter("consensus", "debug"))
assert.Assert(t, filter("consensus", "info"))
assert.Assert(t, filter("state", "debug"))
if !filter("consensus", "debug") {
t.Errorf("expected filter to return true for consensus:debug")
}
if !filter("consensus", "info") {
t.Errorf("expected filter to return true for consensus:info")
}
if !filter("state", "debug") {
t.Errorf("expected filter to return true for state:debug")
}
}
18 changes: 5 additions & 13 deletions log/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,22 +6,21 @@ import (
"fmt"
"io"

"github.com/pkg/errors"
"github.com/bytedance/sonic"
"github.com/rs/zerolog"
"github.com/rs/zerolog/pkgerrors"
)

func init() {
zerolog.InterfaceMarshalFunc = func(i any) ([]byte, error) {
switch v := i.(type) {
case json.Marshaler:
return json.Marshal(i)
return sonic.Marshal(i)
case encoding.TextMarshaler:
return json.Marshal(i)
return sonic.Marshal(i)
case fmt.Stringer:
return json.Marshal(v.String())
return sonic.Marshal(v.String())
default:
return json.Marshal(i)
return sonic.Marshal(i)
}
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🛠️ Refactor suggestion

Consider refactoring to eliminate code duplication between init and WithJSONMarshal.

The init function and WithJSONMarshal both set zerolog.InterfaceMarshalFunc with similar logic. To adhere to the DRY (Don't Repeat Yourself) principle from best practices, consider refactoring the init function to call WithJSONMarshal(sonic.Marshal). This would reduce code duplication and improve maintainability.

Apply this diff to refactor the code:

func init() {
-	zerolog.InterfaceMarshalFunc = func(i any) ([]byte, error) {
-		switch v := i.(type) {
-		case json.Marshaler:
-			return sonic.Marshal(i)
-		case encoding.TextMarshaler:
-			return sonic.Marshal(i)
-		case fmt.Stringer:
-			return sonic.Marshal(v.String())
-		default:
-			return sonic.Marshal(i)
-		}
-	}
+	WithJSONMarshal(sonic.Marshal)
}
📝 Committable suggestion

‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.

Suggested change
"github.com/bytedance/sonic"
"github.com/rs/zerolog"
"github.com/rs/zerolog/pkgerrors"
)
func init() {
zerolog.InterfaceMarshalFunc = func(i any) ([]byte, error) {
switch v := i.(type) {
case json.Marshaler:
return json.Marshal(i)
return sonic.Marshal(i)
case encoding.TextMarshaler:
return json.Marshal(i)
return sonic.Marshal(i)
case fmt.Stringer:
return json.Marshal(v.String())
return sonic.Marshal(v.String())
default:
return json.Marshal(i)
return sonic.Marshal(i)
}
}
"github.com/bytedance/sonic"
"github.com/rs/zerolog"
)
func init() {
WithJSONMarshal(sonic.Marshal)
}

}
Expand Down Expand Up @@ -112,13 +111,6 @@ func NewLogger(dst io.Writer, options ...Option) Logger {
}

logger := zerolog.New(output)
if logCfg.StackTrace {
zerolog.ErrorStackMarshaler = func(err error) interface{} {
return pkgerrors.MarshalStack(errors.WithStack(err))
}

logger = logger.With().Stack().Logger()
}

if logCfg.TimeFormat != "" {
logger = logger.With().Timestamp().Logger()
Expand Down
29 changes: 9 additions & 20 deletions log/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,27 +7,10 @@ import (
"testing"

"github.com/rs/zerolog"
"gotest.tools/v3/assert"

"cosmossdk.io/log"
)

func TestLoggerOptionStackTrace(t *testing.T) {
tac0turtle marked this conversation as resolved.
Show resolved Hide resolved
buf := new(bytes.Buffer)
logger := log.NewLogger(buf, log.TraceOption(true), log.ColorOption(false))
logger.Error("this log should be displayed", "error", inner())
if strings.Count(buf.String(), "logger_test.go") != 1 {
t.Fatalf("stack trace not found, got: %s", buf.String())
}
buf.Reset()

logger = log.NewLogger(buf, log.TraceOption(false), log.ColorOption(false))
logger.Error("this log should be displayed", "error", inner())
if strings.Count(buf.String(), "logger_test.go") > 0 {
t.Fatalf("stack trace found, got: %s", buf.String())
}
}

func inner() error {
return errors.New("seems we have an error here")
}
Expand All @@ -46,11 +29,17 @@ func TestLoggerOptionHooks(t *testing.T) {
)
logger := log.NewLogger(buf, log.HooksOption(mockHook1, mockHook2), log.ColorOption(false))
logger.Info("hello world")
assert.Assert(t, strings.Contains(buf.String(), "mock_message1=true"))
assert.Assert(t, strings.Contains(buf.String(), "mock_message2=true"))
if !strings.Contains(buf.String(), "mock_message1=true") {
t.Fatalf("expected mock_message1=true, got: %s", buf.String())
}
if !strings.Contains(buf.String(), "mock_message2=true") {
t.Fatalf("expected mock_message2=true, got: %s", buf.String())
}

buf.Reset()
logger = log.NewLogger(buf, log.HooksOption(), log.ColorOption(false))
logger.Info("hello world")
assert.Assert(t, strings.Contains(buf.String(), "hello world"))
if !strings.Contains(buf.String(), "hello world") {
t.Fatalf("expected hello world, got: %s", buf.String())
}
}
9 changes: 0 additions & 9 deletions log/options.go
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,6 @@ var defaultConfig = Config{
Filter: nil,
OutputJSON: false,
Color: true,
StackTrace: false,
TimeFormat: time.Kitchen,
Hooks: nil,
}
Expand All @@ -23,7 +22,6 @@ type Config struct {
Filter FilterFunc
OutputJSON bool
Color bool
StackTrace bool
TimeFormat string
Hooks []zerolog.Hook
}
Expand Down Expand Up @@ -83,13 +81,6 @@ func TimeFormatOption(format string) Option {
}
}

// TraceOption add option to enable/disable print of stacktrace on error log
tac0turtle marked this conversation as resolved.
Show resolved Hide resolved
func TraceOption(val bool) Option {
return func(cfg *Config) {
cfg.StackTrace = val
}
}

// HooksOption append hooks to the Logger hooks
func HooksOption(hooks ...zerolog.Hook) Option {
return func(cfg *Config) {
Expand Down
5 changes: 3 additions & 2 deletions log/writer.go
Original file line number Diff line number Diff line change
@@ -1,9 +1,10 @@
package log

import (
"encoding/json"
"fmt"
"io"

"github.com/bytedance/sonic"
)

// NewFilterWriter returns a writer that filters out all key/value pairs that do not match the filter.
Expand All @@ -28,7 +29,7 @@ func (fw *filterWriter) Write(p []byte) (n int, err error) {
Module string `json:"module"`
}

if err := json.Unmarshal(p, &event); err != nil {
if err := sonic.Unmarshal(p, &event); err != nil {
return 0, fmt.Errorf("failed to unmarshal event: %w", err)
}

Expand Down
14 changes: 9 additions & 5 deletions log/writer_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -5,8 +5,6 @@ import (
"strings"
"testing"

"gotest.tools/v3/assert"

"cosmossdk.io/log"
)

Expand All @@ -15,13 +13,19 @@ func TestFilteredWriter(t *testing.T) {

level := "consensus:debug,mempool:debug,*:error"
filter, err := log.ParseLogLevel(level)
assert.NilError(t, err)
if err != nil {
t.Fatalf("failed to parse log level: %v", err)
}

logger := log.NewLogger(buf, log.FilterOption(filter))
logger.Debug("this log line should be displayed", log.ModuleKey, "consensus")
assert.Check(t, strings.Contains(buf.String(), "this log line should be displayed"))
if !strings.Contains(buf.String(), "this log line should be displayed") {
t.Errorf("expected log line to be displayed, but it was not")
}
buf.Reset()

logger.Debug("this log line should be filtered", log.ModuleKey, "server")
assert.Check(t, buf.Len() == 0)
if buf.Len() != 0 {
t.Errorf("expected log line to be filtered, but it was not")
}
}
Loading