log system improved

This commit is contained in:
Dawid Wysokiński 2020-10-24 08:17:52 +02:00
parent 38325e63d4
commit 711760a568
6 changed files with 156 additions and 69 deletions

View File

@ -3,6 +3,7 @@ package cron
import (
"time"
"github.com/sirupsen/logrus"
"github.com/tribalwarshelp/golang-sdk/sdk"
"github.com/tribalwarshelp/shared/mode"
@ -14,6 +15,8 @@ import (
"github.com/robfig/cron/v3"
)
var log = logrus.WithField("package", "cron")
type Config struct {
ServerRepo server.Repository
ObservationRepo observation.Repository
@ -24,7 +27,7 @@ type Config struct {
}
func Attach(c *cron.Cron, cfg Config) {
h := &handler{
w := &worker{
lastEnnoblementAt: make(map[string]time.Time),
serverRepo: cfg.ServerRepo,
observationRepo: cfg.ObservationRepo,
@ -33,16 +36,16 @@ func Attach(c *cron.Cron, cfg Config) {
api: cfg.API,
status: cfg.Status,
}
c.AddFunc("@every 1m", h.checkEnnoblements)
c.AddFunc("@every 30m", h.checkBotServers)
c.AddFunc("@every 2h10m", h.deleteClosedTribalWarsServers)
c.AddFunc("@every 2h", h.updateBotStatus)
c.AddFunc("@every 1m", w.checkEnnoblements)
c.AddFunc("@every 30m", w.checkBotServers)
c.AddFunc("@every 2h10m", w.deleteClosedTribalWarsServers)
c.AddFunc("@every 2h", w.updateBotStatus)
go func() {
h.checkBotServers()
h.deleteClosedTribalWarsServers()
h.updateBotStatus()
w.checkBotServers()
w.deleteClosedTribalWarsServers()
w.updateBotStatus()
if mode.Get() == mode.DevelopmentMode {
h.checkEnnoblements()
w.checkEnnoblements()
}
}()
}

View File

@ -3,7 +3,6 @@ package cron
import (
"context"
"fmt"
"log"
"time"
"github.com/nicksnyder/go-i18n/v2/i18n"
@ -22,7 +21,7 @@ import (
"github.com/tribalwarshelp/golang-sdk/sdk"
)
type handler struct {
type worker struct {
lastEnnoblementAt map[string]time.Time
serverRepo server.Repository
observationRepo observation.Repository
@ -32,7 +31,7 @@ type handler struct {
status string
}
func (h *handler) loadEnnoblements(servers []string) (map[string]ennoblements, error) {
func (w *worker) loadEnnoblements(servers []string) (map[string]ennoblements, error) {
m := make(map[string]ennoblements)
if len(servers) == 0 {
@ -62,12 +61,12 @@ func (h *handler) loadEnnoblements(servers []string) (map[string]ennoblements, e
resp := make(map[string]ennoblements)
if err := h.api.Post(fmt.Sprintf(`query { %s }`, query), &resp); err != nil {
if err := w.api.Post(fmt.Sprintf(`query { %s }`, query), &resp); err != nil {
return m, errors.Wrap(err, "loadEnnoblements")
}
for server, ennoblements := range resp {
lastEnnoblementAt, ok := h.lastEnnoblementAt[server]
lastEnnoblementAt, ok := w.lastEnnoblementAt[server]
if !ok {
lastEnnoblementAt = time.Now().Add(-1 * time.Minute)
}
@ -81,13 +80,13 @@ func (h *handler) loadEnnoblements(servers []string) (map[string]ennoblements, e
if lastEnnoblement != nil {
lastEnnoblementAt = lastEnnoblement.EnnobledAt
}
h.lastEnnoblementAt[server] = lastEnnoblementAt
w.lastEnnoblementAt[server] = lastEnnoblementAt
}
return m, nil
}
func (h *handler) loadLangVersions(servers []string) ([]*shared_models.LangVersion, error) {
func (w *worker) loadLangVersions(servers []string) ([]*shared_models.LangVersion, error) {
languageTags := []shared_models.LanguageTag{}
cache := make(map[shared_models.LanguageTag]bool)
for _, server := range servers {
@ -98,7 +97,7 @@ func (h *handler) loadLangVersions(servers []string) ([]*shared_models.LangVersi
}
}
langVersionList, err := h.api.LangVersions.Browse(&shared_models.LangVersionFilter{
langVersionList, err := w.api.LangVersions.Browse(&shared_models.LangVersionFilter{
Tag: languageTags,
})
if err != nil {
@ -108,32 +107,43 @@ func (h *handler) loadLangVersions(servers []string) ([]*shared_models.LangVersi
return langVersionList.Items, nil
}
func (h *handler) checkEnnoblements() {
func (w *worker) checkEnnoblements() {
start := time.Now()
log.
Infoln("checkEnnoblements: called")
servers, err := h.observationRepo.FetchServers(context.Background())
servers, err := w.observationRepo.FetchServers(context.Background())
if err != nil {
log.Print("checkEnnoblements error: " + err.Error())
log.Errorln("checkEnnoblements:", err.Error())
return
}
log.Print("checkEnnoblements: servers: ", servers)
log.
WithField("servers", servers).
Info("checkEnnoblements: Loaded servers")
groups, total, err := h.groupRepo.Fetch(context.Background(), nil)
groups, total, err := w.groupRepo.Fetch(context.Background(), nil)
if err != nil {
log.Print("checkEnnoblements error: " + err.Error())
log.Errorln("checkEnnoblements:", err.Error())
return
}
log.Print("checkEnnoblements: number of loaded groups: ", total)
log.
WithField("numberOfGroups", total).
Info("checkEnnoblements: Loaded groups")
langVersions, err := h.loadLangVersions(servers)
langVersions, err := w.loadLangVersions(servers)
if err != nil {
log.Print(err)
log.Errorln("checkEnnoblements:", err)
return
}
ennoblementsByServerKey, err := h.loadEnnoblements(servers)
log.
WithField("numberOfLangVersions", len(langVersions)).
Info("checkEnnoblements: Loaded lang versions")
ennoblementsByServerKey, err := w.loadEnnoblements(servers)
if err != nil {
log.Print(err)
log.Errorln("checkEnnoblements:", err)
}
log.Info("checkEnnoblements: Loaded ennoblements")
for _, group := range groups {
if group.ConqueredVillagesChannelID == "" && group.LostVillagesChannelID == "" {
@ -191,7 +201,7 @@ func (h *handler) checkEnnoblements() {
DefaultMessage: message.FallbackMsg(message.CronConqueredVillagesTitle,
"Conquered villages"),
})
go h.discord.SendEmbed(group.ConqueredVillagesChannelID,
go w.discord.SendEmbed(group.ConqueredVillagesChannelID,
discord.
NewEmbed().
SetTitle(title).
@ -207,7 +217,7 @@ func (h *handler) checkEnnoblements() {
DefaultMessage: message.FallbackMsg(message.CronLostVillagesTitle,
"Lost villages"),
})
go h.discord.SendEmbed(group.LostVillagesChannelID,
go w.discord.SendEmbed(group.LostVillagesChannelID,
discord.
NewEmbed().
SetTitle(title).
@ -218,50 +228,69 @@ func (h *handler) checkEnnoblements() {
}
}
log.Printf("checkEnnoblements: finished in %s", time.Since(start).String())
log.
WithField("executionTime", time.Since(start).String()).
Infoln("checkEnnoblements: finished executing")
}
func (h *handler) checkBotServers() {
servers, total, err := h.serverRepo.Fetch(context.Background(), nil)
func (w *worker) checkBotServers() {
start := time.Now()
log.Info("checkBotServers: called")
servers, total, err := w.serverRepo.Fetch(context.Background(), nil)
if err != nil {
log.Print("checkBotServers error: " + err.Error())
log.Error("checkBotServers: " + err.Error())
return
}
log.Print("checkBotServers: total number of loaded discord servers: ", total)
log.
WithField("executionTime", time.Since(start)).
WithField("numberOfServers", total).
Info("checkBotServers: loaded servers")
idsToDelete := []string{}
for _, server := range servers {
if isGuildMember, _ := h.discord.IsGuildMember(server.ID); !isGuildMember {
if isGuildMember, _ := w.discord.IsGuildMember(server.ID); !isGuildMember {
idsToDelete = append(idsToDelete, server.ID)
}
}
if len(idsToDelete) > 0 {
deleted, err := h.serverRepo.Delete(context.Background(), &models.ServerFilter{
deleted, err := w.serverRepo.Delete(context.Background(), &models.ServerFilter{
ID: idsToDelete,
})
if err != nil {
log.Print("checkBotServers error: " + err.Error())
log.Error("checkBotServers: " + err.Error())
} else {
log.Printf("checkBotServers: total number of deleted discord servers: %d", len(deleted))
log.
WithField("numberOfDeletedServers", len(deleted)).
Info("checkBotServers: deleted servers")
}
}
log.
WithField("executionTime", time.Since(start).String()).
Infoln("checkBotServers: finished executing")
}
func (h *handler) deleteClosedTribalWarsServers() {
servers, err := h.observationRepo.FetchServers(context.Background())
func (w *worker) deleteClosedTribalWarsServers() {
start := time.Now()
log.Info("deleteClosedTribalWarsServers: called")
servers, err := w.observationRepo.FetchServers(context.Background())
if err != nil {
log.Print("deleteClosedTribalWarsServers: " + err.Error())
log.Error("deleteClosedTribalWarsServers: " + err.Error())
return
}
log.Print("deleteClosedTribalWarsServers: servers: ", servers)
log.
WithField("servers", servers).
Info("deleteClosedTribalWarsServers: loaded servers")
list, err := h.api.Servers.Browse(&shared_models.ServerFilter{
list, err := w.api.Servers.Browse(&shared_models.ServerFilter{
Key: servers,
Status: []shared_models.ServerStatus{shared_models.ServerStatusClosed},
}, nil)
if err != nil {
log.Print("deleteClosedTribalWarsServers: " + err.Error())
log.Errorln("deleteClosedTribalWarsServers: " + err.Error())
return
}
if list == nil || list.Items == nil {
@ -274,19 +303,32 @@ func (h *handler) deleteClosedTribalWarsServers() {
}
if len(keys) > 0 {
deleted, err := h.observationRepo.Delete(context.Background(), &models.ObservationFilter{
deleted, err := w.observationRepo.Delete(context.Background(), &models.ObservationFilter{
Server: keys,
})
if err != nil {
log.Print("deleteClosedTribalWarsServers error: " + err.Error())
log.Errorln("deleteClosedTribalWarsServers: " + err.Error())
} else {
log.Printf("deleteClosedTribalWarsServers: total number of deleted observations: %d", len(deleted))
log.
WithField("numberOfDeletedObservations", len(deleted)).
Infof("deleteClosedTribalWarsServers: deleted observations")
}
}
log.
WithField("executionTime", time.Since(start).String()).
Infoln("deleteClosedTribalWarsServers: finished executing")
}
func (h *handler) updateBotStatus() {
if err := h.discord.UpdateStatus(h.status); err != nil {
log.Print("updateBotStatus: " + err.Error())
func (w *worker) updateBotStatus() {
start := time.Now()
log.Info("updateBotStatus: updating bot status...")
if err := w.discord.UpdateStatus(w.status); err != nil {
log.Error("updateBotStatus: " + err.Error())
}
log.
WithField("executionTime", time.Since(start).String()).
Infoln("updateBotStatus: bot status has been updated")
}

View File

@ -5,6 +5,7 @@ import (
"fmt"
"strings"
"github.com/sirupsen/logrus"
"github.com/tribalwarshelp/dcbot/message"
"github.com/tribalwarshelp/dcbot/group"
@ -16,6 +17,8 @@ import (
"github.com/bwmarrin/discordgo"
)
var log = logrus.WithField("package", "discord")
type handler struct {
cmd Command
requireAdmPermissions bool
@ -240,8 +243,7 @@ func (s *Session) handleNewMessage(_ *discordgo.Session, m *discordgo.MessageCre
}
splitted := strings.Split(m.Content, " ")
argsLength := len(splitted) - 1
args := splitted[1 : argsLength+1]
args := splitted[1:]
server := &models.Server{
ID: m.GuildID,
Lang: message.GetDefaultLanguage().String(),
@ -256,7 +258,8 @@ func (s *Session) handleNewMessage(_ *discordgo.Session, m *discordgo.MessageCre
localizer: message.NewLocalizer(server.Lang),
}
h := s.handlers.find(Command(splitted[0]))
cmd := Command(splitted[0])
h := s.handlers.find(cmd)
if h != nil {
if h.requireAdmPermissions {
if m.GuildID == "" {
@ -267,6 +270,16 @@ func (s *Session) handleNewMessage(_ *discordgo.Session, m *discordgo.MessageCre
return
}
}
log.
WithFields(logrus.Fields{
"serverID": server.ID,
"lang": server.Lang,
"command": cmd,
"args": args,
"authorID": m.Author.ID,
"authorUsername": m.Author.Username,
}).
Info("handleNewMessage: Executing command")
h.fn(ctx, m, args...)
return
}

3
go.mod
View File

@ -10,10 +10,11 @@ require (
github.com/nicksnyder/go-i18n/v2 v2.1.1
github.com/pkg/errors v0.9.1
github.com/robfig/cron/v3 v3.0.1
github.com/sirupsen/logrus v1.7.0
github.com/tribalwarshelp/golang-sdk v0.0.0-20200903125555-7b6975e64f6f
github.com/tribalwarshelp/shared v0.0.0-20200824102353-ef15dea9c1a3
golang.org/x/crypto v0.0.0-20201016220609-9e8e0b390897 // indirect
golang.org/x/net v0.0.0-20201016165138-7b1cca2348c0 // indirect
golang.org/x/sys v0.0.0-20201017003518-b09fb700fbb7 // indirect
golang.org/x/sys v0.0.0-20201022201747-fb209a7c41cd // indirect
golang.org/x/text v0.3.3
)

8
go.sum
View File

@ -112,7 +112,10 @@ github.com/robfig/cron/v3 v3.0.1 h1:WdRxkvbJztn8LMz/QEvLN5sBU+xKpSqwwUO1Pjr4qDs=
github.com/robfig/cron/v3 v3.0.1/go.mod h1:eQICP3HwyT7UooqI/z+Ov+PtYAWygg1TEWWzGIFLtro=
github.com/segmentio/encoding v0.2.0 h1:lmwUV/WjSX7pL1pbK4MEQBH/M7K2NrgYymeSc1pV1W8=
github.com/segmentio/encoding v0.2.0/go.mod h1:MJjRE6bMDocliO2FyFC2Dusp+uYdBfHWh5Bw7QyExto=
github.com/sirupsen/logrus v1.7.0 h1:ShrD1U9pZB12TX0cVy0DtePoCH97K8EtX+mg7ZARUtM=
github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/testify v1.2.2/go.mod h1:a8OnRcib4nhh0OaRAV+Yts87kKdq0PP7pXfy6kDkUVs=
github.com/stretchr/testify v1.3.0/go.mod h1:M5WIy9Dh21IEIfnGCwXGc5bZfKNJtfHm1UVUgZn+9EI=
github.com/stretchr/testify v1.5.1 h1:nOGnQDM7FYENwehXlg/kFVnos3rEvtKTjRvOWSzb6H4=
github.com/stretchr/testify v1.5.1/go.mod h1:5W2xD1RspED5o8YsWQXVCued0rvSQ+mT+I5cxcmMvtA=
@ -198,6 +201,7 @@ golang.org/x/sys v0.0.0-20190904154756-749cb33beabd/go.mod h1:h1NjWce9XRLGQEsW7w
golang.org/x/sys v0.0.0-20191001151750-bb3f8db39f24/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191005200804-aed5e4c7ecf9/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191010194322-b09406accb47/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191026070338-33540a1f6037/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191120155948-bd437916bb0e/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20200323222414-85ca7c5b95cd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20200519105757-fe76b779f299/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
@ -208,8 +212,8 @@ golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7w
golang.org/x/sys v0.0.0-20201009025420-dfb3f7c4e634/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20201015000850-e3ed0017c211 h1:9UQO31fZ+0aKQOFldThf7BKPMJTiBfWycGh/u3UoO88=
golang.org/x/sys v0.0.0-20201015000850-e3ed0017c211/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20201017003518-b09fb700fbb7 h1:XtNJkfEjb4zR3q20BBBcYUykVOEMgZeIUOpBPfNYgxg=
golang.org/x/sys v0.0.0-20201017003518-b09fb700fbb7/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20201022201747-fb209a7c41cd h1:WgqgiQvkiZWz7XLhphjt2GI2GcGCTIZs9jqXMWmH+oc=
golang.org/x/sys v0.0.0-20201022201747-fb209a7c41cd/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/text v0.3.0 h1:g61tztE5qeGQ89tm6NTjjM9VPIm088od1l6aSorWRWg=
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/text v0.3.2 h1:tW2bmiBqwgJj/UpqtC8EpXEZVYOwU0yG4iWbprSVAcs=

48
main.go
View File

@ -8,6 +8,7 @@ import (
"strings"
"syscall"
"github.com/sirupsen/logrus"
"github.com/tribalwarshelp/dcbot/message"
"github.com/tribalwarshelp/golang-sdk/sdk"
@ -38,26 +39,41 @@ func init() {
if mode.Get() == mode.DevelopmentMode {
godotenv.Load(".env.development")
}
customFormatter := new(logrus.TextFormatter)
customFormatter.TimestampFormat = "2006-01-02 15:04:05"
customFormatter.FullTimestamp = true
logrus.SetFormatter(customFormatter)
}
func main() {
dir, err := os.Getwd()
if err != nil {
log.Fatal(err)
logrus.Fatal(err)
}
if err := message.LoadMessageFiles(path.Join(dir, "message", "translations")); err != nil {
log.Fatal(err)
dirWithMessages := path.Join(dir, "message", "translations")
if err := message.LoadMessageFiles(dirWithMessages); err != nil {
logrus.Fatal(err)
}
logrus.WithField("dir", dirWithMessages).
WithField("languages", message.LanguageTags()).
Info("Loaded messages")
db := pg.Connect(&pg.Options{
dbOptions := &pg.Options{
User: os.Getenv("DB_USER"),
Password: os.Getenv("DB_PASSWORD"),
Database: os.Getenv("DB_NAME"),
Addr: os.Getenv("DB_HOST") + ":" + os.Getenv("DB_PORT"),
})
}
dbFields := logrus.Fields{
"user": dbOptions.User,
"database": dbOptions.Database,
"addr": dbOptions.Addr,
}
db := pg.Connect(dbOptions)
defer func() {
if err := db.Close(); err != nil {
log.Fatal(err)
logrus.WithFields(dbFields).Fatalln(err)
}
}()
if strings.ToUpper(os.Getenv("LOG_DB_QUERIES")) == "TRUE" {
@ -65,19 +81,21 @@ func main() {
Verbose: true,
})
}
logrus.WithFields(dbFields).Info("Connected to the database")
serverRepo, err := server_repository.NewPgRepo(db)
if err != nil {
log.Fatal(err)
logrus.Fatal(err)
}
groupRepo, err := group_repository.NewPgRepo(db)
if err != nil {
log.Fatal(err)
logrus.Fatal(err)
}
observationRepo, err := observation_repository.NewPgRepo(db)
if err != nil {
log.Fatal(err)
logrus.Fatal(err)
}
logrus.Info("Loaded all repositories")
api := sdk.New(os.Getenv("API_URL"))
@ -91,9 +109,14 @@ func main() {
API: api,
})
if err != nil {
log.Fatal(err)
logrus.Fatal(err)
}
defer sess.Close()
logrus.WithFields(logrus.Fields{
"api": os.Getenv("API_URL"),
"commandPrefix": commandPrefix,
"status": status,
}).Info("Initialized new Discord session")
c := cron.New(cron.WithChain(
cron.SkipIfStillRunning(cron.VerbosePrintfLogger(log.New(os.Stdout, "cron: ", log.LstdFlags))),
@ -108,12 +131,13 @@ func main() {
})
c.Start()
defer c.Stop()
logrus.Info("Started cron worker")
log.Print("Bot is waiting for your actions!")
logrus.Info("Bot is waiting for your actions!")
channel := make(chan os.Signal, 1)
signal.Notify(channel, os.Interrupt, os.Kill, syscall.SIGTERM, syscall.SIGINT)
<-channel
log.Print("shutting down")
logrus.Info("shutting down")
}