tracer and logger improvements #312

Merged
vtolstov merged 1 commits from tracer-logger into v3 2024-03-06 00:57:02 +03:00
8 changed files with 513 additions and 61 deletions
Showing only changes of commit 01e05e8df6 - Show all commits

View File

@ -71,76 +71,106 @@ type Logger interface {
type Field interface{} type Field interface{}
// Info writes msg to default logger on info level // Info writes msg to default logger on info level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Info(ctx context.Context, args ...interface{}) { func Info(ctx context.Context, args ...interface{}) {
DefaultLogger.Info(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Info(ctx, args...)
} }
// Error writes msg to default logger on error level // Error writes msg to default logger on error level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Error(ctx context.Context, args ...interface{}) { func Error(ctx context.Context, args ...interface{}) {
DefaultLogger.Error(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Error(ctx, args...)
} }
// Debug writes msg to default logger on debug level // Debug writes msg to default logger on debug level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Debug(ctx context.Context, args ...interface{}) { func Debug(ctx context.Context, args ...interface{}) {
DefaultLogger.Debug(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Debug(ctx, args...)
} }
// Warn writes msg to default logger on warn level // Warn writes msg to default logger on warn level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Warn(ctx context.Context, args ...interface{}) { func Warn(ctx context.Context, args ...interface{}) {
DefaultLogger.Warn(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Warn(ctx, args...)
} }
// Trace writes msg to default logger on trace level // Trace writes msg to default logger on trace level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Trace(ctx context.Context, args ...interface{}) { func Trace(ctx context.Context, args ...interface{}) {
DefaultLogger.Trace(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Trace(ctx, args...)
} }
// Fatal writes msg to default logger on fatal level // Fatal writes msg to default logger on fatal level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Fatal(ctx context.Context, args ...interface{}) { func Fatal(ctx context.Context, args ...interface{}) {
DefaultLogger.Fatal(ctx, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Fatal(ctx, args...)
} }
// Infof writes formatted msg to default logger on info level // Infof writes formatted msg to default logger on info level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Infof(ctx context.Context, msg string, args ...interface{}) { func Infof(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Infof(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Infof(ctx, msg, args...)
} }
// Errorf writes formatted msg to default logger on error level // Errorf writes formatted msg to default logger on error level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Errorf(ctx context.Context, msg string, args ...interface{}) { func Errorf(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Errorf(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Errorf(ctx, msg, args...)
} }
// Debugf writes formatted msg to default logger on debug level // Debugf writes formatted msg to default logger on debug level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Debugf(ctx context.Context, msg string, args ...interface{}) { func Debugf(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Debugf(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Debugf(ctx, msg, args...)
} }
// Warnf writes formatted msg to default logger on warn level // Warnf writes formatted msg to default logger on warn level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Warnf(ctx context.Context, msg string, args ...interface{}) { func Warnf(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Warnf(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Warnf(ctx, msg, args...)
} }
// Tracef writes formatted msg to default logger on trace level // Tracef writes formatted msg to default logger on trace level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Tracef(ctx context.Context, msg string, args ...interface{}) { func Tracef(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Tracef(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Tracef(ctx, msg, args...)
} }
// Fatalf writes formatted msg to default logger on fatal level // Fatalf writes formatted msg to default logger on fatal level
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Fatalf(ctx context.Context, msg string, args ...interface{}) { func Fatalf(ctx context.Context, msg string, args ...interface{}) {
DefaultLogger.Fatalf(ctx, msg, args...) DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Fatalf(ctx, msg, args...)
} }
// V returns true if passed level enabled in default logger // V returns true if passed level enabled in default logger
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func V(level Level) bool { func V(level Level) bool {
return DefaultLogger.V(level) return DefaultLogger.V(level)
} }
// Init initialize logger // Init initialize logger
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Init(opts ...Option) error { func Init(opts ...Option) error {
return DefaultLogger.Init(opts...) return DefaultLogger.Init(opts...)
} }
// Fields create logger with specific fields // Fields create logger with specific fields
//
// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
func Fields(fields ...interface{}) Logger { func Fields(fields ...interface{}) Logger {
return DefaultLogger.Fields(fields...) return DefaultLogger.Fields(fields...)
} }

View File

