Fix closerCore With behaviour (#210)

This commit fixes the behaviour of `closerCore.With` and add tests to
ensure it works as expected.

The tests are a modification of existing tests that calls the
configuration functions like Beats does and ensures both closerCore
and typedCore are used. The method calls get proxyed from one core to
another, so both are tested together.

The race detector is enabled when testing on Linux and MacOS. Windows
requires CGO and installation of gcc on CI, so it is not covered by this commit.

Author: belimawr

.buildkite/scripts/test.sh

@@ -11,7 +11,7 @@ with_go_junit_report
 
 echo "--- Go Test"
 set +e
-go test -v ./... > tests-report.txt
+go test -race -v ./... > tests-report.txt
 exit_code=$?
 set -e
 

NOTICE.txt

@@ -1252,11 +1252,11 @@ Contents of probable licence file $GOMODCACHE/github.com/spf13/[email protected]/LICE
 
 --------------------------------------------------------------------------------
 Dependency : github.com/stretchr/testify
-Version: v1.8.2
+Version: v1.9.0
 Licence type (autodetected): MIT
 --------------------------------------------------------------------------------
 
-Contents of probable licence file $GOMODCACHE/github.com/stretchr/testify@v1.8.2/LICENSE:
+Contents of probable licence file $GOMODCACHE/github.com/stretchr/testify@v1.9.0/LICENSE:
 
 MIT License
 
@@ -4562,11 +4562,11 @@ OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 
 --------------------------------------------------------------------------------
 Dependency : github.com/stretchr/objx
-Version: v0.5.0
+Version: v0.5.2
 Licence type (autodetected): MIT
 --------------------------------------------------------------------------------
 
-Contents of probable licence file $GOMODCACHE/github.com/stretchr/[email protected].0/LICENSE:
+Contents of probable licence file $GOMODCACHE/github.com/stretchr/[email protected].2/LICENSE:
 
 The MIT License
 

go.mod

@@ -15,7 +15,7 @@ require (
 	github.com/mitchellh/hashstructure v1.1.0
 	github.com/rcrowley/go-metrics v0.0.0-20201227073835-cf1acfcdf475
 	github.com/spf13/cobra v1.7.0
-	github.com/stretchr/testify v1.8.2
+	github.com/stretchr/testify v1.9.0
 	go.elastic.co/apm/module/apmhttp/v2 v2.0.0
 	go.elastic.co/ecszap v1.0.1
 	go.elastic.co/go-licence-detector v0.5.0

go.sum

@@ -90,17 +90,13 @@ github.com/spf13/cobra v1.7.0/go.mod h1:uLxZILRyS/50WlhOIKD7W6V5bgeIt+4sICxh6uRM
 github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA=
 github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg=
 github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
-github.com/stretchr/objx v0.4.0/go.mod h1:YvHI0jy2hoMjB+UWwv71VJQ9isScKT/TqJzVSSt89Yw=
-github.com/stretchr/objx v0.5.0/go.mod h1:Yh+to48EsGEfYuaHDzXPcE3xhTkx73EhmCGUpEOglKo=
 github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
 github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
 github.com/stretchr/testify v1.4.0/go.mod h1:j7eGeouHqKxXV5pUuKE4zz7dFj8WfuZ+81PSLYec5m4=
 github.com/stretchr/testify v1.6.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
 github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
-github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU=
-github.com/stretchr/testify v1.8.2 h1:+h33VjcLVPDHtOdpUCuF+7gSuG3yGIftsP1YvFihtJ8=
-github.com/stretchr/testify v1.8.2/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4=
+github.com/stretchr/testify v1.9.0 h1:HtqpIVDClZ4nwg75+f6Lvsy/wHu+3BoSGCbBAcpTsTg=
+github.com/stretchr/testify v1.9.0/go.mod h1:r2ic/lqez/lEtzL7wO/rwa5dbSLXVDPFyf8C91i36aY=
 github.com/yuin/goldmark v1.1.27/go.mod h1:3hX8gzYuyVAZsxl0MRgGTJEmQBFcNTphYh9decYSb74=
 github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
 github.com/yuin/goldmark v1.4.0/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=

logp/core.go

@@ -26,7 +26,6 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
-	"sync"
 	"sync/atomic"
 	"unsafe"
 
@@ -67,14 +66,13 @@ type coreLogger struct {
 type closerCore struct {
 	zapcore.Core
 	io.Closer
-	mutex sync.Mutex
 }
 
-func (c *closerCore) With(fields []zapcore.Field) zapcore.Core {
-	c.mutex.Lock()
-	c.Core = c.Core.With(fields)
-	c.mutex.Unlock()
-	return c
+func (c closerCore) With(fields []zapcore.Field) zapcore.Core {
+	return closerCore{
+		Core:   c.Core.With(fields),
+		Closer: c.Closer,
+	}
 }
 
 // Configure configures the logp package.

logp/core_test.go

@@ -635,6 +635,70 @@ func TestCoresCanBeClosed(t *testing.T) {
 	}
 }
 
+func TestCloserLoggerCoreWith(t *testing.T) {
+	defaultWriter := writeSyncer{}
+
+	cfg := zap.NewProductionEncoderConfig()
+	cfg.TimeKey = "" // remove the time to make the log entry consistent
+
+	core := closerCore{
+		Core: zapcore.NewCore(
+			zapcore.NewJSONEncoder(cfg),
+			&defaultWriter,
+			zapcore.InfoLevel,
+		),
+	}
+
+	expectedLines := []string{
+		// First/Default logger
+		`{"level":"info","msg":"Very first message"}`,
+
+		// Two messages after calling With
+		`{"level":"info","msg":"a message with extra fields","foo":"bar"}`,
+		`{"level":"info","msg":"another message with extra fields","foo":"bar"}`,
+
+		// A message with the default logger
+		`{"level":"info","msg":"a message without extra fields"}`,
+
+		// Two more messages with a different field
+		`{"level":"info","msg":"a message with an answer","answer":"42"}`,
+		`{"level":"info","msg":"another message with an answer","answer":"42"}`,
+
+		// One last message with the default logger
+		`{"level":"info","msg":"another message without any extra fields"}`,
+	}
+
+	// The default logger, it should not be modified by any call to With.
+	logger := zap.New(&core)
+	logger.Info("Very first message")
+
+	// Add a field and write messages
+	loggerWithFields := logger.With(strField("foo", "bar"))
+	loggerWithFields.Info("a message with extra fields")
+	loggerWithFields.Info("another message with extra fields")
+
+	// Use the default logger again
+	logger.Info("a message without extra fields")
+
+	// New logger with other fields
+	loggerWithFields = logger.With(strField("answer", "42"))
+	loggerWithFields.Info("a message with an answer")
+	loggerWithFields.Info("another message with an answer")
+
+	// One last message with the default logger
+	logger.Info("another message without any extra fields")
+
+	scanner := bufio.NewScanner(strings.NewReader(defaultWriter.String()))
+	count := 0
+	for scanner.Scan() {
+		l := scanner.Text()
+		if l != expectedLines[count] {
+			t.Error("Expecting:\n", l, "\nGot:\n", expectedLines[count])
+		}
+		count++
+	}
+}
+
 func strField(key, val string) zapcore.Field {
 	return zapcore.Field{Type: zapcore.StringType, Key: key, String: val}
 }