Better duration formatting in logs

log/formatters.go

@@ -0,0 +1,29 @@
+package log
+
+import (
+	"strings"
+	"time"
+)
+
+func ShortDur(d time.Duration) string {
+	var s string
+	switch {
+	case d > time.Hour:
+		s = d.Round(time.Minute).String()
+	case d > time.Minute:
+		s = d.Round(time.Second).String()
+	case d > time.Second:
+		s = d.Round(10 * time.Millisecond).String()
+	case d > time.Millisecond:
+		s = d.Round(100 * time.Microsecond).String()
+	default:
+		s = d.String()
+	}
+	if strings.HasSuffix(s, "m0s") {
+		s = s[:len(s)-2]
+	}
+	if strings.HasSuffix(s, "h0m") {
+		s = s[:len(s)-2]
+	}
+	return s
+}

log/formatters_test.go

@@ -0,0 +1,35 @@
+package log
+
+import (
+	"time"
+
+	. "github.com/onsi/ginkgo"
+	. "github.com/onsi/gomega"
+)
+
+var _ = Describe("ShortDur", func() {
+	It("formats microseconds", func() {
+		Expect(ShortDur(9 * time.Microsecond)).To(Equal("9µs"))
+		Expect(ShortDur(2 * time.Microsecond)).To(Equal("2µs"))
+	})
+	It("rounds milliseconds", func() {
+		Expect(ShortDur(5*time.Millisecond + 10*time.Microsecond)).To(Equal("5ms"))
+		Expect(ShortDur(5*time.Millisecond + 240*time.Microsecond)).To(Equal("5.2ms"))
+	})
+	It("rounds seconds", func() {
+		Expect(ShortDur(time.Second + 263*time.Millisecond)).To(Equal("1.26s"))
+	})
+	It("removes 0 secs", func() {
+		Expect(ShortDur(4 * time.Minute)).To(Equal("4m"))
+	})
+	It("rounds to seconds", func() {
+		Expect(ShortDur(4*time.Minute + 3*time.Second)).To(Equal("4m3s"))
+	})
+	It("removes 0 minutes", func() {
+		Expect(ShortDur(4 * time.Hour)).To(Equal("4h"))
+	})
+	It("round big durations to the minute", func() {
+		Expect(ShortDur(4*time.Hour + 2*time.Minute + 5*time.Second + 200*time.Millisecond)).
+			To(Equal("4h2m"))
+	})
+})

log/log.go

@@ -7,6 +7,7 @@ import (
 	"net/http"
 	"runtime"
 	"strings"
+	"time"
 
 	"github.com/sirupsen/logrus"
 )
@@ -171,8 +172,12 @@ func addFields(logger *logrus.Entry, keyValuePairs []interface{}) *logrus.Entry
 			if i+1 >= len(keyValuePairs) {
 				logger = logger.WithField(name, "!!!!Invalid number of arguments in log call!!!!")
 			} else {
-				value := keyValuePairs[i+1]
-				logger = logger.WithField(name, value)
+				switch v := keyValuePairs[i+1].(type) {
+				case time.Duration:
+					logger = logger.WithField(name, ShortDur(v))
+				default:
+					logger = logger.WithField(name, v)
+				}
 			}
 		}
 	}