feat(logging): Add 'trace' log-level (influxdata#15695)

docs/CONFIGURATION.md

@@ -410,7 +410,7 @@ Parameters that can be used with any input plugin:
 - **name_suffix**: Specifies a suffix to attach to the measurement name.
 - **tags**: A map of tags to apply to a specific input's measurements.
 - **log_level**: Override the log-level for this plugin. Possible values are
-  `error`, `warn`, `info` and `debug`.
+  `error`, `warn`, `info`, `debug` and `trace`.
 
 The [metric filtering][] parameters can be used to limit what metrics are
 emitted from the input plugin.

logger.go

@@ -14,6 +14,8 @@ const (
 	Info
 	// Debug will log all of the above and debugging messages issued by plugins
 	Debug
+	// Trace will log all of the above and trace messages issued by plugins
+	Trace
 )
 
 func LogLevelFromString(name string) LogLevel {
@@ -26,6 +28,8 @@ func LogLevelFromString(name string) LogLevel {
 		return Info
 	case "DEBUG", "debug":
 		return Debug
+	case "TRACE", "trace":
+		return Trace
 	}
 	return None
 }
@@ -40,6 +44,8 @@ func (e LogLevel) String() string {
 		return "INFO"
 	case Debug:
 		return "DEBUG"
+	case Trace:
+		return "TRACE"
 	}
 	return "NONE"
 }
@@ -54,6 +60,8 @@ func (e LogLevel) Indicator() string {
 		return "I!"
 	case Debug:
 		return "D!"
+	case Trace:
+		return "T!"
 	}
 	return "U!"
 }
@@ -63,18 +71,14 @@ func (e LogLevel) Includes(level LogLevel) bool {
 }
 
 // Logger defines an plugin-related interface for logging.
