feat: improve logging (#151)

go.mod

@@ -83,7 +83,6 @@ require (
 	github.com/magiconair/properties v1.8.7 // indirect
 	github.com/mattn/go-colorable v0.1.13 // indirect
 	github.com/mattn/go-isatty v0.0.18 // indirect
-	github.com/mattn/go-sqlite3 v1.14.16 // indirect
 	github.com/mitchellh/go-homedir v1.1.0 // indirect
 	github.com/mitchellh/mapstructure v1.5.0 // indirect
 	github.com/moby/term v0.0.0-20221205130635-1aeaba878587 // indirect

go.sum

@@ -334,7 +334,6 @@ github.com/mattn/go-isatty v0.0.18 h1:DOKFKCQ7FNG2L1rbrmstDN4QVRdS89Nkh85u68Uwp9
 github.com/mattn/go-isatty v0.0.18/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
 github.com/mattn/go-sqlite3 v1.14.6/go.mod h1:NyWgC/yNuGj7Q9rpYnZvas74GogHl5/Z4A/KQRfk6bU=
 github.com/mattn/go-sqlite3 v1.14.16 h1:yOQRA0RpS5PFz/oikGwBEqvAWhWg5ufRz4ETLjwpU1Y=
-github.com/mattn/go-sqlite3 v1.14.16/go.mod h1:2eHXhiwb8IkHr+BDWZGa96P6+rkvnG63S2DGjv9HUNg=
 github.com/minio/highwayhash v1.0.2 h1:Aak5U0nElisjDCfPSG79Tgzkn2gl66NxOMspRrKnA/g=
 github.com/mitchellh/go-homedir v1.1.0 h1:lukF9ziXFxDFPkA1vsr5zpc1XuPDn/wFntq5mG+4E0Y=
 github.com/mitchellh/go-homedir v1.1.0/go.mod h1:SfyaCUpYCn1Vlf4IUYiD9fPX4A5wJrkLzIz1N1q0pr0=

internal/utils/obfuscate.go

@@ -0,0 +1,7 @@
+package utils
+
+import "github.com/networkteam/obfuscate"
+
+func ObfuscateEmail(email string) string {
+	return obfuscate.EmailAddressPartially(email)
+}

internal/utils/obfuscate_test.go

@@ -0,0 +1,14 @@
+package utils_test
+
+import (
+	"testing"
+
+	"github.com/ludusrusso/kannon/internal/utils"
+	"github.com/stretchr/testify/assert"
+)
+
+func TestEmailObfuscation(t *testing.T) {
+	email := "[email protected]"
+	res := utils.ObfuscateEmail(email)
+	assert.Equal(t, "t*t@t*t.com", res)
+}

pkg/api/mailapi/mailer.go

@@ -90,7 +90,6 @@ func (s mailAPIService) getCallDomainFromContext(ctx context.Context) (sqlc.Doma
 	if !ok {
 		return sqlc.Domain{}, fmt.Errorf("cannot find metatada")
 	}
-	logrus.Infof("ok:%v", ok)
 
 	auths := m.Get("authorization")
 	if len(auths) != 1 {
@@ -101,23 +100,18 @@ func (s mailAPIService) getCallDomainFromContext(ctx context.Context) (sqlc.Doma
 	if !strings.HasPrefix(auth, "Basic ") {
 		return sqlc.Domain{}, fmt.Errorf("no prefix Basic in auth: %v", auth)
 	}
-	logrus.Infof("auth: %v", auth)
 
 	token := strings.Replace(auth, "Basic ", "", 1)
 	data, err := base64.StdEncoding.DecodeString(token)
 	if err != nil {
 		return sqlc.Domain{}, fmt.Errorf("decode token error: %v", token)
 	}
-	logrus.Infof("token: %v, data: %v", token, data)
 
 	authData := string(data)
-	logrus.Infof("authData: %v", authData)
 
 	parts := strings.Split(authData, ":")
 	d, k := parts[0], parts[1]
 
-	logrus.Infof("domain: %v, key: %v", d, k)
-
 	domain, err := s.domains.FindDomainWithKey(ctx, d, k)
 	if err != nil {
 		return sqlc.Domain{}, fmt.Errorf("cannot find domain: %w", err)

pkg/dispatcher/disp.go

@@ -22,6 +22,7 @@ type disp struct {
 	mb  mailbuilder.MailBulder
 	pub publisher.Publisher
 	js  nats.JetStreamContext
+	log *logrus.Entry
 }
 
 func (d disp) DispatchCycle(pctx context.Context) error {
@@ -32,29 +33,29 @@ func (d disp) DispatchCycle(pctx context.Context) error {
 		return fmt.Errorf("cannot prepare emails for send: %v", err)
 	}
 
-	logrus.Debugf("[dispatcher] seding %d emails", len(emails))
+	d.log.Debugf("[dispatcher] seding %d emails", len(emails))
 
 	for _, email := range emails {
 		data, err := d.mb.BuildEmail(ctx, email)
 		if err != nil {
-			logrus.Errorf("Cannot send email %v: %v", email.Email, err)
+			d.log.Errorf("Cannot send email %v: %v", email.Email, err)
 			continue
 		}
 		if err := publisher.SendEmail(d.pub, data); err != nil {
-			logrus.Errorf("Cannot send email %v: %v", email.Email, err)
+			d.log.Errorf("Cannot send email %v: %v", email.Email, err)
 			continue
 		}
-		logrus.Infof("[✅ accepted]: %v %v", data.To, data.EmailId)
+		d.log.Infof("[✅ accepted]: %v %v", utils.ObfuscateEmail(data.To), data.EmailId)
 	}
 
-	logrus.Debugf("[dispatcher] done sending emails")
+	d.log.Debugf("[dispatcher] done sending emails")
 	return nil
 }
 
 func (d disp) handleErrors(ctx context.Context) {
 	sbj := "kannon.stats.error"
 	subName := "dispatcher-error"
-	handleMsg(ctx, d.js, sbj, subName, d.parseErrorsFunc)
+	d.handleMsg(ctx, sbj, subName, d.parseErrorsFunc)
 }
 
 func (d disp) parseErrorsFunc(ctx context.Context, m *statstypes.Stats) error {
@@ -72,7 +73,7 @@ func (d disp) parseErrorsFunc(ctx context.Context, m *statstypes.Stats) error {
 func (d disp) handleDelivereds(ctx context.Context) {
 	sbj := "kannon.stats.delivered"
 	subName := "dispatcher-delivered"
-	handleMsg(ctx, d.js, sbj, subName, d.parsDeliveredFunc)
+	d.handleMsg(ctx, sbj, subName, d.parsDeliveredFunc)
 }
 
 func (d disp) parsDeliveredFunc(ctx context.Context, m *statstypes.Stats) error {
@@ -85,7 +86,7 @@ func (d disp) parsDeliveredFunc(ctx context.Context, m *statstypes.Stats) error
 func (d disp) handleBounced(ctx context.Context) {
 	sbj := "kannon.stats.bounced"
 	subName := "dispatcher-bounced"
-	handleMsg(ctx, d.js, sbj, subName, d.parsBouncedFunc)
+	d.handleMsg(ctx, sbj, subName, d.parsBouncedFunc)
 }
 
 func (d disp) parsBouncedFunc(ctx context.Context, m *statstypes.Stats) error {
@@ -98,36 +99,36 @@ func (d disp) parsBouncedFunc(ctx context.Context, m *statstypes.Stats) error {
 
 type parseFunc func(ctx context.Context, msg *statstypes.Stats) error
 
-func handleMsg(ctx context.Context, js nats.JetStreamContext, sbj, subName string, parse parseFunc) {
-	con := utils.MustGetPullSubscriber(js, sbj, subName)
+func (d disp) handleMsg(ctx context.Context, sbj, subName string, parse parseFunc) {
+	con := utils.MustGetPullSubscriber(d.js, sbj, subName)
 	for {
 		msgs, err := con.Fetch(10, nats.MaxWait(10*time.Second))
 		if err != nil {
 			if err != nats.ErrTimeout {
-				logrus.Errorf("error fetching messages: %v", err)
+				d.log.Errorf("error fetching messages: %v", err)
 			}
 			continue
 		}
 		for _, msg := range msgs {
 			m := &statstypes.Stats{}
 			if err := proto.Unmarshal(msg.Data, m); err != nil {
-				handleAck(msg, err)
+				d.handleAck(msg, err)
 				continue
 			}
 			err := parse(ctx, m)
-			handleAck(msg, err)
+			d.handleAck(msg, err)
 		}
 	}
 }
 
-func handleAck(msg *nats.Msg, err error) {
+func (d disp) handleAck(msg *nats.Msg, err error) {
 	if err != nil {
 		if err := msg.Nak(); err != nil {
-			logrus.Errorf("Cannot nak msg to nats: %v", err)
+			d.log.Errorf("Cannot nak msg to nats: %v", err)
 		}
 	} else {
 		if err := msg.Ack(); err != nil {
-			logrus.Errorf("Cannot hack msg to nats: %v", err)
+			d.log.Errorf("Cannot hack msg to nats: %v", err)
 		}
 	}
 }

pkg/dispatcher/dispatcher.go

@@ -24,11 +24,13 @@ func Run(ctx context.Context) {
 	dbURL := viper.GetString("database_url")
 	natsURL := viper.GetString("nats_url")
 
-	logrus.Info("🚀 Starting dispatcher")
+	log := logrus.WithField("component", "dispatcher")
+
+	log.Info("🚀 Starting dispatcher")
 
 	db, q, err := sqlc.Conn(ctx, dbURL)
 	if err != nil {
-		logrus.Fatalf("cannot connect to database: %v", err)
+		log.Fatalf("cannot connect to database: %v", err)
 	}
 	defer db.Close()
 
@@ -46,6 +48,7 @@ func Run(ctx context.Context) {
 		mb:  mb,
 		pub: nc,
 		js:  js,
+		log: log,
 	}
 
 	var wg sync.WaitGroup

pkg/sender/sender.go

@@ -76,10 +76,10 @@ func handleMessage(msg *nats.Msg, sender smtp.Sender, nc *nats.Conn) error {
 	}
 	sendErr := sender.Send(data.ReturnPath, data.To, data.Body)
 	if sendErr != nil {
-		logrus.Infof("Cannot send email %v - %v: %v", data.GetObfuscatedTo(), data.EmailId, sendErr.Error())
+		logrus.Infof("Cannot send email %v - %v: %v", utils.ObfuscateEmail(data.To), data.EmailId, sendErr.Error())
 		return handleSendError(sendErr, data, nc)
 	}
-	logrus.Infof("Email delivered: %v - %v", data.GetObfuscatedTo(), data.EmailId)
+	logrus.Infof("Email delivered: %v - %v", utils.ObfuscateEmail(data.To), data.EmailId)
 	return handleSendSuccess(data, nc)
 }
 

pkg/smtp/smtp.go

@@ -85,7 +85,7 @@ func (s *Session) Data(r io.Reader) error {
 		},
 	}
 
-	logrus.Infof("[🤷 got bounce] %vs - %d - %s", email, code, errMsg)
+	logrus.Infof("[🤷 got bounce] %vs - %d - %s", utils.ObfuscateEmail(email), code, errMsg)
 
 	msg, err := proto.Marshal(m)
 	if err != nil {

pkg/stats/stats.go

@@ -51,7 +51,7 @@ func handleStats(ctx context.Context, js nats.JetStreamContext, q *sq.Queries) {
 				logrus.Errorf("cannot marshal message %v", err.Error())
 			} else {
 				stype := sq.GetStatsType(data)
-				logrus.Printf("[%s] %s %s", StatsShow[stype], data.GetObfuscatedEmail(), data.MessageId)
+				logrus.Printf("[%s] %s %s", StatsShow[stype], utils.ObfuscateEmail(data.Email), data.MessageId)
 				err := q.InsertStat(ctx, sq.InsertStatParams{
 					Email:     data.Email,
 					MessageID: data.MessageId,

pkg/validator/validator.go

@@ -17,23 +17,29 @@ import (
 	"google.golang.org/protobuf/types/known/timestamppb"
 )
 
-func NewValidator(pm pool.SendingPoolManager, pub publisher.Publisher) *Validator {
+func NewValidator(pm pool.SendingPoolManager, pub publisher.Publisher, log *logrus.Entry) *Validator {
+	if log == nil {
+		log = logrus.WithField("component", "validator")
+	}
 	return &Validator{
 		pm:  pm,
 		pub: pub,
+		log: log,
 	}
 }
 
 type Validator struct {
 	pm  pool.SendingPoolManager
 	pub publisher.Publisher
+	log *logrus.Entry
 }
 
 func Run(ctx context.Context) error {
 	dbURL := viper.GetString("database_url")
 	natsURL := viper.GetString("nats_url")
+	l := logrus.WithField("component", "validator")
 
-	logrus.Info("🚀 Starting dispatcher")
+	l.Info("🚀 Starting validator")
 
 	db, q, err := sqlc.Conn(ctx, dbURL)
 	if err != nil {
@@ -49,6 +55,7 @@ func Run(ctx context.Context) error {
 	v := Validator{
 		pm:  pm,
 		pub: nc,
+		log: l,
 	}
 
 	return runner.Run(ctx, v.Cycle, runner.WaitLoop(1*time.Second))
@@ -62,11 +69,11 @@ func (d *Validator) Cycle(pctx context.Context) error {
 		return fmt.Errorf("cannot prepare emails for send: %v", err)
 	}
 
-	logrus.Debugf("[validator] preparing %d emails", len(emails))
+	d.log.Debugf("[validator] preparing %d emails", len(emails))
 
 	for _, pool := range emails {
 		if err := d.handlePool(ctx, pool); err != nil {
-			logrus.Errorf("error handling pool email: %#v", pool)
+			d.log.Errorf("error handling pool email: %#v", pool)
 		}
 	}
 	return nil

pkg/validator/validator_test.go

@@ -48,7 +48,7 @@ func TestMain(m *testing.M) {
 
 	q = sqlc.New(db)
 	pm := pool.NewSendingPoolManager(q)
-	vt = validator.NewValidator(pm, &mp)
+	vt = validator.NewValidator(pm, &mp, nil)
 
 	ts = mailapi.NewMailerAPIV1(q)
 	adminAPI = adminapi.CreateAdminAPIService(q)

proto/kannon/stats/types/stats.go

@@ -4,7 +4,6 @@ import (
 	"database/sql/driver"
 	"fmt"
 
-	"github.com/networkteam/obfuscate"
 	"google.golang.org/protobuf/encoding/protojson"
 )
 
@@ -27,7 +26,3 @@ func (d *StatsData) Scan(src interface{}) error {
 func (d *StatsData) Value() (driver.Value, error) {
 	return protojson.Marshal(d)
 }
-
-func (d *Stats) GetObfuscatedEmail() string {
-	return obfuscate.EmailAddressPartially(d.Email)
-}