chore: add more tests for logx/logc (#4603)

core/logc/logs.go

@@ -37,16 +37,18 @@ func Debugf(ctx context.Context, format string, v ...interface{}) {
 	getLogger(ctx).Debugf(format, v...)
 }
 
+// Debugfn writes fn result into access log.
+// This is useful when the function is expensive to compute,
+// and we want to log it only when necessary.
+func Debugfn(ctx context.Context, fn func() any) {
+	getLogger(ctx).Debugfn(fn)
+}
+
 // Debugv writes v into access log with json content.
 func Debugv(ctx context.Context, v interface{}) {
 	getLogger(ctx).Debugv(v)
 }
 
-// Debugfn writes fn result into access log.
-func Debugfn(ctx context.Context, fn func() string) {
-	getLogger(ctx).Debugfn(fn)
-}
-
 // Debugw writes msg along with fields into the access log.
 func Debugw(ctx context.Context, msg string, fields ...LogField) {
 	getLogger(ctx).Debugw(msg, fields...)
@@ -62,6 +64,13 @@ func Errorf(ctx context.Context, format string, v ...any) {
 	getLogger(ctx).Errorf(fmt.Errorf(format, v...).Error())
 }
 
+// Errorfn writes fn result into error log.
+// This is useful when the function is expensive to compute,
+// and we want to log it only when necessary.
+func Errorfn(ctx context.Context, fn func() any) {
+	getLogger(ctx).Errorfn(fn)
+}
+
 // Errorv writes v into error log with json content.
 // No call stack attached, because not elegant to pack the messages.
 func Errorv(ctx context.Context, v any) {
@@ -88,16 +97,18 @@ func Infof(ctx context.Context, format string, v ...any) {
 	getLogger(ctx).Infof(format, v...)
 }
 
+// Infofn writes fn result into access log.
+// This is useful when the function is expensive to compute,
+// and we want to log it only when necessary.
+func Infofn(ctx context.Context, fn func() any) {
+	getLogger(ctx).Infofn(fn)
+}
+
 // Infov writes v into access log with json content.
 func Infov(ctx context.Context, v any) {
 	getLogger(ctx).Infov(v)
 }
 
-// Infofn writes fn result into access log.
-func Infofn(ctx context.Context, fn func() string) {
-	getLogger(ctx).Infofn(fn)
-}
-
 // Infow writes msg along with fields into the access log.
 func Infow(ctx context.Context, msg string, fields ...LogField) {
 	getLogger(ctx).Infow(msg, fields...)
@@ -137,6 +148,13 @@ func Slowf(ctx context.Context, format string, v ...any) {
 	getLogger(ctx).Slowf(format, v...)
 }
 
+// Slowfn writes fn result into slow log.
+// This is useful when the function is expensive to compute,
+// and we want to log it only when necessary.
+func Slowfn(ctx context.Context, fn func() any) {
+	getLogger(ctx).Slowfn(fn)
+}
+
 // Slowv writes v into slow log with json content.
 func Slowv(ctx context.Context, v any) {
 	getLogger(ctx).Slowv(v)

core/logc/logs_test.go

@@ -49,6 +49,15 @@ func TestErrorf(t *testing.T) {
 	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
 }
 
+func TestErrorfn(t *testing.T) {
+	buf := logtest.NewCollector(t)
+	file, line := getFileLine()
+	Errorfn(context.Background(), func() any {
+		return fmt.Sprintf("foo %s", "bar")
+	})
+	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
+}
+
 func TestErrorv(t *testing.T) {
 	buf := logtest.NewCollector(t)
 	file, line := getFileLine()
@@ -77,6 +86,15 @@ func TestInfof(t *testing.T) {
 	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
 }
 
+func TestInfofn(t *testing.T) {
+	buf := logtest.NewCollector(t)
+	file, line := getFileLine()
+	Infofn(context.Background(), func() any {
+		return fmt.Sprintf("foo %s", "bar")
+	})
+	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
+}
+
 func TestInfov(t *testing.T) {
 	buf := logtest.NewCollector(t)
 	file, line := getFileLine()
@@ -105,6 +123,15 @@ func TestDebugf(t *testing.T) {
 	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
 }
 
+func TestDebugfn(t *testing.T) {
+	buf := logtest.NewCollector(t)
+	file, line := getFileLine()
+	Debugfn(context.Background(), func() any {
+		return fmt.Sprintf("foo %s", "bar")
+	})
+	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)))
+}
+
 func TestDebugv(t *testing.T) {
 	buf := logtest.NewCollector(t)
 	file, line := getFileLine()
@@ -148,6 +175,15 @@ func TestSlowf(t *testing.T) {
 	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)), buf.String())
 }
 
+func TestSlowfn(t *testing.T) {
+	buf := logtest.NewCollector(t)
+	file, line := getFileLine()
+	Slowfn(context.Background(), func() any {
+		return fmt.Sprintf("foo %s", "bar")
+	})
+	assert.True(t, strings.Contains(buf.String(), fmt.Sprintf("%s:%d", file, line+1)), buf.String())
+}
+
 func TestSlowv(t *testing.T) {
 	buf := logtest.NewCollector(t)
 	file, line := getFileLine()

core/logx/logger.go

@@ -11,16 +11,18 @@ type Logger interface {
 	Debug(...any)
 	// Debugf logs a message at debug level.
 	Debugf(string, ...any)
+	// Debugfn logs a message at debug level.
+	Debugfn(func() any)
 	// Debugv logs a message at debug level.
 	Debugv(any)
-	// Debugfn logs a message at debug level.
-	Debugfn(func() string)
 	// Debugw logs a message at debug level.
 	Debugw(string, ...LogField)
 	// Error logs a message at error level.
 	Error(...any)
 	// Errorf logs a message at error level.
 	Errorf(string, ...any)
+	// Errorfn logs a message at error level.
+	Errorfn(func() any)
 	// Errorv logs a message at error level.
 	Errorv(any)
 	// Errorw logs a message at error level.
@@ -29,16 +31,18 @@ type Logger interface {
 	Info(...any)
 	// Infof logs a message at info level.
 	Infof(string, ...any)
+	// Infofn logs a message at info level.
+	Infofn(func() any)
 	// Infov logs a message at info level.
 	Infov(any)
-	// Infofn logs a message at info level.
-	Infofn(func() string)
 	// Infow logs a message at info level.
 	Infow(string, ...LogField)
 	// Slow logs a message at slow level.
 	Slow(...any)
 	// Slowf logs a message at slow level.
 	Slowf(string, ...any)
+	// Slowfn logs a message at slow level.
+	Slowfn(func() any)
 	// Slowv logs a message at slow level.
 	Slowv(any)
 	// Sloww logs a message at slow level.

core/logx/logs.go

@@ -100,6 +100,14 @@ func Debugf(format string, v ...any) {
 	}
 }
 
+// Debugfn writes function result into access log if debug level enabled.
+// This is useful when the function is expensive to call and debug level disabled.
+func Debugfn(fn func() any) {
+	if shallLog(DebugLevel) {
+		writeDebug(fn())
+	}
+}
+
 // Debugv writes v into access log with json content.
 func Debugv(v any) {
 	if shallLog(DebugLevel) {
@@ -107,13 +115,6 @@ func Debugv(v any) {
 	}
 }
 
-// Debugfn writes function result into access log.
-func Debugfn(fn func() string) {
-	if shallLog(DebugLevel) {
-		writeDebug(fn())
-	}
-}
-
 // Debugw writes msg along with fields into the access log.
 func Debugw(msg string, fields ...LogField) {
 	if shallLog(DebugLevel) {
@@ -146,6 +147,13 @@ func Errorf(format string, v ...any) {
 	}
 }
 
+// Errorfn writes function result into error log.
+func Errorfn(fn func() any) {
+	if shallLog(ErrorLevel) {
+		writeError(fn())
+	}
+}
+
 // ErrorStack writes v along with call stack into error log.
 func ErrorStack(v ...any) {
 	if shallLog(ErrorLevel) {
@@ -229,6 +237,14 @@ func Infof(format string, v ...any) {
 	}
 }
 
+// Infofn writes function result into access log.
+// This is useful when the function is expensive to call and info level disabled.
+func Infofn(fn func() any) {
+	if shallLog(InfoLevel) {
+		writeInfo(fn())
+	}
+}
+
 // Infov writes v into access log with json content.
 func Infov(v any) {
 	if shallLog(InfoLevel) {
@@ -236,13 +252,6 @@ func Infov(v any) {
 	}
 }
 
-// Infofn writes function result into access log.
-func Infofn(fn func() string) {
-	if shallLog(InfoLevel) {
-		writeInfo(fn())
-	}
-}
-
 // Infow writes msg along with fields into the access log.
 func Infow(msg string, fields ...LogField) {
 	if shallLog(InfoLevel) {
@@ -362,6 +371,14 @@ func Slowf(format string, v ...any) {
 	}
 }
 
+// Slowfn writes function result into slow log.
+// This is useful when the function is expensive to call and slow level disabled.
+func Slowfn(fn func() any) {
+	if shallLog(ErrorLevel) {
+		writeSlow(fn())
+	}
+}
+
 // Slowv writes v into slow log with json content.
 func Slowv(v any) {
 	if shallLog(ErrorLevel) {

core/logx/logs_test.go

@@ -248,6 +248,32 @@ func TestStructedLogDebugf(t *testing.T) {
 	})
 }
 
+func TestStructedLogDebugfn(t *testing.T) {
+	t.Run("debugfn with output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLog(t, levelDebug, w, func(v ...any) {
+			Debugfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+
+	t.Run("debugfn without output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLogEmpty(t, w, InfoLevel, func(v ...any) {
+			Debugfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+}
+
 func TestStructedLogDebugv(t *testing.T) {
 	w := new(mockWriter)
 	old := writer.Swap(w)
@@ -257,26 +283,7 @@ func TestStructedLogDebugv(t *testing.T) {
 		Debugv(fmt.Sprint(v...))
 	})
 }
-func TestStructedLogDebugfn(t *testing.T) {
-	w := new(mockWriter)
-	old := writer.Swap(w)
-	defer writer.Store(old)
-	doTestStructedLog(t, levelDebug, w, func(v ...any) {
-		Debugfn(func() string {
-			return fmt.Sprint(v...)
-		})
-	})
-}
-func TestDebugfnWithInfoLevel(t *testing.T) {
-	called := false
-	SetLevel(InfoLevel)
-	defer SetLevel(DebugLevel)
-	Debugfn(func() string {
-		called = true
-		return "long time log"
-	})
-	assert.False(t, called)
-}
+
 func TestStructedLogDebugw(t *testing.T) {
 	w := new(mockWriter)
 	old := writer.Swap(w)
@@ -307,6 +314,32 @@ func TestStructedLogErrorf(t *testing.T) {
 	})
 }
 
+func TestStructedLogErrorfn(t *testing.T) {
+	t.Run("errorfn with output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLog(t, levelError, w, func(v ...any) {
+			Errorfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+
+	t.Run("errorfn without output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLogEmpty(t, w, SevereLevel, func(v ...any) {
+			Errorfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+}
+
 func TestStructedLogErrorv(t *testing.T) {
 	w := new(mockWriter)
 	old := writer.Swap(w)
@@ -347,6 +380,32 @@ func TestStructedLogInfof(t *testing.T) {
 	})
 }
 
+func TestStructedInfofn(t *testing.T) {
+	t.Run("infofn with output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLog(t, levelInfo, w, func(v ...any) {
+			Infofn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+
+	t.Run("infofn without output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLogEmpty(t, w, ErrorLevel, func(v ...any) {
+			Infofn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+}
+
 func TestStructedLogInfov(t *testing.T) {
 	w := new(mockWriter)
 	old := writer.Swap(w)
@@ -469,22 +528,12 @@ func TestStructedLogInfoConsoleText(t *testing.T) {
 		Info(fmt.Sprint(v...))
 	})
 }
-func TestStructedInfofn(t *testing.T) {
-	w := new(mockWriter)
-	old := writer.Swap(w)
-	defer writer.Store(old)
 
-	doTestStructedLog(t, levelInfo, w, func(v ...any) {
-		Infofn(func() string {
-			return fmt.Sprint(v...)
-		})
-	})
-}
 func TestInfofnWithErrorLevel(t *testing.T) {
 	called := false
 	SetLevel(ErrorLevel)
 	defer SetLevel(DebugLevel)
-	Infofn(func() string {
+	Infofn(func() any {
 		called = true
 		return "info log"
 	})
@@ -511,6 +560,32 @@ func TestStructedLogSlowf(t *testing.T) {
 	})
 }
 
+func TestStructedLogSlowfn(t *testing.T) {
+	t.Run("slowfn with output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLog(t, levelSlow, w, func(v ...any) {
+			Slowfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+
+	t.Run("slowfn without output", func(t *testing.T) {
+		w := new(mockWriter)
+		old := writer.Swap(w)
+		defer writer.Store(old)
+
+		doTestStructedLogEmpty(t, w, SevereLevel, func(v ...any) {
+			Slowfn(func() any {
+				return fmt.Sprint(v...)
+			})
+		})
+	})
+}
+
 func TestStructedLogSlowv(t *testing.T) {
 	w := new(mockWriter)
 	old := writer.Swap(w)
@@ -887,6 +962,16 @@ func doTestStructedLogConsole(t *testing.T, w *mockWriter, write func(...any)) {
 	assert.True(t, strings.Contains(w.String(), message))
 }
 
+func doTestStructedLogEmpty(t *testing.T, w *mockWriter, level uint32, write func(...any)) {
+	olevel := atomic.LoadUint32(&logLevel)
+	SetLevel(level)
+	defer SetLevel(olevel)
+
+	const message = "hello there"
+	write(message)
+	assert.Empty(t, w.String())
+}
+
 func testSetLevelTwiceWithMode(t *testing.T, mode string, w *mockWriter) {
 	writer.Store(nil)
 	SetUp(LogConf{

core/logx/richlogger.go

@@ -52,16 +52,17 @@ func (l *richLogger) Debugf(format string, v ...any) {
 	}
 }
 
+func (l *richLogger) Debugfn(fn func() any) {
+	if shallLog(DebugLevel) {
+		l.debug(fn())
+	}
+}
+
 func (l *richLogger) Debugv(v any) {
 	if shallLog(DebugLevel) {
 		l.debug(v)
 	}
 }
-func (l *richLogger) Debugfn(fn func() string) {
-	if shallLog(DebugLevel) {
-		l.debug(fn())
-	}
-}
 
 func (l *richLogger) Debugw(msg string, fields ...LogField) {
 	if shallLog(DebugLevel) {
@@ -81,6 +82,12 @@ func (l *richLogger) Errorf(format string, v ...any) {
 	}
 }
 
+func (l *richLogger) Errorfn(fn func() any) {
+	if shallLog(ErrorLevel) {
+		l.err(fn())
+	}
+}
+
 func (l *richLogger) Errorv(v any) {
 	if shallLog(ErrorLevel) {
 		l.err(v)
@@ -105,15 +112,15 @@ func (l *richLogger) Infof(format string, v ...any) {
 	}
 }
 
-func (l *richLogger) Infov(v any) {
+func (l *richLogger) Infofn(fn func() any) {
 	if shallLog(InfoLevel) {
-		l.info(v)
+		l.info(fn())
 	}
 }
 
-func (l *richLogger) Infofn(fn func() string) {
+func (l *richLogger) Infov(v any) {
 	if shallLog(InfoLevel) {
-		l.info(fn())
+		l.info(v)
 	}
 }
 
@@ -135,6 +142,12 @@ func (l *richLogger) Slowf(format string, v ...any) {
 	}
 }
 
+func (l *richLogger) Slowfn(fn func() any) {
+	if shallLog(ErrorLevel) {
+		l.slow(fn())
+	}
+}
+
 func (l *richLogger) Slowv(v any) {
 	if shallLog(ErrorLevel) {
 		l.slow(v)

core/logx/richlogger_test.go

@@ -63,6 +63,11 @@ func TestTraceDebug(t *testing.T) {
 	l.WithDuration(time.Second).Debugf(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
+	l.WithDuration(time.Second).Debugfn(func() any {
+		return testlog
+	})
+	validate(t, w.String(), true, true)
+	w.Reset()
 	l.WithDuration(time.Second).Debugv(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
@@ -103,6 +108,11 @@ func TestTraceError(t *testing.T) {
 	l.WithDuration(time.Second).Errorf(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
+	l.WithDuration(time.Second).Errorfn(func() any {
+		return testlog
+	})
+	validate(t, w.String(), true, true)
+	w.Reset()
 	l.WithDuration(time.Second).Errorv(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
@@ -140,6 +150,11 @@ func TestTraceInfo(t *testing.T) {
 	l.WithDuration(time.Second).Infof(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
+	l.WithDuration(time.Second).Infofn(func() any {
+		return testlog
+	})
+	validate(t, w.String(), true, true)
+	w.Reset()
 	l.WithDuration(time.Second).Infov(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
@@ -213,6 +228,11 @@ func TestTraceSlow(t *testing.T) {
 	l.WithDuration(time.Second).Slowf(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()
+	l.WithDuration(time.Second).Slowfn(func() any {
+		return testlog
+	})
+	validate(t, w.String(), true, true)
+	w.Reset()
 	l.WithDuration(time.Second).Slowv(testlog)
 	validate(t, w.String(), true, true)
 	w.Reset()

zrpc/server_test.go

@@ -27,7 +27,7 @@ func TestServer(t *testing.T) {
 				Mode:        "console",
 			},
 		},
-		ListenOn:      "localhost:8080",
+		ListenOn:      "localhost:0",
 		Etcd:          discov.EtcdConf{},
 		Auth:          false,
 		Redis:         redis.RedisKeyConf{},
@@ -64,7 +64,7 @@ func TestServerError(t *testing.T) {
 				Mode:        "console",
 			},
 		},
-		ListenOn: "localhost:8080",
+		ListenOn: "localhost:0",
 		Etcd: discov.EtcdConf{
 			Hosts: []string{"localhost"},
 		},
@@ -91,7 +91,7 @@ func TestServer_HasEtcd(t *testing.T) {
 				Mode:        "console",
 			},
 		},
-		ListenOn: "localhost:8080",
+		ListenOn: "localhost:0",
 		Etcd: discov.EtcdConf{
 			Hosts: []string{"notexist"},
 			Key:   "any",