Add message logger (#4)

.gitignore

@@ -1,9 +1,11 @@
 .DS_Store
 .idea/
+.run/
 
 # Output of the go coverage tool, specifically when used with LiteIDE
 *.out
 
 # app binary
 /app/app
 .env
+logs/

app/bot/bot.go

@@ -33,7 +33,8 @@ type Chat struct {
 
 // User represents a user or bot.
 type User struct {
-	ID int64 `json:"id"`
+	ID       int64  `json:"id"`
+	UserName string `json:"username"`
 }
 
 // Response describes bot's answer on particular message

app/bot/sys_test.go

@@ -1,9 +1,10 @@
 package bot
 
 import (
+	"testing"
+
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
-	"testing"
 )
 
 func TestSys_OnMessage(t *testing.T) {

app/events/superuser.go

@@ -0,0 +1,18 @@
+package events
+
+import (
+	"strings"
+)
+
+// SuperUser for moderators
+type SuperUser []string
+
+// IsSuper checks if user name in su list
+func (s SuperUser) IsSuper(userName string) bool {
+	for _, super := range s {
+		if strings.EqualFold(userName, super) || strings.EqualFold("/"+userName, super) {
+			return true
+		}
+	}
+	return false
+}

app/events/telegram.go

@@ -3,35 +3,44 @@ package events
 import (
 	"context"
 	"fmt"
-	"github.com/cinehouse/bot/app/bot"
+	"log"
+
 	tgbotapi "github.com/go-telegram-bot-api/telegram-bot-api/v5"
 	"github.com/pkg/errors"
-	"log"
+
+	"github.com/cinehouse/bot/app/bot"
 )
 
-//go:generate mockery --inpackage --name=BotAPI --case=snake --testonly
+//go:generate mockery --inpackage --name=TgBotAPI --case=snake
+//go:generate mockery --inpackage --name=MessageLogger --case=snake
 
 // TelegramListener listens to tg update, forward to bots and send back responses
 // Not thread safe
 type TelegramListener struct {
-	BotAPI BotAPI
-	Bots   bot.Interface
-	Debug  bool
+	TgBotAPI      TgBotAPI
+	MessageLogger MessageLogger
+	Bots          bot.Interface
+	SuperUsers    SuperUser
+	Debug         bool
 }
 
-type BotAPI interface {
+type TgBotAPI interface {
 	GetUpdatesChan(config tgbotapi.UpdateConfig) tgbotapi.UpdatesChannel
 	Send(c tgbotapi.Chattable) (tgbotapi.Message, error)
 }
 
+type MessageLogger interface {
+	Save(msg *bot.Message)
+}
+
 // Do process all events, blocked call
 func (l *TelegramListener) Do(ctx context.Context) (err error) {
 	log.Printf("[TelegramListener] Start listening")
 
 	u := tgbotapi.NewUpdate(0)
 	u.Timeout = 60
 
-	updates := l.BotAPI.GetUpdatesChan(u)
+	updates := l.TgBotAPI.GetUpdatesChan(u)
 
 	for {
 		select {
@@ -56,6 +65,7 @@ func (l *TelegramListener) Do(ctx context.Context) (err error) {
 			log.Printf("[%s] %s", update.Message.From.UserName, update.Message.Text)
 
 			msg := l.transform(update.Message)
+			l.MessageLogger.Save(msg) // save an incoming update to report
 
 			log.Printf("[DEBUG] Incoming msg: %+v", msg)
 
@@ -79,14 +89,20 @@ func (l *TelegramListener) sendBotResponse(chatID int64, resp bot.Response) erro
 	msg.ParseMode = tgbotapi.ModeMarkdownV2
 	msg.DisableWebPagePreview = !resp.Preview
 
-	_, err := l.BotAPI.Send(msg)
+	res, err := l.TgBotAPI.Send(msg)
 	if err != nil {
 		return errors.Wrapf(err, "can't send message to telegram %q", resp.Text)
 	}
 
+	l.saveBotMessage(&res)
+
 	return nil
 }
 
+func (l *TelegramListener) saveBotMessage(msg *tgbotapi.Message) {
+	l.MessageLogger.Save(l.transform(msg))
+}
+
 func (l *TelegramListener) transform(msg *tgbotapi.Message) *bot.Message {
 	message := bot.Message{
 		MessageID: msg.MessageID,
@@ -101,7 +117,8 @@ func (l *TelegramListener) transform(msg *tgbotapi.Message) *bot.Message {
 
 	if msg.From != nil {
 		message.From = bot.User{
-			ID: msg.From.ID,
+			ID:       msg.From.ID,
+			UserName: msg.From.UserName,
 		}
 	}
 

app/events/telegram_test.go

@@ -13,12 +13,14 @@ import (
 )
 
 func TestTelegramListener_DoNoBots(t *testing.T) {
-	tbAPI := &MockBotAPI{}
+	messageLogger := &MockMessageLogger{}
+	tgBotAPI := &MockTgBotAPI{}
 	bots := &bot.MockInterface{}
 
 	l := TelegramListener{
-		BotAPI: tbAPI,
-		Bots:   bots,
+		TgBotAPI:      tgBotAPI,
+		MessageLogger: messageLogger,
+		Bots:          bots,
 	}
 
 	ctx, cancel := context.WithTimeout(context.Background(), 500*time.Millisecond)
@@ -32,16 +34,79 @@ func TestTelegramListener_DoNoBots(t *testing.T) {
 		},
 	}
 
-	tbAPI.On("GetChat", mock.Anything).Return(tgbotapi.Chat{ID: 123}, nil)
+	tgBotAPI.On("GetChat", mock.Anything).Return(tgbotapi.Chat{ID: 123}, nil)
 
 	updChan := make(chan tgbotapi.Update, 1)
 	updChan <- updMsg
 	close(updChan)
-	tbAPI.On("GetUpdatesChan", mock.Anything).Return(tgbotapi.UpdatesChannel(updChan), nil)
+	tgBotAPI.On("GetUpdatesChan", mock.Anything).Return(tgbotapi.UpdatesChannel(updChan), nil)
 
 	bots.On("OnMessage", mock.Anything).Return(bot.Response{Send: false})
+	messageLogger.On("Save", mock.MatchedBy(func(msg *bot.Message) bool {
+		t.Logf("%v", msg)
+		return msg.Text == "text 123" && msg.From.UserName == "user"
+	}))
 	err := l.Do(ctx)
 	assert.EqualError(t, err, "[ERROR] Telegram listener: updates channel closed")
+
+	messageLogger.AssertExpectations(t)
+	messageLogger.AssertNumberOfCalls(t, "Save", 1)
+}
+
+func TestTelegramListener_DoWithBots(t *testing.T) {
+	messageLogger := &MockMessageLogger{}
+	tgBotAPI := &MockTgBotAPI{}
+	bots := &bot.MockInterface{}
+
+	l := TelegramListener{
+		MessageLogger: messageLogger,
+		TgBotAPI:      tgBotAPI,
+		Bots:          bots,
+	}
+
+	ctx, cancel := context.WithTimeout(context.Background(), 500*time.Minute)
+	defer cancel()
+
+	updMsg := tgbotapi.Update{
+		Message: &tgbotapi.Message{
+			Chat: &tgbotapi.Chat{ID: 123},
+			Text: "text 123",
+			From: &tgbotapi.User{UserName: "user"},
+			Date: int(time.Date(2020, 2, 11, 19, 35, 55, 9, time.UTC).Unix()),
+		},
+	}
+
+	tgBotAPI.On("GetChat", mock.Anything).Return(tgbotapi.Chat{ID: 123}, nil)
+
+	updChan := make(chan tgbotapi.Update, 1)
+	updChan <- updMsg
+	close(updChan)
+	tgBotAPI.On("GetUpdatesChan", mock.Anything).Return(tgbotapi.UpdatesChannel(updChan), nil)
+
+	bots.On("OnMessage", mock.MatchedBy(func(msg bot.Message) bool {
+		t.Logf("on-message: %+v", msg)
+		return msg.Text == "text 123" && msg.From.UserName == "user"
+	})).Return(bot.Response{Send: true, Text: "bot's answer"})
+
+	messageLogger.On("Save", mock.MatchedBy(func(msg *bot.Message) bool {
+		t.Logf("save: %+v", msg)
+		return msg.Text == "text 123" && msg.From.UserName == "user"
+	}))
+	messageLogger.On("Save", mock.MatchedBy(func(msg *bot.Message) bool {
+		t.Logf("save: %+v", msg)
+		return msg.Text == "bot's answer"
+	}))
+
+	tgBotAPI.On("Send", mock.MatchedBy(func(c tgbotapi.MessageConfig) bool {
+		t.Logf("send: %+v", c)
+		return c.Text == "bot's answer"
+	})).Return(tgbotapi.Message{Text: "bot's answer", From: &tgbotapi.User{UserName: "user"}}, nil)
+
+	err := l.Do(ctx)
+	assert.EqualError(t, err, "[ERROR] Telegram listener: updates channel closed")
+	messageLogger.AssertExpectations(t)
+	messageLogger.AssertNumberOfCalls(t, "Save", 2)
+	tgBotAPI.AssertNumberOfCalls(t, "Send", 1)
 }
 
 func TestTelegram_transformTextMessage(t *testing.T) {

app/main.go

@@ -3,20 +3,26 @@ package main
 import (
 	"context"
 	"fmt"
-	"github.com/cinehouse/bot/app/bot"
-	"github.com/cinehouse/bot/app/events"
-	tgbotapi "github.com/go-telegram-bot-api/telegram-bot-api/v5"
-	"github.com/jessevdk/go-flags"
 	"log"
 	"os"
+
+	"github.com/go-pkgz/lgr"
+	tgbotapi "github.com/go-telegram-bot-api/telegram-bot-api/v5"
+	"github.com/jessevdk/go-flags"
+
+	"github.com/cinehouse/bot/app/bot"
+	"github.com/cinehouse/bot/app/events"
+	"github.com/cinehouse/bot/app/reporter"
 )
 
 var opts struct {
 	Telegram struct {
 		Token string `long:"token" env:"TOKEN" description:"Telegram bot token"`
 	} `group:"telegram" namespace:"telegram" env-namespace:"TELEGRAM"`
-	SysData string `long:"sys-data" env:"SYS_DATA" default:"data" description:"location of sys data"`
-	Debug   bool   `long:"debug" description:"Show debug information"`
+	LogsPath   string           `short:"l" long:"logs" env:"TELEGRAM_LOGS" default:"logs" description:"path to logs"`
+	SuperUsers events.SuperUser `long:"super" description:"super-users"`
+	SysData    string           `long:"sys-data" env:"SYS_DATA" default:"data" description:"location of sys data"`
+	Debug      bool             `long:"debug" description:"Show debug information"`
 }
 
 func main() {
@@ -29,6 +35,8 @@ func main() {
 	}
 
 	fmt.Printf("Debug: %v\n", opts.Debug)
+	setupLog(opts.Debug)
+	log.Printf("[INFO] super users: %v", opts.SuperUsers)
 
 	tgBot, err := tgbotapi.NewBotAPI(opts.Telegram.Token)
 	if err != nil {
@@ -47,11 +55,20 @@ func main() {
 	}
 
 	tgListener := events.TelegramListener{
-		BotAPI: tgBot,
-		Bots:   multiBot,
+		TgBotAPI:      tgBot,
+		MessageLogger: reporter.NewLogger(opts.LogsPath),
+		Bots:          multiBot,
 	}
 
 	if err := tgListener.Do(ctx); err != nil {
 		log.Fatalf("[ERROR] telegram listener failed, %v", err)
 	}
 }
+
+func setupLog(debug bool) {
+	logOpts := []lgr.Option{lgr.Msec, lgr.LevelBraces}
+	if debug {
+		logOpts = []lgr.Option{lgr.Debug, lgr.CallerFile, lgr.CallerFunc, lgr.Msec, lgr.LevelBraces}
+	}
+	lgr.SetupStdLogger(logOpts...)
+}