From adc3cacc246e1cf0768f8667ee86f4f2ae0818fa Mon Sep 17 00:00:00 2001 From: Ash Keel Date: Sun, 23 Apr 2023 02:26:46 +0200 Subject: [PATCH] refactor: slightly nicer logs --- app.go | 30 +++++++++++++++--------------- backup.go | 22 +++++++++++----------- cli.database.go | 6 +++--- database/driver.pebble.go | 4 ++-- loyalty/manager.go | 9 +++++---- loyalty/twitch-bot.go | 4 ++-- twitch/bot.alerts.go | 32 ++++++++++++++++---------------- twitch/bot.timer.go | 14 +++++++------- twitch/client.go | 22 +++++++++++----------- twitch/commands.go | 2 +- utils/deferlogger.go | 2 +- 11 files changed, 74 insertions(+), 73 deletions(-) diff --git a/app.go b/app.go index 0a892a3..c612167 100644 --- a/app.go +++ b/app.go @@ -159,20 +159,20 @@ func (a *App) startup(ctx context.Context) { func (a *App) stop(context.Context) { if a.lock != nil { - warnOnError(a.lock.Unlock(), "could not remove lock file") + warnOnError(a.lock.Unlock(), "Could not remove lock file") } if a.loyaltyManager != nil { - warnOnError(a.loyaltyManager.Close(), "could not cleanly close loyalty manager") + warnOnError(a.loyaltyManager.Close(), "Could not cleanly close loyalty manager") } if a.twitchManager != nil { - warnOnError(a.twitchManager.Close(), "could not cleanly close twitch client") + warnOnError(a.twitchManager.Close(), "Could not cleanly close twitch client") } if a.httpServer != nil { - warnOnError(a.httpServer.Close(), "could not cleanly close HTTP server") + warnOnError(a.httpServer.Close(), "Could not cleanly close HTTP server") } - warnOnError(a.db.Close(), "could not cleanly close database") + warnOnError(a.db.Close(), "Could not cleanly close database") - warnOnError(a.driver.Close(), "could not close driver") + warnOnError(a.driver.Close(), "Could not close driver") } func (a *App) AuthenticateKVClient(id string) { @@ -180,7 +180,7 @@ func (a *App) AuthenticateKVClient(id string) { if err != nil { return } - warnOnError(a.driver.Hub().SetAuthenticated(idInt, true), "could not mark session as authenticated", zap.String("session-id", id)) + warnOnError(a.driver.Hub().SetAuthenticated(idInt, true), "Could not mark session as authenticated", zap.String("session-id", id)) } func (a *App) IsServerReady() bool { @@ -220,11 +220,11 @@ func (a *App) SendCrashReport(errorData string, info string) (string, error) { // Add text fields if err := w.WriteField("error", errorData); err != nil { - logger.Error("could not encode field error for crash report", zap.Error(err)) + logger.Error("Could not encode field error for crash report", zap.Error(err)) } if len(info) > 0 { if err := w.WriteField("info", info); err != nil { - logger.Error("could not encode field info for crash report", zap.Error(err)) + logger.Error("Could not encode field info for crash report", zap.Error(err)) } } @@ -234,20 +234,20 @@ func (a *App) SendCrashReport(errorData string, info string) (string, error) { addFile(w, "paniclog", panicFilename) if err := w.Close(); err != nil { - logger.Error("could not prepare request for crash report", zap.Error(err)) + logger.Error("Could not prepare request for crash report", zap.Error(err)) return "", err } resp, err := nethttp.Post(crashReportURL, w.FormDataContentType(), &b) if err != nil { - logger.Error("could not send crash report", zap.Error(err)) + logger.Error("Could not send crash report", zap.Error(err)) return "", err } // Check the response if resp.StatusCode != nethttp.StatusOK { byt, _ := io.ReadAll(resp.Body) - logger.Error("crash report server returned error", zap.String("status", resp.Status), zap.String("response", string(byt))) + logger.Error("Crash report server returned error", zap.String("status", resp.Status), zap.String("response", string(byt))) return "", fmt.Errorf("crash report server returned error: %s - %s", resp.Status, string(byt)) } @@ -297,17 +297,17 @@ func (a *App) showFatalError(err error, text string, fields ...zap.Field) { func addFile(m *multipart.Writer, field string, filename string) { logfile, err := m.CreateFormFile(field, filename) if err != nil { - logger.Error("could not encode field log for crash report", zap.Error(err)) + logger.Error("Could not encode field log for crash report", zap.Error(err)) return } file, err := os.Open(filename) if err != nil { - logger.Error("could not open file for including in crash report", zap.Error(err), zap.String("file", filename)) + logger.Error("Could not open file for including in crash report", zap.Error(err), zap.String("file", filename)) return } if _, err = io.Copy(logfile, file); err != nil { - logger.Error("could not read from file for including in crash report", zap.Error(err), zap.String("file", filename)) + logger.Error("Could not read from file for including in crash report", zap.Error(err), zap.String("file", filename)) } } diff --git a/backup.go b/backup.go index e544b34..08988b5 100644 --- a/backup.go +++ b/backup.go @@ -15,15 +15,15 @@ import ( func BackupTask(driver database.DatabaseDriver, options database.BackupOptions) { if options.BackupDir == "" { - logger.Warn("backup directory not set, database backups are disabled") + logger.Warn("Backup directory not set, database backups are disabled") return } err := os.MkdirAll(options.BackupDir, 0o755) if err != nil { - logger.Error("could not create backup directory, moving to a temporary folder", zap.Error(err)) + logger.Error("Could not create backup directory, moving to a temporary folder", zap.Error(err)) options.BackupDir = os.TempDir() - logger.Info("using temporary directory", zap.String("backup-dir", options.BackupDir)) + logger.Info("Using temporary directory", zap.String("backup-dir", options.BackupDir)) return } @@ -33,19 +33,19 @@ func BackupTask(driver database.DatabaseDriver, options database.BackupOptions) // Run backup procedure file, err := os.Create(fmt.Sprintf("%s/%s.db", options.BackupDir, time.Now().Format("20060102-150405"))) if err != nil { - logger.Error("could not create backup file", zap.Error(err)) + logger.Error("Could not create backup file", zap.Error(err)) continue } err = driver.Backup(file) if err != nil { - logger.Error("could not backup database", zap.Error(err)) + logger.Error("Could not backup database", zap.Error(err)) } _ = file.Close() - logger.Info("database backed up", zap.String("backup-file", file.Name())) + logger.Info("Database backup created", zap.String("backup-file", file.Name())) // Remove old backups files, err := os.ReadDir(options.BackupDir) if err != nil { - logger.Error("could not read backup directory", zap.Error(err)) + logger.Error("Could not read backup directory", zap.Error(err)) continue } // If maxBackups is set, remove older backups when we reach the limit @@ -57,7 +57,7 @@ func BackupTask(driver database.DatabaseDriver, options database.BackupOptions) for _, file := range toRemove { err = os.Remove(fmt.Sprintf("%s/%s", options.BackupDir, file.Name())) if err != nil { - logger.Error("could not remove backup file", zap.Error(err)) + logger.Error("Could not remove backup file", zap.Error(err)) } } } @@ -73,7 +73,7 @@ type BackupInfo struct { func (a *App) GetBackups() (list []BackupInfo) { files, err := os.ReadDir(a.backupOptions.BackupDir) if err != nil { - logger.Error("could not read backup directory", zap.Error(err)) + logger.Error("Could not read backup directory", zap.Error(err)) return nil } @@ -84,7 +84,7 @@ func (a *App) GetBackups() (list []BackupInfo) { info, err := file.Info() if err != nil { - logger.Error("could not get info for backup file", zap.Error(err)) + logger.Error("Could not get info for backup file", zap.Error(err)) continue } @@ -119,6 +119,6 @@ func (a *App) RestoreBackup(backupName string) error { return fmt.Errorf("could not restore database: %w", err) } - logger.Info("restored database from backup") + logger.Info("Restored database from backup") return nil } diff --git a/cli.database.go b/cli.database.go index 2529df4..bb3f496 100644 --- a/cli.database.go +++ b/cli.database.go @@ -37,7 +37,7 @@ func cliImport(ctx *cli.Context) error { return fatalError(err, "import failed") } - logger.Info("imported database from file") + logger.Info("Imported database from file") return nil } @@ -63,7 +63,7 @@ func cliRestore(ctx *cli.Context) error { return fatalError(err, "restore failed") } - logger.Info("restored database from backup") + logger.Info("Restored database from backup") return nil } @@ -89,6 +89,6 @@ func cliExport(ctx *cli.Context) error { return fatalError(err, "export failed") } - logger.Info("exported database") + logger.Info("Exported database") return nil } diff --git a/database/driver.pebble.go b/database/driver.pebble.go index 4b2ebc0..decaa3f 100644 --- a/database/driver.pebble.go +++ b/database/driver.pebble.go @@ -79,14 +79,14 @@ func (p *PebbleDatabase) Restore(file io.Reader) error { in := make(map[string]string) err := json.NewDecoder(file).Decode(&in) if err != nil { - return fmt.Errorf("Could not decode backup: %w", err) + return fmt.Errorf("could not decode backup: %w", err) } b := p.db.NewBatch() for k, v := range in { err = b.Set([]byte(k), []byte(v), nil) if err != nil { - return fmt.Errorf("Could not set key %s: %w", k, err) + return fmt.Errorf("could not set key %s: %w", k, err) } } diff --git a/loyalty/manager.go b/loyalty/manager.go index ec4bc22..9899cc4 100644 --- a/loyalty/manager.go +++ b/loyalty/manager.go @@ -19,6 +19,7 @@ import ( var json = jsoniter.ConfigFastest var ( + ErrRedeemNotFound = errors.New("redeem not found") ErrRedeemInCooldown = errors.New("redeem is on cooldown") ErrGoalNotFound = errors.New("goal not found") ErrGoalAlreadyReached = errors.New("goal already reached") @@ -121,7 +122,7 @@ func NewManager(db *database.LocalDBClient, twitchManager *twitch.Manager, logge // SubscribePrefix for changes err, loyalty.cancelSub = db.SubscribePrefix(loyalty.update, "loyalty/") if err != nil { - logger.Error("could not setup loyalty reload subscription", zap.Error(err)) + logger.Error("Could not setup loyalty reload subscription", zap.Error(err)) } loyalty.SetBanList(config.BanList) @@ -189,9 +190,9 @@ func (m *Manager) update(key, value string) { } } if err != nil { - m.logger.Error("subscribe error: invalid JSON received on key", zap.Error(err), zap.String("key", key)) + m.logger.Error("Subscribe error: invalid JSON received on key", zap.Error(err), zap.String("key", key)) } else { - m.logger.Debug("updated key", zap.String("key", key)) + m.logger.Debug("Updated key", zap.String("key", key)) } } @@ -293,7 +294,7 @@ func (m *Manager) RemoveRedeem(redeem Redeem) error { } } - return errors.New("redeem not found") + return ErrRedeemNotFound } func (m *Manager) SaveGoals() error { diff --git a/loyalty/twitch-bot.go b/loyalty/twitch-bot.go index 347e4cd..4ff133c 100644 --- a/loyalty/twitch-bot.go +++ b/loyalty/twitch-bot.go @@ -232,7 +232,7 @@ func (m *Manager) cmdRedeemReward(bot *twitch.Bot, message irc.PrivateMessage) { bot.Client.Say(message.Channel, fmt.Sprintf("%s: That reward is in cooldown (available in %s)", message.User.DisplayName, time.Until(nextAvailable).Truncate(time.Second))) default: - m.logger.Error("error while performing redeem", zap.Error(err)) + m.logger.Error("Error while performing redeem", zap.Error(err)) } return } @@ -332,7 +332,7 @@ func (m *Manager) cmdContributeGoal(bot *twitch.Bot, message irc.PrivateMessage) // Add points to goal points, err := m.PerformContribution(selectedGoal, message.User.Name, points) if err != nil { - m.logger.Error("error while contributing to goal", zap.Error(err)) + m.logger.Error("Error while contributing to goal", zap.Error(err)) return } if points == 0 { diff --git a/twitch/bot.alerts.go b/twitch/bot.alerts.go index 63b1ab4..5e7b586 100644 --- a/twitch/bot.alerts.go +++ b/twitch/bot.alerts.go @@ -97,12 +97,12 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { // Load config from database err := bot.api.db.GetJSON(BotAlertsKey, &mod.Config) if err != nil { - bot.logger.Debug("config load error", zap.Error(err)) + bot.logger.Debug("Config load error", zap.Error(err)) mod.Config = BotAlertsConfig{} // Save empty config err = bot.api.db.PutJSON(BotAlertsKey, mod.Config) if err != nil { - bot.logger.Warn("could not save default config for bot alerts", zap.Error(err)) + bot.logger.Warn("Could not save default config for bot alerts", zap.Error(err)) } } @@ -111,14 +111,14 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { err, mod.cancelAlertSub = bot.api.db.SubscribeKey(BotAlertsKey, func(value string) { err := json.UnmarshalFromString(value, &mod.Config) if err != nil { - bot.logger.Debug("error reloading timer config", zap.Error(err)) + bot.logger.Debug("Error reloading timer config", zap.Error(err)) } else { - bot.logger.Info("reloaded alert config") + bot.logger.Info("Reloaded alert config") } mod.compileTemplates() }) if err != nil { - bot.logger.Error("could not set-up bot alert reload subscription", zap.Error(err)) + bot.logger.Error("Could not set-up bot alert reload subscription", zap.Error(err)) } // Subscriptions are handled with a slight delay as info come from different events and must be aggregated @@ -236,7 +236,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var ev eventSubNotification err := json.UnmarshalFromString(value, &ev) if err != nil { - bot.logger.Debug("error parsing webhook payload", zap.Error(err)) + bot.logger.Debug("Error parsing webhook payload", zap.Error(err)) return } switch ev.Subscription.Type { @@ -249,7 +249,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var followEv helix.EventSubChannelFollowEvent err := json.Unmarshal(ev.Event, &followEv) if err != nil { - bot.logger.Debug("error parsing follow event", zap.Error(err)) + bot.logger.Debug("Error parsing follow event", zap.Error(err)) return } // Pick a random message @@ -270,7 +270,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var raidEv helix.EventSubChannelRaidEvent err := json.Unmarshal(ev.Event, &raidEv) if err != nil { - bot.logger.Debug("error parsing raid event", zap.Error(err)) + bot.logger.Debug("Error parsing raid event", zap.Error(err)) return } // Pick a random message from base set @@ -306,7 +306,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var cheerEv helix.EventSubChannelCheerEvent err := json.Unmarshal(ev.Event, &cheerEv) if err != nil { - bot.logger.Debug("error parsing cheer event", zap.Error(err)) + bot.logger.Debug("Error parsing cheer event", zap.Error(err)) return } // Pick a random message from base set @@ -342,7 +342,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var subEv helix.EventSubChannelSubscribeEvent err := json.Unmarshal(ev.Event, &subEv) if err != nil { - bot.logger.Debug("error parsing sub event", zap.Error(err)) + bot.logger.Debug("Error parsing new subscription event", zap.Error(err)) return } addPendingSub(subEv) @@ -355,7 +355,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var subEv helix.EventSubChannelSubscriptionMessageEvent err := json.Unmarshal(ev.Event, &subEv) if err != nil { - bot.logger.Debug("error parsing sub event", zap.Error(err)) + bot.logger.Debug("Error parsing returning subscription event", zap.Error(err)) return } addPendingSub(subEv) @@ -368,7 +368,7 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { var giftEv helix.EventSubChannelSubscriptionGiftEvent err := json.Unmarshal(ev.Event, &giftEv) if err != nil { - bot.logger.Debug("error parsing raid event", zap.Error(err)) + bot.logger.Debug("Error parsing subscription gifted event", zap.Error(err)) return } // Pick a random message from base set @@ -411,10 +411,10 @@ func SetupAlerts(bot *Bot) *BotAlertsModule { } }) if err != nil { - bot.logger.Error("could not setup twitch alert subscription", zap.Error(err)) + bot.logger.Error("Could not setup twitch alert subscription", zap.Error(err)) } - bot.logger.Debug("loaded bot alerts") + bot.logger.Debug("Loaded bot alerts") return mod } @@ -468,7 +468,7 @@ func (m *BotAlertsModule) compileTemplates() { func (m *BotAlertsModule) addTemplate(templateList templateCache, msg string) { tpl, err := template.New("").Funcs(m.bot.customFunctions).Funcs(sprig.TxtFuncMap()).Parse(msg) if err != nil { - m.bot.logger.Error("error compiling template", zap.Error(err)) + m.bot.logger.Error("Error compiling alert template", zap.Error(err)) return } templateList[msg] = tpl @@ -488,7 +488,7 @@ func writeTemplate(bot *Bot, tpl *template.Template, data interface{}) { var buf bytes.Buffer err := tpl.Execute(&buf, data) if err != nil { - bot.logger.Error("error executing template for alert", zap.Error(err)) + bot.logger.Error("Error executing template for bot alert", zap.Error(err)) return } bot.WriteMessage(buf.String()) diff --git a/twitch/bot.timer.go b/twitch/bot.timer.go index df90763..a462735 100644 --- a/twitch/bot.timer.go +++ b/twitch/bot.timer.go @@ -62,30 +62,30 @@ func SetupTimers(bot *Bot) *BotTimerModule { // Load config from database err := bot.api.db.GetJSON(BotTimersKey, &mod.Config) if err != nil { - bot.logger.Debug("config load error", zap.Error(err)) + bot.logger.Debug("Config load error", zap.Error(err)) mod.Config = BotTimersConfig{ Timers: make(map[string]BotTimer), } // Save empty config err = bot.api.db.PutJSON(BotTimersKey, mod.Config) if err != nil { - bot.logger.Warn("could not save default config for bot timers", zap.Error(err)) + bot.logger.Warn("Could not save default config for bot timers", zap.Error(err)) } } err, mod.cancelTimerSub = bot.api.db.SubscribeKey(BotTimersKey, func(value string) { err := json.UnmarshalFromString(value, &mod.Config) if err != nil { - bot.logger.Debug("error reloading timer config", zap.Error(err)) + bot.logger.Debug("Error reloading timer config", zap.Error(err)) } else { - bot.logger.Info("reloaded timer config") + bot.logger.Info("Reloaded timer config") } }) if err != nil { - bot.logger.Error("could not set-up timer reload subscription", zap.Error(err)) + bot.logger.Error("Could not set-up timer reload subscription", zap.Error(err)) } - bot.logger.Debug("loaded timers", zap.Int("timers", len(mod.Config.Timers))) + bot.logger.Debug("Loaded timers", zap.Int("timers", len(mod.Config.Timers))) // Start goroutine for clearing message counters and running timers go mod.runTimers() @@ -103,7 +103,7 @@ func (m *BotTimerModule) runTimers() { err := m.bot.api.db.PutJSON(ChatActivityKey, m.messages.Get()) if err != nil { - m.bot.logger.Warn("error saving chat activity", zap.Error(err)) + m.bot.logger.Warn("Error saving chat activity", zap.Error(err)) } // Calculate activity diff --git a/twitch/client.go b/twitch/client.go index bfe2977..be3c7bf 100644 --- a/twitch/client.go +++ b/twitch/client.go @@ -61,44 +61,44 @@ func NewManager(db *database.LocalDBClient, server *http.Server, logger *zap.Log err, cancelConfigSub := db.SubscribeKey(ConfigKey, func(value string) { var newConfig Config if err := json.UnmarshalFromString(value, &newConfig); err != nil { - logger.Error("failed to unmarshal config", zap.Error(err)) + logger.Error("Failed to decode Twitch integration config", zap.Error(err)) return } var updatedClient *Client updatedClient, err = newClient(newConfig, db, server, logger) if err != nil { - logger.Error("could not create twitch client with new config, keeping old", zap.Error(err)) + logger.Error("Could not create twitch client with new config, keeping old", zap.Error(err)) return } err = manager.client.Close() if err != nil { - logger.Warn("twitch client could not close cleanly", zap.Error(err)) + logger.Warn("Twitch client could not close cleanly", zap.Error(err)) } // New client works, replace old updatedClient.Merge(manager.client) manager.client = updatedClient - logger.Info("reloaded/updated Twitch client") + logger.Info("Reloaded/updated Twitch integration") }) if err != nil { - logger.Error("could not setup twitch config reload subscription", zap.Error(err)) + logger.Error("Could not setup twitch config reload subscription", zap.Error(err)) } // Listen for bot config changes err, cancelBotSub := db.SubscribeKey(BotConfigKey, func(value string) { var newBotConfig BotConfig if err := json.UnmarshalFromString(value, &newBotConfig); err != nil { - logger.Error("failed to unmarshal Config", zap.Error(err)) + logger.Error("Failed to decode bot config", zap.Error(err)) return } if manager.client.Bot != nil { err = manager.client.Bot.Close() if err != nil { - manager.client.logger.Warn("failed to disconnect old bot from Twitch IRC", zap.Error(err)) + manager.client.logger.Warn("Failed to disconnect old bot from Twitch IRC", zap.Error(err)) } } @@ -113,7 +113,7 @@ func NewManager(db *database.LocalDBClient, server *http.Server, logger *zap.Log manager.client.logger.Info("reloaded/restarted Twitch bot") }) if err != nil { - client.logger.Error("could not setup twitch bot config reload subscription", zap.Error(err)) + client.logger.Error("Could not setup twitch bot config reload subscription", zap.Error(err)) } manager.cancelSubs = func() { @@ -211,15 +211,15 @@ func newClient(config Config, db *database.LocalDBClient, server *http.Server, l if userClient, err := client.GetUserClient(true); err == nil { users, err := userClient.GetUsers(&helix.UsersParams{}) if err != nil { - client.logger.Error("failed looking up user", zap.Error(err)) + client.logger.Error("Failed looking up user", zap.Error(err)) } else if len(users.Data.Users) < 1 { - client.logger.Error("no users found, please authenticate in Twitch configuration -> Events") + client.logger.Error("No users found, please authenticate in Twitch configuration -> Events") } else { client.User = users.Data.Users[0] go client.eventSubLoop(userClient) } } else { - client.logger.Warn("twitch user not identified, this will break most features") + client.logger.Warn("Twitch user not identified, this will break most features") } go client.runStatusPoll() diff --git a/twitch/commands.go b/twitch/commands.go index fb2b3bd..0656433 100644 --- a/twitch/commands.go +++ b/twitch/commands.go @@ -93,7 +93,7 @@ func (b *Bot) setupFunctions() { counter += 1 err := b.api.db.PutKey(counterKey, strconv.Itoa(counter)) if err != nil { - b.logger.Error("error saving key", zap.Error(err), zap.String("key", counterKey)) + b.logger.Error("Error saving key", zap.Error(err), zap.String("key", counterKey)) } return counter }, diff --git a/utils/deferlogger.go b/utils/deferlogger.go index d0fdd9e..6cb2fa9 100644 --- a/utils/deferlogger.go +++ b/utils/deferlogger.go @@ -11,6 +11,6 @@ import ( func Close(res io.Closer, logger *zap.Logger) { err := res.Close() if err != nil { - logger.Error("could not close resource", zap.String("name", reflect.TypeOf(res).String()), zap.Error(err), zap.String("stack", string(debug.Stack()))) + logger.Error("Could not close resource", zap.String("name", reflect.TypeOf(res).String()), zap.Error(err), zap.String("stack", string(debug.Stack()))) } }