Migrate logger to go-kit/log (ortuman#187)

eaglexmw-gmail · Jan 3, 2022 · fa5d851 · fa5d851
1 parent c69dded
commit fa5d851
Show file tree

Hide file tree

Showing 82 changed files with 789 additions and 827 deletions.
diff --git a/go.mod b/go.mod
@@ -8,6 +8,7 @@ require (
 	github.com/bgentry/speakeasy v0.1.0
 	github.com/cockroachdb/errors v1.8.4
 	github.com/cockroachdb/sentry-go v0.6.1-cockroachdb.2
+	github.com/go-kit/log v0.2.0
 	github.com/go-sql-driver/mysql v1.5.0 // indirect
 	github.com/golang/protobuf v1.5.2
 	github.com/google/uuid v1.1.2
@@ -22,7 +23,6 @@ require (
 	github.com/spf13/pflag v1.0.5
 	github.com/stretchr/testify v1.7.0
 	go.etcd.io/etcd/client/v3 v3.5.1
-	go.uber.org/zap v1.17.0
 	golang.org/x/crypto v0.0.0-20201002170205-7f63de1d35b0
 	golang.org/x/time v0.0.0-20210220033141-f8bda1e9f3ba
 	google.golang.org/grpc v1.38.0
@@ -37,6 +37,7 @@ require (
 	github.com/coreos/go-semver v0.3.0 // indirect
 	github.com/coreos/go-systemd/v22 v22.3.2 // indirect
 	github.com/davecgh/go-spew v1.1.1 // indirect
+	github.com/go-logfmt/logfmt v0.5.1 // indirect
 	github.com/gogo/protobuf v1.3.2 // indirect
 	github.com/inconshreveable/mousetrap v1.0.0 // indirect
 	github.com/kr/pretty v0.1.0 // indirect
@@ -55,6 +56,7 @@ require (
 	go.etcd.io/etcd/client/pkg/v3 v3.5.1 // indirect
 	go.uber.org/atomic v1.7.0 // indirect
 	go.uber.org/multierr v1.6.0 // indirect
+	go.uber.org/zap v1.17.0 // indirect
 	golang.org/x/net v0.0.0-20210415231046-e915ea6b2b7d // indirect
 	golang.org/x/sys v0.0.0-20210603081109-ebe580a85c40 // indirect
 	golang.org/x/text v0.3.6 // indirect

diff --git a/go.sum b/go.sum
@@ -110,9 +110,13 @@ github.com/go-gl/glfw v0.0.0-20190409004039-e6da0acd62b1/go.mod h1:vR7hzQXu2zJy9
 github.com/go-kit/kit v0.8.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as=
 github.com/go-kit/kit v0.9.0/go.mod h1:xBxKIO96dXMWWy0MnWVtmwkA9/13aqxPnvrjFYMA2as=
 github.com/go-kit/log v0.1.0/go.mod h1:zbhenjAZHb184qTLMA9ZjW7ThYL0H2mk7Q6pNt4vbaY=
+github.com/go-kit/log v0.2.0 h1:7i2K3eKTos3Vc0enKCfnVcgHh2olr/MyfboYq7cAcFw=
+github.com/go-kit/log v0.2.0/go.mod h1:NwTd00d/i8cPZ3xOwwiv2PO5MOcx78fFErGNcVmBjv0=
 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-logfmt/logfmt v0.5.1 h1:otpy5pqBCBZ1ng9RQ0dPu4PN7ba75Y/aA+UpowDyNVA=
+github.com/go-logfmt/logfmt v0.5.1/go.mod h1:WYhtIu8zTZfxdn5+rREduYbwxfcBr/Vr6KEVveWlfTs=
 github.com/go-martini/martini v0.0.0-20170121215854-22fa46961aab/go.mod h1:/P9AEU963A2AYjv4d1V5eVL1CQbEJq6aCNHDDjibzu8=
 github.com/go-sql-driver/mysql v1.5.0 h1:ozyZYNQW3x3HtqT1jira07DN2PArx2v7/mN66gGcHOs=
 github.com/go-sql-driver/mysql v1.5.0/go.mod h1:DCzpHaOWr8IXmIStZouvnhqoel9Qv2LBy8hT2VhHyBg=

diff --git a/pkg/admin/server/server.go b/pkg/admin/server/server.go
@@ -20,11 +20,14 @@ import (
 	"strconv"
 	"sync/atomic"
 
+	kitlog "github.com/go-kit/log"
+
+	"github.com/go-kit/log/level"
+
 	grpc_prometheus "github.com/grpc-ecosystem/go-grpc-prometheus"
 	adminpb "github.com/ortuman/jackal/pkg/admin/pb"
 	"github.com/ortuman/jackal/pkg/auth/pepper"
 	"github.com/ortuman/jackal/pkg/hook"
-	"github.com/ortuman/jackal/pkg/log"
 	"github.com/ortuman/jackal/pkg/storage/repository"
 	"google.golang.org/grpc"
 )
@@ -41,6 +44,7 @@ type Server struct {
 	rep     repository.Repository
 	peppers *pepper.Keys
 	hk      *hook.Hooks
+	logger  kitlog.Logger
 }
 
 // Config contains Server configuration parameters.
@@ -56,6 +60,7 @@ func New(
 	rep repository.Repository,
 	peppers *pepper.Keys,
 	hk *hook.Hooks,
+	logger kitlog.Logger,
 ) *Server {
 	if cfg.Disabled {
 		return nil
@@ -66,6 +71,7 @@ func New(
 		rep:      rep,
 		peppers:  peppers,
 		hk:       hk,
+		logger:   logger,
 	}
 }
 
@@ -80,17 +86,17 @@ func (s *Server) Start(_ context.Context) error {
 	s.ln = ln
 	s.active = 1
 
-	log.Infof("Started admin server at %s", addr)
+	level.Info(s.logger).Log("msg", "started admin server", "bind_addr", addr)
 
 	go func() {
 		grpcServer := grpc.NewServer(
 			grpc.StreamInterceptor(grpc_prometheus.StreamServerInterceptor),
 			grpc.UnaryInterceptor(grpc_prometheus.UnaryServerInterceptor),
 		)
-		adminpb.RegisterUsersServer(grpcServer, newUsersService(s.rep, s.peppers, s.hk))
+		adminpb.RegisterUsersServer(grpcServer, newUsersService(s.rep, s.peppers, s.hk, s.logger))
 		if err := grpcServer.Serve(s.ln); err != nil {
 			if atomic.LoadInt32(&s.active) == 1 {
-				log.Errorf("Admin server error: %s", err)
+				level.Error(s.logger).Log("msg", "admin server error", "err", err)
 			}
 		}
 	}()
@@ -103,7 +109,7 @@ func (s *Server) Stop(_ context.Context) error {
 	if err := s.ln.Close(); err != nil {
 		return err
 	}
-	log.Infof("Closed admin server at %s", s.getAddress())
+	level.Info(s.logger).Log("msg", "closed admin server", "bind_addr", s.getAddress())
 	return nil
 }
 

diff --git a/pkg/admin/server/service.go b/pkg/admin/server/service.go
@@ -25,10 +25,13 @@ import (
 	"fmt"
 	"hash"
 
+	kitlog "github.com/go-kit/log"
+
+	"github.com/go-kit/log/level"
+
 	userspb "github.com/ortuman/jackal/pkg/admin/pb"
 	"github.com/ortuman/jackal/pkg/auth/pepper"
 	"github.com/ortuman/jackal/pkg/hook"
-	"github.com/ortuman/jackal/pkg/log"
 	usermodel "github.com/ortuman/jackal/pkg/model/user"
 	"github.com/ortuman/jackal/pkg/storage/repository"
 	"golang.org/x/crypto/pbkdf2"
@@ -43,13 +46,15 @@ type usersService struct {
 	rep     repository.Repository
 	peppers *pepper.Keys
 	hk      *hook.Hooks
+	logger  kitlog.Logger
 }
 
-func newUsersService(rep repository.Repository, peppers *pepper.Keys, hk *hook.Hooks) userspb.UsersServer {
+func newUsersService(rep repository.Repository, peppers *pepper.Keys, hk *hook.Hooks, logger kitlog.Logger) userspb.UsersServer {
 	return &usersService{
 		rep:     rep,
 		peppers: peppers,
 		hk:      hk,
+		logger:  logger,
 	}
 }
 
@@ -70,7 +75,7 @@ func (s *usersService) CreateUser(ctx context.Context, req *userspb.CreateUserRe
 	if err != nil {
 		return nil, err
 	}
-	log.Infow(fmt.Sprintf("User %s created", username), "username", username)
+	level.Info(s.logger).Log("msg", "user created", "username", username)
 	return &userspb.CreateUserResponse{}, nil
 }
 
@@ -82,7 +87,7 @@ func (s *usersService) ChangeUserPassword(ctx context.Context, req *userspb.Chan
 	if err := s.upsertUser(ctx, username, req.GetNewPassword()); err != nil {
 		return nil, err
 	}
-	log.Infow(fmt.Sprintf("Password updated for user %s", username), "username", username)
+	level.Info(s.logger).Log("msg", "password updated", "username", username)
 
 	return &userspb.ChangeUserPasswordResponse{}, nil
 }
@@ -104,7 +109,7 @@ func (s *usersService) DeleteUser(ctx context.Context, req *userspb.DeleteUserRe
 	if err != nil {
 		return nil, err
 	}
-	log.Infow(fmt.Sprintf("User %s deleted", username), "username", username)
+	level.Info(s.logger).Log("msg", "user deleted", "username", username)
 
 	return &userspb.DeleteUserResponse{}, nil
 }

diff --git a/pkg/c2s/in.go b/pkg/c2s/in.go
@@ -24,6 +24,10 @@ import (
 	"sync/atomic"
 	"time"
 
+	kitlog "github.com/go-kit/log"
+
+	"github.com/go-kit/log/level"
+
 	"github.com/google/uuid"
 	"github.com/jackal-xmpp/runqueue/v2"
 	"github.com/jackal-xmpp/stravaganza/v2"
@@ -35,7 +39,6 @@ import (
 	"github.com/ortuman/jackal/pkg/component"
 	"github.com/ortuman/jackal/pkg/hook"
 	"github.com/ortuman/jackal/pkg/host"
-	"github.com/ortuman/jackal/pkg/log"
 	c2smodel "github.com/ortuman/jackal/pkg/model/c2s"
 	"github.com/ortuman/jackal/pkg/module"
 	xmppparser "github.com/ortuman/jackal/pkg/parser"
@@ -114,6 +117,7 @@ type inC2S struct {
 	session      session
 	shapers      shaper.Shapers
 	hk           *hook.Hooks
+	logger       kitlog.Logger
 	rq           *runqueue.RunQueue
 	discTm       *time.Timer
 	doneCh       chan struct{}
@@ -138,6 +142,7 @@ func newInC2S(
 	resMng *ResourceManager,
 	shapers shaper.Shapers,
 	hk *hook.Hooks,
+	logger kitlog.Logger,
 ) (*inC2S, error) {
 	// set default rate limiter
 	rLim := shapers.DefaultC2S().RateLimiter()
@@ -154,6 +159,7 @@ func newInC2S(
 		xmppsession.Config{
 			MaxStanzaSize: cfg.maxStanzaSize,
 		},
+		logger,
 	)
 	// init stream
 	stm := &inC2S{
@@ -173,6 +179,7 @@ func newInC2S(
 		doneCh:  make(chan struct{}),
 		state:   inConnecting,
 		hk:      hk,
+		logger:  logger,
 	}
 	if cfg.useTLS {
 		stm.flags.setSecured() // stream already secured
@@ -396,7 +403,7 @@ func (s *inC2S) handleSessionResult(elem stravaganza.Element, sErr error) {
 		case sErr == nil && elem != nil:
 			err := s.handleElement(ctx, elem)
 			if err != nil {
-				log.Warnw("Failed to process incoming C2S session element", "error", err, "id", s.id)
+				level.Warn(s.logger).Log("msg", "failed to process incoming C2S session element", "err", err, "id", s.id)
 				return
 			}
 
@@ -855,7 +862,7 @@ func (s *inC2S) proceedStartTLS(ctx context.Context, elem stravaganza.Element) e
 		Certificates: s.hosts.Certificates(),
 	}, false)
 
-	log.Infow("Secured C2S stream", "id", s.id)
+	level.Info(s.logger).Log("msg", "secured C2S stream", "id", s.id)
 
 	s.restartSession()
 	return nil
@@ -910,7 +917,7 @@ func (s *inC2S) finishAuthentication() error {
 	if err := s.updateRateLimiter(); err != nil {
 		return err
 	}
-	log.Infow("Authenticated C2S stream", "id", s.id, "username", username)
+	level.Info(s.logger).Log("msg", "authenticated C2S stream", "id", s.id, "username", username)
 
 	s.authSt.reset()
 	s.restartSession()
@@ -919,7 +926,7 @@ func (s *inC2S) finishAuthentication() error {
 
 func (s *inC2S) failAuthentication(ctx context.Context, saslErr *auth.SASLError) error {
 	if saslErr.Err != nil {
-		log.Warnf("Authentication error: %v", saslErr.Err)
+		level.Warn(s.logger).Log("msg", "authentication error", "err", saslErr.Err)
 	}
 	s.authSt.failedTimes++
 	if s.authSt.failedTimes >= maxAuthFailed {
@@ -971,7 +978,7 @@ func (s *inC2S) compress(ctx context.Context, elem stravaganza.Element) error {
 	s.tr.EnableCompression(s.cfg.compressionLevel)
 	s.flags.setCompressed()
 
-	log.Infow("Compressed C2S stream", "id", s.id, "username", s.Username())
+	level.Info(s.logger).Log("msg", "compressed C2S stream", "id", s.id, "username", s.Username())
 
 	s.restartSession()
 	return nil

diff --git a/pkg/c2s/in_test.go b/pkg/c2s/in_test.go
@@ -24,6 +24,7 @@ import (
 	"testing"
 	"time"
 
+	kitlog "github.com/go-kit/log"
 	"github.com/jackal-xmpp/runqueue/v2"
 	"github.com/jackal-xmpp/stravaganza/v2"
 	streamerror "github.com/jackal-xmpp/stravaganza/v2/errors/stream"
@@ -744,6 +745,7 @@ func TestInC2S_HandleSessionElement(t *testing.T) {
 				session: ssMock,
 				resMng:  resMngMock,
 				hk:      hook.NewHooks(),
+				logger:  kitlog.NewNopLogger(),
 			}
 			// when
 			stm.handleSessionResult(tt.sessionResFn())
@@ -830,6 +832,7 @@ func TestInC2S_HandleSessionError(t *testing.T) {
 				router:  routerMock,
 				resMng:  resMngMock,
 				hk:      hook.NewHooks(),
+				logger:  kitlog.NewNopLogger(),
 			}
 			// when
 			stm.handleSessionResult(nil, tt.sErr)

diff --git a/pkg/c2s/resource_manager.go b/pkg/c2s/resource_manager.go
@@ -21,14 +21,16 @@ import (
 	"sync"
 	"time"
 
+	kitlog "github.com/go-kit/log"
+
+	"github.com/go-kit/log/level"
 	"github.com/ortuman/jackal/pkg/cluster/instance"
 
 	"github.com/golang/protobuf/proto"
 	"github.com/jackal-xmpp/stravaganza/v2"
 	"github.com/jackal-xmpp/stravaganza/v2/jid"
 	resourcemanagerpb "github.com/ortuman/jackal/pkg/c2s/pb"
 	"github.com/ortuman/jackal/pkg/cluster/kv"
-	"github.com/ortuman/jackal/pkg/log"
 	c2smodel "github.com/ortuman/jackal/pkg/model/c2s"
 )
 
@@ -41,6 +43,7 @@ const clearActiveKeyTimeout = time.Minute
 // ResourceManager type is in charge of keeping track of all cluster resources.
 type ResourceManager struct {
 	kv        kv.KV
+	logger    kitlog.Logger
 	ctx       context.Context
 	ctxCancel context.CancelFunc
 
@@ -52,10 +55,11 @@ type ResourceManager struct {
 }
 
 // NewResourceManager creates a new resource manager given a KV storage instance.
-func NewResourceManager(kv kv.KV) *ResourceManager {
+func NewResourceManager(kv kv.KV, logger kitlog.Logger) *ResourceManager {
 	ctx, ctxCancel := context.WithCancel(context.Background())
 	return &ResourceManager{
 		kv:        kv,
+		logger:    logger,
 		ctx:       ctx,
 		ctxCancel: ctxCancel,
 		store:     make(map[string][]c2smodel.ResourceDesc),
@@ -126,7 +130,7 @@ func (m *ResourceManager) Start(ctx context.Context) error {
 	if err := m.watchKVResources(ctx); err != nil {
 		return err
 	}
-	log.Infow("Started C2S resource manager")
+	level.Info(m.logger).Log("msg", "started C2S resource manager")
 	return nil
 }
 
@@ -136,7 +140,7 @@ func (m *ResourceManager) Stop(_ context.Context) error {
 	m.ctxCancel()
 	<-m.stopCh
 
-	log.Infow("Stopped C2S resource manager")
+	level.Info(m.logger).Log("msg", "stopped C2S resource manager")
 	return nil
 }
 
@@ -159,12 +163,12 @@ func (m *ResourceManager) watchKVResources(ctx context.Context) error {
 		// watch changes
 		for wResp := range wCh {
 			if err := wResp.Err; err != nil {
-				log.Warnf("Error occurred watching resources: %v", err)
+				level.Warn(m.logger).Log("msg", "error occurred watching resources", "err", err)
 				continue
 			}
 			// process changes
 			if err := m.processKVEvents(wResp.Events); err != nil {
-				log.Warnf("Failed to process resources changes: %v", err)
+				level.Warn(m.logger).Log("msg", "failed to process resources changes", "err", err)
 			}
 		}
 		close(m.stopCh) // signal stop