update logging

This commit is contained in:
Tigor Hutasuhut 2024-08-27 15:22:42 +07:00
parent b0d52be920
commit dba226c1c1
9 changed files with 518 additions and 79 deletions

1
.gitignore vendored
View file

@ -1,2 +1,3 @@
.direnv
gen
bin/

View file

@ -1,5 +1,8 @@
.ONESHELL:
build: generate
go build -o ./bin ./cmd/zen
generate: generate-proto
generate-proto:

View file

@ -46,30 +46,3 @@ func (j *jsonHandler) Put() {
j.pool.Put(j)
}
}
type bufferPool struct {
*sync.Pool
}
func newBufferPool() *bufferPool {
return &bufferPool{
&sync.Pool{
New: func() any {
buf := new(bytes.Buffer)
buf.Grow(1024)
return buf
},
},
}
}
func (bp *bufferPool) Get() *bytes.Buffer {
return bp.Pool.Get().(*bytes.Buffer)
}
func (bp *bufferPool) Put(buf *bytes.Buffer) {
if buf.Cap() < 1024*1024*4 {
buf.Reset()
bp.Pool.Put(buf)
}
}

153
core/zlog/exported.go Normal file
View file

@ -0,0 +1,153 @@
package zlog
import (
"context"
"fmt"
"log/slog"
"os"
"time"
"gitlab.bareksa.com/backend/zen/core/zcaller"
)
var Logger = New(os.Stderr, defaultOpts)
func Info(ctx context.Context, msg string) {
if !Logger.Enabled(ctx, slog.LevelInfo) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelInfo)
}
func Infof(ctx context.Context, msg string, args ...any) {
if !Logger.Enabled(ctx, slog.LevelInfo) {
return
}
pc := zcaller.Get(3)
t := time.Now()
msg = fmt.Sprintf(msg, args...)
Log(ctx, msg, pc, t, slog.LevelInfo)
}
func Infow(ctx context.Context, msg string, fields ...any) {
if !Logger.Enabled(ctx, slog.LevelInfo) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelInfo, fields...)
}
func Debug(ctx context.Context, msg string) {
if !Logger.Enabled(ctx, slog.LevelDebug) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelDebug)
}
func Debugf(ctx context.Context, msg string, args ...any) {
if !Logger.Enabled(ctx, slog.LevelDebug) {
return
}
pc := zcaller.Get(3)
t := time.Now()
msg = fmt.Sprintf(msg, args...)
Log(ctx, msg, pc, t, slog.LevelDebug)
}
func Debugw(ctx context.Context, msg string, fields ...any) {
if !Logger.Enabled(ctx, slog.LevelDebug) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelDebug, fields...)
}
func Warn(ctx context.Context, msg string) {
if !Logger.Enabled(ctx, slog.LevelWarn) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelWarn)
}
func Warnf(ctx context.Context, msg string, args ...any) {
if !Logger.Enabled(ctx, slog.LevelWarn) {
return
}
pc := zcaller.Get(3)
t := time.Now()
msg = fmt.Sprintf(msg, args...)
Log(ctx, msg, pc, t, slog.LevelWarn)
}
func Warnw(ctx context.Context, msg string, fields ...any) {
if !Logger.Enabled(ctx, slog.LevelWarn) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelWarn, fields...)
}
func Error(ctx context.Context, msg string) {
if !Logger.Enabled(ctx, slog.LevelError) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelError)
}
func Errorf(ctx context.Context, msg string, args ...any) {
if !Logger.Enabled(ctx, slog.LevelError) {
return
}
pc := zcaller.Get(3)
t := time.Now()
msg = fmt.Sprintf(msg, args...)
Log(ctx, msg, pc, t, slog.LevelError)
}
func Errorw(ctx context.Context, msg string, fields ...any) {
if !Logger.Enabled(ctx, slog.LevelError) {
return
}
pc := zcaller.Get(3)
t := time.Now()
Log(ctx, msg, pc, t, slog.LevelError, fields...)
}
func LogRecord(ctx context.Context, record slog.Record) {
if !Logger.Enabled(ctx, record.Level) {
return
}
Logger.Handle(ctx, record)
}
func Log(ctx context.Context, msg string, pc uintptr, t time.Time, level slog.Level, fields ...any) {
record := slog.NewRecord(t, level, msg, pc)
record.Add(fields...)
// error is only returned if the output writer fails.
if err := Logger.Handle(ctx, record); err != nil {
slog.ErrorContext(ctx, "failed to log", "error", err)
}
}
func SetDefault(log *ZLog) {
Logger = log
}

