From b21162d6382430a10d6aa5d6fae5adbf100f808a Mon Sep 17 00:00:00 2001
From: swliao425 <107254153+swliao425@users.noreply.github.com>
Date: Sat, 22 Oct 2022 21:57:40 +0800
Subject: [PATCH] fix: redis's pipeline logs are not printed completely (#2538)

* fix: redis's pipeline logs are not printed completely

* add unit test

Signed-off-by: liaoshiwei <liaoshiwei@uniontech.com>

Signed-off-by: liaoshiwei <liaoshiwei@uniontech.com>
---
 core/stores/redis/hook.go      | 21 ++++++++++++++-------
 core/stores/redis/hook_test.go | 11 +++++++++++
 2 files changed, 25 insertions(+), 7 deletions(-)

diff --git a/core/stores/redis/hook.go b/core/stores/redis/hook.go
index 7994fdd7..37f3644f 100644
--- a/core/stores/redis/hook.go
+++ b/core/stores/redis/hook.go
@@ -56,7 +56,7 @@ func (h hook) AfterProcess(ctx context.Context, cmd red.Cmder) error {
 
 	duration := timex.Since(start)
 	if duration > slowThreshold.Load() {
-		logDuration(ctx, cmd, duration)
+		logDuration(ctx, []red.Cmder{cmd}, duration)
 	}
 
 	metricReqDur.Observe(int64(duration/time.Millisecond), cmd.Name())
@@ -103,7 +103,7 @@ func (h hook) AfterProcessPipeline(ctx context.Context, cmds []red.Cmder) error
 
 	duration := timex.Since(start)
 	if duration > slowThreshold.Load()*time.Duration(len(cmds)) {
-		logDuration(ctx, cmds[0], duration)
+		logDuration(ctx, cmds, duration)
 	}
 
 	metricReqDur.Observe(int64(duration/time.Millisecond), "Pipeline")
@@ -136,13 +136,20 @@ func formatError(err error) string {
 	}
 }
 
-func logDuration(ctx context.Context, cmd red.Cmder, duration time.Duration) {
+func logDuration(ctx context.Context, cmds []red.Cmder, duration time.Duration) {
 	var buf strings.Builder
-	for i, arg := range cmd.Args() {
-		if i > 0 {
-			buf.WriteByte(' ')
+	for k, cmd := range cmds {
+		if k > 0 {
+			buf.WriteByte('\n')
 		}
-		buf.WriteString(mapping.Repr(arg))
+		var build strings.Builder
+		for i, arg := range cmd.Args() {
+			if i > 0 {
+				build.WriteByte(' ')
+			}
+			build.WriteString(mapping.Repr(arg))
+		}
+		buf.WriteString(mapping.Repr(build.String()))
 	}
 	logx.WithContext(ctx).WithDuration(duration).Slowf("[REDIS] slowcall on executing: %s", buf.String())
 }
diff --git a/core/stores/redis/hook_test.go b/core/stores/redis/hook_test.go
index ed10f549..7fb7551c 100644
--- a/core/stores/redis/hook_test.go
+++ b/core/stores/redis/hook_test.go
@@ -163,6 +163,17 @@ func TestHookProcessPipelineCase5(t *testing.T) {
 	assert.True(t, buf.Len() == 0)
 }
 
+func TestLogDuration(t *testing.T) {
+	w, restore := injectLog()
+	defer restore()
+
+	logDuration(context.Background(), []red.Cmder{red.NewCmd(context.Background(), "get", "foo")}, 1*time.Second)
+	assert.True(t, strings.Contains(w.String(), "get foo"))
+
+	logDuration(context.Background(), []red.Cmder{red.NewCmd(context.Background(), "get", "foo"), red.NewCmd(context.Background(), "set", "bar", 0)}, 1*time.Second)
+	assert.True(t, strings.Contains(w.String(), "get foo\\nset bar 0"))
+}
+
 func injectLog() (r *strings.Builder, restore func()) {
 	var buf strings.Builder
 	w := logx.NewWriter(&buf)