@ -20,6 +20,7 @@ type Options struct {
Name string Name string
// Fields holds additional metadata // Fields holds additional metadata
Fields []interface{} Fields []interface{}
// CallerSkipCount number of frmaes to skip // CallerSkipCount number of frmaes to skip
CallerSkipCount int CallerSkipCount int
// ContextAttrFuncs contains funcs that executed before log func on context // ContextAttrFuncs contains funcs that executed before log func on context
@ -28,14 +29,18 @@ type Options struct {
TimeKey string TimeKey string
// LevelKey is the key used for the level of the log call // LevelKey is the key used for the level of the log call
LevelKey string LevelKey string
// ErroreKey is the key used for the error of the log call
ErrorKey string
// MessageKey is the key used for the message of the log call // MessageKey is the key used for the message of the log call
MessageKey string MessageKey string
// SourceKey is the key used for the source file and line of the log call // SourceKey is the key used for the source file and line of the log call
SourceKey string SourceKey string
// StacktraceKey is the key used for the stacktrace // StacktraceKey is the key used for the stacktrace
StacktraceKey string StacktraceKey string
// Stacktrace controls writing of stacktaces on error // AddStacktrace controls writing of stacktaces on error
Stacktrace bool AddStacktrace bool
// AddSource enabled writing source file and position in log
AddSource bool
// The logging level the logger should log // The logging level the logger should log
Level Level Level Level
} }
@ -49,6 +54,7 @@ func NewOptions(opts ...Option) Options {
CallerSkipCount: DefaultCallerSkipCount, CallerSkipCount: DefaultCallerSkipCount,
Context: context.Background(), Context: context.Background(),
ContextAttrFuncs: DefaultContextAttrFuncs, ContextAttrFuncs: DefaultContextAttrFuncs,
AddSource: true,
} }
WithMicroKeys()(&options) WithMicroKeys()(&options)
@ -56,6 +62,7 @@ func NewOptions(opts ...Option) Options {
for _, o := range opts { for _, o := range opts {
o(&options) o(&options)
} }
return options return options
} }
@ -87,10 +94,17 @@ func WithOutput(out io.Writer) Option {
} }
} }
// WithStacktrace controls writing stacktrace on error // WitAddStacktrace controls writing stacktrace on error
func WithStacktrace(v bool) Option { func WithAddStacktrace(v bool) Option {
return func(o *Options) { return func(o *Options) {
o.Stacktrace = v o.AddStacktrace = v
}
}
// WitAddSource controls writing source file and pos in log
func WithAddSource(v bool) Option {
return func(o *Options) {
o.AddSource = v
} }
} }
@ -122,6 +136,7 @@ func WithZapKeys() Option {
o.MessageKey = "msg" o.MessageKey = "msg"
o.SourceKey = "caller" o.SourceKey = "caller"
o.StacktraceKey = "stacktrace" o.StacktraceKey = "stacktrace"
o.ErrorKey = "error"
} }
} }
@ -132,6 +147,7 @@ func WithZerologKeys() Option {
o.MessageKey = "message" o.MessageKey = "message"
o.SourceKey = "caller" o.SourceKey = "caller"
o.StacktraceKey = "stacktrace" o.StacktraceKey = "stacktrace"
o.ErrorKey = "error"
} }
} }
@ -142,6 +158,7 @@ func WithSlogKeys() Option {
o.MessageKey = slog.MessageKey o.MessageKey = slog.MessageKey
o.SourceKey = slog.SourceKey o.SourceKey = slog.SourceKey
o.StacktraceKey = "stacktrace" o.StacktraceKey = "stacktrace"
o.ErrorKey = "error"
} }
} }
@ -152,5 +169,6 @@ func WithMicroKeys() Option {
o.MessageKey = "msg" o.MessageKey = "msg"
o.SourceKey = "caller" o.SourceKey = "caller"
o.StacktraceKey = "stacktrace" o.StacktraceKey = "stacktrace"
o.ErrorKey = "error"
} }
} }

View File