18
core/zlog/notification.go Normal file
View file

@ -0,0 +1,18 @@
package zlog
import (
"context"
"log/slog"
"gitlab.bareksa.com/backend/zen/core/zoptions"
)
type Notifier interface {
Notify(options ...zoptions.NotifyOption)
}
type NotificationHandler interface {
NotifyLog(ctx context.Context, record slog.Record)
}
type notifyHandler struct{}

23
core/zlog/write_locker.go Normal file
View file

@ -0,0 +1,23 @@
package zlog
import (
"io"
"sync"
)
type WriteLocker interface {
io.Writer
sync.Locker
}
func WrapLocker(w io.Writer) WriteLocker {
if wl, ok := w.(WriteLocker); ok {
return wl
}
return &writeLocker{Writer: w}
}
type writeLocker struct {
io.Writer
sync.Mutex
}

View file

@ -2,48 +2,77 @@ package zlog
import (
"context"
"errors"
"io"
"log/slog"
"sync"
"os"
"testing"
"time"
"github.com/fatih/color"
"github.com/mattn/go-isatty"
"github.com/tidwall/pretty"
"gitlab.bareksa.com/backend/zen/internal/bufferpool"
)
type WriteLocker interface {
io.Writer
sync.Locker
}
func WrapLocker(w io.Writer) WriteLocker {
if wl, ok := w.(WriteLocker); ok {
return wl
}
return &writeLocker{Writer: w}
}
type writeLocker struct {
io.Writer
sync.Mutex
}
type Log struct {
level slog.Level
bufPool *bufferPool
type ZLog struct {
bufPool *bufferpool.Pool
jsonPool *jsonHandlerPool
withAttrs []slog.Attr
withGroup []string
opts *slog.HandlerOptions
pretty bool
color bool
opts *ZLogOptions
writer WriteLocker
}
type ZLogOptions struct {
// HandlerOptions handles the options for the underlying slog.Handler.
//
// If nil, default options are used.
HandlerOptions *slog.HandlerOptions
// Pretty enables pretty-printing of log messages.
Pretty bool
// Color enables colorized output.
Color bool
// NotificationHandler is a handler that is called when a log message is
// intended to be sent to a notification service.
//
// If nil, no notification is sent.
NotificationHandler NotificationHandler
}
// New creates a new Logger that writes to w.
//
// if opts is nil, default options are used.
func New(w io.Writer, opts *ZLogOptions) *ZLog {
if w == nil {
panic(errors.New("zlog: New: w is nil"))
}
pretty := isatty.IsTerminal(os.Stderr.Fd())
if opts == nil {
opts = defaultOpts
} else {
if opts.HandlerOptions == nil {
opts.HandlerOptions = defaultHandlerOptions
} else {
opts.HandlerOptions.ReplaceAttr = wrapPrettyReplaceAttr(pretty, opts.HandlerOptions.ReplaceAttr)
}
}
wl := WrapLocker(w)
return &ZLog{
bufPool: bufferpool.New(bufferpool.SharedCap, bufferpool.BufCap),
jsonPool: newJsonHandlerPool(opts.HandlerOptions),
withAttrs: []slog.Attr{},
withGroup: []string{},
opts: opts,
writer: wl,
}
}
// Clone clones the Logger, replacing the output writer with w.
//
// If w is nil, the clone shares the original Logger's output writer.
func (log *Log) Clone(w io.Writer) *Log {
func (log *ZLog) Clone(w io.Writer) *ZLog {
var output WriteLocker
if w == nil {
output = log.writer
@ -54,26 +83,24 @@ func (log *Log) Clone(w io.Writer) *Log {
copy(withAttrs, log.withAttrs)
withGroup := make([]string, len(log.withGroup))
copy(withGroup, log.withGroup)
return &Log{
level: log.level,
return &ZLog{
withAttrs: withAttrs,
withGroup: withGroup,
opts: log.opts,
pretty: log.pretty,
bufPool: newBufferPool(),
jsonPool: newJsonHandlerPool(log.opts),
bufPool: bufferpool.New(bufferpool.SharedCap, bufferpool.BufCap),
jsonPool: newJsonHandlerPool(log.opts.HandlerOptions),
writer: output,
}
}
// Enabled implements the slog.Handler interface.
func (lo *Log) Enabled(ctx context.Context, lvl slog.Level) bool {
return lvl >= lo.level
func (lo *ZLog) Enabled(ctx context.Context, lvl slog.Level) bool {
return lvl >= lo.opts.HandlerOptions.Level.Level()
}
// Handle implements the slog.Handler interface.
func (lo *Log) Handle(ctx context.Context, record slog.Record) error {
if !lo.pretty {
func (lo *ZLog) Handle(ctx context.Context, record slog.Record) error {
if !lo.opts.Pretty {
j := lo.jsonPool.Get()
defer j.Put()
return j.Handle(ctx, record)
@ -92,9 +119,9 @@ func (lo *Log) Handle(ctx context.Context, record slog.Record) error {
}
buf := lo.bufPool.Get()
defer lo.bufPool.Put(buf)
defer buf.Close()
if record.PC != 0 && lo.opts.AddSource {
if record.PC != 0 && lo.opts.HandlerOptions.AddSource {
f := frame{Caller(record.PC).Frame()}
levelColor.Fprint(buf, f.ShortFile())
levelColor.Fprint(buf, ":")
@ -127,7 +154,7 @@ func (lo *Log) Handle(ctx context.Context, record slog.Record) error {
if jHandler.buf.Len() > 3 { // Skip empty objects like "{}\n"
jsonData := jHandler.buf.Bytes()
jsonData = pretty.Pretty(jsonData)
if lo.color {
if lo.opts.Color {
jsonData = pretty.Color(jsonData, nil)
}
buf.Write(jsonData)
@ -142,14 +169,14 @@ func (lo *Log) Handle(ctx context.Context, record slog.Record) error {
}
// WithAttrs implements the slog.Handler interface.
func (lo *Log) WithAttrs(attrs []slog.Attr) slog.Handler {
func (lo *ZLog) WithAttrs(attrs []slog.Attr) slog.Handler {
l := lo.Clone(nil)
l.withAttrs = append(l.withAttrs, attrs...)
return l
}
// WithGroup implements the slog.Handler interface.
func (lo *Log) WithGroup(name string) slog.Handler {
func (lo *ZLog) WithGroup(name string) slog.Handler {
l := lo.Clone(nil)
l.withGroup = append(l.withGroup, name)
return l
@ -157,11 +184,15 @@ func (lo *Log) WithGroup(name string) slog.Handler {
type replaceAttrFunc = func([]string, slog.Attr) slog.Attr
// wrapReplaceAttr disables adding Time, Level, Source, Message
// fields when pretty mode is enabled.
func (lo *Log) wrapReplaceAttr(f replaceAttrFunc) replaceAttrFunc {
func wrapPrettyReplaceAttr(pretty bool, f replaceAttrFunc) replaceAttrFunc {
if f == nil {
f = func(s []string, a slog.Attr) slog.Attr { return a }
}
return func(s []string, a slog.Attr) slog.Attr {
if !lo.pretty {
if len(s) > 0 {
return f(s, a)
}
if pretty {
return f(s, a)
}
switch a.Key {
@ -171,3 +202,25 @@ func (lo *Log) wrapReplaceAttr(f replaceAttrFunc) replaceAttrFunc {
return f(s, a)
}
}
func defaultLevel() slog.Leveler {
if testing.Testing() {
return slog.Level(999) // Disable logging in tests
}
return slog.LevelInfo
}
var defaultOpts = &ZLogOptions{
Pretty: isatty.IsTerminal(os.Stderr.Fd()),
Color: isatty.IsTerminal(os.Stderr.Fd()),
HandlerOptions: defaultHandlerOptions,
}
var defaultHandlerOptions = &slog.HandlerOptions{
AddSource: true,
Level: defaultLevel(),
ReplaceAttr: wrapPrettyReplaceAttr(
isatty.IsTerminal(os.Stderr.Fd()),
nil,
),
}

View file

@ -13,7 +13,7 @@ import (
"sync/atomic"
)
type BufferPool struct {
type Pool struct {
pool *sync.Pool
maxSharedCapacity uint64
currentCapacity atomic.Uint64
@ -28,7 +28,7 @@ type BufferPool struct {
// Close never returns an error. The signature is to implement io.Closer.
type Buffer struct {
*bytes.Buffer
pool *BufferPool
pool *Pool
}
// Close puts the buffer back to the pool.
@ -38,13 +38,13 @@ func (buf *Buffer) Close() error {
return nil
}
func (b *BufferPool) Get() *Buffer {
func (b *Pool) Get() *Buffer {
buf := b.pool.Get().(*Buffer)
b.currentCapacity.Add(-uint64(buf.Cap()))
return buf
}
func (b *BufferPool) Put(buf *Buffer) {
func (b *Pool) Put(buf *Buffer) {
bufCap := uint64(buf.Cap())
overloaded := b.currentCapacity.Add(bufCap) > b.maxSharedCapacity
if buf.Cap() < b.maxBufferCapacity && !overloaded {
@ -55,8 +55,8 @@ func (b *BufferPool) Put(buf *Buffer) {
}
}
func New(sharedCapacity uint64, bufferCapacity int) *BufferPool {
b := &BufferPool{
func New(sharedCapacity uint64, bufferCapacity int) *Pool {
b := &Pool{
maxSharedCapacity: sharedCapacity,
maxBufferCapacity: bufferCapacity,
}
@ -67,11 +67,11 @@ func New(sharedCapacity uint64, bufferCapacity int) *BufferPool {
}
const (
sharedCap uint64 = 64 * 1024 * 1024 // 64MB
bufCap int = 8 * 1024 * 1024 // 8MB
SharedCap uint64 = 64 * 1024 * 1024 // 64MB
BufCap int = 8 * 1024 * 1024 // 8MB
)
var pool = New(sharedCap, bufCap)
var pool = New(SharedCap, BufCap)
// Get returns a bytes.Buffer from the global pool.
func Get() *Buffer {

215
log.go Normal file
View file

@ -0,0 +1,215 @@
package zen
import (
"gitlab.bareksa.com/backend/zen/core/zlog"
)
var (
// Info logs a message at level Info.
// Use this method to log basic information like "server is starting".
//
// To log with additional information, use the Infof or Infow methods.
//
// Use Infof to log with a format.
//
// Use Infow to log with additional json fields.
Info = zlog.Info
// Infof logs a message at level Info with format.
//
// msg and args are passed to fmt.Sprintf.
//
// Use Infow to log with additional json fields.
//
// Use Infow to print structs and maps since they will
// be rendered as json.
//
// Example:
//
// zen.Infof(ctx, "user '%s' logged in", user)
Infof = zlog.Infof
// Infow logs a message with additional json fields.
//
// Use Infow to render structs and maps as json.
//
// fields is an alternating key-value sequence.
// `key` must be a string type (including not alias), and `value` can be any
// serializeable type.
//
// wrong number of fields or non-string key will cause the misplaced
// value to be paired with `!BADKEY` key.
//
// failing to serialize json value will cause the value to be replaced with
// the string `!ERROR:{reason}`.
//
// If value implements [slog.LogValuer] interface, it will be used as log fields.
// If does not, it will look if it implements [json.Marshaler] interface and
// use it to serialize.
// Then for the last resort, use normal json.Marshal.
//
// Note that primitive values are already optimized and will not use heavy reflection.
//
// Example:
//
// zen.Infow(ctx, "API called without error",
// "method", request.Method,
// "path", request.URL.Path,
// "query", request.URL.Query(),
// "duration", dur,
// )
Infow = zlog.Infow
// Debug logs a message at level Debug.
// Use this method to log detailed information for debugging purposes.
//
// To log with additional information, use the Debugf or Debugw methods.
//
// Use [Debugf] to log with a format.
//
// Use [Debugw] to log with additional json fields.
Debug = zlog.Debug
// Debugf logs a message at level Debug with format.
//
// msg and args are passed to fmt.Sprintf.
//
// Use Debugw to log with additional json fields.
//
// Use Debugw to print structs and maps since they will
// be rendered as json.
//
// Example:
//
// zen.Debugf(ctx, "user '%s' logged in", user)
Debugf = zlog.Debugf
// Debugw logs a message with additional json fields.
//
// Use Debugw to render structs and maps as json.
//
// fields is an alternating key-value sequence.
// `key` must be a string type (including not alias), and `value` can be any
// serializeable type.
//
// wrong number of fields or non-string key will cause the misplaced
// value to be paired with `!BADKEY` key.
//
// failing to serialize json value will cause the value to be replaced with
// the string `!ERROR:{reason}`.
//
// If value implements [slog.LogValuer] interface, it will be used as log fields.
// If does not, it will look if it implements [json.Marshaler] interface and
// use it to serialize.
// Then for the last resort, use normal json.Marshal.
//
// Example:
//
// zen.Debugw(ctx, "database query",
// "query", query,
// "args", args,
// )
Debugw = zlog.Debugw
// Warn logs a message at level Warn.
// Use this method to log warnings.
//
// To log with additional information, use the Warnf or Warnw methods.
//
// Use Warnf to log with a format.
//
// Use Warnw to log with additional json fields.
Warn = zlog.Warn
// Warnf logs a message at level Warn with format.
//
// msg and args are passed to fmt.Sprintf.
//
// Use Warnw to log with additional json fields.
//
// Use Warnw to print structs and maps since they will
// be rendered as json.
//
// Example:
//
// zen.Warnf(ctx, "user '%s' logged in", user)
Warnf = zlog.Warnf
// Warnw logs a message with additional json fields.
//
// Use Warnw to render structs and maps as json.
//
// fields is an alternating key-value sequence.
// `key` must be a string type (including not alias), and `value` can be any
// serializeable type.
//
// wrong number of fields or non-string key will cause the misplaced
// value to be paired with `!BADKEY` key.
//
// failing to serialize json value will cause the value to be replaced with
// the string `!ERROR:{reason}`.
//
// If value implements [slog.LogValuer] interface, it will be used as log fields.
// If does not, it will look if it implements [json.Marshaler] interface and
// use it to serialize.
// Then for the last resort, use normal json.Marshal.
Warnw = zlog.Warnw
// Error logs a message at level Error.
// Use this method to log errors.
//
// To log with additional information, use the Errorf or Errorw methods.
//
// Use Errorf to log with a format.
//
// Use Errorw to log with additional json fields.
Error = zlog.Error
// Errorf logs a message at level Error with format.
//
// msg and args are passed to fmt.Sprintf.
//
// Use Errorw to log with additional json fields.
//
// Use Errorw to print structs and maps since they will
// be rendered as json.
//
// Example:
//
// zen.Errorf(ctx, "user '%s' logged in", user)
Errorf = zlog.Errorf
// Errorw logs a message with additional json fields.
//
// Use Errorw to render structs and maps as json.
//
// fields is an alternating key-value sequence.
// `key` must be a string type (including not alias), and `value` can be any
// serializeable type.
//
// wrong number of fields or non-string key will cause the misplaced
// value to be paired with `!BADKEY` key.
//
// failing to serialize json value will cause the value to be replaced with
// the string `!ERROR:{reason}`.
//
// If value implements [slog.LogValuer] interface, it will be used as log fields.
// If does not, it will look if it implements [json.Marshaler] interface and
// use it to serialize.
// Then for the last resort, use normal json.Marshal.
//
// Example:
//
// zlog.Errorw(ctx, "RPC Error",
// "error", err,
// "requeset", request,
// )
Errorw = zlog.Errorw
// SetDefaultLogger sets the default logger that is
// used by the package level functions.
//
// SetDefaultLogger is not thread-safe and should be
// called early in the startup phase of the application.
SetDefaultLogger = zlog.SetDefault
)