Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
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
3 changes: 1 addition & 2 deletions common/flogging/core.go
Original file line number Diff line number Diff line change
Expand Up @@ -15,11 +15,10 @@ type Encoding int8
const (
CONSOLE = iota
JSON
LOGFMT
)

// EncodingSelector is used to determine whether log records are
// encoded as JSON or in human readable CONSOLE or LOGFMT formats.
// encoded as JSON or in human-readable CONSOLE format.
type EncodingSelector interface {
Encoding() Encoding
}
Expand Down
107 changes: 76 additions & 31 deletions common/flogging/fabenc/encoder.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,18 +7,29 @@ SPDX-License-Identifier: Apache-2.0
package fabenc

import (
"errors"
"fmt"
"io"
"maps"
"slices"
"time"

zaplogfmt "github.com/sykesm/zap-logfmt"
"github.com/go-logfmt/logfmt"
"go.uber.org/zap/buffer"
"go.uber.org/zap/zapcore"
)

// A FormatEncoder is a zapcore.Encoder that formats log records according to a
// go-logging based format specifier.
// go-logging based format specifier. Structured fields are appended to the
// formatted record in logfmt (key=value) form: context added via With is
// emitted first, sorted by key, followed by the entry's own fields in the order
// they were supplied. Fields are not de-duplicated, so a repeated key is
// emitted once per occurrence with its own value.
//
// The embedded MapObjectEncoder provides the zapcore.ObjectEncoder
// implementation used to accumulate the With context.
type FormatEncoder struct {
zapcore.Encoder
*zapcore.MapObjectEncoder
formatters []Formatter
pool buffer.Pool
}
Expand All @@ -30,51 +41,85 @@ type Formatter interface {

func NewFormatEncoder(formatters ...Formatter) *FormatEncoder {
return &FormatEncoder{
Encoder: zaplogfmt.NewEncoder(zapcore.EncoderConfig{
MessageKey: "", // disable
LevelKey: "", // disable
TimeKey: "", // disable
NameKey: "", // disable
CallerKey: "", // disable
StacktraceKey: "", // disable
LineEnding: "\n",
EncodeDuration: zapcore.StringDurationEncoder,
EncodeTime: func(t time.Time, enc zapcore.PrimitiveArrayEncoder) {
enc.AppendString(t.Format("2006-01-02T15:04:05.999Z07:00"))
},
Comment on lines -34 to -44

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Why did you delete these settings? they were before the addition of the zap-logfmt dependency.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

They are hard-coded in the new implementation. This is because we only have one use case for this module.
The original one was an external lib; thus, it had to be generic.

}),
formatters: formatters,
pool: buffer.NewPool(),
MapObjectEncoder: zapcore.NewMapObjectEncoder(),
formatters: formatters,
pool: buffer.NewPool(),
}
}

// Clone creates a new instance of this encoder with the same configuration.
func (f *FormatEncoder) Clone() zapcore.Encoder {
clone := zapcore.NewMapObjectEncoder()
maps.Copy(clone.Fields, f.Fields)
return &FormatEncoder{
Encoder: f.Encoder.Clone(),
formatters: f.formatters,
pool: f.pool,
MapObjectEncoder: clone,
formatters: f.formatters,
pool: f.pool,
}
}

// EncodeEntry formats a zap log record. The structured fields are formatted by a
// zapcore.ConsoleEncoder and are appended as JSON to the end of the formatted entry.
// EncodeEntry formats a zap log record. The With context is appended sorted by
// key, followed by this entry's fields in insertion order, all in logfmt form.
// All entries are terminated by a newline.
func (f *FormatEncoder) EncodeEntry(entry zapcore.Entry, fields []zapcore.Field) (*buffer.Buffer, error) {
line := f.pool.Get()
for _, f := range f.formatters {
f.Format(line, entry, fields)
for _, formatter := range f.formatters {
formatter.Format(line, entry, fields)
}

encodedFields, err := f.Encoder.EncodeEntry(entry, fields)
if err != nil {
return nil, err
type keyVal struct {
key string
val any
}
if line.Len() > 0 && encodedFields.Len() != 1 {

// Assemble the output: the With context first, sorted by key (map order is
// unrecoverable), then this entry's fields in the order supplied.
keyVals := make([]keyVal, 0, len(f.Fields)+len(fields))
for _, key := range slices.Sorted(maps.Keys(f.Fields)) {
keyVals = append(keyVals, keyVal{key: key, val: f.Fields[key]})
}
for _, field := range fields {
// Fields are not de-duplicated, so a repeated key is preserved with its own value, as
// the original logfmt encoder did. Thus, we decode each field on its own map encoder.
mapEncoder := zapcore.NewMapObjectEncoder()
field.AddTo(mapEncoder)
// Some fields are skipped, so we need to check if it was actually added.
if v, ok := mapEncoder.Fields[field.Key]; ok {
keyVals = append(keyVals, keyVal{key: field.Key, val: v})
}
}

// Separate the first field from the formatted prefix; logfmt inserts
// the separators between subsequent fields itself.
if len(keyVals) > 0 && line.Len() > 0 {
line.AppendString(" ")
}
line.AppendString(encodedFields.String())
encodedFields.Free()

enc := logfmt.NewEncoder(line)
for _, kv := range keyVals {
if err := encodeKeyValue(enc, kv.key, kv.val); err != nil {
return nil, err
}
}

line.AppendString("\n")

return line, nil
}

func encodeKeyValue(enc *logfmt.Encoder, key string, value any) error {
if t, ok := value.(time.Time); ok {
// Normalizes values that logfmt would otherwise render differently
// than intended. Timestamps use a millisecond-precision layout instead of the
// nanosecond-precision encoding.TextMarshaler output.
value = t.Format("2006-01-02T15:04:05.999Z07:00")
}

err := enc.EncodeKeyval(key, value)
if errors.Is(err, logfmt.ErrUnsupportedValueType) {
// logfmt rejects composite types (structs, maps, slices, ...); fall
// back to their fmt representation, matching what EncodeKeyvals() does.
err = enc.EncodeKeyval(key, fmt.Sprint(value))
}
return err
}
55 changes: 46 additions & 9 deletions common/flogging/fabenc/encoder_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,6 @@ SPDX-License-Identifier: Apache-2.0
package fabenc_test

import (
"errors"
"fmt"
"runtime"
"testing"
Expand All @@ -16,7 +15,6 @@ import (
"github.com/hyperledger/fabric-lib-go/common/flogging/fabenc"
"github.com/stretchr/testify/require"
"go.uber.org/zap"
"go.uber.org/zap/buffer"
"go.uber.org/zap/zapcore"
)

Expand Down Expand Up @@ -63,18 +61,57 @@ func TestEncodeEntry(t *testing.T) {
}
}

type brokenEncoder struct{ zapcore.Encoder }
func TestEncodeFieldsFailed(t *testing.T) {
enc := fabenc.NewFormatEncoder()
// A key that reduces to nothing once invalid runes are stripped cannot be
// encoded as logfmt, so EncodeEntry surfaces the error.
_, err := enc.EncodeEntry(zapcore.Entry{}, []zapcore.Field{zap.String(" ", "value")})
require.Error(t, err)
}

func (b *brokenEncoder) EncodeEntry(zapcore.Entry, []zapcore.Field) (*buffer.Buffer, error) {
return nil, errors.New("broken encoder")
// TestEncodeEntryPreservesOrder verifies that an entry's own fields are emitted
// in insertion order rather than sorted by key.
func TestEncodeEntryPreservesOrder(t *testing.T) {
enc := fabenc.NewFormatEncoder()
line, err := enc.EncodeEntry(zapcore.Entry{}, []zapcore.Field{
zap.String("zebra", "z"),
zap.Int("apple", 1),
zap.String("mango", "m"),
})
require.NoError(t, err)
require.Equal(t, "zebra=z apple=1 mango=m\n", line.String())
}

func TestEncodeFieldsFailed(t *testing.T) {
// TestEncodeEntryPreservesDuplicateKeys verifies that repeated keys are not
// merged: each occurrence is emitted with its own value. The With context is
// emitted (sorted) before the entry's fields, and a key present in both the
// context and the entry appears in each.
func TestEncodeEntryPreservesDuplicateKeys(t *testing.T) {
enc := fabenc.NewFormatEncoder()
enc.Encoder = &brokenEncoder{}
enc.Fields["ctx"] = "c" // With context
enc.Fields["dup"] = "from-with"

line, err := enc.EncodeEntry(zapcore.Entry{}, []zapcore.Field{
zap.String("dup", "from-field"), // same key as the context entry
zap.String("zzz", "z"),
zap.String("zzz", "z2"), // duplicated within the entry
})
require.NoError(t, err)
require.Equal(t, "ctx=c dup=from-with dup=from-field zzz=z zzz=z2\n", line.String())
}

_, err := enc.EncodeEntry(zapcore.Entry{}, nil)
require.EqualError(t, err, "broken encoder")
// TestEncodeEntrySkipsValuelessFields verifies that a field which adds no value
// under its key (e.g. zap.Skip, whose key is empty) is dropped rather than
// emitted as an invalid key.
func TestEncodeEntrySkipsValuelessFields(t *testing.T) {
enc := fabenc.NewFormatEncoder()
line, err := enc.EncodeEntry(zapcore.Entry{}, []zapcore.Field{
zap.Skip(),
zap.String("k", "v"),
zap.Skip(),
})
require.NoError(t, err)
require.Equal(t, "k=v\n", line.String())
}

func TestFormatEncoderClone(t *testing.T) {
Expand Down
17 changes: 0 additions & 17 deletions common/flogging/global_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -66,23 +66,6 @@ func TestGlobalInitJSON(t *testing.T) {
require.Regexp(t, `{"level":"debug","ts":\d+.\d+,"name":"testlogger","caller":"flogging/global_test.go:\d+","msg":"this is a message"}\s+`, buf.String())
}

func TestGlobalInitLogfmt(t *testing.T) {
flogging.Reset()
defer flogging.Reset()

buf := &bytes.Buffer{}
flogging.Init(flogging.Config{
Format: "logfmt",
LogSpec: "DEBUG",
Writer: buf,
})

logger := flogging.MustGetLogger("testlogger")
logger.Debug("this is a message")

require.Regexp(t, `^ts=\d+.\d+ level=debug name=testlogger caller=flogging/global_test.go:\d+ msg="this is a message"`, buf.String())
}

func TestGlobalInitPanic(t *testing.T) {
flogging.Reset()
defer flogging.Reset()
Expand Down
9 changes: 1 addition & 8 deletions common/flogging/logging.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,6 @@ import (
"sync"

"github.com/hyperledger/fabric-lib-go/common/flogging/fabenc"
zaplogfmt "github.com/sykesm/zap-logfmt"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
Expand Down Expand Up @@ -90,7 +89,7 @@ func (l *Logging) Apply(c Config) error {
c.LogSpec = defaultLevel.String()
}

err = l.LoggerLevels.ActivateSpec(c.LogSpec)
err = l.ActivateSpec(c.LogSpec)
if err != nil {
return err
}
Expand Down Expand Up @@ -119,11 +118,6 @@ func (l *Logging) SetFormat(format string) error {
return nil
}

if format == "logfmt" {
l.encoding = LOGFMT
return nil
}

formatters, err := fabenc.ParseFormat(format)
if err != nil {
return err
Expand Down Expand Up @@ -211,7 +205,6 @@ func (l *Logging) ZapLogger(name string) *zap.Logger {
Encoders: map[Encoding]zapcore.Encoder{
JSON: zapcore.NewJSONEncoder(l.encoderConfig),
CONSOLE: fabenc.NewFormatEncoder(l.multiFormatter),
LOGFMT: zaplogfmt.NewEncoder(l.encoderConfig),
},
Selector: l,
Output: l,
Expand Down
3 changes: 1 addition & 2 deletions go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ go 1.25.10

require (
github.com/go-kit/kit v0.13.0
github.com/go-logfmt/logfmt v0.6.1
github.com/go-viper/mapstructure/v2 v2.5.0
github.com/miekg/pkcs11 v1.1.2
github.com/onsi/ginkgo/v2 v2.28.3
Expand All @@ -12,7 +13,6 @@ require (
github.com/prometheus/client_golang v1.23.2
github.com/spf13/viper v1.21.0
github.com/stretchr/testify v1.11.1
github.com/sykesm/zap-logfmt v0.0.4
go.uber.org/zap v1.28.0
golang.org/x/sync v0.20.0
golang.org/x/tools v0.45.0
Expand All @@ -26,7 +26,6 @@ require (
github.com/davecgh/go-spew v1.1.1 // indirect
github.com/fsnotify/fsnotify v1.9.0 // indirect
github.com/go-kit/log v0.2.1 // indirect
github.com/go-logfmt/logfmt v0.6.1 // indirect
github.com/go-logr/logr v1.4.3 // indirect
github.com/go-task/slim-sprig/v3 v3.0.0 // indirect
github.com/google/go-cmp v0.7.0 // indirect
Expand Down
Loading
Loading