chore(logging): Refactor code (#15556)

This commit is contained in:
Sven Rebhan 2024-06-25 09:48:56 -04:00 committed by GitHub
parent 6da035ba44
commit 32a5b44d7b
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
15 changed files with 357 additions and 276 deletions

View File

@ -84,7 +84,7 @@ To migrate the file 'mysettings.conf' use
},
Action: func(cCtx *cli.Context) error {
// Setup logging
logConfig := logger.Config{Debug: cCtx.Bool("debug")}
logConfig := &logger.Config{Debug: cCtx.Bool("debug")}
if err := logger.SetupLogging(logConfig); err != nil {
return err
}

View File

@ -137,7 +137,7 @@ func runApp(args []string, outputBuffer io.Writer, pprof Server, c TelegrafConfi
return fmt.Errorf("unknown command %q", cCtx.Args().First())
}
err := logger.SetupLogging(logger.Config{})
err := logger.SetupLogging(&logger.Config{})
if err != nil {
return err
}

View File

@ -336,7 +336,7 @@ func (t *Telegraf) runAgent(ctx context.Context, reloadConfig bool) error {
}
// Setup logging as configured.
logConfig := logger.Config{
logConfig := &logger.Config{
Debug: c.Agent.Debug || t.debug,
Quiet: c.Agent.Quiet || t.quiet,
LogTarget: c.Agent.LogTarget,

View File

@ -16,8 +16,6 @@ import (
"golang.org/x/sys/windows/svc"
"golang.org/x/sys/windows/svc/eventlog"
"golang.org/x/sys/windows/svc/mgr"
"github.com/influxdata/telegraf/logger"
)
func getLockedMemoryLimit() uint64 {
@ -31,11 +29,6 @@ func getLockedMemoryLimit() uint64 {
}
func (t *Telegraf) Run() error {
// Register the eventlog logging target for windows.
if err := logger.RegisterEventLogger(t.serviceName); err != nil {
return err
}
// Process the service commands
if t.service != "" {
fmt.Println("The use of --service is deprecated, please use the 'service' command instead!")

View File

@ -343,7 +343,6 @@ func printPluginDeprecationNotice(level telegraf.LogLevel, name string, info tel
switch level {
case telegraf.Warn, telegraf.Error:
prefix := deprecationPrefix(level)
log.Printf(
"%s: Plugin %q deprecated since version %s and will be removed in %s: %s",
prefix, name, info.Since, info.RemovalIn, info.Notice,

View File

@ -75,10 +75,6 @@ func TestPluginDeprecation(t *testing.T) {
}
if tt.expected != "" {
// Remove the time for comparison
parts := strings.SplitN(actual, " ", 3)
require.Len(t, parts, 3)
actual = parts[2]
expected := deprecationPrefix(tt.level) + ": " + tt.expected
require.Equal(t, expected, actual)
} else {
@ -160,10 +156,6 @@ func TestPluginOptionDeprecation(t *testing.T) {
}
if tt.expected != "" {
// Remove the time for comparison
parts := strings.SplitN(actual, " ", 3)
require.Len(t, parts, 3)
actual = parts[2]
expected := deprecationPrefix(tt.expectedLevel) + ": " + tt.expected
require.Equal(t, expected, actual)
} else {
@ -259,9 +251,7 @@ func TestPluginOptionValueDeprecation(t *testing.T) {
}, timeout, 100*time.Millisecond)
// Remove the time for comparison
parts := strings.SplitN(strings.TrimSpace(buf.String()), " ", 3)
require.Len(t, parts, 3)
actual := parts[2]
actual := strings.TrimSpace(buf.String())
expected := deprecationPrefix(tt.expectedLevel) + ": " + tt.expected
require.Equal(t, expected, actual)
} else {

View File

@ -1,25 +0,0 @@
package logger
import "time"
// Config contains the log configuration settings
type Config struct {
// will set the log level to DEBUG
Debug bool
//will set the log level to ERROR
Quiet bool
//stderr, stdout, file or eventlog (Windows only)
LogTarget string
// will direct the logging output to a file. Empty string is
// interpreted as stderr. If there is an error opening the file the
// logger will fall back to stderr
Logfile string
// will rotate when current file at the specified time interval
RotationInterval time.Duration
// will rotate when current file size exceeds this parameter.
RotationMaxSize int64
// maximum rotated files to keep (older ones will be deleted)
RotationMaxArchives int
// pick a timezone to use when logging. or type 'local' for local time.
LogWithTimezone string
}

View File

@ -5,22 +5,28 @@ import (
"io"
"log"
"os"
"regexp"
"strings"
"time"
"github.com/influxdata/telegraf"
"github.com/influxdata/telegraf/internal/rotate"
"github.com/influxdata/wlog"
)
var prefixRegex = regexp.MustCompile("^[DIWE]!")
const (
LogTargetFile = "file"
LogTargetStderr = "stderr"
)
type defaultLogger struct {
Category string
Name string
Alias string
LogLevel telegraf.LogLevel
prefix string
onError []func()
writer io.Writer
internalWriter io.Writer
timezone *time.Location
@ -39,6 +45,32 @@ func (t *defaultLogger) Write(b []byte) (n int, err error) {
return t.writer.Write(line)
}
// NewLogger creates a new logger instance
func (t *defaultLogger) New(category, name, alias string) telegraf.Logger {
var prefix string
if category != "" {
prefix = "[" + category
if name != "" {
prefix += "." + name
}
if alias != "" {
prefix += "::" + alias
}
prefix += "] "
}
return &defaultLogger{
Category: category,
Name: name,
Alias: alias,
LogLevel: t.LogLevel,
prefix: prefix,
writer: t.writer,
internalWriter: t.internalWriter,
timezone: t.timezone,
}
}
func (t *defaultLogger) Close() error {
// avoid closing stderr
if t.internalWriter == os.Stderr {
@ -52,49 +84,113 @@ func (t *defaultLogger) Close() error {
return closer.Close()
}
// newTelegrafWriter returns a logging-wrapped writer.
func newTelegrafWriter(w io.Writer, c Config) (*defaultLogger, error) {
timezoneName := c.LogWithTimezone
if strings.EqualFold(timezoneName, "local") {
timezoneName = "Local"
// OnErr defines a callback that triggers only when errors are about to be written to the log
func (t *defaultLogger) RegisterErrorCallback(f func()) {
t.onError = append(t.onError, f)
}
tz, err := time.LoadLocation(timezoneName)
if err != nil {
return nil, errors.New("error while setting logging timezone: " + err.Error())
func (t *defaultLogger) Level() telegraf.LogLevel {
return t.LogLevel
}
return &defaultLogger{
writer: wlog.NewWriter(w),
internalWriter: w,
timezone: tz,
}, nil
// Errorf logs an error message, patterned after log.Printf.
func (t *defaultLogger) Errorf(format string, args ...interface{}) {
log.Printf("E! "+t.prefix+format, args...)
for _, f := range t.onError {
f()
}
}
func createStderrLogger(cfg Config) (io.WriteCloser, error) {
return newTelegrafWriter(os.Stderr, cfg)
// Error logs an error message, patterned after log.Print.
func (t *defaultLogger) Error(args ...interface{}) {
for _, f := range t.onError {
f()
}
log.Print(append([]interface{}{"E! " + t.prefix}, args...)...)
}
func createFileLogger(cfg Config) (io.WriteCloser, error) {
if cfg.Logfile == "" {
return createStderrLogger(cfg)
// Debugf logs a debug message, patterned after log.Printf.
func (t *defaultLogger) Debugf(format string, args ...interface{}) {
log.Printf("D! "+t.prefix+" "+format, args...)
}
writer, err := rotate.NewFileWriter(
// Debug logs a debug message, patterned after log.Print.
func (t *defaultLogger) Debug(args ...interface{}) {
log.Print(append([]interface{}{"D! " + t.prefix}, args...)...)
}
// Warnf logs a warning message, patterned after log.Printf.
func (t *defaultLogger) Warnf(format string, args ...interface{}) {
log.Printf("W! "+t.prefix+format, args...)
}
// Warn logs a warning message, patterned after log.Print.
func (t *defaultLogger) Warn(args ...interface{}) {
log.Print(append([]interface{}{"W! " + t.prefix}, args...)...)
}
// Infof logs an information message, patterned after log.Printf.
func (t *defaultLogger) Infof(format string, args ...interface{}) {
log.Printf("I! "+t.prefix+format, args...)
}
// Info logs an information message, patterned after log.Print.
func (t *defaultLogger) Info(args ...interface{}) {
log.Print(append([]interface{}{"I! " + t.prefix}, args...)...)
}
func createDefaultLogger(cfg *Config) (logger, error) {
log.SetFlags(0)
// Set the log-level
switch cfg.logLevel {
case telegraf.Error:
wlog.SetLevel(wlog.ERROR)
case telegraf.Warn:
wlog.SetLevel(wlog.WARN)
case telegraf.Info:
wlog.SetLevel(wlog.INFO)
case telegraf.Debug:
wlog.SetLevel(wlog.DEBUG)
}
// Setup the writer target
var writer io.Writer = os.Stderr
if cfg.LogTarget == "file" && cfg.Logfile != "" {
w, err := rotate.NewFileWriter(
cfg.Logfile,
cfg.RotationInterval,
cfg.RotationMaxSize,
cfg.RotationMaxArchives,
)
if err != nil {
log.Printf("E! Unable to open %s (%s), using stderr", cfg.Logfile, err)
return createStderrLogger(cfg)
return nil, err
}
writer = w
}
return newTelegrafWriter(writer, cfg)
// Get configured timezone
timezoneName := cfg.LogWithTimezone
if strings.EqualFold(timezoneName, "local") {
timezoneName = "Local"
}
tz, err := time.LoadLocation(timezoneName)
if err != nil {
return nil, errors.New("error while setting logging timezone: " + err.Error())
}
// Setup the logger
l := &defaultLogger{
writer: wlog.NewWriter(writer),
internalWriter: writer,
timezone: tz,
}
log.SetOutput(l)
return l, nil
}
func init() {
registerLogger(LogTargetStderr, createStderrLogger)
registerLogger(LogTargetFile, createFileLogger)
add("stderr", createDefaultLogger)
add("file", createDefaultLogger)
}

View File

@ -1,13 +1,15 @@
package logger
import (
"bytes"
"io"
"log"
"os"
"path/filepath"
"testing"
"github.com/stretchr/testify/require"
"github.com/influxdata/wlog"
)
func TestWriteLogToFile(t *testing.T) {
@ -107,7 +109,7 @@ func TestWriteToFileInRotation(t *testing.T) {
cfg.RotationMaxSize = 30
require.NoError(t, SetupLogging(cfg))
// Close the writer here, otherwise the temp folder cannot be deleted because the current log file is in use.
t.Cleanup(func() { require.NoError(t, actualLogger.Close()) })
t.Cleanup(func() { require.NoError(t, instance.Close()) })
log.Printf("I! TEST 1") // Writes 31 bytes, will rotate
log.Printf("I! TEST") // Writes 29 byes, no rotation expected
@ -117,46 +119,42 @@ func TestWriteToFileInRotation(t *testing.T) {
}
func TestLogTargetSettings(t *testing.T) {
actualLogger = nil
cfg := Config{
instance = nil
cfg := &Config{
LogTarget: "",
Quiet: true,
}
err := SetupLogging(cfg)
require.NoError(t, err)
logger, isTelegrafLogger := actualLogger.(*defaultLogger)
require.NoError(t, SetupLogging(cfg))
logger, isTelegrafLogger := instance.(*defaultLogger)
require.True(t, isTelegrafLogger)
require.Equal(t, logger.internalWriter, os.Stderr)
cfg = Config{
cfg = &Config{
LogTarget: "stderr",
Quiet: true,
}
err = SetupLogging(cfg)
require.NoError(t, err)
logger, isTelegrafLogger = actualLogger.(*defaultLogger)
require.NoError(t, SetupLogging(cfg))
logger, isTelegrafLogger = instance.(*defaultLogger)
require.True(t, isTelegrafLogger)
require.Equal(t, logger.internalWriter, os.Stderr)
}
func BenchmarkTelegrafLogWrite(b *testing.B) {
var msg = []byte("test")
var buf bytes.Buffer
w, err := newTelegrafWriter(&buf, Config{})
if err != nil {
panic("Unable to create log writer.")
}
l, err := createDefaultLogger(&Config{})
require.NoError(b, err)
// Discard all logging output
dl := l.(*defaultLogger)
dl.writer = wlog.NewWriter(io.Discard)
dl.internalWriter = io.Discard
for i := 0; i < b.N; i++ {
buf.Reset()
_, err = w.Write(msg)
if err != nil {
panic("Unable to write message")
}
dl.Info("test")
}
}
func createBasicConfig(filename string) Config {
return Config{
func createBasicConfig(filename string) *Config {
return &Config{
Logfile: filename,
LogTarget: "file",
RotationMaxArchives: -1,

View File

@ -3,11 +3,11 @@
package logger
import (
"io"
"fmt"
"log"
"strings"
"github.com/influxdata/wlog"
"github.com/influxdata/telegraf"
"golang.org/x/sys/windows/svc/eventlog"
)
@ -17,63 +17,149 @@ const (
eidError = 3
)
type eventWriter struct {
logger *eventlog.Log
type eventLogger struct {
Category string
Name string
Alias string
LogLevel telegraf.LogLevel
prefix string
onError []func()
eventlog *eventlog.Log
}
func (w *eventWriter) Write(b []byte) (int, error) {
func (e *eventLogger) Write(b []byte) (int, error) {
loc := prefixRegex.FindIndex(b)
n := len(b)
if loc == nil {
return n, w.logger.Info(1, string(b))
return n, e.eventlog.Info(1, string(b))
}
// Skip empty log messages
if n <= 2 {
return 0, nil
}
//skip empty log messages
if n > 2 {
line := strings.Trim(string(b[loc[1]:]), " \t\r\n")
switch rune(b[loc[0]]) {
case 'I':
return n, w.logger.Info(eidInfo, line)
return n, e.eventlog.Info(eidInfo, line)
case 'W':
return n, w.logger.Warning(eidWarning, line)
return n, e.eventlog.Warning(eidWarning, line)
case 'E':
return n, w.logger.Error(eidError, line)
}
return n, e.eventlog.Error(eidError, line)
}
return n, nil
}
type eventLogger struct {
writer io.Writer
eventlog *eventlog.Log
// NewLogger creates a new logger instance
func (e *eventLogger) New(category, name, alias string) telegraf.Logger {
var prefix string
if category != "" {
prefix = "[" + category
if name != "" {
prefix += "." + name
}
if alias != "" {
prefix += "::" + alias
}
prefix += "] "
}
func (e *eventLogger) Write(b []byte) (int, error) {
return e.writer.Write(b)
return &eventLogger{
Category: category,
Name: name,
Alias: alias,
LogLevel: e.LogLevel,
prefix: prefix,
eventlog: e.eventlog,
}
}
func (e *eventLogger) Close() error {
return e.eventlog.Close()
}
func createEventLogger(name string) creator {
return func(Config) (io.WriteCloser, error) {
eventLog, err := eventlog.Open(name)
// OnErr defines a callback that triggers only when errors are about to be written to the log
func (e *eventLogger) RegisterErrorCallback(f func()) {
e.onError = append(e.onError, f)
}
func (e *eventLogger) Level() telegraf.LogLevel {
return e.LogLevel
}
// Errorf logs an error message, patterned after log.Printf.
func (e *eventLogger) Errorf(format string, args ...interface{}) {
e.Error(fmt.Sprintf(format, args...))
}
// Error logs an error message, patterned after log.Print.
func (e *eventLogger) Error(args ...interface{}) {
if e.LogLevel >= telegraf.Error {
if err := e.eventlog.Error(eidError, "E! "+e.prefix+fmt.Sprint(args...)); err != nil {
log.Printf("E! Writing log message failed: %v", err)
}
}
for _, f := range e.onError {
f()
}
}
// Warnf logs a warning message, patterned after log.Printf.
func (e *eventLogger) Warnf(format string, args ...interface{}) {
e.Warn(fmt.Sprintf(format, args...))
}
// Warn logs a warning message, patterned after log.Print.
func (e *eventLogger) Warn(args ...interface{}) {
if e.LogLevel < telegraf.Warn {
return
}
if err := e.eventlog.Warning(eidError, "W! "+e.prefix+fmt.Sprint(args...)); err != nil {
log.Printf("E! Writing log message failed: %v", err)
}
}
// Infof logs an information message, patterned after log.Printf.
func (e *eventLogger) Infof(format string, args ...interface{}) {
e.Info(fmt.Sprintf(format, args...))
}
// Info logs an information message, patterned after log.Print.
func (e *eventLogger) Info(args ...interface{}) {
if e.LogLevel < telegraf.Info {
return
}
if err := e.eventlog.Info(eidError, "I! "+e.prefix+fmt.Sprint(args...)); err != nil {
log.Printf("E! Writing log message failed: %v", err)
}
}
// No debugging output for eventlog to not spam the service
func (e *eventLogger) Debugf(string, ...interface{}) {}
// No debugging output for eventlog to not spam the service
func (e *eventLogger) Debug(...interface{}) {}
func createEventLogger(cfg *Config) (logger, error) {
eventLog, err := eventlog.Open(cfg.InstanceName)
if err != nil {
log.Printf("E! An error occurred while initializing an event logger. %s", err)
return nil, err
}
writer := wlog.NewWriter(&eventWriter{logger: eventLog})
return &eventLogger{
writer: writer,
l := &eventLogger{
eventlog: eventLog,
}, nil
}
}
func RegisterEventLogger(name string) error {
registerLogger("eventlog", createEventLogger(name))
return nil
log.SetOutput(l)
return l, nil
}
func init() {
add("eventlog", createEventLogger)
}

View File

@ -53,9 +53,7 @@ func TestEventLogIntegration(t *testing.T) {
if testing.Short() {
t.Skip("Skipping integration test in short mode")
}
registerLogger("eventlog", createEventLogger("telegraf"))
config := Config{
config := &Config{
LogTarget: "eventlog",
Logfile: "",
}
@ -76,9 +74,8 @@ func TestRestrictedEventLogIntegration(t *testing.T) {
if testing.Short() {
t.Skip("Skipping integration test in short mode")
}
registerLogger("eventlog", createEventLogger("telegraf"))
config := Config{
config := &Config{
LogTarget: "eventlog",
Quiet: true,
}

View File

@ -1,96 +0,0 @@
package logger
import (
"log"
"github.com/influxdata/telegraf"
)
// Logger defines a logging structure for plugins.
type Logger struct {
Category string
Name string
Alias string
LogLevel telegraf.LogLevel
prefix string
onError []func()
}
// NewLogger creates a new logger instance
func NewLogger(category, name, alias string) telegraf.Logger {
var prefix string
if category != "" {
prefix = "[" + category
if name != "" {
prefix += "." + name
}
if alias != "" {
prefix += "::" + alias
}
prefix += "] "
}
return &Logger{
Category: category,
Name: name,
Alias: alias,
LogLevel: telegraf.Info,
prefix: prefix,
}
}
// OnErr defines a callback that triggers only when errors are about to be written to the log
func (l *Logger) RegisterErrorCallback(f func()) {
l.onError = append(l.onError, f)
}
func (l *Logger) Level() telegraf.LogLevel {
return l.LogLevel
}
// Errorf logs an error message, patterned after log.Printf.
func (l *Logger) Errorf(format string, args ...interface{}) {
log.Printf("E! "+l.prefix+format, args...)
for _, f := range l.onError {
f()
}
}
// Error logs an error message, patterned after log.Print.
func (l *Logger) Error(args ...interface{}) {
for _, f := range l.onError {
f()
}
log.Print(append([]interface{}{"E! " + l.prefix}, args...)...)
}
// Debugf logs a debug message, patterned after log.Printf.
func (l *Logger) Debugf(format string, args ...interface{}) {
log.Printf("D! "+l.prefix+" "+format, args...)
}
// Debug logs a debug message, patterned after log.Print.
func (l *Logger) Debug(args ...interface{}) {
log.Print(append([]interface{}{"D! " + l.prefix}, args...)...)
}
// Warnf logs a warning message, patterned after log.Printf.
func (l *Logger) Warnf(format string, args ...interface{}) {
log.Printf("W! "+l.prefix+format, args...)
}
// Warn logs a warning message, patterned after log.Print.
func (l *Logger) Warn(args ...interface{}) {
log.Print(append([]interface{}{"W! " + l.prefix}, args...)...)
}
// Infof logs an information message, patterned after log.Printf.
func (l *Logger) Infof(format string, args ...interface{}) {
log.Printf("I! "+l.prefix+format, args...)
}
// Info logs an information message, patterned after log.Print.
func (l *Logger) Info(args ...interface{}) {
log.Print(append([]interface{}{"I! " + l.prefix}, args...)...)
}

View File

@ -1,42 +1,81 @@
package logger
import (
"io"
"log"
"fmt"
"regexp"
"sync"
"time"
"github.com/influxdata/wlog"
"github.com/influxdata/telegraf"
)
var prefixRegex = regexp.MustCompile("^[DIWE]!")
type logger interface {
telegraf.Logger
New(category, name, alias string) telegraf.Logger
Close() error
}
type Config struct {
// will set the log level to DEBUG
Debug bool
// will set the log level to ERROR
Quiet bool
//stderr, stdout, file or eventlog (Windows only)
LogTarget string
// will direct the logging output to a file. Empty string is
// interpreted as stderr. If there is an error opening the file the
// logger will fall back to stderr
Logfile string
// will rotate when current file at the specified time interval
RotationInterval time.Duration
// will rotate when current file size exceeds this parameter.
RotationMaxSize int64
// maximum rotated files to keep (older ones will be deleted)
RotationMaxArchives int
// pick a timezone to use when logging. or type 'local' for local time.
LogWithTimezone string
// Logger instance name
InstanceName string
// internal log-level
logLevel telegraf.LogLevel
}
// Keep track what is actually set as a log output, because log package doesn't provide a getter.
// It allows closing previous writer if re-set and have possibility to test what is actually set
var actualLogger io.WriteCloser
var instance logger
var once sync.Once
// SetupLogging configures the logging output.
func SetupLogging(cfg Config) error {
log.SetFlags(0)
func SetupLogging(cfg *Config) error {
if cfg.Debug {
wlog.SetLevel(wlog.DEBUG)
cfg.logLevel = telegraf.Debug
}
if cfg.Quiet {
wlog.SetLevel(wlog.ERROR)
cfg.logLevel = telegraf.Error
}
if !cfg.Debug && !cfg.Quiet {
wlog.SetLevel(wlog.INFO)
cfg.logLevel = telegraf.Info
}
if cfg.InstanceName == "" {
cfg.InstanceName = "telegraf"
}
if cfg.LogTarget == "" {
cfg.LogTarget = LogTargetStderr
cfg.LogTarget = "stderr"
}
// Get the logging factory
logCreator, ok := loggerRegistry[cfg.LogTarget]
creator, ok := registry[cfg.LogTarget]
if !ok {
log.Printf("E! Unsupported logtarget: %s, using stderr", cfg.LogTarget)
logCreator = createStderrLogger
return fmt.Errorf("unsupported logtarget: %s, using stderr", cfg.LogTarget)
}
// Create the root logging instance
logWriter, err := logCreator(cfg)
l, err := creator(cfg)
if err != nil {
return err
}
@ -47,16 +86,25 @@ func SetupLogging(cfg Config) error {
}
// Use the new logger and store a reference
log.SetOutput(logWriter)
actualLogger = logWriter
instance = l
return nil
}
func NewLogger(category, name, alias string) telegraf.Logger {
return instance.New(category, name, alias)
}
func CloseLogging() error {
if actualLogger == nil {
if instance != nil {
return instance.Close()
}
return nil
}
return actualLogger.Close()
func init() {
once.Do(func() {
//nolint:errcheck // This should always succeed with the default config
SetupLogging(&Config{})
})
}

View File

@ -13,7 +13,7 @@ func TestErrorCounting(t *testing.T) {
"errors",
map[string]string{"input": "test"},
)
iLog := Logger{Name: "inputs.test"}
iLog := NewLogger("inputs", "test", "")
iLog.RegisterErrorCallback(func() {
reg.Incr(1)
})

View File

@ -1,14 +1,9 @@
package logger
import "io"
type creator func(cfg *Config) (logger, error)
type creator func(cfg Config) (io.WriteCloser, error)
var registry = make(map[string]creator)
var loggerRegistry map[string]creator
func registerLogger(name string, loggerCreator creator) {
if loggerRegistry == nil {
loggerRegistry = make(map[string]creator)
}
loggerRegistry[name] = loggerCreator
func add(name string, creator creator) {
registry[name] = creator
}