fix(promslog): always print time.Duration values as go duration strings (#798)

* fix(promslog): always print time.Duration values as go duration strings

Addresses: prometheus/prometheus#16766

As brought up in the linked issue, it seems that upstream slog handles
time.Duration values in a sub-optimal way in the JSON handler. To
improve handling of duration values in a consistent way across the
ecosystem, we should ensure that duration values are handled the same
way across all supported log formats (json and logfmt).

This change ensures that any key containing a value that is a
time.Duration is reformatted as a boring string value, explicitly
formatted as a Go duration string (ie, "1d2h3m") by calling the
`String()` method on the duration.

Example test output pre/post patch:

Before:
```
~/go/src/github.com/prometheus/common (main [ U ]) -> go test -v -race ./promslog -run TestDurationValues
=== RUN   TestDurationValues
time=2025-06-30T22:11:01.682-04:00 level=INFO source=slog_test.go:108 msg="duration testing" duration_raw=1m30s duration_string=1m30s

{"time":"2025-06-30T22:11:01.683153372-04:00","level":"INFO","source":"slog_test.go:123","msg":"duration testing","duration_raw":90000000000,"duration_string":"1m30s"}

    slog_test.go:128:
                Error Trace:    /home/tjhop/go/src/github.com/prometheus/common/promslog/slog_test.go:128
                Error:          "{\"time\":\"2025-06-30T22:11:01.683153372-04:00\",\"level\":\"INFO\",\"source\":\"slog_test.go:123\",\"msg\":\"duration testing\",\"duration_raw\":90000000000,\"duration_string\":\"1m30s\"}\n" should not contain "\"duration_raw\":90000000000"
                Test:           TestDurationValues
                Messages:       Expected duration to be output as Go duration string "1m30s", got "90000000000"
--- FAIL: TestDurationValues (0.00s)
FAIL
FAIL    github.com/prometheus/common/promslog   0.018s
FAIL
```

After:

```
~/go/src/github.com/prometheus/common (main [ U ]) -> go test -v -race ./promslog -run TestDurationValues
=== RUN   TestDurationValues
time=2025-06-30T22:13:03.714-04:00 level=INFO source=slog_test.go:108 msg="duration testing" duration_raw=1m30s duration_string=1m30s

{"time":"2025-06-30T22:13:03.714880745-04:00","level":"INFO","source":"slog_test.go:123","msg":"duration testing","duration_raw":"1m30s","duration_string":"1m30s"}

--- PASS: TestDurationValues (0.00s)
PASS
ok      github.com/prometheus/common/promslog   1.014s
```

Signed-off-by: TJ Hoplock <[email protected]>

* test(promslog): improve duration tests, convert to table driven suite

Addresses PR feedback

Signed-off-by: TJ Hoplock <[email protected]>

* test(promslog): refactor duration tests

Signed-off-by: TJ Hoplock <[email protected]>

* test(promslog): more specific string check for duration testing

Signed-off-by: TJ Hoplock <[email protected]>

---------

Signed-off-by: TJ Hoplock <[email protected]>

Author: tjhop

promslog/slog.go

@@ -197,6 +197,13 @@ func newGoKitStyleReplaceAttrFunc(lvl *Level) func(groups []string, a slog.Attr)
 			}
 		default:
 		}
+
+		// Ensure time.Duration values are _always_ formatted as a Go
+		// duration string (ie, "1d2h3m").
+		if v, ok := a.Value.Any().(time.Duration); ok {
+			a.Value = slog.StringValue(v.String())
+		}
+
 		return a
 	}
 }
@@ -238,6 +245,13 @@ func defaultReplaceAttr(_ []string, a slog.Attr) slog.Attr {
 		}
 	default:
 	}
+
+	// Ensure time.Duration values are _always_ formatted as a Go duration
+	// string (ie, "1d2h3m").
+	if v, ok := a.Value.Any().(time.Duration); ok {
+		a.Value = slog.StringValue(v.String())
+	}
+
 	return a
 }
 

promslog/slog_test.go

@@ -21,6 +21,7 @@ import (
 	"regexp"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/require"
 	"gopkg.in/yaml.v2"
@@ -94,6 +95,33 @@ func getLogEntryLevelCounts(s string, re *regexp.Regexp) map[string]int {
 	return counters
 }
 
+func TestDurationValues(t *testing.T) {
+	dur, err := time.ParseDuration("1m30s")
+	require.NoError(t, err)
+
+	tests := map[string]struct {
+		logFormat string
+		want      string
+	}{
+		"logfmt_duration_testing": {want: "duration_raw=1m30s duration_string=1m30s", logFormat: "logfmt"},
+		"json_duration_testing":   {want: "\"duration_raw\":\"1m30s\",\"duration_string\":\"1m30s\"", logFormat: "json"},
+	}
+
+	for name, tc := range tests {
+		t.Run(name, func(t *testing.T) {
+			var buf bytes.Buffer
+			config := &Config{
+				Writer: &buf,
+				Format: NewFormat(),
+			}
+			require.NoError(t, config.Format.Set(tc.logFormat))
+			logger := New(config)
+			logger.Info("duration testing", "duration_raw", dur, "duration_string", dur.String())
+			require.Contains(t, buf.String(), tc.want)
+		})
+	}
+}
+
 func TestDynamicLevels(t *testing.T) {
 	var buf bytes.Buffer
 	wantedLevelCounts := map[string]int{"info": 1, "debug": 1}