feat(logging): Implement structured logging (influxdata#15751)

Co-authored-by: Thomas Casteleyn <thomas.casteleyn@me.com>

CHANGELOG.md

@@ -1,6 +1,20 @@
 <!-- markdownlint-disable MD024 -->
 # Changelog
 
+## Unreleased
+
+### Important Changes
+
+- This release contains a logging overhaul as well as some new features for
+  logging (see PRs [#15556](https://github.com/influxdata/telegraf/pull/15556),
+  [#15629](https://github.com/influxdata/telegraf/pull/15629),
+  [#15677](https://github.com/influxdata/telegraf/pull/15677),
+  [#15695](https://github.com/influxdata/telegraf/pull/15695) and
+  [#15751](https://github.com/influxdata/telegraf/pull/15751)).
+  As a consequence the redunant `logtarget` setting is deprecated, `stderr` is
+  used if no `logfile` is provided, otherwise messages are logged to the given
+  file. For using the Windows `eventlog` set `logformat = "eventlog"`!
+
 ## v1.31.3 [2024-08-12]
 
 ### Bugfixes

cmd/telegraf/agent.conf

@@ -53,13 +53,12 @@
   ## Log only error level messages.
   # quiet = false
 
-  ## Log target controls the destination for logs and can be one of "file",
-  ## "stderr" or, on Windows, "eventlog".  When set to "file", the output file
-  ## is determined by the "logfile" setting.
-  # logtarget = "file"
+  ## Log format controls the way messages are logged and can be one of "text",
+  ## "structured" or, on Windows, "eventlog".
+  # logformat = "text"
 
-  ## Name of the file to be logged to when using the "file" logtarget.  If set to
-  ## the empty string then logs are written to stderr.
+  ## Name of the file to be logged to or stderr if unset or empty. This
+  ## setting is ignored for the "eventlog" format.
   # logfile = ""
 
   ## The logfile will be rotated after the time interval specified.  When set
@@ -80,9 +79,9 @@
   # log_with_timezone = ""
 
   ## Override default hostname, if empty use os.Hostname()
-  hostname = ""
+  # hostname = ""
   ## If set to true, do no set the "host" tag in the telegraf agent.
-  omit_hostname = false
+  # omit_hostname = false
 
   ## Method of translating SNMP objects. Can be "netsnmp" (deprecated) which
   ## translates by calling external programs snmptranslate and snmptable,
@@ -95,7 +94,7 @@
   ## the state in the file will be restored for the plugins.
   # statefile = ""
 
-	## Flag to skip running processors after aggregators
-	## By default, processors are run a second time after aggregators. Changing
-	## this setting to true will skip the second run of processors.
-	# skip_processors_after_aggregators = false
+  ## Flag to skip running processors after aggregators
+  ## By default, processors are run a second time after aggregators. Changing
+  ## this setting to true will skip the second run of processors.
+  # skip_processors_after_aggregators = false

cmd/telegraf/telegraf.go

@@ -362,6 +362,7 @@ func (t *Telegraf) runAgent(ctx context.Context, reloadConfig bool) error {
 		Debug:               c.Agent.Debug || t.debug,
 		Quiet:               c.Agent.Quiet || t.quiet,
 		LogTarget:           c.Agent.LogTarget,
+		LogFormat:           c.Agent.LogFormat,
 		Logfile:             c.Agent.Logfile,
 		RotationInterval:    time.Duration(c.Agent.LogfileRotationInterval),
 		RotationMaxSize:     int64(c.Agent.LogfileRotationMaxSize),

config/config.go

@@ -123,7 +123,7 @@ func NewConfig() *Config {
 			Interval:                   Duration(10 * time.Second),
 			RoundInterval:              true,
 			FlushInterval:              Duration(10 * time.Second),
-			LogTarget:                  "file",
+			LogFormat:                  "text",
 			LogfileRotationMaxArchives: 5,
 		},
 
@@ -226,12 +226,15 @@ type AgentConfig struct {
 	Quiet bool `toml:"quiet"`
 
 	// Log target controls the destination for logs and can be one of "file",
-	// "stderr" or, on Windows, "eventlog".  When set to "file", the output file
-	// is determined by the "logfile" setting.
-	LogTarget string `toml:"logtarget"`
+	// "stderr" or, on Windows, "eventlog". When set to "file", the output file
+	// is determined by the "logfile" setting
+	LogTarget string `toml:"logtarget" deprecated:"1.32.0;1.40.0;use 'logformat' and 'logfile' instead"`
 
-	// Name of the file to be logged to when using the "file" logtarget.  If set to
-	// the empty string then logs are written to stderr.
+	// Log format controls the way messages are logged and can be one of "text",
+	// "structured" or, on Windows, "eventlog".
+	LogFormat string `toml:"logformat"`
+
+	// Name of the file to be logged to or stderr if empty. Ignored for "eventlog" format.
 	Logfile string `toml:"logfile"`
 
 	// The file will be rotated after the time interval specified.  When set

config/migration.go

@@ -151,8 +151,31 @@ func ApplyMigrations(data []byte) ([]byte, uint64, error) {
 		return nil, 0, fmt.Errorf("assigning text failed: %w", err)
 	}
 
-	// Do the actual plugin migration(s)
 	var applied uint64
+	// Do the actual global section migration(s)
+	for idx, s := range sections {
+		if strings.Contains(s.name, ".") {
+			continue
+		}
+		log.Printf("D!   applying global migrations to section %q in line %d...", s.name, s.begin)
+		for _, migrate := range migrations.GlobalMigrations {
+			result, msg, err := migrate(s.name, s.content)
+			if err != nil {
+				if errors.Is(err, migrations.ErrNotApplicable) {
+					continue
+				}
+				return nil, 0, fmt.Errorf("migrating options of %q (line %d) failed: %w", s.name, s.begin, err)
+			}
+			if msg != "" {
+				log.Printf("I! Global section %q in line %d: %s", s.name, s.begin, msg)
+			}
+			s.raw = bytes.NewBuffer(result)
+			applied++
+		}
+		sections[idx] = s
+	}
+
+	// Do the actual plugin migration(s)
 	for idx, s := range sections {
 		migrate, found := migrations.PluginMigrations[s.name]
 		if !found {

docs/CONFIGURATION.md

@@ -296,14 +296,14 @@ The agent table configures Telegraf and the defaults used across all plugins.
 - **quiet**:
   Log only error level messages.
 
-- **logtarget**:
-  Log target controls the destination for logs and can be one of "file",
-  "stderr" or, on Windows, "eventlog".  When set to "file", the output file is
-  determined by the "logfile" setting.
+- **logformat**:
+  Log format controls the way messages are logged and can be one of "text",
+  "structured" or, on Windows, "eventlog". The output file (if any) is
+  determined by the `logfile` setting.
 
 - **logfile**:
-  Name of the file to be logged to when using the "file" logtarget.  If set to
-  the empty string then logs are written to stderr.
+  Name of the file to be logged to or stderr if unset or empty. This
+  setting is ignored for the "eventlog" format.
 
 - **logfile_rotation_interval**:
   The logfile will be rotated after the time interval specified.  When set to

logger.go

@@ -75,6 +75,9 @@ type Logger interface { //nolint:interfacebloat // All functions are required
 	// Level returns the configured log-level of the logger
 	Level() LogLevel
 
+	// AddAttribute allows to add a key-value attribute to the logging output
+	AddAttribute(key string, value interface{})
+
 	// Errorf logs an error message, patterned after log.Printf.
 	Errorf(format string, args ...interface{})
 	// Error logs an error message, patterned after log.Print.

logger/event_logger.go

@@ -27,7 +27,7 @@ func (l *eventLogger) Close() error {
 	return l.eventlog.Close()
 }
 
-func (l *eventLogger) Print(level telegraf.LogLevel, _ time.Time, prefix string, args ...interface{}) {
+func (l *eventLogger) Print(level telegraf.LogLevel, _ time.Time, prefix string, _ map[string]interface{}, args ...interface{}) {
 	// Skip debug and beyond as they cannot be logged
 	if level >= telegraf.Debug {
 		return
@@ -47,6 +47,8 @@ func (l *eventLogger) Print(level telegraf.LogLevel, _ time.Time, prefix string,
 	if err != nil {
 		l.errlog.Printf("E! Writing log message failed: %v", err)
 	}
+
+	// TODO attributes...
 }
 
 func createEventLogger(cfg *Config) (sink, error) {

logger/event_logger_test.go

@@ -54,7 +54,7 @@ func TestEventLogIntegration(t *testing.T) {
 		t.Skip("Skipping integration test in short mode")
 	}
 	config := &Config{
-		LogTarget: "eventlog",
+		LogFormat: "eventlog",
 		Logfile:   "",
 	}
 	require.NoError(t, SetupLogging(config))
@@ -76,7 +76,7 @@ func TestRestrictedEventLogIntegration(t *testing.T) {
 	}
 
 	config := &Config{
-		LogTarget: "eventlog",
+		LogFormat: "eventlog",
 		Quiet:     true,
 	}
 	require.NoError(t, SetupLogging(config))

logger/handler.go

@@ -6,17 +6,19 @@ import (
 	"io"
 	"log"
 	"os"
+	"strings"
 	"sync"
 	"time"
 
 	"github.com/influxdata/telegraf"
 )
 
 type entry struct {
-	timestamp time.Time
-	level     telegraf.LogLevel
-	prefix    string
-	args      []interface{}
+	timestamp  time.Time
+	level      telegraf.LogLevel
+	prefix     string
+	attributes map[string]interface{}
+	args       []interface{}
 }
 
 type handler struct {
@@ -60,7 +62,7 @@ func (h *handler) switchSink(impl sink, level telegraf.LogLevel, tz *time.Locati
 		current := h.earlylogs.Front()
 		for current != nil {
 			e := current.Value.(*entry)
-			h.impl.Print(e.level, e.timestamp.In(h.timezone), e.prefix, e.args...)
+			h.impl.Print(e.level, e.timestamp.In(h.timezone), e.prefix, e.attributes, e.args...)
 			next := current.Next()
 			h.earlylogs.Remove(current)
 			current = next
@@ -69,12 +71,13 @@ func (h *handler) switchSink(impl sink, level telegraf.LogLevel, tz *time.Locati
 	h.Unlock()
 }
 
-func (h *handler) add(level telegraf.LogLevel, ts time.Time, prefix string, args ...interface{}) *entry {
+func (h *handler) add(level telegraf.LogLevel, ts time.Time, prefix string, attr map[string]interface{}, args ...interface{}) *entry {
 	e := &entry{
-		timestamp: ts,
-		level:     level,
-		prefix:    prefix,
-		args:      args,
+		timestamp:  ts,
+		level:      level,
+		prefix:     prefix,
+		attributes: attr,
+		args:       args,
 	}
 
 	h.Lock()
@@ -109,7 +112,16 @@ type redirectLogger struct {
 	writer io.Writer
 }
 
-func (l *redirectLogger) Print(level telegraf.LogLevel, ts time.Time, prefix string, args ...interface{}) {
-	msg := append([]interface{}{ts.In(time.UTC).Format(time.RFC3339), " ", level.Indicator(), " ", prefix}, args...)
+func (l *redirectLogger) Print(level telegraf.LogLevel, ts time.Time, prefix string, attr map[string]interface{}, args ...interface{}) {
+	var attrMsg string
+	if len(attr) > 0 {
+		var parts []string
+		for k, v := range attr {
+			parts = append(parts, fmt.Sprintf("%s=%v", k, v))
+		}
+		attrMsg = " (" + strings.Join(parts, ",") + ")"
+	}
+
+	msg := append([]interface{}{ts.In(time.UTC).Format(time.RFC3339), " ", level.Indicator(), " ", prefix + attrMsg}, args...)
 	fmt.Fprintln(l.writer, msg...)
 }