Unify logging in tests (#38)

adapters.go

@@ -235,7 +235,6 @@ func (a *whisperAdapter) handleMessages(shhMessage *whisper.Message, application
 	statusMessages, err := statusMessage.HandleDatasync(a.datasync)
 	if err != nil {
 		hlogger.Debug("failed to handle datasync message", zap.Error(err))
-
 	}
 
 	for _, statusMessage := range statusMessages {

encryption/encryption_multi_device_test.go

@@ -6,6 +6,8 @@ import (
 	"io/ioutil"
 	"testing"
 
+	"github.com/status-im/status-protocol-go/tt"
+
 	"github.com/status-im/status-protocol-go/encryption/migrations"
 	"github.com/status-im/status-protocol-go/sqlite"
 
@@ -78,12 +80,10 @@ func setupUser(user string, s *EncryptionServiceMultiDeviceSuite, n int) error {
 }
 
 func (s *EncryptionServiceMultiDeviceSuite) SetupTest() {
-	logger, err := zap.NewDevelopment()
+	s.logger = tt.MustCreateTestLogger()
-	s.Require().NoError(err)
-	s.logger = logger
 
 	s.services = make(map[string]*serviceAndKey)
-	err = setupUser(aliceUser, s, 4)
+	err := setupUser(aliceUser, s, 4)
 	s.Require().NoError(err)
 
 	err = setupUser(bobUser, s, 4)

encryption/protocol_test.go

@@ -5,6 +5,8 @@ import (
 	"os"
 	"testing"
 
+	"github.com/status-im/status-protocol-go/tt"
+
 	migrations "github.com/status-im/status-protocol-go/encryption/migrations"
 	"github.com/status-im/status-protocol-go/sqlite"
 
@@ -32,9 +34,7 @@ type ProtocolServiceTestSuite struct {
 func (s *ProtocolServiceTestSuite) SetupTest() {
 	var err error
 
-	logger, err := zap.NewDevelopment()
+	s.logger = tt.MustCreateTestLogger()
-	s.Require().NoError(err)
-	s.logger = logger
 
 	s.aliceDBPath, err = ioutil.TempFile("", "alice.db.sql")
 	s.Require().NoError(err)
@@ -58,7 +58,7 @@ func (s *ProtocolServiceTestSuite) SetupTest() {
 		addedBundlesHandler,
 		onNewSharedSecretHandler,
 		func(*ProtocolMessageSpec) {},
-		logger.With(zap.String("user", "alice")),
+		s.logger.With(zap.String("user", "alice")),
 	)
 
 	db, err = sqlite.Open(s.bobDBPath.Name(), bobDBKey, sqlite.MigrationConfig{
@@ -72,7 +72,7 @@ func (s *ProtocolServiceTestSuite) SetupTest() {
 		addedBundlesHandler,
 		onNewSharedSecretHandler,
 		func(*ProtocolMessageSpec) {},
-		logger.With(zap.String("user", "bob")),
+		s.logger.With(zap.String("user", "bob")),
 	)
 }
 

encryption/publisher/publisher_test.go

@@ -7,6 +7,8 @@ import (
 
 	"github.com/stretchr/testify/suite"
 	"go.uber.org/zap"
+
+	"github.com/status-im/status-protocol-go/tt"
 )
 
 func TestServiceTestSuite(t *testing.T) {
@@ -26,11 +28,8 @@ func (p *PublisherTestSuite) SetupTest(installationID string) {
 	db, err := sql.Open("sqlite3", dir)
 	p.Require().NoError(err)
 
-	logger, err := zap.NewDevelopment()
+	p.logger = tt.MustCreateTestLogger()
-	p.Require().NoError(err)
+	p.publisher = New(db, p.logger)
-	p.logger = logger
-
-	p.publisher = New(db, logger)
 }
 
 func (p *PublisherTestSuite) TearDownTest() {

encryption/sharedsecret/service_test.go

@@ -5,6 +5,8 @@ import (
 	"os"
 	"testing"
 
+	"github.com/status-im/status-protocol-go/tt"
+
 	"github.com/ethereum/go-ethereum/crypto"
 	migrations "github.com/status-im/status-protocol-go/encryption/migrations"
 	"github.com/status-im/status-protocol-go/sqlite"
@@ -24,9 +26,7 @@ type SharedSecretTestSuite struct {
 }
 
 func (s *SharedSecretTestSuite) SetupTest() {
-	logger, err := zap.NewDevelopment()
+	s.logger = tt.MustCreateTestLogger()
-	s.Require().NoError(err)
-	s.logger = logger
 
 	dbFile, err := ioutil.TempFile(os.TempDir(), "sharedsecret")
 	s.Require().NoError(err)
@@ -40,7 +40,7 @@ func (s *SharedSecretTestSuite) SetupTest() {
 	})
 	s.Require().NoError(err)
 
-	s.service = New(db, logger)
+	s.service = New(db, s.logger)
 }
 
 func (s *SharedSecretTestSuite) TearDownTest() {

log_encoder_test.go

@@ -1,23 +0,0 @@
-package statusproto
-
-import (
-	"testing"
-	"time"
-
-	"github.com/stretchr/testify/require"
-	"go.uber.org/zap"
-	"go.uber.org/zap/zapcore"
-)
-
-func TestJSONHexEncoder(t *testing.T) {
-	encoder := NewJSONHexEncoder(zap.NewDevelopmentEncoderConfig())
-	encoder.AddBinary("test-key", []byte{0x01, 0x02, 0x03})
-	buf, err := encoder.EncodeEntry(zapcore.Entry{
-		LoggerName: "",
-		Time:       time.Now(),
-		Level:      zapcore.DebugLevel,
-		Message:    "",
-	}, nil)
-	require.NoError(t, err)
-	require.Contains(t, buf.String(), `"test-key":"0x010203"`)
-}

messenger_test.go

@@ -9,6 +9,8 @@ import (
 	"testing"
 	"time"
 
+	"github.com/status-im/status-protocol-go/tt"
+
 	"github.com/stretchr/testify/suite"
 	"go.uber.org/zap"
 
@@ -53,9 +55,7 @@ type MessengerSuite struct {
 func (s *MessengerSuite) SetupTest() {
 	var err error
 
-	logger, err := zap.NewDevelopment()
+	s.logger = tt.MustCreateTestLogger()
-	s.Require().NoError(err)
-	s.logger = logger
 
 	s.tmpFile, err = ioutil.TempFile("", "messenger-test.sql")
 	s.Require().NoError(err)
@@ -73,7 +73,7 @@ func (s *MessengerSuite) SetupTest() {
 		nil,
 		shh,
 		"installation-1",
-		WithCustomLogger(logger),
+		WithCustomLogger(s.logger),
 		WithMessagesPersistenceEnabled(),
 		WithDatabaseConfig(s.tmpFile.Name(), "some-key"),
 	)

transport/whisper/filter/chats_test.go

@@ -8,6 +8,8 @@ import (
 	"os"
 	"testing"
 
+	"github.com/status-im/status-protocol-go/tt"
+
 	"github.com/ethereum/go-ethereum/crypto"
 	_ "github.com/mutecomm/go-sqlcipher"
 	whisper "github.com/status-im/whisper/whisperv6"
@@ -52,9 +54,7 @@ func newTestKey(privateKey string, partitionedTopic int) (*testKey, error) {
 }
 
 func (s *ChatsTestSuite) SetupTest() {
-	logger, err := zap.NewDevelopment()
+	s.logger = tt.MustCreateTestLogger()
-	s.Require().NoError(err)
-	s.logger = logger
 
 	keyStrs := []string{
 		"c6cbd7d76bc5baca530c875663711b947efa6a86a900a9e8645ce32e5821484e",
@@ -82,7 +82,7 @@ func (s *ChatsTestSuite) SetupTest() {
 
 	whisper := whisper.New(nil)
 
-	s.chats, err = New(db, whisper, s.keys[0].privateKey, logger)
+	s.chats, err = New(db, whisper, s.keys[0].privateKey, s.logger)
 	s.Require().NoError(err)
 }
 

transport/whisper/whisper_service_test.go

@@ -9,11 +9,12 @@ import (
 	migrations "github.com/status-im/status-protocol-go/transport/whisper/migrations"
 
 	"github.com/stretchr/testify/require"
-	"go.uber.org/zap"
+
+	"github.com/status-im/status-protocol-go/tt"
 )
 
 func TestSelectAndAddNoMailservers(t *testing.T) {
-	logger := zap.NewNop()
+	logger := tt.MustCreateTestLogger()
 	svc := &WhisperServiceTransport{
 		logger: logger,
 	}
@@ -34,7 +35,7 @@ func TestNewWhisperServiceTransport(t *testing.T) {
 	})
 	require.NoError(t, err)
 
-	logger, err := zap.NewDevelopment()
+	logger := tt.MustCreateTestLogger()
 	require.NoError(t, err)
 	defer func() { _ = logger.Sync() }()
 

tt/logger.go

@@ -0,0 +1,28 @@
+package tt
+
+import (
+	"sync"
+
+	"github.com/status-im/status-protocol-go/zaputil"
+
+	"go.uber.org/zap"
+)
+
+var registerOnce sync.Once
+
+// MustCreateTestLogger returns a logger based on the passed flags.
+func MustCreateTestLogger() *zap.Logger {
+	registerOnce.Do(func() {
+		if err := zaputil.RegisterConsoleHexEncoder(); err != nil {
+			panic(err)
+		}
+	})
+
+	cfg := zap.NewDevelopmentConfig()
+	cfg.Encoding = "console-hex"
+	l, err := cfg.Build()
+	if err != nil {
+		panic(err)
+	}
+	return l
+}

zaputil/encoder.go

@@ -1,4 +1,4 @@
-package statusproto
+package zaputil
 
 import (
 	"encoding/hex"
@@ -26,6 +26,11 @@ func (enc *jsonHexEncoder) AddBinary(key string, val []byte) {
 	enc.AddString(key, "0x"+hex.EncodeToString(val))
 }
 
+func (enc *jsonHexEncoder) Clone() zapcore.Encoder {
+	encoderClone := enc.Encoder.Clone()
+	return &jsonHexEncoder{Encoder: encoderClone}
+}
+
 // RegisterJSONHexEncoder registers a jsonHexEncoder under "json-hex" name.
 // Later, this name can be used as a value for zap.Config.Encoding to enable
 // jsonHexEncoder.
@@ -34,3 +39,29 @@ func RegisterJSONHexEncoder() error {
 		return NewJSONHexEncoder(cfg), nil
 	})
 }
+
+type consoleHexEncoder struct {
+	zapcore.Encoder
+}
+
+func NewConsoleHexEncoder(cfg zapcore.EncoderConfig) zapcore.Encoder {
+	consoleEncoder := zapcore.NewConsoleEncoder(cfg)
+	return &consoleHexEncoder{
+		Encoder: consoleEncoder,
+	}
+}
+
+func (enc *consoleHexEncoder) AddBinary(key string, val []byte) {
+	enc.AddString(key, "0x"+hex.EncodeToString(val))
+}
+
+func (enc *consoleHexEncoder) Clone() zapcore.Encoder {
+	encoderClone := enc.Encoder.Clone()
+	return &consoleHexEncoder{Encoder: encoderClone}
+}
+
+func RegisterConsoleHexEncoder() error {
+	return zap.RegisterEncoder("console-hex", func(cfg zapcore.EncoderConfig) (zapcore.Encoder, error) {
+		return NewConsoleHexEncoder(cfg), nil
+	})
+}

zaputil/encoder_test.go

@@ -0,0 +1,81 @@
+package zaputil
+
+import (
+	"io/ioutil"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/require"
+	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
+)
+
+func TestJSONHexEncoder(t *testing.T) {
+	encoder := NewJSONHexEncoder(zap.NewDevelopmentEncoderConfig())
+	encoder.AddBinary("test-key", []byte{0x01, 0x02, 0x03})
+	buf, err := encoder.EncodeEntry(zapcore.Entry{
+		LoggerName: "",
+		Time:       time.Now(),
+		Level:      zapcore.DebugLevel,
+		Message:    "",
+	}, nil)
+	require.NoError(t, err)
+	require.Contains(t, buf.String(), `"test-key":"0x010203"`)
+}
+
+func TestLoggerWithJSONHexEncoder(t *testing.T) {
+	err := RegisterJSONHexEncoder()
+	require.NoError(t, err)
+
+	tmpFile, err := ioutil.TempFile("", "")
+	require.NoError(t, err)
+
+	cfg := zap.NewDevelopmentConfig()
+	cfg.OutputPaths = []string{tmpFile.Name()}
+	cfg.Encoding = "json-hex"
+	l, err := cfg.Build()
+	require.NoError(t, err)
+
+	l.With(zap.Binary("some-field", []byte{0x01, 0x02, 0x03})).Debug("test message")
+	err = l.Sync()
+	require.NoError(t, err)
+
+	data, err := ioutil.ReadFile(tmpFile.Name())
+	require.NoError(t, err)
+	require.Contains(t, string(data), "0x010203")
+}
+
+func TestConsoleHexEncoder(t *testing.T) {
+	encoder := NewConsoleHexEncoder(zap.NewDevelopmentEncoderConfig())
+	encoder.AddBinary("test-key", []byte{0x01, 0x02, 0x03})
+	buf, err := encoder.EncodeEntry(zapcore.Entry{
+		LoggerName: "",
+		Time:       time.Now(),
+		Level:      zapcore.DebugLevel,
+		Message:    "",
+	}, nil)
+	require.NoError(t, err)
+	require.Contains(t, buf.String(), `{"test-key": "0x010203"}`)
+}
+
+func TestLoggerWithConsoleHexEncoder(t *testing.T) {
+	err := RegisterConsoleHexEncoder()
+	require.NoError(t, err)
+
+	tmpFile, err := ioutil.TempFile("", "")
+	require.NoError(t, err)
+
+	cfg := zap.NewDevelopmentConfig()
+	cfg.OutputPaths = []string{tmpFile.Name()}
+	cfg.Encoding = "console-hex"
+	l, err := cfg.Build()
+	require.NoError(t, err)
+
+	l.With(zap.Binary("some-field", []byte{0x01, 0x02, 0x03})).Debug("test message")
+	err = l.Sync()
+	require.NoError(t, err)
+
+	data, err := ioutil.ReadFile(tmpFile.Name())
+	require.NoError(t, err)
+	require.Contains(t, string(data), "0x010203")
+}