Repository: zeromicro/go-zero (go)

Issue:
通过 WithContext、WithDuration 生成的日志对象不支持并发调用

代码

   ```go
   
	l := logx.WithContext(context.Background())

	arr := []int{1, 2, 3, 4, 5, 6, 7, 8, 9, 0}
	for _, i := range arr {
		go func(i int) {
			l.Info(i)
		}(i)
	}

   ```

输出

   ```
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}
    2021/12/09 16:05:24 {"@timestamp":"2021-12-09T16:05:24.743+08","level":"info","content":"8"}

   ```

可以明显的看见所有的日志 content 内容为 8 ，显然不是预期结果。

问题出在：
``` go

    func (l *traceLogger) write(writer io.Writer, level string, val interface{}) {
	    l.Timestamp = getTimestamp()
	    l.Level = level
	    l.Content = val
	    l.Trace = traceIdFromContext(l.ctx)
	    l.Span = spanIdFromContext(l.ctx)
	    outputJson(writer, l)
    }

```
这段代码，
复用了 traceLogger 对象，在执行 outputJson 前，对象的变量值已被其他 goroutine 修改，才导致了这个问题的出现。
durationLogger 也是同样的问题


Pull request:
fix #1309

Patch:
diff --git a/core/fx/stream.go b/core/fx/stream.go
index e832ffba..9f5e7364 100644
--- a/core/fx/stream.go
+++ b/core/fx/stream.go
@@ -246,7 +246,7 @@ func (s Stream) Head(n int64) Stream {
 			}
 			if n == 0 {
 				// let successive method go ASAP even we have more items to skip
-				// why we don't just break the loop, because if break,
+				// why we don't just break the loop, because if breaks,
 				// this former goroutine will block forever, which will cause goroutine leak.
 				close(source)
 			}
diff --git a/core/logx/durationlogger.go b/core/logx/durationlogger.go
index d55af95f..d4a2447c 100644
--- a/core/logx/durationlogger.go
+++ b/core/logx/durationlogger.go
@@ -79,8 +79,10 @@ func (l *durationLogger) WithDuration(duration time.Duration) Logger {
 }
 
 func (l *durationLogger) write(writer io.Writer, level string, val interface{}) {
-	l.Timestamp = getTimestamp()
-	l.Level = level
-	l.Content = val
-	outputJson(writer, l)
+	outputJson(writer, &durationLogger{
+		Timestamp: getTimestamp(),
+		Level:     level,
+		Content:   val,
+		Duration:  l.Duration,
+	})
 }
diff --git a/core/logx/tracelogger.go b/core/logx/tracelogger.go
index c02e0c9d..21b1628c 100644
--- a/core/logx/tracelogger.go
+++ b/core/logx/tracelogger.go
@@ -77,12 +77,16 @@ func (l *traceLogger) WithDuration(duration time.Duration) Logger {
 }
 
 func (l *traceLogger) write(writer io.Writer, level string, val interface{}) {
-	l.Timestamp = getTimestamp()
-	l.Level = level
-	l.Content = val
-	l.Trace = traceIdFromContext(l.ctx)
-	l.Span = spanIdFromContext(l.ctx)
-	outputJson(writer, l)
+	outputJson(writer, &traceLogger{
+		logEntry: logEntry{
+			Timestamp: getTimestamp(),
+			Level:     level,
+			Duration:  l.Duration,
+			Content:   val,
+		},
+		Trace: traceIdFromContext(l.ctx),
+		Span:  spanIdFromContext(l.ctx),
+	})
 }
 
 // WithContext sets ctx to log, for keeping tracing information.


Test patch:
diff --git a/core/logx/durationlogger_test.go b/core/logx/durationlogger_test.go
index f5b6eb77..b916c2b5 100644
--- a/core/logx/durationlogger_test.go
+++ b/core/logx/durationlogger_test.go
@@ -23,6 +23,13 @@ func TestWithDurationErrorf(t *testing.T) {
 	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
 }
 
+func TestWithDurationErrorv(t *testing.T) {
+	var builder strings.Builder
+	log.SetOutput(&builder)
+	WithDuration(time.Second).Errorv("foo")
+	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
+}
+
 func TestWithDurationInfo(t *testing.T) {
 	var builder strings.Builder
 	log.SetOutput(&builder)
@@ -37,6 +44,13 @@ func TestWithDurationInfof(t *testing.T) {
 	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
 }
 
+func TestWithDurationInfov(t *testing.T) {
+	var builder strings.Builder
+	log.SetOutput(&builder)
+	WithDuration(time.Second).Infov("foo")
+	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
+}
+
 func TestWithDurationSlow(t *testing.T) {
 	var builder strings.Builder
 	log.SetOutput(&builder)
@@ -50,3 +64,10 @@ func TestWithDurationSlowf(t *testing.T) {
 	WithDuration(time.Second).WithDuration(time.Hour).Slowf("foo")
 	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
 }
+
+func TestWithDurationSlowv(t *testing.T) {
+	var builder strings.Builder
+	log.SetOutput(&builder)
+	WithDuration(time.Second).WithDuration(time.Hour).Slowv("foo")
+	assert.True(t, strings.Contains(builder.String(), "duration"), builder.String())
+}
diff --git a/core/logx/tracelogger_test.go b/core/logx/tracelogger_test.go
index c05c0f86..52363497 100644
--- a/core/logx/tracelogger_test.go
+++ b/core/logx/tracelogger_test.go
@@ -51,6 +51,10 @@ func TestTraceError(t *testing.T) {
 	l.WithDuration(time.Second).Errorf(testlog)
 	assert.True(t, strings.Contains(buf.String(), traceKey))
 	assert.True(t, strings.Contains(buf.String(), spanKey))
+	buf.Reset()
+	l.WithDuration(time.Second).Errorv(testlog)
+	assert.True(t, strings.Contains(buf.String(), traceKey))
+	assert.True(t, strings.Contains(buf.String(), spanKey))
 }
 
 func TestTraceInfo(t *testing.T) {
@@ -72,6 +76,10 @@ func TestTraceInfo(t *testing.T) {
 	l.WithDuration(time.Second).Infof(testlog)
 	assert.True(t, strings.Contains(buf.String(), traceKey))
 	assert.True(t, strings.Contains(buf.String(), spanKey))
+	buf.Reset()
+	l.WithDuration(time.Second).Infov(testlog)
+	assert.True(t, strings.Contains(buf.String(), traceKey))
+	assert.True(t, strings.Contains(buf.String(), spanKey))
 }
 
 func TestTraceSlow(t *testing.T) {
@@ -93,6 +101,10 @@ func TestTraceSlow(t *testing.T) {
 	l.WithDuration(time.Second).Slowf(testlog)
 	assert.True(t, strings.Contains(buf.String(), traceKey))
 	assert.True(t, strings.Contains(buf.String(), spanKey))
+	buf.Reset()
+	l.WithDuration(time.Second).Slowv(testlog)
+	assert.True(t, strings.Contains(buf.String(), traceKey))
+	assert.True(t, strings.Contains(buf.String(), spanKey))
 }
 
 func TestTraceWithoutContext(t *testing.T) {