-type Logger interface {
+type Logger interface { //nolint:interfacebloat // All functions are required
 	// Level returns the configured log-level of the logger
 	Level() LogLevel
 
 	// Errorf logs an error message, patterned after log.Printf.
 	Errorf(format string, args ...interface{})
 	// Error logs an error message, patterned after log.Print.
 	Error(args ...interface{})
-	// Debugf logs a debug message, patterned after log.Printf.
-	Debugf(format string, args ...interface{})
-	// Debug logs a debug message, patterned after log.Print.
-	Debug(args ...interface{})
 	// Warnf logs a warning message, patterned after log.Printf.
 	Warnf(format string, args ...interface{})
 	// Warn logs a warning message, patterned after log.Print.
@@ -83,4 +87,12 @@ type Logger interface {
 	Infof(format string, args ...interface{})
 	// Info logs an information message, patterned after log.Print.
 	Info(args ...interface{})
+	// Debugf logs a debug message, patterned after log.Printf.
+	Debugf(format string, args ...interface{})
+	// Debug logs a debug message, patterned after log.Print.
+	Debug(args ...interface{})
+	// Tracef logs a trace message, patterned after log.Printf.
+	Tracef(format string, args ...interface{})
+	// Trace logs a trace message, patterned after log.Print.
+	Trace(args ...interface{})
 }

logger/logger.go

@@ -55,19 +55,6 @@ func New(category, name, alias string) *logger {
 	return l
 }
 
-// SetLevel changes the log-level to the given one
-func (l *logger) SetLogLevel(name string) error {
-	if name == "" {
-		return nil
-	}
-	level := telegraf.LogLevelFromString(name)
-	if level == telegraf.None {
-		return fmt.Errorf("invalid log-level %q", name)
-	}
-	l.level = &level
-	return nil
-}
-
 // SubLogger creates a new logger with the given name added as suffix
 func (l *logger) SubLogger(name string) telegraf.Logger {
 	suffix := l.suffix
@@ -118,6 +105,24 @@ func (l *logger) Level() telegraf.LogLevel {
 	return instance.level
 }
 
+// SetLevel overrides the current log-level of the logger
+func (l *logger) SetLevel(level telegraf.LogLevel) {
+	l.level = &level
+}
+
+// SetLevel changes the log-level to the given one
+func (l *logger) SetLogLevel(name string) error {
+	if name == "" {
+		return nil
+	}
+	level := telegraf.LogLevelFromString(name)
+	if level == telegraf.None {
+		return fmt.Errorf("invalid log-level %q", name)
+	}
+	l.SetLevel(level)
+	return nil
+}
+
 // Register a callback triggered when errors are about to be written to the log
 func (l *logger) RegisterErrorCallback(f func()) {
 	l.onError = append(l.onError, f)
@@ -162,6 +167,15 @@ func (l *logger) Debug(args ...interface{}) {
 	l.Print(telegraf.Debug, time.Now(), args...)
 }
 
+// Trace logging, this is suppressed on console
+func (l *logger) Tracef(format string, args ...interface{}) {
+	l.Trace(fmt.Sprintf(format, args...))
+}
+
+func (l *logger) Trace(args ...interface{}) {
+	l.Print(telegraf.Trace, time.Now(), args...)
+}
+
 func (l *logger) Print(level telegraf.LogLevel, ts time.Time, args ...interface{}) {
 	// Check if we are in early logging state and store the message in this case
 	if instance.impl == nil {

logger/stdlog_redirector.go

@@ -24,6 +24,8 @@ func (s *stdlogRedirector) Write(b []byte) (n int, err error) {
 
 	// Log with the given level
 	switch level {
+	case 'T':
+		s.log.Trace(string(msg))
 	case 'D':
 		s.log.Debug(string(msg))
 	case 'I':

plugins/common/kafka/logger.go

@@ -1,33 +1,41 @@
 package kafka
 
 import (
+	"sync"
+
 	"github.com/IBM/sarama"
 
 	"github.com/influxdata/telegraf"
 	"github.com/influxdata/telegraf/logger"
 )
 
-type Logger struct {
-}
+var (
+	log  = logger.New("sarama", "", "")
+	once sync.Once
+)
 
-// DebugLogger logs messages from sarama at the debug level.
-type DebugLogger struct {
-	Log telegraf.Logger
-}
+type debugLogger struct{}
 
-func (l *DebugLogger) Print(v ...interface{}) {
-	l.Log.Debug(v...)
+func (l *debugLogger) Print(v ...interface{}) {
+	log.Trace(v...)
 }
 
-func (l *DebugLogger) Printf(format string, v ...interface{}) {
-	l.Log.Debugf(format, v...)
+func (l *debugLogger) Printf(format string, v ...interface{}) {
+	log.Tracef(format, v...)
 }
 
-func (l *DebugLogger) Println(v ...interface{}) {
+func (l *debugLogger) Println(v ...interface{}) {
 	l.Print(v...)
 }
 
 // SetLogger configures a debug logger for kafka (sarama)
-func (k *Logger) SetLogger() {
-	sarama.Logger = &DebugLogger{Log: logger.New("sarama", "", "")}
+func SetLogger(level telegraf.LogLevel) {
+	// Set-up the sarama logger only once
+	once.Do(func() {
+		sarama.Logger = &debugLogger{}
+	})
+	// Increase the log-level if needed.
+	if !log.Level().Includes(level) {
+		log.SetLevel(level)
+	}
 }

plugins/inputs/kafka_consumer/kafka_consumer.go

@@ -52,11 +52,8 @@ type KafkaConsumer struct {
 	ConsumerFetchDefault                 config.Size     `toml:"consumer_fetch_default"`
 	ConnectionStrategy                   string          `toml:"connection_strategy"`
 	ResolveCanonicalBootstrapServersOnly bool            `toml:"resolve_canonical_bootstrap_servers_only"`
-
+	Log                                  telegraf.Logger `toml:"-"`
 	kafka.ReadConfig
-	kafka.Logger
-
-	Log telegraf.Logger `toml:"-"`
 
 	ConsumerCreator ConsumerGroupCreator `toml:"-"`
 	consumer        ConsumerGroup
@@ -99,7 +96,7 @@ func (k *KafkaConsumer) SetParser(parser telegraf.Parser) {
 }
 
 func (k *KafkaConsumer) Init() error {
-	k.SetLogger()
+	kafka.SetLogger(k.Log.Level())
 
 	if k.MaxUndeliveredMessages == 0 {
 		k.MaxUndeliveredMessages = defaultMaxUndeliveredMessages

plugins/inputs/kafka_consumer/kafka_consumer_test.go

@@ -67,7 +67,7 @@ func TestInit(t *testing.T) {
 	}{
 		{
 			name:   "default config",
-			plugin: &KafkaConsumer{},
+			plugin: &KafkaConsumer{Log: testutil.Logger{}},
 			check: func(t *testing.T, plugin *KafkaConsumer) {
 				require.Equal(t, defaultConsumerGroup, plugin.ConsumerGroup)
 				require.Equal(t, defaultMaxUndeliveredMessages, plugin.MaxUndeliveredMessages)

plugins/inputs/modbus/README.md

@@ -60,9 +60,8 @@ See the [CONFIGURATION.md][CONFIGURATION.md] for more details.
   ## and "RTU" for serial connections.
   # transmission_mode = "auto"
 
-  ## Trace the connection to the modbus device as debug messages
-  ## Note: You have to enable telegraf's debug mode to see those messages!
-  # debug_connection = false
+  ## Trace the connection to the modbus device
+  # log_level = "trace"
 
   ## Define the configuration schema
   ##  |---register -- define fields per register type in the original style (only supports one slave ID)

plugins/inputs/modbus/modbus.go

@@ -58,7 +58,7 @@ type Modbus struct {
 	Timeout           config.Duration   `toml:"timeout"`
 	Retries           int               `toml:"busy_retries"`
 	RetriesWaitTime   config.Duration   `toml:"busy_retries_wait"`
-	DebugConnection   bool              `toml:"debug_connection"`
+	DebugConnection   bool              `toml:"debug_connection" deprecated:"1.35.0;use 'log_level' 'trace' instead"`
 	Workarounds       ModbusWorkarounds `toml:"workarounds"`
 	ConfigurationType string            `toml:"configuration_type"`
 	Log               telegraf.Logger   `toml:"-"`
@@ -261,6 +261,11 @@ func (m *Modbus) initClient() error {
 		return err
 	}
 
+	var tracelog mb.Logger
+	if m.Log.Level().Includes(telegraf.Trace) || m.DebugConnection { // for backward compatibility
+		tracelog = m
+	}
+
 	switch u.Scheme {
 	case "tcp":
 		host, port, err := net.SplitHostPort(u.Host)
@@ -271,23 +276,17 @@ func (m *Modbus) initClient() error {
 		case "", "auto", "TCP":
 			handler := mb.NewTCPClientHandler(host + ":" + port)
 			handler.Timeout = time.Duration(m.Timeout)
-			if m.DebugConnection {
-				handler.Logger = m
-			}
+			handler.Logger = tracelog
 			m.handler = handler
 		case "RTUoverTCP":
 			handler := mb.NewRTUOverTCPClientHandler(host + ":" + port)
 			handler.Timeout = time.Duration(m.Timeout)
-			if m.DebugConnection {
-				handler.Logger = m
-			}
+			handler.Logger = tracelog
 			m.handler = handler
 		case "ASCIIoverTCP":
 			handler := mb.NewASCIIOverTCPClientHandler(host + ":" + port)
 			handler.Timeout = time.Duration(m.Timeout)
-			if m.DebugConnection {
-				handler.Logger = m
-			}
+			handler.Logger = tracelog
 			m.handler = handler
 		default:
 			return fmt.Errorf("invalid transmission mode %q for %q", m.TransmissionMode, u.Scheme)
@@ -305,9 +304,7 @@ func (m *Modbus) initClient() error {
 			handler.DataBits = m.DataBits
 			handler.Parity = m.Parity
 			handler.StopBits = m.StopBits
-			if m.DebugConnection {
-				handler.Logger = m
-			}
+			handler.Logger = tracelog
 			if m.RS485 != nil {
 				handler.RS485.Enabled = true
 				handler.RS485.DelayRtsBeforeSend = time.Duration(m.RS485.DelayRtsBeforeSend)
@@ -324,9 +321,7 @@ func (m *Modbus) initClient() error {
 			handler.DataBits = m.DataBits
 			handler.Parity = m.Parity
 			handler.StopBits = m.StopBits
-			if m.DebugConnection {
-				handler.Logger = m
-			}
+			handler.Logger = tracelog
 			if m.RS485 != nil {
 				handler.RS485.Enabled = true
 				handler.RS485.DelayRtsBeforeSend = time.Duration(m.RS485.DelayRtsBeforeSend)
@@ -541,7 +536,7 @@ func (m *Modbus) collectFields(acc telegraf.Accumulator, timestamp time.Time, ta
 
 // Implement the logger interface of the modbus client
 func (m *Modbus) Printf(format string, v ...interface{}) {
-	m.Log.Debugf(format, v...)
+	m.Log.Tracef(format, v...)
 }
 
 // Add this plugin to telegraf

plugins/inputs/modbus/sample_general_begin.conf

@@ -42,9 +42,8 @@
   ## and "RTU" for serial connections.
   # transmission_mode = "auto"
 
-  ## Trace the connection to the modbus device as debug messages
-  ## Note: You have to enable telegraf's debug mode to see those messages!
-  # debug_connection = false
+  ## Trace the connection to the modbus device
+  # log_level = "trace"
 
   ## Define the configuration schema
   ##  |---register -- define fields per register type in the original style (only supports one slave ID)

plugins/inputs/netflow/README.md

@@ -64,10 +64,8 @@ See the [CONFIGURATION.md][CONFIGURATION.md] for more details.
   ## decoding.
   # private_enterprise_number_files = []
 
-  ## Dump incoming packets to the log
-  ## This can be helpful to debug parsing issues. Only active if
-  ## Telegraf is in debug mode.
-  # dump_packets = false
+  ## Log incoming packets for tracing issues
+  # log_level = "trace"
 ```
 
 ## Private Enterprise Number mapping

plugins/inputs/netflow/netflow.go

@@ -28,7 +28,7 @@ type NetFlow struct {
 	ServiceAddress string          `toml:"service_address"`
 	ReadBufferSize config.Size     `toml:"read_buffer_size"`
 	Protocol       string          `toml:"protocol"`
-	DumpPackets    bool            `toml:"dump_packets"`
+	DumpPackets    bool            `toml:"dump_packets" deprecated:"1.35.0;use 'log_level' 'trace' instead"`
 	PENFiles       []string        `toml:"private_enterprise_number_files"`
 	Log            telegraf.Logger `toml:"-"`
 
@@ -135,8 +135,8 @@ func (n *NetFlow) read(acc telegraf.Accumulator) {
 		if count < 1 {
 			continue
 		}
-		if n.DumpPackets {
-			n.Log.Debugf("raw data: %s", hex.EncodeToString(buf[:count]))
+		if n.Log.Level().Includes(telegraf.Trace) || n.DumpPackets { // for backward compatibility
+			n.Log.Tracef("raw data: %s", hex.EncodeToString(buf[:count]))
 		}
 		metrics, err := n.decoder.Decode(src.IP, buf[:count])
 		if err != nil {

plugins/inputs/netflow/sample.conf

@@ -24,7 +24,5 @@
   ## decoding.
   # private_enterprise_number_files = []
 
-  ## Dump incoming packets to the log
-  ## This can be helpful to debug parsing issues. Only active if
-  ## Telegraf is in debug mode.
-  # dump_packets = false
+  ## Log incoming packets for tracing issues
+  # log_level = "trace"

plugins/inputs/s7comm/README.md

@@ -47,9 +47,8 @@ using the `startup_error_behavior` setting. Available values are:
   ## Timeout for requests
   # timeout = "10s"
 
-  ## Log detailed connection messages for debugging
-  ## This option only has an effect when Telegraf runs in debug mode
-  # debug_connection = false
+  ## Log detailed connection messages for tracing issues
+  # log_level = "trace"
 
   ## Metric definition(s)
   [[inputs.s7comm.metric]]