diff --git a/logs/zap/core.go b/logs/zap/core.go index 482cb8594c23f781344df4e8e4b7a22e9f67a466..aee31e41c7c676d282724b3033c0e364f9400b1b 100644 --- a/logs/zap/core.go +++ b/logs/zap/core.go @@ -1,12 +1,7 @@ package zap import ( - "fmt" - - oid "git.perx.ru/perxis/perxis-go/id" "git.perx.ru/perxis/perxis-go/logs" - "git.perx.ru/perxis/perxis-go/pkg/id" - "go.uber.org/zap" "go.uber.org/zap/zapcore" ) @@ -20,22 +15,25 @@ type WriteSyncer interface { type Core struct { zapcore.LevelEnabler - writeSyncer WriteSyncer - fields []zap.Field + ws WriteSyncer + enc Encoder } func NewCore(writeSyncer WriteSyncer) *Core { return &Core{ LevelEnabler: zapcore.InfoLevel, - writeSyncer: writeSyncer, + ws: writeSyncer, + enc: NewEntryEncoder(), } } func (core *Core) With(fields []zapcore.Field) zapcore.Core { + enc := core.enc.Clone() + enc.AddFields(fields) return &Core{ LevelEnabler: core.LevelEnabler, - writeSyncer: core.writeSyncer, - fields: append(core.fields, fields...), + ws: core.ws, + enc: enc, } } @@ -47,48 +45,13 @@ func (core *Core) Check(entry zapcore.Entry, checkedEntry *zapcore.CheckedEntry) } func (core *Core) Write(entry zapcore.Entry, fields []zapcore.Field) error { - return core.writeSyncer.Write(core.getEntry(entry, fields)) + encodedEntry, err := core.enc.EncodeEntry(entry, fields) + if err != nil { + return err + } + return core.ws.Write(encodedEntry) } func (core *Core) Sync() error { - return core.writeSyncer.Sync() -} - -func (core *Core) getEntry(entry zapcore.Entry, fields []zapcore.Field) *logs.Entry { - if len(core.fields) > 0 { - fields = append(fields, core.fields...) - } - - enc := zapcore.NewMapObjectEncoder() - for _, field := range fields { - field.AddTo(enc) - } - - ent := &logs.Entry{ - ID: id.GenerateNewID(), - Timestamp: entry.Time, - Level: logs.Level(entry.Level), - Message: entry.Message, - } - - ent.Category, _ = enc.Fields["category"].(string) - ent.Component, _ = enc.Fields["component"].(string) - ent.Event, _ = enc.Fields["event"].(string) - ent.ObjectID, _ = enc.Fields["object"].(*oid.ObjectId) - ent.CallerID, _ = enc.Fields["caller"].(*oid.ObjectId) - ent.Attr = enc.Fields["attr"] - - if err, _ := enc.Fields["error"].(error); err != nil { - ent.Message = fmt.Sprintf("%s. Error: %s", ent.Message, err.Error()) - } - - if tags, ok := enc.Fields["tags"].([]any); ok { - for _, item := range tags { - if tag, ok := item.(string); ok { - ent.Tags = append(ent.Tags, tag) - } - } - } - - return ent + return core.ws.Sync() } diff --git a/logs/zap/core_test.go b/logs/zap/core_test.go deleted file mode 100644 index 360e850a410b321239e948b6c35d08e1a397ab45..0000000000000000000000000000000000000000 --- a/logs/zap/core_test.go +++ /dev/null @@ -1,65 +0,0 @@ -package zap - -import ( - "testing" - - "git.perx.ru/perxis/perxis-go/id" - "git.perx.ru/perxis/perxis-go/logs" - logzap "git.perx.ru/perxis/perxis-go/zap" - "github.com/stretchr/testify/require" - "go.uber.org/zap" - "go.uber.org/zap/zapcore" -) - -func TestCore_getEntry(t *testing.T) { - core := NewCore(nil) - - tests := []struct { - name string - input struct { - entry zapcore.Entry - fields []zapcore.Field - } - want *logs.Entry - }{ - { - name: "simple", - input: struct { - entry zapcore.Entry - fields []zapcore.Field - }{ - entry: zapcore.Entry{Level: zapcore.InfoLevel, Message: "создан элемент коллекции"}, - fields: []zapcore.Field{ - zap.String("key", "val"), // будет проигнорировано - logzap.Category("create"), - logzap.Component("Items.Service"), - logzap.Event("Items.Create"), - logzap.Object("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl"), - logzap.Caller("/users/PHVz"), - logzap.Attr("any"), - logzap.Tags("tag1", "tag2", "tag3"), - }, - }, - want: &logs.Entry{ - Level: logs.Level(zapcore.InfoLevel), - Message: "создан элемент коллекции", - Category: "create", - Component: "Items.Service", - Event: "Items.Create", - ObjectID: id.MustObjectId("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl"), - CallerID: id.MustObjectId("/users/PHVz"), - Attr: "any", - Tags: []string{"tag1", "tag2", "tag3"}, - }, - }, - } - - for _, tc := range tests { - t.Run(tc.name, func(t *testing.T) { - got := core.getEntry(tc.input.entry, tc.input.fields) - got.ID = tc.want.ID // игнорируем ID - got.Timestamp = tc.want.Timestamp // игнорируем Timestamp - require.Equal(t, tc.want, got) - }) - } -} diff --git a/logs/zap/entry_encoder.go b/logs/zap/entry_encoder.go new file mode 100644 index 0000000000000000000000000000000000000000..d7db9b301a7a41c9b869ddcc0c06146afafe9780 --- /dev/null +++ b/logs/zap/entry_encoder.go @@ -0,0 +1,78 @@ +package zap + +import ( + "fmt" + "slices" + + oid "git.perx.ru/perxis/perxis-go/id" + "git.perx.ru/perxis/perxis-go/logs" + "git.perx.ru/perxis/perxis-go/pkg/id" + "git.perx.ru/perxis/perxis-go/zap" + "go.uber.org/zap/zapcore" +) + +type Encoder interface { + Clone() Encoder + AddFields([]zapcore.Field) + EncodeEntry(zapcore.Entry, []zapcore.Field) (*logs.Entry, error) +} + +type entryEncoder struct { + fields []zapcore.Field +} + +func NewEntryEncoder() Encoder { + return &entryEncoder{} +} + +func (enc *entryEncoder) AddFields(fields []zapcore.Field) { + enc.fields = slices.Concat(enc.fields, fields) +} + +func (enc *entryEncoder) Clone() Encoder { + return enc.clone() +} + +func (enc *entryEncoder) clone() *entryEncoder { + return &entryEncoder{fields: slices.Clone(enc.fields)} +} + +func (enc *entryEncoder) EncodeEntry(entry zapcore.Entry, fields []zapcore.Field) (*logs.Entry, error) { + ent := &logs.Entry{ + ID: id.GenerateNewID(), + Timestamp: entry.Time, + Level: logs.Level(entry.Level), + Message: entry.Message, + } + + clone := enc.clone() + clone.AddFields(fields) + + for i := range clone.fields { + switch clone.fields[i].Key { + // При добавлении новых полей стоит учитывать, как zap хранит значения в структуре Field. + // Например: + // zap.Bool хранит bool как 1/0 в поле Field.Integer + case "category": + ent.Category = clone.fields[i].String + case "component": + ent.Component = clone.fields[i].String + case "event": + ent.Event = clone.fields[i].String + case "object": + ent.ObjectID, _ = clone.fields[i].Interface.(*oid.ObjectId) + case "caller": + ent.CallerID, _ = clone.fields[i].Interface.(*oid.ObjectId) + case "attr": + ent.Attr = clone.fields[i].Interface + case "error": + if err, _ := clone.fields[i].Interface.(error); err != nil { + ent.Message = fmt.Sprintf("%s. Error: %s", ent.Message, err.Error()) + } + case "tags": + ent.Tags, _ = clone.fields[i].Interface.(zap.StringArray) + } + } + + return ent, nil +} diff --git a/logs/zap/entry_encoder_slow.go b/logs/zap/entry_encoder_slow.go new file mode 100644 index 0000000000000000000000000000000000000000..77bf275d93d242ac9ae38f04efe937fa986e5733 --- /dev/null +++ b/logs/zap/entry_encoder_slow.go @@ -0,0 +1,71 @@ +package zap + +import ( + "fmt" + "maps" + + oid "git.perx.ru/perxis/perxis-go/id" + "git.perx.ru/perxis/perxis-go/logs" + "git.perx.ru/perxis/perxis-go/pkg/id" + "go.uber.org/zap/zapcore" +) + +type EncoderSlow interface { + zapcore.ObjectEncoder + + Clone() EncoderSlow + EncodeEntry(zapcore.Entry, []zapcore.Field) (*logs.Entry, error) +} + +type entryEncoderSlow struct { + *zapcore.MapObjectEncoder +} + +func NewEntryEncoderSlow() EncoderSlow { + return &entryEncoderSlow{MapObjectEncoder: zapcore.NewMapObjectEncoder()} +} + +func (enc *entryEncoderSlow) Clone() EncoderSlow { + return enc.clone() +} + +func (enc *entryEncoderSlow) clone() *entryEncoderSlow { + objEnc := zapcore.NewMapObjectEncoder() + maps.Copy(objEnc.Fields, enc.MapObjectEncoder.Fields) + return &entryEncoderSlow{MapObjectEncoder: objEnc} +} + +func (enc *entryEncoderSlow) EncodeEntry(entry zapcore.Entry, fields []zapcore.Field) (*logs.Entry, error) { + clone := enc.clone() + for i := range fields { + fields[i].AddTo(clone) + } + + ent := &logs.Entry{ + ID: id.GenerateNewID(), + Timestamp: entry.Time, + Level: logs.Level(entry.Level), + Message: entry.Message, + } + + ent.Category, _ = clone.Fields["category"].(string) + ent.Component, _ = clone.Fields["component"].(string) + ent.Event, _ = clone.Fields["event"].(string) + ent.ObjectID, _ = clone.Fields["object"].(*oid.ObjectId) + ent.CallerID, _ = clone.Fields["caller"].(*oid.ObjectId) + ent.Attr = clone.Fields["attr"] + + if err, _ := clone.Fields["error"].(error); err != nil { + ent.Message = fmt.Sprintf("%s. Error: %s", ent.Message, err.Error()) + } + + if tags, ok := clone.Fields["tags"].([]any); ok { + for i := range tags { + if tag, ok := tags[i].(string); ok { + ent.Tags = append(ent.Tags, tag) + } + } + } + + return ent, nil +} diff --git a/logs/zap/entry_encoder_test.go b/logs/zap/entry_encoder_test.go new file mode 100644 index 0000000000000000000000000000000000000000..01b8b51ce0bf9c8fc9b6a384dec97f82ab98c19c --- /dev/null +++ b/logs/zap/entry_encoder_test.go @@ -0,0 +1,131 @@ +package zap + +import ( + "fmt" + "testing" + + "git.perx.ru/perxis/perxis-go/id" + "git.perx.ru/perxis/perxis-go/logs" + "git.perx.ru/perxis/perxis-go/pkg/items" + logzap "git.perx.ru/perxis/perxis-go/zap" + "github.com/stretchr/testify/require" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +func TestEntryEncoder_EncodeEntry(t *testing.T) { + tests := []struct { + name string + input struct { + entry zapcore.Entry + fields []zapcore.Field + } + want *logs.Entry + }{ + { + name: "simple", + input: struct { + entry zapcore.Entry + fields []zapcore.Field + }{ + entry: zapcore.Entry{Level: zapcore.InfoLevel, Message: "создан элемент коллекции"}, + fields: []zapcore.Field{ + zap.String("key", "val"), // будет проигнорировано + logzap.Category("create"), + logzap.Component("Items.Service"), + logzap.Event("Items.Create"), + logzap.Object("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl"), + logzap.Caller("/users/PHVz"), + logzap.Attr("any"), + logzap.Tags("tag1", "tag2", "tag3"), + }, + }, + want: &logs.Entry{ + Level: logs.Level(zapcore.InfoLevel), + Message: "создан элемент коллекции", + Category: "create", + Component: "Items.Service", + Event: "Items.Create", + ObjectID: id.MustObjectId("/spaces/WPNN/envs/9VGP/cols/GxNv/items/W0fl"), + CallerID: id.MustObjectId("/users/PHVz"), + Attr: "any", + Tags: []string{"tag1", "tag2", "tag3"}, + }, + }, + } + + enc := NewEntryEncoder() + + for _, tc := range tests { + t.Run(tc.name, func(t *testing.T) { + got, _ := enc.EncodeEntry(tc.input.entry, tc.input.fields) + got.ID = tc.want.ID // игнорируем ID + got.Timestamp = tc.want.Timestamp // игнорируем Timestamp + require.Equal(t, tc.want, got) + }) + } +} + +func BenchmarkEntryEncoderSimple(b *testing.B) { + fields := []zapcore.Field{ + logzap.Event(items.EventCreateItem), + logzap.Object(items.NewItem("WPNN", "9VGP", "GxNv", "W0fl", nil, nil)), + logzap.Caller("/system"), + logzap.Tags("tag1", "tag2", "tag3"), + } + + enc := NewEntryEncoderSlow() + for i := 0; i < b.N; i++ { + _, _ = enc.EncodeEntry(zapcore.Entry{Message: fmt.Sprintf("Msg: %d", i)}, fields) + } +} + +func BenchmarkEntryEncoderUnknownFields(b *testing.B) { + fields := []zapcore.Field{ + logzap.Event(items.EventCreateItem), + logzap.Object(items.NewItem("WPNN", "9VGP", "GxNv", "W0fl", nil, nil)), + logzap.Caller("/system"), + logzap.Tags("tag1", "tag2", "tag3"), + } + + for i := 0; i < 1000; i++ { + fields = append(fields, zap.String(fmt.Sprintf("Key: %d", i), fmt.Sprintf("Value: %d", i))) + } + + enc := NewEntryEncoderSlow() + for i := 0; i < b.N; i++ { + _, _ = enc.EncodeEntry(zapcore.Entry{Message: fmt.Sprintf("Msg: %d", i)}, fields) + } +} + +func BenchmarkEntryEncoderV2Simple(b *testing.B) { + fields := []zapcore.Field{ + logzap.Event(items.EventCreateItem), + logzap.Object(items.NewItem("WPNN", "9VGP", "GxNv", "W0fl", nil, nil)), + logzap.Caller("/system"), + logzap.Tags("tag1", "tag2", "tag3"), + } + + enc := NewEntryEncoder() + for i := 0; i < b.N; i++ { + _, _ = enc.EncodeEntry(zapcore.Entry{Message: fmt.Sprintf("Msg: %d", i)}, fields) + } +} + +func BenchmarkEntryEncoderV2UnknownFields(b *testing.B) { + fields := []zapcore.Field{ + logzap.Event(items.EventCreateItem), + logzap.Object(items.NewItem("WPNN", "9VGP", "GxNv", "W0fl", nil, nil)), + logzap.Caller("/system"), + logzap.Tags("tag1", "tag2", "tag3"), + } + + for i := 0; i < 1000; i++ { + fields = append(fields, zap.String(fmt.Sprintf("Key: %d", i), fmt.Sprintf("Value: %d", i))) + } + + enc := NewEntryEncoder() + for i := 0; i < b.N; i++ { + _, _ = enc.EncodeEntry(zapcore.Entry{Message: fmt.Sprintf("Msg: %d", i)}, fields) + } +} diff --git a/zap/channels.go b/zap/channels.go index 5753163514b1a91605e54e41adfdac711a2518b4..8726cc54ce4f8ab55ad27b469dff3809c68804fa 100644 --- a/zap/channels.go +++ b/zap/channels.go @@ -17,7 +17,7 @@ func ContainsChannels(channels ...string) FilterFunc { return func(entry zapcore.Entry, fields []zapcore.Field) bool { for _, f := range fields { if f.Key == channelKey && f.Type == zapcore.SkipType { - for _, v := range f.Interface.(stringArray) { + for _, v := range f.Interface.(StringArray) { if data.Contains(v, channels) { return true } diff --git a/zap/field.go b/zap/field.go index 308c21d6e83a4a80c35ab9866cb757e65c4b7a24..f967504c6c9e797fd75eb7185fa718609e82151b 100644 --- a/zap/field.go +++ b/zap/field.go @@ -10,9 +10,9 @@ import ( "go.uber.org/zap/zapcore" ) -type stringArray []string +type StringArray []string -func (ss stringArray) MarshalLogArray(arr zapcore.ArrayEncoder) error { +func (ss StringArray) MarshalLogArray(arr zapcore.ArrayEncoder) error { for i := range ss { arr.AppendString(ss[i]) } @@ -24,7 +24,7 @@ func Channels(channels ...string) zap.Field { return zap.Field{ Key: channelKey, Type: zapcore.SkipType, // используем тип zapcore.SkipType, чтобы при кодировании поле игнорировалось - Interface: stringArray(channels), + Interface: StringArray(channels), } } @@ -60,9 +60,9 @@ func CallerFromContext(ctx context.Context) zap.Field { } func Attr(attr any) zap.Field { - return zap.Any("attr", attr) + return zap.Reflect("attr", attr) } func Tags(tags ...string) zap.Field { - return zap.Strings("tags", tags) + return zap.Array("tags", StringArray(tags)) } diff --git a/zap/field_test.go b/zap/field_test.go index 84efa584f85a66468e160334510e39ddee0246b0..b15f01565bc207a62eb64cde804d56adc3d17ec1 100644 --- a/zap/field_test.go +++ b/zap/field_test.go @@ -19,8 +19,8 @@ func TestChannels(t *testing.T) { field zap.Field want zap.Field }{ - {name: "ok", field: Channels("master"), want: zap.Field{Key: channelKey, Type: zapcore.SkipType, Interface: stringArray{"master"}}}, - {name: "invalid", field: Channels(), want: zap.Field{Key: channelKey, Type: zapcore.SkipType, Interface: stringArray(nil)}}, + {name: "ok", field: Channels("master"), want: zap.Field{Key: channelKey, Type: zapcore.SkipType, Interface: StringArray{"master"}}}, + {name: "invalid", field: Channels(), want: zap.Field{Key: channelKey, Type: zapcore.SkipType, Interface: StringArray(nil)}}, } for _, tc := range tests { @@ -208,13 +208,13 @@ func TestTags(t *testing.T) { field zap.Field want zap.Field }{ - {name: "ok", field: Tags("a", "b", "c"), want: zap.Strings("tags", []string{"a", "b", "c"})}, - {name: "invalid", field: Tags(nil...), want: zap.Strings("tags", nil)}, + {name: "ok", field: Tags("a", "b", "c"), want: zap.Array("tags", StringArray{"a", "b", "c"})}, + {name: "invalid", field: Tags(nil...), want: zap.Array("tags", StringArray(nil))}, } for _, tc := range tests { t.Run(tc.name, func(t *testing.T) { - assert.True(t, tc.want.Equals(tc.field)) + assert.Equal(t, tc.want, tc.field) }) } } diff --git a/zap/filter_core.go b/zap/filter_core.go index 7e99d942e439afc8a05faaf55be29b8cb604b7fc..24a80b3a20cb996be27b49ae4b4fd4dee507f7ed 100644 --- a/zap/filter_core.go +++ b/zap/filter_core.go @@ -1,6 +1,8 @@ package zap import ( + "slices" + "go.uber.org/zap" "go.uber.org/zap/zapcore" ) @@ -51,9 +53,9 @@ type filterCore struct { filters []FilterFunc - // fields хранит контекст записей ядра, передаваемых при вызове With. + // context хранит контекст записей ядра, передаваемых при вызове With. // В методе Write передаются только поля конкретной записи, но мы также хотим учитывать поля контекста ядра. - fields []zap.Field + context []zap.Field } // WithFilters - добавить фильтры, которые будут применяться при записи лога (вызове `core.Write`) @@ -80,7 +82,7 @@ func (core *filterCore) With(fields []zapcore.Field) zapcore.Core { return &filterCore{ Core: core.Core.With(fields), filters: core.filters, - fields: append(core.fields, fields...), + context: slices.Concat(core.context, fields), } } @@ -92,15 +94,11 @@ func (core *filterCore) Check(entry zapcore.Entry, checkedEntry *zapcore.Checked } func (core *filterCore) Write(entry zapcore.Entry, fields []zapcore.Field) error { - if len(core.fields) > 0 { - fields = append(core.fields, fields...) - } - + all := slices.Concat(core.context, fields) for _, filter := range core.filters { - if !filter(entry, fields) { + if !filter(entry, all) { return nil } } - return core.Core.Write(entry, fields) } diff --git a/zap/filter_core_test.go b/zap/filter_core_test.go index 21c906f24f5b7458c7628985871f1480564a3164..01e4694f9b04c1a7eca79ff12cb662a614c56320 100644 --- a/zap/filter_core_test.go +++ b/zap/filter_core_test.go @@ -9,6 +9,20 @@ import ( "go.uber.org/zap/zaptest/observer" ) +func TestFilterCore_With(t *testing.T) { + core, logs := observer.New(zapcore.InfoLevel) + core = WithFilters(core) + + field := zap.String("k", "v") + err := core.With([]zapcore.Field{field}).Write(zapcore.Entry{Message: "msg"}, nil) + require.NoError(t, err) + + entries := logs.All() + require.Len(t, entries, 1) + require.Len(t, entries[0].Context, 1) + require.True(t, field.Equals(entries[0].Context[0])) +} + func TestFilterCore_Write(t *testing.T) { core, logs := observer.New(zapcore.InfoLevel) core = WithFilters(core, ContainsField(zap.Bool("check", true)))