Merge pull request #101 from hashicorp/infer-level-with-timestamp

Add `InferLevelsWithTimestamp` option

README.md

@@ -143,3 +143,6 @@ log.Printf("[DEBUG] %d", 42)
 Notice that if `appLogger` is initialized with the `INFO` log level _and_ you
 specify `InferLevels: true`, you will not see any output here. You must change
 `appLogger` to `DEBUG` to see output. See the docs for more information.
+
+If the log lines start with a timestamp you can use the
+`InferLevelsWithTimestamp` option to try and ignore them.

interceptlogger.go

@@ -180,9 +180,10 @@ func (i *interceptLogger) StandardWriterIntercept(opts *StandardLoggerOptions) i
 
 func (i *interceptLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer {
 	return &stdlogAdapter{
-		log:         i,
-		inferLevels: opts.InferLevels,
-		forceLevel:  opts.ForceLevel,
+		log:                      i,
+		inferLevels:              opts.InferLevels,
+		inferLevelsWithTimestamp: opts.InferLevelsWithTimestamp,
+		forceLevel:               opts.ForceLevel,
 	}
 }
 

intlogger.go

@@ -704,9 +704,10 @@ func (l *intLogger) StandardWriter(opts *StandardLoggerOptions) io.Writer {
 		newLog.callerOffset = l.callerOffset + 4
 	}
 	return &stdlogAdapter{
-		log:         &newLog,
-		inferLevels: opts.InferLevels,
-		forceLevel:  opts.ForceLevel,
+		log:                      &newLog,
+		inferLevels:              opts.InferLevels,
+		inferLevelsWithTimestamp: opts.InferLevelsWithTimestamp,
+		forceLevel:               opts.ForceLevel,
 	}
 }
 

logger.go

@@ -212,6 +212,15 @@ type StandardLoggerOptions struct {
 	// [DEBUG] and strip it off before reapplying it.
 	InferLevels bool
 
+	// Indicate that some minimal parsing should be done on strings to try
+	// and detect their level and re-emit them while ignoring possible
+	// timestamp values in the beginning of the string.
+	// This supports the strings like [ERROR], [ERR] [TRACE], [WARN], [INFO],
+	// [DEBUG] and strip it off before reapplying it.
+	// The timestamp detection may result in false positives and incomplete
+	// string outputs.
+	InferLevelsWithTimestamp bool
+
 	// ForceLevel is used to force all output from the standard logger to be at
 	// the specified level. Similar to InferLevels, this will strip any level
 	// prefix contained in the logged string before applying the forced level.

stdlog.go

@@ -3,16 +3,22 @@ package hclog
 import (
 	"bytes"
 	"log"
+	"regexp"
 	"strings"
 )
 
+// Regex to ignore characters commonly found in timestamp formats from the
+// beginning of inputs.
+var logTimestampRegexp = regexp.MustCompile(`^[\d\s\:\/\.\+-TZ]*`)
+
 // Provides a io.Writer to shim the data out of *log.Logger
 // and back into our Logger. This is basically the only way to
 // build upon *log.Logger.
 type stdlogAdapter struct {
-	log         Logger
-	inferLevels bool
-	forceLevel  Level
+	log                      Logger
+	inferLevels              bool
+	inferLevelsWithTimestamp bool
+	forceLevel               Level
 }
 
 // Take the data, infer the levels if configured, and send it through
@@ -28,6 +34,10 @@ func (s *stdlogAdapter) Write(data []byte) (int, error) {
 		// Log at the forced level
 		s.dispatch(str, s.forceLevel)
 	} else if s.inferLevels {
+		if s.inferLevelsWithTimestamp {
+			str = s.trimTimestamp(str)
+		}
+
 		level, str := s.pickLevel(str)
 		s.dispatch(str, level)
 	} else {
@@ -74,6 +84,11 @@ func (s *stdlogAdapter) pickLevel(str string) (Level, string) {
 	}
 }
 
+func (s *stdlogAdapter) trimTimestamp(str string) string {
+	idx := logTimestampRegexp.FindStringIndex(str)
+	return str[idx[1]:]
+}
+
 type logWriter struct {
 	l *log.Logger
 }

stdlog_test.go

@@ -69,6 +69,68 @@ func TestStdlogAdapter_PickLevel(t *testing.T) {
 	})
 }
 
+func TestStdlogAdapter_TrimTimestamp(t *testing.T) {
+	cases := []struct {
+		name   string
+		input  string
+		expect string
+	}{
+		{
+			name:   "Go log Ldate",
+			input:  "2009/01/23 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "Go log Ldate|Ltime",
+			input:  "2009/01/23 01:23:23 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "Go log Ldate|Ltime|Lmicroseconds",
+			input:  "2009/01/23 01:23:23.123123 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "Go log Ltime",
+			input:  "01:23:23 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "Go log Ltime|Lmicroseconds",
+			input:  "01:23:23.123123 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "ISO 8601 date",
+			input:  "2021-10-28 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "ISO 8601 date and time",
+			input:  "2021-10-28T19:27:28+00:00 [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "ISO 8601 date and time zulu",
+			input:  "2021-10-28T19:27:28Z [ERR] message",
+			expect: "[ERR] message",
+		},
+		{
+			name:   "no timestamp",
+			input:  "[ERR] message",
+			expect: "[ERR] message",
+		},
+	}
+
+	for _, c := range cases {
+		t.Run(c.name, func(t *testing.T) {
+			var s stdlogAdapter
+			got := s.trimTimestamp(c.input)
+			assert.Equal(t, c.expect, got)
+		})
+	}
+}
+
 func TestStdlogAdapter_ForceLevel(t *testing.T) {
 	cases := []struct {
 		name        string
@@ -188,8 +250,8 @@ func TestFromStandardLogger_helper(t *testing.T) {
 	sl := log.New(&buf, "test-stdlib-log ", log.Ltime)
 
 	hl := FromStandardLogger(sl, &LoggerOptions{
-		Name:             "hclog-inner",
-		IncludeLocation:  true,
+		Name:                     "hclog-inner",
+		IncludeLocation:          true,
 		AdditionalLocationOffset: 1,
 	})