More logs.

Use zerolog (I prefer it now) for some new log.

CHANGELOG.md

@@ -1,4 +1,8 @@
-Unreleased
+2023-08-21 v1.5.1
+  - More logs.
+  - Use zerolog (I prefer it now) for some new log.
+
+2023-08-21 v1.5.0
   - Fix openapi linter warnings.
   - Use latest oapi.
   - Support for ignore domains in message from newbie.

go.mod

@@ -16,6 +16,7 @@ require (
 	github.com/kak-tus/nan v0.7.0
 	github.com/kelseyhightower/envconfig v1.4.0
 	github.com/lib/pq v1.10.2
+	github.com/rs/zerolog v1.30.0
 	github.com/stretchr/testify v1.7.1
 	github.com/zach-klippenstein/goregen v0.0.0-20160303162051-795b5e3961ea
 	go.uber.org/zap v1.20.0
@@ -44,6 +45,8 @@ require (
 	github.com/jackc/pgtype v1.9.1 // indirect
 	github.com/josharian/intern v1.0.0 // indirect
 	github.com/mailru/easyjson v0.7.7 // indirect
+	github.com/mattn/go-colorable v0.1.12 // indirect
+	github.com/mattn/go-isatty v0.0.14 // indirect
 	github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect
 	github.com/modern-go/reflect2 v1.0.2 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect
@@ -52,6 +55,7 @@ require (
 	go.uber.org/atomic v1.9.0 // indirect
 	go.uber.org/multierr v1.7.0 // indirect
 	golang.org/x/crypto v0.0.0-20220513210258-46612604a0f9 // indirect
+	golang.org/x/sys v0.0.0-20220513210249-45d2b4557a2a // indirect
 	golang.org/x/text v0.3.7 // indirect
 	gopkg.in/inf.v0 v0.9.1 // indirect
 	gopkg.in/yaml.v2 v2.4.0 // indirect

go.sum

@@ -13,6 +13,7 @@ github.com/cockroachdb/apd v1.1.0 h1:3LFP3629v+1aKXU5Q37mxmRxX/pIu1nijXydLShEq5I
 github.com/cockroachdb/apd v1.1.0/go.mod h1:8Sl8LxpKi29FqWXR16WEFZRNSz3SoPzUzeMeY4+DwBQ=
 github.com/coreos/go-systemd v0.0.0-20190321100706-95778dfbb74e/go.mod h1:F5haX7vjVVG0kc13fIWeqUViNPyEJxv/OmvnBo0Yme4=
 github.com/coreos/go-systemd v0.0.0-20190719114852-fd7a80b32e1f/go.mod h1:F5haX7vjVVG0kc13fIWeqUViNPyEJxv/OmvnBo0Yme4=
+github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/creack/pty v1.1.7/go.mod h1:lj5s0c3V2DBrqTV7llrYr5NG6My20zk30Fl46Y7DoTY=
 github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 github.com/cyberdelia/templates v0.0.0-20141128023046-ca7fffd4298c/go.mod h1:GyV+0YP4qX0UQ7r2MoYZ+AvYDp12OF5yg4q8rGnyNh4=
@@ -65,6 +66,7 @@ github.com/goccy/go-json v0.9.7 h1:IcB+Aqpx/iMHu5Yooh7jEzJk1JZ7Pjtmys2ukPr7EeM=
 github.com/goccy/go-json v0.9.7/go.mod h1:6MelG93GURQebXPDq3khkgXZkazVtN9CRI+MGFi0w8I=
 github.com/gocql/gocql v0.0.0-20211222173705-d73e6b1002a7 h1:jmIMM+nEO+vjz9xaRIg9sZNtNLq5nsSbsxwe1OtRwv4=
 github.com/gocql/gocql v0.0.0-20211222173705-d73e6b1002a7/go.mod h1:3gM2c4D3AnkISwBxGnMMsS8Oy4y2lhbPRsH4xnJrHG8=
+github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
 github.com/gofrs/uuid v4.0.0+incompatible h1:1SD/1F5pU8p29ybwgQSwpQk+mwdRrXCYuPhW6m+TnJw=
 github.com/gofrs/uuid v4.0.0+incompatible/go.mod h1:b2aQJv3Z4Fp6yNu3cdSllBxTCLRxnplIgP/c0N/04lM=
 github.com/golang-jwt/jwt v3.2.2+incompatible/go.mod h1:8pz2t5EyA70fFQQSrl6XZXzqecmYZeUEB8OUGHkxJ+I=
@@ -235,8 +237,11 @@ github.com/rogpeppe/go-internal v1.6.1/go.mod h1:xXDCJY+GAPziupqXw64V24skbSoqbTE
 github.com/rogpeppe/go-internal v1.8.0 h1:FCbCCtXNOY3UtUuHUYaghJg4y7Fd14rXifAYUAtL9R8=
 github.com/rogpeppe/go-internal v1.8.0/go.mod h1:WmiCO8CzOY8rg0OYDC4/i/2WRWAB6poM+XZ2dLUbcbE=
 github.com/rs/xid v1.2.1/go.mod h1:+uKXf+4Djp6Md1KODXJxgGQPKngRmWyn10oCKFzNHOQ=
+github.com/rs/xid v1.5.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
 github.com/rs/zerolog v1.13.0/go.mod h1:YbFCdg8HfsridGWAh22vktObvhZbQsZXe4/zB0OKkWU=
 github.com/rs/zerolog v1.15.0/go.mod h1:xYTKnLHcpfU2225ny5qZjxnj9NvkumZYjJHlAThCjNc=
+github.com/rs/zerolog v1.30.0 h1:SymVODrcRsaRaSInD9yQtKbtWqwsfoPcRff/oRXLj4c=
+github.com/rs/zerolog v1.30.0/go.mod h1:/tk+P47gFdPXq4QYjvCmT5/Gsug2nagsFWBWhAiSi1w=
 github.com/satori/go.uuid v1.2.0/go.mod h1:dA0hQrYB0VpLJoorglMZABFdXlWrHn1NEOzdhQKdks0=
 github.com/shopspring/decimal v0.0.0-20180709203117-cd690d0c9e24/go.mod h1:M+9NzErvs504Cn4c5DxATwIqPbtswREoFCre64PpcG4=
 github.com/shopspring/decimal v1.2.0 h1:abSATXmQEYyShuxI4/vyW3tV1MrKAJzCZ/0zLUXYbsQ=

main.go

@@ -12,72 +12,76 @@ import (
 	"github.com/kak-tus/irma_bot/model"
 	"github.com/kak-tus/irma_bot/storage"
 	"github.com/kak-tus/irma_bot/telegram"
+	"github.com/rs/zerolog"
 	"go.uber.org/zap"
 )
 
 //go:generate sqlc generate
 //go:generate oapi-codegen --config openapi-codegen.yml openapi.yml
 
 func main() {
-	logger, err := zap.NewProduction()
+	log := zerolog.New(os.Stdout).With().Timestamp().Logger()
+
+	oldLogger, err := zap.NewProduction()
 	if err != nil {
 		panic(err)
 	}
 
-	log := logger.Sugar()
+	oldLog := oldLogger.Sugar()
 
 	cnf, err := config.NewConf()
 	if err != nil {
-		log.Panic(err)
+		log.Panic().Err(err).Msg("fail load config")
 	}
 
 	modelOpts := model.Options{
-		Log: log,
+		Log: oldLog,
 		URL: cnf.DB.Addr,
 	}
 
 	modelHdl, err := model.NewModel(modelOpts)
 	if err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
 	storOptions := storage.Options{
-		Log:    log,
+		Log:    oldLog,
 		Config: cnf.Storage,
 	}
 
 	stor, err := storage.NewStorage(storOptions)
 	if err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
 	apiOpts := api.Options{
-		Log:     log,
+		Log:     oldLog,
 		Model:   modelHdl,
 		Storage: stor,
 	}
 
 	apiHdl, err := api.NewAPI(apiOpts)
 	if err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
 	telegramOpts := telegram.Options{
-		Log:     log,
+		OldLog:  oldLog,
 		Config:  cnf.Telegram,
 		Model:   modelHdl,
 		Router:  apiHdl.GetHTTPRouter(),
 		Storage: stor,
+		Log:     log.With().Str("module", "telegram").Logger(),
 	}
 
 	tg, err := telegram.NewTelegram(telegramOpts)
 	if err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
 	go func() {
 		if err := tg.Start(); err != nil {
-			log.Panic(err)
+			oldLog.Panic(err)
 		}
 	}()
 
@@ -89,28 +93,28 @@ func main() {
 	go func() {
 		err = srv.ListenAndServe()
 		if err != nil && err != http.ErrServerClosed {
-			log.Panic(err)
+			oldLog.Panic(err)
 		}
 	}()
 
 	st := make(chan os.Signal, 1)
 	signal.Notify(st, os.Interrupt)
 
 	<-st
-	log.Info("stop")
+	oldLog.Info("stop")
 
 	ctx, cancel := context.WithTimeout(context.Background(), time.Minute)
 
 	err = srv.Shutdown(ctx)
 	if err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
 	cancel()
 
 	if err := tg.Stop(); err != nil {
-		log.Panic(err)
+		oldLog.Panic(err)
 	}
 
-	_ = log.Sync()
+	_ = oldLog.Sync()
 }

telegram/ban.go

@@ -18,7 +18,7 @@ func (hdl *InstanceObj) banLongNames(msg *tgbotapi.Message) (bool, error) {
 
 	for _, u := range msg.NewChatMembers {
 		if len(u.FirstName) >= nameLimit || len(u.LastName) >= nameLimit {
-			hdl.log.Infow("Ban long name",
+			hdl.oldLog.Infow("Ban long name",
 				"User", u.FirstName,
 				"Chat", msg.Chat.ID,
 			)
@@ -65,7 +65,7 @@ func (hdl *InstanceObj) banKickPool(ctx context.Context, msg *tgbotapi.Message)
 		return false, err
 	}
 
-	hdl.log.Infow("User found in kick pool",
+	hdl.oldLog.Infow("User found in kick pool",
 		"User", msg.From.FirstName,
 		"Chat", msg.Chat.ID,
 	)

telegram/newbie.go

@@ -26,10 +26,8 @@ func (hdl *InstanceObj) messageFromNewbie(ctx context.Context, msg *tgbotapi.Mes
 		return hdl.stor.AddNewbieMessages(ctx, msg.Chat.ID, int(msg.From.ID))
 	}
 
-	hdl.log.Infow("Restricted message",
-		"User", msg.From.FirstName,
-		"Chat", msg.Chat.ID,
-	)
+	hdl.log.Info().Str("user", msg.From.FirstName).Int64("chat", msg.Chat.ID).
+		Str("msg", msg.Text).Msg("restricted message")
 
 	kick := tgbotapi.KickChatMemberConfig{
 		ChatMemberConfig: tgbotapi.ChatMemberConfig{
@@ -58,7 +56,7 @@ func (hdl *InstanceObj) newMembers(ctx context.Context, msg *tgbotapi.Message) e
 	}
 
 	if isAdm {
-		hdl.log.Infow(
+		hdl.oldLog.Infow(
 			"Newbie added by admin, it is normal",
 			"Admin", msg.From.ID,
 		)
@@ -74,7 +72,7 @@ func (hdl *InstanceObj) newMembers(ctx context.Context, msg *tgbotapi.Message) e
 	defaultGroup := hdl.model.GetDefaultGroup()
 
 	for _, m := range msg.NewChatMembers {
-		hdl.log.Infow("Newbie found, add messages",
+		hdl.oldLog.Infow("Newbie found, add messages",
 			"User", m.FirstName,
 			"Chat", msg.Chat.ID,
 		)
@@ -102,7 +100,7 @@ func (hdl *InstanceObj) newMembers(ctx context.Context, msg *tgbotapi.Message) e
 	}
 
 	for _, newMember := range msg.NewChatMembers {
-		hdl.log.Infow("Newbie found, send question",
+		hdl.oldLog.Infow("Newbie found, send question",
 			"User", newMember.FirstName,
 			"Chat", msg.Chat.ID,
 		)
@@ -186,6 +184,7 @@ func (hdl *InstanceObj) isBanNewbie(
 	msg *tgbotapi.Message,
 ) (bool, error) {
 	if hdl.isBanNewbieForEntities(append(msg.Entities, msg.CaptionEntities...)...) {
+		hdl.log.Info().Str("user", msg.From.FirstName).Int64("chat", msg.Chat.ID).Msg("ban for entries")
 		return true, nil
 	}
 
@@ -198,10 +197,12 @@ func (hdl *InstanceObj) isBanNewbie(
 		msg.Video != nil ||
 		msg.VideoNote != nil ||
 		msg.Voice != nil {
+		hdl.log.Info().Str("user", msg.From.FirstName).Int64("chat", msg.Chat.ID).Msg("ban for media")
 		return true, nil
 	}
 
 	if len(gomoji.CollectAll(msg.Text)) > maxEmojiis {
+		hdl.log.Info().Str("user", msg.From.FirstName).Int64("chat", msg.Chat.ID).Msg("ban for emojii")
 		return true, nil
 	}
 
@@ -219,7 +220,10 @@ func (hdl *InstanceObj) isBanNewbie(
 			ignore[domain] = struct{}{}
 		}
 
-		return hdl.isBanNewbieForURLs(ignore, urlsList), nil
+		if hdl.isBanNewbieForURLs(ignore, urlsList) {
+			hdl.log.Info().Str("user", msg.From.FirstName).Int64("chat", msg.Chat.ID).Msg("ban for url")
+			return true, nil
+		}
 	}
 
 	return false, nil
@@ -274,14 +278,14 @@ func (hdl *InstanceObj) isBanNewbieForURLs(
 	for _, urlStr := range checkUrls {
 		parsed, err := url.Parse(urlStr)
 		if err != nil {
-			hdl.log.Errorw("can't parse url in message", "url", urlStr)
+			hdl.oldLog.Errorw("can't parse url in message", "url", urlStr)
 
 			// Ban also in case of incorrect url because it is some url
 			return true
 		}
 
 		if parsed.Hostname() == "" {
-			hdl.log.Errorw("can't parse url in message, but no error", "url", urlStr)
+			hdl.oldLog.Errorw("can't parse url in message, but no error", "url", urlStr)
 
 			// Can't parse? Ban!
 			return true

telegram/telegram.go

@@ -13,6 +13,7 @@ import (
 	"github.com/kak-tus/irma_bot/config"
 	"github.com/kak-tus/irma_bot/model"
 	"github.com/kak-tus/irma_bot/storage"
+	"github.com/rs/zerolog"
 	"go.uber.org/zap"
 	"golang.org/x/net/proxy"
 )
@@ -21,17 +22,19 @@ type InstanceObj struct {
 	bot    *tgbotapi.BotAPI
 	cnf    config.Tg
 	lock   *sync.WaitGroup
-	log    *zap.SugaredLogger
+	log    zerolog.Logger
 	model  *model.Model
+	oldLog *zap.SugaredLogger
 	router *chi.Mux
 	stop   chan bool
 	stor   *storage.InstanceObj
 }
 
 type Options struct {
 	Config  config.Tg
-	Log     *zap.SugaredLogger
+	Log     zerolog.Logger
 	Model   *model.Model
+	OldLog  *zap.SugaredLogger
 	Router  *chi.Mux
 	Storage *storage.InstanceObj
 }
@@ -53,6 +56,7 @@ func NewTelegram(opts Options) (*InstanceObj, error) {
 		lock:   &sync.WaitGroup{},
 		log:    opts.Log,
 		model:  opts.Model,
+		oldLog: opts.OldLog,
 		router: opts.Router,
 		stop:   make(chan bool, 1),
 		stor:   opts.Storage,
@@ -62,7 +66,7 @@ func NewTelegram(opts Options) (*InstanceObj, error) {
 }
 
 func (hdl *InstanceObj) Start() error {
-	hdl.log.Info("start telegram")
+	hdl.oldLog.Info("start telegram")
 
 	webhookCnf, err := tgbotapi.NewWebhook(hdl.cnf.URL + hdl.cnf.Path)
 	if err != nil {
@@ -74,7 +78,7 @@ func (hdl *InstanceObj) Start() error {
 		return err
 	}
 
-	hdl.log.Info(resp.Description)
+	hdl.oldLog.Info(resp.Description)
 
 	upd := hdl.bot.ListenForWebhook("/" + hdl.cnf.Path)
 
@@ -96,7 +100,7 @@ func (hdl *InstanceObj) Start() error {
 		case <-tick.C:
 			err := hdl.processActions()
 			if err != nil {
-				hdl.log.Error(err)
+				hdl.oldLog.Error(err)
 				continue
 			}
 		case <-hdl.stop:
@@ -107,7 +111,7 @@ func (hdl *InstanceObj) Start() error {
 
 			err := hdl.process(ctx, msg)
 			if err != nil {
-				hdl.log.Error(err)
+				hdl.oldLog.Error(err)
 			}
 
 			cancel()
@@ -116,12 +120,12 @@ func (hdl *InstanceObj) Start() error {
 }
 
 func (hdl *InstanceObj) Stop() error {
-	hdl.log.Info("stop telegram")
+	hdl.oldLog.Info("stop telegram")
 
 	hdl.stop <- true
 	hdl.lock.Wait()
 
-	hdl.log.Info("stopped telegram")
+	hdl.oldLog.Info("stopped telegram")
 
 	return nil
 }
@@ -135,7 +139,7 @@ func (hdl *InstanceObj) deleteMessage(chatID int64, messageID int) error {
 			return err
 		}
 
-		hdl.log.Warnw("Message in chat is already deleted",
+		hdl.oldLog.Warnw("Message in chat is already deleted",
 			"Chat", chatID,
 			"Message", messageID,
 		)