@ -82,9 +82,9 @@ func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger {
l.leveler = new(slog.LevelVar) l.leveler = new(slog.LevelVar)
handleOpt := &slog.HandlerOptions{ handleOpt := &slog.HandlerOptions{
ReplaceAttr: s.renameAttr, ReplaceAttr: l.renameAttr,
Level: l.leveler, Level: l.leveler,
AddSource: true, AddSource: l.opts.AddSource,
} }
l.leveler.Set(loggerToSlogLevel(l.opts.Level)) l.leveler.Set(loggerToSlogLevel(l.opts.Level))
handler := slog.NewJSONHandler(options.Out, handleOpt) handler := slog.NewJSONHandler(options.Out, handleOpt)
@ -109,22 +109,22 @@ func (s *slogLogger) Options() logger.Options {
func (s *slogLogger) Fields(attrs ...interface{}) logger.Logger { func (s *slogLogger) Fields(attrs ...interface{}) logger.Logger {
s.mu.RLock() s.mu.RLock()
nl := &slogLogger{opts: s.opts} l := &slogLogger{opts: s.opts}
nl.leveler = new(slog.LevelVar) l.leveler = new(slog.LevelVar)
nl.leveler.Set(s.leveler.Level()) l.leveler.Set(s.leveler.Level())
handleOpt := &slog.HandlerOptions{ handleOpt := &slog.HandlerOptions{
ReplaceAttr: nl.renameAttr, ReplaceAttr: l.renameAttr,
Level: nl.leveler, Level: l.leveler,
AddSource: true, AddSource: l.opts.AddSource,
} }
handler := slog.NewJSONHandler(s.opts.Out, handleOpt) handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
nl.slog = slog.New(handler).With(attrs...) l.slog = slog.New(handler).With(attrs...)
s.mu.RUnlock() s.mu.RUnlock()
return nl return l
} }
func (s *slogLogger) Init(opts ...logger.Option) error { func (s *slogLogger) Init(opts ...logger.Option) error {
@ -142,7 +142,7 @@ func (s *slogLogger) Init(opts ...logger.Option) error {
handleOpt := &slog.HandlerOptions{ handleOpt := &slog.HandlerOptions{
ReplaceAttr: s.renameAttr, ReplaceAttr: s.renameAttr,
Level: s.leveler, Level: s.leveler,
AddSource: true, AddSource: s.opts.AddSource,
} }
s.leveler.Set(loggerToSlogLevel(s.opts.Level)) s.leveler.Set(loggerToSlogLevel(s.opts.Level))
handler := slog.NewJSONHandler(s.opts.Out, handleOpt) handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
@ -160,16 +160,35 @@ func (s *slogLogger) Log(ctx context.Context, lvl logger.Level, attrs ...interfa
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), fmt.Sprintf("%s", attrs[0]), pcs[0])
if s.opts.Stacktrace && lvl == logger.ErrorLevel { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
if s.opts.AddStacktrace && lvl == logger.ErrorLevel {
stackInfo := make([]byte, 1024*1024) stackInfo := make([]byte, 1024*1024)
if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 { if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1) traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
if len(traceLines) != 0 { if len(traceLines) != 0 {
r.AddAttrs(slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1])) attrs = append(attrs, slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1]))
} }
} }
} }
// r.Add(attrs[1:]...) r.Add(attrs[1:]...)
r.Attrs(func(a slog.Attr) bool {
if a.Key == s.opts.ErrorKey {
if span, ok := tracer.SpanFromContext(ctx); ok {
span.SetStatus(tracer.SpanStatusError, a.Value.String())
return false
}
}
return true
})
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -179,17 +198,36 @@ func (s *slogLogger) Logf(ctx context.Context, lvl logger.Level, msg string, att
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), msg, pcs[0])
if s.opts.Stacktrace && lvl == logger.ErrorLevel { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
if s.opts.AddStacktrace && lvl == logger.ErrorLevel {
stackInfo := make([]byte, 1024*1024) stackInfo := make([]byte, 1024*1024)
if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 { if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1) traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
if len(traceLines) != 0 { if len(traceLines) != 0 {
r.AddAttrs(slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1])) attrs = append(attrs, (slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1])))
} }
} }
} }
// r.Add(attrs...) r.Add(attrs[1:]...)
r.Attrs(func(a slog.Attr) bool {
if a.Key == s.opts.ErrorKey {
if span, ok := tracer.SpanFromContext(ctx); ok {
span.SetStatus(tracer.SpanStatusError, a.Value.String())
return false
}
}
return true
})
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -200,7 +238,17 @@ func (s *slogLogger) Info(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -210,8 +258,18 @@ func (s *slogLogger) Infof(ctx context.Context, msg string, attrs ...interface{}
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -222,7 +280,17 @@ func (s *slogLogger) Debug(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -232,8 +300,18 @@ func (s *slogLogger) Debugf(ctx context.Context, msg string, attrs ...interface{
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -244,7 +322,17 @@ func (s *slogLogger) Trace(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug-1, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug-1, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -254,8 +342,18 @@ func (s *slogLogger) Tracef(ctx context.Context, msg string, attrs ...interface{
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug-1, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug-1, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -266,18 +364,28 @@ func (s *slogLogger) Error(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
if s.opts.Stacktrace { attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
if s.opts.AddStacktrace {
stackInfo := make([]byte, 1024*1024) stackInfo := make([]byte, 1024*1024)
if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 { if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1) traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
if len(traceLines) != 0 { if len(traceLines) != 0 {
r.AddAttrs(slog.String("stacktrace", traceLines[len(traceLines)-1])) attrs = append(attrs, slog.String("stacktrace", traceLines[len(traceLines)-1]))
} }
} }
} }
r.Add(attrs[1:]...)
r.Attrs(func(a slog.Attr) bool { r.Attrs(func(a slog.Attr) bool {
if a.Key == "error" { if a.Key == s.opts.ErrorKey {
if span, ok := tracer.SpanFromContext(ctx); ok { if span, ok := tracer.SpanFromContext(ctx); ok {
span.SetStatus(tracer.SpanStatusError, a.Value.String()) span.SetStatus(tracer.SpanStatusError, a.Value.String())
return false return false
@ -294,19 +402,29 @@ func (s *slogLogger) Errorf(ctx context.Context, msg string, attrs ...interface{
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
if s.opts.Stacktrace { attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
if s.opts.AddStacktrace {
stackInfo := make([]byte, 1024*1024) stackInfo := make([]byte, 1024*1024)
if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 { if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1) traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
if len(traceLines) != 0 { if len(traceLines) != 0 {
r.AddAttrs(slog.String("stacktrace", traceLines[len(traceLines)-1])) attrs = append(attrs, slog.String("stacktrace", traceLines[len(traceLines)-1]))
} }
} }
} }
r.Add(attrs...)
r.Attrs(func(a slog.Attr) bool { r.Attrs(func(a slog.Attr) bool {
if a.Key == "error" { if a.Key == s.opts.ErrorKey {
if span, ok := tracer.SpanFromContext(ctx); ok { if span, ok := tracer.SpanFromContext(ctx); ok {
span.SetStatus(tracer.SpanStatusError, a.Value.String()) span.SetStatus(tracer.SpanStatusError, a.Value.String())
return false return false
@ -324,7 +442,17 @@ func (s *slogLogger) Fatal(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError+1, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError+1, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
os.Exit(1) os.Exit(1)
} }
@ -335,8 +463,18 @@ func (s *slogLogger) Fatalf(ctx context.Context, msg string, attrs ...interface{
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError+1, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError+1, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
os.Exit(1) os.Exit(1)
} }
@ -348,7 +486,17 @@ func (s *slogLogger) Warn(ctx context.Context, attrs ...interface{}) {
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelWarn, fmt.Sprintf("%s", attrs[0]), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelWarn, fmt.Sprintf("%s", attrs[0]), pcs[0])
// r.Add(attrs[1:]...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
@ -358,8 +506,18 @@ func (s *slogLogger) Warnf(ctx context.Context, msg string, attrs ...interface{}
} }
var pcs [1]uintptr var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelWarn, fmt.Sprintf(msg, attrs...), pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelWarn, msg, pcs[0])
// r.Add(attrs...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)...)
}
for idx, attr := range attrs {
if ve, ok := attr.(error); ok && ve != nil {
attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
break
}
}
r.Add(attrs[1:]...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }

View File

@ -3,6 +3,7 @@ package slog
import ( import (
"bytes" "bytes"
"context" "context"
"fmt"
"log" "log"
"testing" "testing"
@ -17,10 +18,30 @@ func TestError(t *testing.T) {
t.Fatal(err) t.Fatal(err)
} }
l.Error(ctx, "message") l.Error(ctx, "message", fmt.Errorf("error message"))
if !bytes.Contains(buf.Bytes(), []byte(`"stacktrace":"`)) { if !bytes.Contains(buf.Bytes(), []byte(`"stacktrace":"`)) {
t.Fatalf("logger stacktrace not works, buf contains: %s", buf.Bytes()) t.Fatalf("logger stacktrace not works, buf contains: %s", buf.Bytes())
} }
if !bytes.Contains(buf.Bytes(), []byte(`"error":"`)) {
t.Fatalf("logger error not works, buf contains: %s", buf.Bytes())
}
}
func TestErrorf(t *testing.T) {
ctx := context.TODO()
buf := bytes.NewBuffer(nil)
l := NewLogger(logger.WithLevel(logger.ErrorLevel), logger.WithOutput(buf), logger.WithStacktrace(true))
if err := l.Init(); err != nil {
t.Fatal(err)
}
l.Errorf(ctx, "message", fmt.Errorf("error message"))
if !bytes.Contains(buf.Bytes(), []byte(`"stacktrace":"`)) {
t.Fatalf("logger stacktrace not works, buf contains: %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"error":"`)) {
t.Fatalf("logger error not works, buf contains: %s", buf.Bytes())
}
} }
func TestContext(t *testing.T) { func TestContext(t *testing.T) {

139
tracer/memory/memory.go Normal file
View File

@ -0,0 +1,139 @@
package memory
import (
"context"
"time"
"go.unistack.org/micro/v3/tracer"
"go.unistack.org/micro/v3/util/id"
)
var _ tracer.Tracer = (*Tracer)(nil)
type Tracer struct {
opts tracer.Options
spans []tracer.Span
}
func (t *Tracer) Spans() []tracer.Span {
return t.spans
}
func (t *Tracer) Start(ctx context.Context, name string, opts ...tracer.SpanOption) (context.Context, tracer.Span) {
options := tracer.NewSpanOptions(opts...)
span := &Span{
name: name,
ctx: ctx,
tracer: t,
kind: options.Kind,
startTime: time.Now(),
}
span.spanID.s, _ = id.New()
span.traceID.s, _ = id.New()
if span.ctx == nil {
span.ctx = context.Background()
}
t.spans = append(t.spans, span)
return tracer.NewSpanContext(ctx, span), span
}
func (t *Tracer) Flush(_ context.Context) error {
return nil
}
func (t *Tracer) Init(opts ...tracer.Option) error {
for _, o := range opts {
o(&t.opts)
}
return nil
}
func (t *Tracer) Name() string {
return t.opts.Name
}
type noopStringer struct {
s string
}
func (s noopStringer) String() string {
return s.s
}
type Span struct {
ctx context.Context
tracer tracer.Tracer
name string
statusMsg string
startTime time.Time
finishTime time.Time
traceID noopStringer
spanID noopStringer
events []*Event
labels []interface{}
logs []interface{}
kind tracer.SpanKind
status tracer.SpanStatus
}
func (s *Span) Finish(_ ...tracer.SpanOption) {
s.finishTime = time.Now()
}
func (s *Span) Context() context.Context {
return s.ctx
}
func (s *Span) Tracer() tracer.Tracer {
return s.tracer
}
type Event struct {
name string
labels []interface{}
}
func (s *Span) AddEvent(name string, opts ...tracer.EventOption) {
options := tracer.NewEventOptions(opts...)
s.events = append(s.events, &Event{name: name, labels: options.Labels})
}
func (s *Span) SetName(name string) {
s.name = name
}
func (s *Span) AddLogs(kv ...interface{}) {
s.logs = append(s.logs, kv...)
}
func (s *Span) AddLabels(kv ...interface{}) {
s.labels = append(s.labels, kv...)
}
func (s *Span) Kind() tracer.SpanKind {
return s.kind
}
func (s *Span) TraceID() string {
return s.traceID.String()
}
func (s *Span) SpanID() string {
return s.spanID.String()
}
func (s *Span) Status() (tracer.SpanStatus, string) {
return s.status, s.statusMsg
}
func (s *Span) SetStatus(st tracer.SpanStatus, msg string) {
s.status = st
s.statusMsg = msg
}
// NewTracer returns new memory tracer
func NewTracer(opts ...tracer.Option) *Tracer {
return &Tracer{
opts: tracer.NewOptions(opts...),
}
}

View File

@ -0,0 +1,38 @@
package memory
import (
"bytes"
"context"
"fmt"
"strings"
"testing"
"go.unistack.org/micro/v3/logger"
"go.unistack.org/micro/v3/logger/slog"
"go.unistack.org/micro/v3/tracer"
)
func TestLoggerWithTracer(t *testing.T) {
ctx := context.TODO()
buf := bytes.NewBuffer(nil)
logger.DefaultLogger = slog.NewLogger(logger.WithOutput(buf))
if err := logger.Init(); err != nil {
t.Fatal(err)
}
var span tracer.Span
tr := NewTracer()
ctx, span = tr.Start(ctx, "test1")
logger.Error(ctx, "my test error", fmt.Errorf("error"))
if !strings.Contains(buf.String(), span.TraceID()) {
t.Fatalf("log does not contains trace id: %s", buf.Bytes())
}
_, _ = tr.Start(ctx, "test2")
for _, s := range tr.Spans() {
_ = s
}
}

View File

@ -2,6 +2,8 @@ package tracer
import ( import (
"context" "context"
"go.unistack.org/micro/v3/util/id"
) )
var _ Tracer = (*noopTracer)(nil) var _ Tracer = (*noopTracer)(nil)
@ -24,6 +26,8 @@ func (t *noopTracer) Start(ctx context.Context, name string, opts ...SpanOption)
labels: options.Labels, labels: options.Labels,
kind: options.Kind, kind: options.Kind,
} }
span.spanID.s, _ = id.New()
span.traceID.s, _ = id.New()
if span.ctx == nil { if span.ctx == nil {
span.ctx = context.Background() span.ctx = context.Background()
} }
@ -31,6 +35,14 @@ func (t *noopTracer) Start(ctx context.Context, name string, opts ...SpanOption)
return NewSpanContext(ctx, span), span return NewSpanContext(ctx, span), span
} }
type noopStringer struct {
s string
}
func (s noopStringer) String() string {
return s.s
}
func (t *noopTracer) Flush(ctx context.Context) error { func (t *noopTracer) Flush(ctx context.Context) error {
return nil return nil
} }
@ -56,6 +68,8 @@ type noopSpan struct {
tracer Tracer tracer Tracer
name string name string
statusMsg string statusMsg string
traceID noopStringer
spanID noopStringer
events []*noopEvent events []*noopEvent
labels []interface{} labels []interface{}
logs []interface{} logs []interface{}
@ -63,7 +77,15 @@ type noopSpan struct {
status SpanStatus status SpanStatus
} }
func (s *noopSpan) Finish(opts ...SpanOption) { func (s *noopSpan) TraceID() string {
return s.traceID.String()
}
func (s *noopSpan) SpanID() string {
return s.spanID.String()
}
func (s *noopSpan) Finish(_ ...SpanOption) {
} }
func (s *noopSpan) Context() context.Context { func (s *noopSpan) Context() context.Context {

View File

@ -5,11 +5,33 @@ import (
"context" "context"
"fmt" "fmt"
"sort" "sort"
"go.unistack.org/micro/v3/logger"
) )
// DefaultTracer is the global default tracer // DefaultTracer is the global default tracer
var DefaultTracer = NewTracer() var DefaultTracer = NewTracer()
var (
// TraceIDKey is the key used for the trace id in the log call
TraceIDKey = "trace-id"
// SpanIDKey is the key used for the span id in the log call
SpanIDKey = "span-id"
)
func init() {
logger.DefaultContextAttrFuncs = append(logger.DefaultContextAttrFuncs,
func(ctx context.Context) []interface{} {
if span, ok := SpanFromContext(ctx); ok {
return []interface{}{
TraceIDKey, span.TraceID(),
SpanIDKey, span.SpanID(),
}
}
return nil
})
}
// Tracer is an interface for distributed tracing // Tracer is an interface for distributed tracing
type Tracer interface { type Tracer interface {
// Name return tracer name // Name return tracer name
@ -43,6 +65,10 @@ type Span interface {
AddLogs(kv ...interface{}) AddLogs(kv ...interface{})
// Kind returns span kind // Kind returns span kind
Kind() SpanKind Kind() SpanKind
// TraceID returns trace id
TraceID() string
// SpanID returns span id
SpanID() string
} }
// sort labels alphabeticaly by label name // sort labels alphabeticaly by label name