From 8e1778271a717e86ad86a4a682847bef54632710 Mon Sep 17 00:00:00 2001
From: Martin Holst Swende <martin@swende.se>
Date: Thu, 7 Sep 2023 13:55:23 +0200
Subject: [PATCH] log: fix tests

---
 common/types_test.go | 12 +++++++++++
 log/logger_test.go   | 47 ++++++++++++++++++++++----------------------
 2 files changed, 35 insertions(+), 24 deletions(-)

diff --git a/common/types_test.go b/common/types_test.go
index ad892671b5..cec689ea39 100644
--- a/common/types_test.go
+++ b/common/types_test.go
@@ -25,6 +25,7 @@ import (
 	"reflect"
 	"strings"
 	"testing"
+	"time"
 )
 
 func TestBytesConversion(t *testing.T) {
@@ -583,3 +584,14 @@ func TestAddressEIP55(t *testing.T) {
 		t.Fatal("Unexpected address after unmarshal")
 	}
 }
+
+func BenchmarkPrettyDuration(b *testing.B) {
+	var x = PrettyDuration(time.Duration(int64(1203123912312)))
+	b.Logf("Pre %s", time.Duration(x).String())
+	var a string
+	b.ResetTimer()
+	for i := 0; i < b.N; i++ {
+		a = x.String()
+	}
+	b.Logf("Post %s", a)
+}
diff --git a/log/logger_test.go b/log/logger_test.go
index 5a48782676..2e59b3fdf0 100644
--- a/log/logger_test.go
+++ b/log/logger_test.go
@@ -5,26 +5,8 @@ import (
 	"os"
 	"strings"
 	"testing"
-	"time"
 )
 
-func BenchmarkTraceLogging(b *testing.B) {
-	Root().SetHandler(LvlFilterHandler(LvlInfo, StreamHandler(os.Stderr, TerminalFormat(true))))
-	b.ResetTimer()
-	for i := 0; i < b.N; i++ {
-		Trace("a message", "v", i)
-	}
-}
-
-type notimeHandler struct {
-	next Handler
-}
-
-func (n notimeHandler) Log(r *Record) error {
-	r.Time = time.Unix(0, 0)
-	return n.next.Log(r)
-}
-
 // TestLoggingWithTrace checks that if BackTraceAt is set, then the
 // gloghandler is capable of spitting out a stacktrace
 func TestLoggingWithTrace(t *testing.T) {
@@ -34,15 +16,21 @@ func TestLoggingWithTrace(t *testing.T) {
 	{
 		glog := NewGlogHandler(StreamHandler(out, TerminalFormat(false)))
 		glog.Verbosity(LvlTrace)
-		if err := glog.BacktraceAt("logger_test.go:42"); err != nil {
+		if err := glog.BacktraceAt("logger_test.go:24"); err != nil {
 			t.Fatal(err)
 		}
-		logger.SetHandler(notimeHandler{glog})
+		logger.SetHandler(glog)
 	}
 	logger.Trace("a message", "foo", "bar") // Will be bumped to INFO
 	have := out.String()
-	wantPrefix := "INFO [01-01|01:00:00.000] a message\n\ngoroutine"
-	if len(have) < len(wantPrefix) || !strings.HasPrefix(have, wantPrefix) {
+	if !strings.HasPrefix(have, "INFO") {
+		t.Fatalf("backtraceat should bump level to info: %s", have)
+	}
+	// The timestamp is locale-dependent, so we want to trim that off
+	// "INFO [01-01|00:00:00.000] a messag ..." -> "a messag..."
+	have = strings.Split(have, "]")[1]
+	wantPrefix := " a message\n\ngoroutine"
+	if !strings.HasPrefix(have, wantPrefix) {
 		t.Errorf("\nhave: %q\nwant: %q\n", have, wantPrefix)
 	}
 }
@@ -55,14 +43,25 @@ func TestLoggingWithVmodule(t *testing.T) {
 	{
 		glog := NewGlogHandler(StreamHandler(out, TerminalFormat(false)))
 		glog.Verbosity(LvlCrit)
-		logger.SetHandler(notimeHandler{glog})
+		logger.SetHandler(glog)
 		logger.Warn("This should not be seen", "ignored", "true")
 		glog.Vmodule("logger_test.go=5")
 	}
 	logger.Trace("a message", "foo", "bar")
 	have := out.String()
-	want := "TRACE[01-01|01:00:00.000] a message                                foo=bar\n"
+	// The timestamp is locale-dependent, so we want to trim that off
+	// "INFO [01-01|00:00:00.000] a messag ..." -> "a messag..."
+	have = strings.Split(have, "]")[1]
+	want := " a message                                foo=bar\n"
 	if have != want {
 		t.Errorf("\nhave: %q\nwant: %q\n", have, want)
 	}
 }
+
+func BenchmarkTraceLogging(b *testing.B) {
+	Root().SetHandler(LvlFilterHandler(LvlInfo, StreamHandler(os.Stderr, TerminalFormat(true))))
+	b.ResetTimer()
+	for i := 0; i < b.N; i++ {
+		Trace("a message", "v", i)
+	}
+}