feat: improve ExecuteTime log formatting and add output test

- Change log output in ExecuteTime to display the title first and elapsed time in milliseconds
- Add a unit test for ExecuteTime to verify the log output format

Signed-off-by: Bo-Yi Wu <[email protected]>

Author: appleboy

trace/trace.go

@@ -9,5 +9,5 @@ func ExecuteTime(title string, fn func()) {
 	start := time.Now()
 	fn()
 	elapsed := time.Since(start)
-	log.Printf("[%s] %s", elapsed, title)
+	log.Printf("[%s] elapsed=%dms", title, elapsed.Milliseconds())
 }

trace/trace_test.go

@@ -1,6 +1,10 @@
 package trace
 
 import (
+	"bytes"
+	"log"
+	"strings"
+	"testing"
 	"time"
 )
 
@@ -19,3 +23,19 @@ func ExampleExecuteTime() {
 
 	// Output:
 }
+
+func TestExecuteTime(t *testing.T) {
+	var buf bytes.Buffer
+	orig := log.Writer()
+	log.SetOutput(&buf)
+	defer log.SetOutput(orig)
+
+	ExecuteTime("unit test", func() {
+		time.Sleep(10 * time.Millisecond)
+	})
+
+	out := buf.String()
+	if !strings.Contains(out, "[unit test] elapsed=") || !strings.Contains(out, "ms") {
+		t.Errorf("log output format incorrect: %q", out)
+	}
+}