Merge pull request #135 from bstasyszyn/logutil-go

chore: Use logutil-go for logging

cmd/internal/serverutil/serverutil.go

@@ -36,7 +36,9 @@ import (
 	"google.golang.org/grpc/credentials"
 	"google.golang.org/grpc/reflection"
 
-	"github.com/trustbloc/vct/internal/pkg/log"
+	"github.com/trustbloc/logutil-go/pkg/log"
+
+	logfields "github.com/trustbloc/vct/internal/pkg/log"
 )
 
 var logger = log.New("internal/serverutil")
@@ -153,7 +155,7 @@ func (m *Main) Run(ctx context.Context) error { // nolint: funlen
 		}()
 	}
 
-	logger.Info("RPC server starting", log.WithServiceEndpoint(m.RPCEndpoint))
+	logger.Info("RPC server starting", logfields.WithServiceEndpoint(m.RPCEndpoint))
 
 	lis, err := net.Listen("tcp", m.RPCEndpoint)
 	if err != nil {
@@ -239,11 +241,11 @@ func AnnounceSelf(ctx context.Context, client *clientv3.Client, etcdService, end
 
 	fullEndpoint := fmt.Sprintf("%s/%s", etcdService, endpoint)
 	em.AddEndpoint(ctx, fullEndpoint, endpoints.Endpoint{Addr: endpoint}) // nolint: errcheck, gosec
-	logger.Info("Announcing our presence", log.WithServiceEndpoint(etcdService))
+	logger.Info("Announcing our presence", logfields.WithServiceEndpoint(etcdService))
 
 	return func() {
 		// Use a background context because the original context may have been cancelled.
-		logger.Info("Removing our presence", log.WithServiceEndpoint(etcdService))
+		logger.Info("Removing our presence", logfields.WithServiceEndpoint(etcdService))
 
 		ctx := context.Background()
 		em.DeleteEndpoint(ctx, fullEndpoint) // nolint: errcheck, gosec

cmd/log_server/main.go

@@ -20,10 +20,10 @@ import (
 
 	"github.com/google/trillian/quota"
 	"github.com/google/trillian/storage"
+	"github.com/trustbloc/logutil-go/pkg/log"
 
 	"github.com/trustbloc/vct/cmd/internal/serverutil"
 	"github.com/trustbloc/vct/cmd/log_server/startcmd"
-	"github.com/trustbloc/vct/internal/pkg/log"
 	"github.com/trustbloc/vct/pkg/storage/memory"
 	"github.com/trustbloc/vct/pkg/storage/postgres"
 )

cmd/log_signer/main.go

@@ -20,9 +20,9 @@ import (
 	"github.com/google/trillian/log"
 	"github.com/google/trillian/quota"
 	"github.com/google/trillian/storage"
+	logs "github.com/trustbloc/logutil-go/pkg/log"
 
 	"github.com/trustbloc/vct/cmd/log_signer/startcmd"
-	logs "github.com/trustbloc/vct/internal/pkg/log"
 	"github.com/trustbloc/vct/pkg/storage/memory"
 	"github.com/trustbloc/vct/pkg/storage/postgres"
 )

cmd/vct/main.go

@@ -23,9 +23,9 @@ package main
 
 import (
 	"github.com/spf13/cobra"
+	"github.com/trustbloc/logutil-go/pkg/log"
 
 	"github.com/trustbloc/vct/cmd/vct/startcmd"
-	"github.com/trustbloc/vct/internal/pkg/log"
 )
 
 var logger = log.New("vct")

cmd/vct/startcmd/start.go

@@ -55,6 +55,7 @@ import (
 	"github.com/rs/cors"
 	"github.com/spf13/cobra"
 	awssvc "github.com/trustbloc/kms/pkg/aws"
+	"github.com/trustbloc/logutil-go/pkg/log"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/credentials/insecure"
 	"google.golang.org/protobuf/types/known/durationpb"
@@ -64,7 +65,7 @@ import (
 	logsignerstart "github.com/trustbloc/vct/cmd/log_signer/startcmd"
 	"github.com/trustbloc/vct/internal/pkg/cmdutil"
 	"github.com/trustbloc/vct/internal/pkg/ldcontext"
-	"github.com/trustbloc/vct/internal/pkg/log"
+	logfields "github.com/trustbloc/vct/internal/pkg/log"
 	"github.com/trustbloc/vct/internal/pkg/tlsutil"
 	"github.com/trustbloc/vct/pkg/controller/command"
 	"github.com/trustbloc/vct/pkg/controller/rest"
@@ -928,7 +929,7 @@ func createTreeAndInit(conn *grpc.ClientConn, cfg storage.Store, alias string, t
 			return err // nolint: wrapcheck
 		}, backoff.WithMaxRetries(backoff.NewConstantBackOff(time.Second), timeout), func(err error, duration time.Duration) {
 			logger.Warn("Create tree failed, will sleep a while before trying again",
-				log.WithBackoff(duration), log.WithError(err))
+				logfields.WithBackoff(duration), log.WithError(err))
 		})
 
 		if err != nil {
@@ -1079,7 +1080,7 @@ func createStoreProvider(dbURL, prefix string, timeout uint64) (storeProvider, e
 		timeout,
 	), func(retryErr error, t time.Duration) {
 		logger.Warn("Failed to connect to storage, will sleep a while before trying again",
-			log.WithBackoff(t), log.WithError(retryErr))
+			logfields.WithBackoff(t), log.WithError(retryErr))
 	})
 }
 

go.mod

@@ -12,7 +12,7 @@ require (
 	github.com/cucumber/godog v0.9.0
 	github.com/golang/mock v1.6.0
 	github.com/golang/protobuf v1.5.2
-	github.com/google/go-cmp v0.5.7
+	github.com/google/go-cmp v0.5.9
 	github.com/google/trillian v1.3.14-0.20210520152752-ceda464a95a3
 	github.com/google/uuid v1.3.0
 	github.com/gorilla/mux v1.8.0
@@ -31,8 +31,9 @@ require (
 	github.com/spf13/cobra v1.3.0
 	github.com/stretchr/testify v1.8.1
 	github.com/trustbloc/kms v0.1.9-0.20221024131747-f895f91207f1
+	github.com/trustbloc/logutil-go v1.0.0-rc1
 	go.etcd.io/etcd/client/v3 v3.5.0
-	go.uber.org/zap v1.17.0
+	go.uber.org/zap v1.23.0
 	google.golang.org/grpc v1.44.0
 	google.golang.org/protobuf v1.28.1
 )
@@ -131,6 +132,8 @@ require (
 	go.etcd.io/etcd/client/pkg/v3 v3.5.1 // indirect
 	go.mongodb.org/mongo-driver v1.8.0 // indirect
 	go.opencensus.io v0.23.0 // indirect
+	go.opentelemetry.io/otel v1.12.0 // indirect
+	go.opentelemetry.io/otel/trace v1.12.0 // indirect
 	go.uber.org/atomic v1.9.0 // indirect
 	go.uber.org/multierr v1.6.0 // indirect
 	golang.org/x/crypto v0.1.0 // indirect

go.sum

@@ -155,6 +155,7 @@ github.com/aws/aws-sdk-go v1.43.9 h1:k1S/29Bp2QD5ZopnGzIn0Sp63yyt3WH1JRE2OOU3Aig
 github.com/aws/aws-sdk-go v1.43.9/go.mod h1:y4AeaBuwd2Lk+GepC1E9v0qOiTws0MIWAX4oIKwKHZo=
 github.com/aws/aws-sdk-go-v2 v0.18.0/go.mod h1:JWVYvqSMppoMJC0x5wdwiImzgXTI9FuZwxzkQq9wy+g=
 github.com/aybabtme/rgbterm v0.0.0-20170906152045-cc83f3b3ce59/go.mod h1:q/89r3U2H7sSsE2t6Kca0lfwTK8JdoNGS/yzM/4iH5I=
+github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8=
 github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q=
 github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8=
 github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
@@ -334,6 +335,8 @@ github.com/go-kivik/kiviktest/v3 v3.0.3/go.mod h1:sqsz3M2sJxTxAUdOj+2SU21y4phcpY
 github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE=
 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk=
 github.com/go-logfmt/logfmt v0.5.0/go.mod h1:wCYkCAKZfumFQihp8CzCvQ3paCTfi41vtzG1KdI/P7A=
+github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0=
+github.com/go-logr/stdr v1.2.2 h1:hSWxHoqTgW2S2qGc0LTAI563KZ5YKYRhT3MFKZMbjag=
 github.com/go-redis/redis v6.15.9+incompatible/go.mod h1:NAIEuMOZ/fxfXJIrKDQDz8wamY7mA7PouImQ2Jvg6kA=
 github.com/go-sql-driver/mysql v1.4.0/go.mod h1:zAC/RDZ24gD3HViQzih4MyKcchzm+sOG5ZlKdlhCg5w=
 github.com/go-sql-driver/mysql v1.4.1/go.mod h1:zAC/RDZ24gD3HViQzih4MyKcchzm+sOG5ZlKdlhCg5w=
@@ -414,8 +417,9 @@ github.com/google/go-cmp v0.5.3/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/
 github.com/google/go-cmp v0.5.4/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
 github.com/google/go-cmp v0.5.5/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
 github.com/google/go-cmp v0.5.6/go.mod h1:v8dTdLbMG2kIc/vJvl+f65V22dbkXbowE6jgT/gNBxE=
-github.com/google/go-cmp v0.5.7 h1:81/ik6ipDQS2aGcBfIN5dHDB36BwrStyeAQquSYCV4o=
 github.com/google/go-cmp v0.5.7/go.mod h1:n+brtR0CgQNWTVd5ZUFpTBC8YFBDLK/h/bpaJ8/DtOE=
+github.com/google/go-cmp v0.5.9 h1:O2Tfq5qg4qc4AmwVlvv0oLiVAGB7enBSJ2x2DqQFi38=
+github.com/google/go-cmp v0.5.9/go.mod h1:17dUlkBOakJ0+DkrSSNjCkIjxS6bF9zb3elmeNGIjoY=
 github.com/google/go-github/v28 v28.1.1/go.mod h1:bsqJWQX05omyWVmc00nEUql9mhQyv38lDZ8kPZcQVoM=
 github.com/google/go-licenses v0.0.0-20210329231322-ce1d9163b77d/go.mod h1:+TYOmkVoJOpwnS0wfdsJCV9CoD5nJYsHoFk/0CrTK4M=
 github.com/google/go-querystring v1.0.0/go.mod h1:odCYkC5MyYFN7vkCjXpyrEuKhc/BUO6wN/zVPAxq5ck=
@@ -1011,6 +1015,8 @@ github.com/tmc/grpc-websocket-proxy v0.0.0-20200427203606-3cfed13b9966/go.mod h1
 github.com/tomasen/realip v0.0.0-20180522021738-f0c99a92ddce/go.mod h1:o8v6yHRoik09Xen7gje4m9ERNah1d1PPsVq1VEx9vE4=
 github.com/trustbloc/kms v0.1.9-0.20221024131747-f895f91207f1 h1:u617zM5QPsAawgQq8n797jj1PTBIp+7fHbmKjd/FeQM=
 github.com/trustbloc/kms v0.1.9-0.20221024131747-f895f91207f1/go.mod h1:Vv+mv35QeUo5f+Llm/gsp6x4FgLkLH9dTp4dGK0+aQU=
+github.com/trustbloc/logutil-go v1.0.0-rc1 h1:rRJbvgQfrlUfyej+mY0nuQJymGqjRW4oZEwKi544F4c=
+github.com/trustbloc/logutil-go v1.0.0-rc1/go.mod h1:JlxT0oZfNKgIlSNtgc001WEeDMxlnAvOM43gNm8DQVc=
 github.com/tv42/httpunix v0.0.0-20150427012821-b75d8614f926/go.mod h1:9ESjWnEqriFuLhtthL60Sar/7RFoluCcXsuvEwTV5KM=
 github.com/ugorji/go v1.1.4/go.mod h1:uQMGLiO92mf5W77hV/PUCpI3pbzQx3CRekS0kk+RGrc=
 github.com/ugorji/go/codec v0.0.0-20181204163529-d75b2dcb6bc8/go.mod h1:VFNgLljTbGfSG7qAOspJ7OScBnGdDN/yBr0sguwnwf0=
@@ -1095,6 +1101,11 @@ go.opencensus.io v0.22.5/go.mod h1:5pWMHQbX5EPX2/62yrJeAkowc+lfs/XD7Uxpq3pI6kk=
 go.opencensus.io v0.22.6/go.mod h1:XItmlyltB5F7CS4xOC1DcqMoFqwtC6OG2xF7mCv7P7E=
 go.opencensus.io v0.23.0 h1:gqCw0LfLxScz8irSi8exQc7fyQ0fKQU/qnC/X8+V/1M=
 go.opencensus.io v0.23.0/go.mod h1:XItmlyltB5F7CS4xOC1DcqMoFqwtC6OG2xF7mCv7P7E=
+go.opentelemetry.io/otel v1.12.0 h1:IgfC7kqQrRccIKuB7Cl+SRUmsKbEwSGPr0Eu+/ht1SQ=
+go.opentelemetry.io/otel v1.12.0/go.mod h1:geaoz0L0r1BEOR81k7/n9W4TCXYCJ7bPO7K374jQHG0=
+go.opentelemetry.io/otel/sdk v1.12.0 h1:8npliVYV7qc0t1FKdpU08eMnOjgPFMnriPhn0HH4q3o=
+go.opentelemetry.io/otel/trace v1.12.0 h1:p28in++7Kd0r2d8gSt931O57fdjUyWxkVbESuILAeUc=
+go.opentelemetry.io/otel/trace v1.12.0/go.mod h1:pHlgBynn6s25qJ2szD+Bv+iwKJttjHSI3lUAyf0GNuQ=
 go.opentelemetry.io/proto/otlp v0.7.0/go.mod h1:PqfVotwruBrMGOCsRd/89rSnXhoiJIqeYNgFYFoEGnI=
 go.uber.org/atomic v1.3.2/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE=
 go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE=
@@ -1103,6 +1114,7 @@ go.uber.org/atomic v1.6.0/go.mod h1:sABNBOSYdrvTF6hTgEIbc7YasKWGhgEQZyfxyTvoXHQ=
 go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
 go.uber.org/atomic v1.9.0 h1:ECmE8Bn/WFTYwEW/bpKD3M8VtR/zQVbavAoalC1PYyE=
 go.uber.org/atomic v1.9.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
+go.uber.org/goleak v1.1.11 h1:wy28qYRKZgnJTxGxvye5/wgWr1EKjmUDGYox5mGlRlI=
 go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0=
 go.uber.org/multierr v1.3.0/go.mod h1:VgVr7evmIr6uPjLBxg28wmKNXyqE9akIJ5XnfpiKl+4=
 go.uber.org/multierr v1.5.0/go.mod h1:FeouvMocqHpRaaGuG9EjoKcStLC43Zu/fmqdUMPcKYU=
@@ -1113,8 +1125,9 @@ go.uber.org/zap v1.9.1/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
 go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
 go.uber.org/zap v1.13.0/go.mod h1:zwrFLgMcdUuIBviXEYEH1YKNaOBnKXsx2IPda5bBwHM=
 go.uber.org/zap v1.16.0/go.mod h1:MA8QOfq0BHJwdXa996Y4dYkAqRKB8/1K1QMMZVaNZjQ=
-go.uber.org/zap v1.17.0 h1:MTjgFu6ZLKvY6Pvaqk97GlxNBuMpV4Hy/3P6tRGlI2U=
 go.uber.org/zap v1.17.0/go.mod h1:MXVU+bhUf/A7Xi2HNOnopQOrmycQ5Ih87HtOu4q5SSo=
+go.uber.org/zap v1.23.0 h1:OjGQ5KQDEUawVHxNwQgPpiypGHOxo2mNZsOqTak4fFY=
+go.uber.org/zap v1.23.0/go.mod h1:D+nX8jyLsMHMYrln8A0rJjFt/T/9/bGgIhAqxv5URuY=
 gocloud.dev v0.19.0/go.mod h1:SmKwiR8YwIMMJvQBKLsC3fHNyMwXLw3PMDO+VVteJMI=
 golang.org/x/crypto v0.0.0-20170930174604-9419663f5a44/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=
 golang.org/x/crypto v0.0.0-20171113213409-9f005a07e0d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4=

internal/pkg/log/fields.go

@@ -17,7 +17,6 @@ import (
 const (
 	FieldServiceName          = "service"
 	FieldSize                 = "size"
-	FieldAddress              = "address"
 	FieldBackoff              = "backoff"
 	FieldServiceEndpoint      = "serviceEndpoint"
 	FieldTreeID               = "treeID"
@@ -30,11 +29,6 @@ const (
 	FieldPublicKey            = "publicKey"
 )
 
-// WithError sets the error field.
-func WithError(err error) zap.Field {
-	return zap.Error(err)
-}
-
 // WithServiceName sets the service field.
 func WithServiceName(value string) zap.Field {
 	return zap.String(FieldServiceName, value)
@@ -45,11 +39,6 @@ func WithSize(value int) zap.Field {
 	return zap.Int(FieldSize, value)
 }
 
-// WithAddress sets the address field.
-func WithAddress(value string) zap.Field {
-	return zap.String(FieldAddress, value)
-}
-
 // WithBackoff sets the backoff field.
 func WithBackoff(value time.Duration) zap.Field {
 	return zap.Duration(FieldBackoff, value)

internal/pkg/log/fields_test.go

@@ -7,63 +7,31 @@ SPDX-License-Identifier: Apache-2.0
 package log
 
 import (
+	"bytes"
 	"encoding/json"
-	"errors"
 	"net/url"
 	"testing"
 	"time"
 
 	"github.com/stretchr/testify/require"
+	"github.com/trustbloc/logutil-go/pkg/log"
 )
 
 func TestStandardFields(t *testing.T) {
 	const module = "test_module"
 
 	u1 := parseURL(t, "https://example1.com")
 
-	t.Run("console error", func(t *testing.T) {
-		stdErr := newMockWriter()
-
-		logger := New(module,
-			WithStdErr(stdErr),
-			WithFields(WithServiceName("myservice")),
-		)
-
-		logger.Error("Sample error", WithError(errors.New("some error")))
-
-		require.Contains(t, stdErr.Buffer.String(), `Sample error	{"service": "myservice", "error": "some error"}`)
-	})
-
-	t.Run("json error", func(t *testing.T) {
-		stdErr := newMockWriter()
-
-		logger := New(module,
-			WithStdErr(stdErr), WithEncoding(JSON),
-			WithFields(WithServiceName("myservice")),
-		)
-
-		logger.Error("Sample error", WithError(errors.New("some error")))
-
-		l := unmarshalLogData(t, stdErr.Bytes())
-
-		require.Equal(t, "myservice", l.Service)
-		require.Equal(t, "test_module", l.Logger)
-		require.Equal(t, "Sample error", l.Msg)
-		require.Contains(t, l.Caller, "log/fields_test.go")
-		require.Equal(t, "some error", l.Error)
-		require.Equal(t, "error", l.Level)
-	})
-
 	t.Run("json fields", func(t *testing.T) {
 		leaf := &mockObject{Field1: "leaf1", Field2: 32123}
 		pubKey := &mockObject{Field1: "key1", Field2: 32432}
 
 		stdOut := newMockWriter()
 
-		logger := New(module, WithStdOut(stdOut), WithEncoding(JSON))
+		logger := log.New(module, log.WithStdOut(stdOut), log.WithEncoding(log.JSON))
 
 		logger.Info("Some message",
-			WithServiceName("service1"), WithSize(1234), WithAddress(u1.String()),
+			WithServiceName("service1"), WithSize(1234),
 			WithBackoff(time.Minute), WithServiceEndpoint(u1.String()), WithTreeID(1234),
 			WithLeaf(leaf), WithStore("store1"), WithCommand("doit"),
 			WithVerifiableCredential([]byte(`"id":"vc1"`)), WithSignature([]byte("my signature")),
@@ -76,7 +44,6 @@ func TestStandardFields(t *testing.T) {
 		require.Equal(t, `Some message`, l.Msg)
 		require.Equal(t, `service1`, l.Service)
 		require.Equal(t, 1234, l.Size)
-		require.Equal(t, u1.String(), l.Address)
 		require.Equal(t, "1m0s", l.Backoff)
 		require.Equal(t, u1.String(), l.ServiceEndpoint)
 		require.Equal(t, 1234, l.TreeID)
@@ -105,7 +72,6 @@ type logData struct {
 
 	Service              string      `json:"service"`
 	Size                 int         `json:"size"`
-	Address              string      `json:"address"`
 	Backoff              string      `json:"backoff"`
 	ServiceEndpoint      string      `json:"serviceEndpoint"`
 	TreeID               int         `json:"treeID"`
@@ -136,3 +102,15 @@ func parseURL(t *testing.T, raw string) *url.URL {
 
 	return u
 }
+
+type mockWriter struct {
+	*bytes.Buffer
+}
+
+func (m *mockWriter) Sync() error {
+	return nil
+}
+
+func newMockWriter() *mockWriter {
+	return &mockWriter{Buffer: bytes.NewBuffer(nil)}
+}