Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor(log): convert from logrus to zerolog #173

Merged
merged 3 commits into from
Apr 28, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
62 changes: 29 additions & 33 deletions core/configure.go
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
package core

import (
"os"
"strings"

log "github.com/sirupsen/logrus"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"

"github.com/target/flottbot/models"
"github.com/target/flottbot/utils"
Expand All @@ -14,29 +16,23 @@ var defaultSlackListenerPort = "3000"
// Configure searches the config directory for the bot.yml to create a Bot object.
// The Bot object will be passed around to make accessible system-specific information.
func Configure(bot *models.Bot) {
log.Info("Configuring bot...")
log.Info().Msg("Configuring bot...")

initLogger(bot)

validateRemoteSetup(bot)

configureChatApplication(bot)

bot.Log.Infof("Configured bot '%s'!", bot.Name)
bot.Log.Info().Msgf("Configured bot '%s'!", bot.Name)
}

// initLogger sets log configuration for the bot
func initLogger(b *models.Bot) {
b.Log = *log.New()

b.Log.SetLevel(log.ErrorLevel)
b.Log = zerolog.New(os.Stdout).Level(zerolog.ErrorLevel)

if b.Debug {
b.Log.SetLevel(log.DebugLevel)
}

if b.LogJSON {
b.Log.Formatter = &log.JSONFormatter{}
b.Log = zerolog.New(os.Stdout).Level(zerolog.DebugLevel)
}
}

Expand All @@ -47,7 +43,7 @@ func configureChatApplication(bot *models.Bot) {
// update the bot name
token, err := utils.Substitute(bot.Name, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not configure bot Name: %s", err.Error())
bot.Log.Warn().Msgf("Could not configure bot Name: %s", err)
}

bot.Name = token
Expand All @@ -58,12 +54,12 @@ func configureChatApplication(bot *models.Bot) {
// Discord bot token
token, err := utils.Substitute(bot.DiscordToken, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not set Discord Token: %s", err.Error())
bot.Log.Warn().Msgf("Could not set Discord Token: %s", err)
bot.RunChat = false
}

if token == "" {
bot.Log.Warnf("Discord Token is empty: '%s'", token)
bot.Log.Warn().Msgf("Discord Token is empty: '%s'", token)
bot.RunChat = false
}

Expand All @@ -73,12 +69,12 @@ func configureChatApplication(bot *models.Bot) {
// See https://support.discordapp.com/hc/en-us/articles/206346498-Where-can-I-find-my-User-Server-Message-ID-
serverID, err := utils.Substitute(bot.DiscordServerID, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not set Discord Server ID: %s", err.Error())
bot.Log.Warn().Msgf("Could not set Discord Server ID: %s", err)
bot.RunChat = false
}

if serverID == "" {
bot.Log.Warnf("Discord Server ID is empty: '%s'", serverID)
bot.Log.Warn().Msgf("Discord Server ID is empty: '%s'", serverID)
bot.RunChat = false
}

Expand All @@ -90,19 +86,19 @@ func configureChatApplication(bot *models.Bot) {
case "telegram":
token, err := utils.Substitute(bot.TelegramToken, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not set telegram Token: %s", err.Error())
bot.Log.Warn().Msgf("Could not set telegram Token: %s", err)
bot.RunChat = false
}

if token == "" {
bot.Log.Warnf("telegram Token is empty: '%s'", token)
bot.Log.Warn().Msgf("telegram Token is empty: '%s'", token)
bot.RunChat = false
}

bot.TelegramToken = token

default:
bot.Log.Errorf("Chat application '%s' is not supported", bot.ChatApplication)
bot.Log.Error().Msgf("Chat application '%s' is not supported", bot.ChatApplication)
bot.RunChat = false
}
}
Expand All @@ -112,12 +108,12 @@ func configureSlackBot(bot *models.Bot) {
// Slack bot token
token, err := utils.Substitute(bot.SlackToken, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not set Slack Token: %s", err.Error())
bot.Log.Warn().Msgf("Could not set Slack Token: %s", err)
bot.RunChat = false
}

if token == "" {
bot.Log.Warnf("Slack Token is empty: %s", token)
bot.Log.Warn().Msgf("Slack Token is empty: %s", token)
bot.RunChat = false
}

Expand All @@ -126,8 +122,8 @@ func configureSlackBot(bot *models.Bot) {
// Slack signing secret
signingSecret, err := utils.Substitute(bot.SlackSigningSecret, map[string]string{})
if err != nil {
bot.Log.Warnf("Could not set Slack Signing Secret: %s", err.Error())
bot.Log.Warn("Defaulting to use Slack RTM")
bot.Log.Warn().Msgf("Could not set Slack Signing Secret: %s", err)
bot.Log.Warn().Msg("Defaulting to use Slack RTM")

signingSecret = ""
}
Expand All @@ -137,8 +133,8 @@ func configureSlackBot(bot *models.Bot) {
// Get Slack Events path
eCallbackPath, err := utils.Substitute(bot.SlackEventsCallbackPath, map[string]string{})
if err != nil {
bot.Log.Errorf("Could not set Slack Events API callback path: %s", err.Error())
bot.Log.Warn("Defaulting to use Slack RTM")
bot.Log.Error().Msgf("Could not set Slack Events API callback path: %s", err)
bot.Log.Warn().Msg("Defaulting to use Slack RTM")
bot.SlackSigningSecret = ""
}

Expand All @@ -147,12 +143,12 @@ func configureSlackBot(bot *models.Bot) {
// Get Slack Interactive Components path
iCallbackPath, err := utils.Substitute(bot.SlackInteractionsCallbackPath, map[string]string{})
if err != nil {
bot.Log.Errorf("Could not set Slack Interactive Components callback path: %s", err.Error())
bot.Log.Error().Msgf("Could not set Slack Interactive Components callback path: %s", err)
bot.InteractiveComponents = false
}

if iCallbackPath == "" {
bot.Log.Warnf("Slack Interactive Components callback path is empty: %s", iCallbackPath)
bot.Log.Warn().Msgf("Slack Interactive Components callback path is empty: %s", iCallbackPath)
bot.InteractiveComponents = false
}

Expand All @@ -161,15 +157,15 @@ func configureSlackBot(bot *models.Bot) {
// Get Slack HTTP listener port
lPort, err := utils.Substitute(bot.SlackListenerPort, map[string]string{})
if err != nil {
bot.Log.Errorf("Could not set Slack listener por: %s", err.Error())
bot.Log.Error().Msgf("Could not set Slack listener port: %s", err)
bot.SlackListenerPort = ""
}

// set slack http listener port from config file or default
lPortEnvWasUnset := strings.Contains(lPort, "${") // e.g. slack_listener_port: ${PORT}
if lPort == "" || lPortEnvWasUnset {
bot.Log.Warnf("Slack listener port is empty: %s", lPort)
bot.Log.WithField("defaultSlackListenerPort", defaultSlackListenerPort).Info("Using default slack listener port.")
bot.Log.Warn().Msgf("Slack listener port is empty: %s", lPort)
bot.Log.Info().Str("defaultSlackListenerPort", defaultSlackListenerPort).Msg("Using default slack listener port.")
lPort = defaultSlackListenerPort
}

Expand All @@ -186,18 +182,18 @@ func validateRemoteSetup(bot *models.Bot) {
}

if !bot.CLI && bot.ChatApplication == "" {
bot.Log.Fatalf("No chat_application specified and cli mode is not enabled. Exiting...")
bot.Log.Fatal().Msgf("No chat_application specified and cli mode is not enabled. Exiting...")
}

if bot.Scheduler {
bot.RunScheduler = true
if bot.CLI && bot.ChatApplication == "" {
bot.Log.Warn("Scheduler does not support scheduled outputs to CLI mode")
bot.Log.Warn().Msg("Scheduler does not support scheduled outputs to CLI mode")
bot.RunScheduler = false
}

if bot.ChatApplication == "" {
bot.Log.Warn("Scheduler did not find any configured chat applications. Scheduler is closing")
bot.Log.Warn().Msg("Scheduler did not find any configured chat applications. Scheduler is closing")
bot.RunScheduler = false
}
}
Expand Down
27 changes: 2 additions & 25 deletions core/configure_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,10 +2,8 @@ package core

import (
"os"
"reflect"
"testing"

"github.com/sirupsen/logrus"
"github.com/target/flottbot/models"
)

Expand All @@ -31,32 +29,11 @@ func TestInitLogger(t *testing.T) {
}
t.Run(tt.name, func(t *testing.T) {
initLogger(tt.args.bot)
if tt.want != tt.args.bot.Log.Level.String() {
t.Errorf("initLogger() wanted level set at %s, but got %s", tt.want, tt.args.bot.Log.Level.String())
if tt.want != tt.args.bot.Log.GetLevel().String() {
t.Errorf("initLogger() wanted level set at %s, but got %s", tt.want, tt.args.bot.Log.GetLevel().String())
}
})
}

// Test setting the JSON formatter
jsonTests := []struct {
name string
args args
want bool
}{
{"JSON logging set", args{testBot}, true},
{"JSON logging not set", args{testBot}, false},
}
for _, tt := range jsonTests {
testBot.LogJSON = tt.want
t.Run(tt.name, func(t *testing.T) {
initLogger(tt.args.bot)
equals := reflect.DeepEqual(tt.args.bot.Log.Formatter, logrus.JSONFormatter{})
if equals {
t.Errorf("initLogger() wanted to set JSON logging formatter to %t, but got %t", tt.want, equals)
}

})
}
}

func Test_configureChatApplication(t *testing.T) {
Expand Down
36 changes: 18 additions & 18 deletions core/matcher.go
Original file line number Diff line number Diff line change
Expand Up @@ -75,15 +75,15 @@ func handleChatServiceRule(outputMsgs chan<- models.Message, message models.Mess
if rule.Respond != "" || rule.Hear != "" {
// You can only use 'respond' OR 'hear'
if rule.Respond != "" && rule.Hear != "" {
bot.Log.Debugf("Rule '%s' has both 'hear' and 'match' or 'respond' defined. Please choose one or the other", rule.Name)
bot.Log.Debug().Msgf("Rule '%s' has both 'hear' and 'match' or 'respond' defined. Please choose one or the other", rule.Name)
}
// Args are not implemented for 'hear'
if rule.Hear != "" && len(rule.Args) > 0 {
bot.Log.Debugf("Rule '%s' has both 'args' and 'hear' set. To use 'args', use 'respond' instead of 'hear'", rule.Name)
bot.Log.Debug().Msgf("Rule '%s' has both 'args' and 'hear' set. To use 'args', use 'respond' instead of 'hear'", rule.Name)
}

if hit && message.ThreadTimestamp != "" && rule.IgnoreThreads {
bot.Log.Debug("Response suppressed due to 'ignore_threads' being set")
bot.Log.Debug().Msg("Response suppressed due to 'ignore_threads' being set")
return true, true
}

Expand All @@ -93,7 +93,7 @@ func handleChatServiceRule(outputMsgs chan<- models.Message, message models.Mess
}

if hit {
bot.Log.Debugf("Found rule match '%s' for input '%s'", rule.Name, message.Input)
bot.Log.Debug().Msgf("Found rule match '%s' for input '%s'", rule.Name, message.Input)
// Don't go through more rules if rule is matched
match, stopSearch = true, true
// Publish metric to prometheus - metricname will be combination of bot name and rule name
Expand Down Expand Up @@ -136,7 +136,7 @@ func handleNoMatch(outputMsgs chan<- models.Message, message models.Message, hit
if message.Type == models.MsgTypeDirect || message.BotMentioned {
// Do not send help message if DisableNoMatchHelp is true
if !bot.DisableNoMatchHelp {
bot.Log.Debug("Bot was addressed, but no rule matched. Showing help")
bot.Log.Debug().Msg("Bot was addressed, but no rule matched. Showing help")
// Publish metric as none
Prommetric(bot.Name+"-None", bot)
// Set custom_help_text if it is set in bot.yml
Expand Down Expand Up @@ -250,15 +250,15 @@ func doRuleActions(message models.Message, outputMsgs chan<- models.Message, rul
switch strings.ToLower(action.Type) {
// HTTP actions.
case "get", "post", "put":
bot.Log.Debugf("Executing action '%s'...", action.Name)
bot.Log.Debug().Msgf("Executing action '%s'...", action.Name)
err = handleHTTP(action, &message, bot)
// Exec (script) actions
case "exec":
bot.Log.Debugf("Executing action '%s'...", action.Name)
bot.Log.Debug().Msgf("Executing action '%s'...", action.Name)
err = handleExec(action, &message, bot)
// Normal message/log actions
case "message", "log":
bot.Log.Debugf("Executing action '%s'...", action.Name)
bot.Log.Debug().Msgf("Executing action '%s'...", action.Name)
// Log actions cannot direct message users by default
directive := rule.DirectMessageOnly
if action.Type == "log" {
Expand All @@ -269,15 +269,15 @@ func doRuleActions(message models.Message, outputMsgs chan<- models.Message, rul
err = handleMessage(action, outputMsgs, &copy, directive, rule.StartMessageThread, hitRule, bot)
// Fallback to error if action type is invalid
default:
bot.Log.Errorf("The rule '%s' of type %s is not a supported action", action.Name, action.Type)
bot.Log.Error().Msgf("The rule '%s' of type %s is not a supported action", action.Name, action.Type)
}

// Handle reaction update
updateReaction(action, &rule, message.Vars, bot)

// Handle error
if err != nil {
bot.Log.Error(err)
bot.Log.Error().Msg(err.Error())
}
}

Expand All @@ -296,7 +296,7 @@ func doRuleActions(message models.Message, outputMsgs chan<- models.Message, rul
// After running through all the actions, compose final message
val, err := craftResponse(rule, message, bot)
if err != nil {
bot.Log.Error(err)
bot.Log.Error().Msg(err.Error())
message.Output = err.Error()
outputMsgs <- message
} else {
Expand Down Expand Up @@ -327,12 +327,12 @@ func craftResponse(rule models.Rule, msg models.Message, bot *models.Bot) (strin
if len(rule.OutputToUsers) == 0 {
return "", errors.New(msg)
}
bot.Log.Warn(msg)
bot.Log.Warn().Msg(msg)
}

// Simple warning that we will ignore 'output_to_rooms' when 'direct_message_only' is set
if rule.DirectMessageOnly && len(rule.OutputToRooms) > 0 {
bot.Log.Debugf("The rule '%s' has 'direct_message_only' set, 'output_to_rooms' will be ignored", rule.Name)
bot.Log.Debug().Msgf("The rule '%s' has 'direct_message_only' set, 'output_to_rooms' will be ignored", rule.Name)
}

// Use FormatOutput as source for output and find variables and replace content the variable exists
Expand Down Expand Up @@ -392,11 +392,11 @@ func handleHTTP(action models.Action, msg *models.Message, bot *models.Bot) erro

// Just a friendly debugger warning on failed requests
if resp.Status >= 400 {
bot.Log.Debugf("Error in request made by action '%s'. %s returned %d with response: `%s`", action.Name, action.URL, resp.Status, resp.Raw)
bot.Log.Debug().Msgf("Error in request made by action '%s'. %s returned %d with response: `%s`", action.Name, action.URL, resp.Status, resp.Raw)
}

// Always store raw response
bot.Log.Debugf("Successfully executed action '%s'", action.Name)
bot.Log.Debug().Msgf("Successfully executed action '%s'", action.Name)
// Set explicit variables to make raw response output, http status code accessible in rules
msg.Vars["_raw_http_output"] = resp.Raw
msg.Vars["_raw_http_status"] = strconv.Itoa(resp.Status)
Expand Down Expand Up @@ -454,7 +454,7 @@ func handleMessage(action models.Action, outputMsgs chan<- models.Message, msg *
msg.Output = output
// Send to desired room(s)
if direct && len(action.LimitToRooms) > 0 { // direct=true and limit_to_rooms is specified
bot.Log.Debugf("You have specified to send only direct messages. The 'limit_to_rooms' field on the '%s' action will be ignored", action.Name)
bot.Log.Debug().Msgf("You have specified to send only direct messages. The 'limit_to_rooms' field on the '%s' action will be ignored", action.Name)
} else if !direct && len(action.LimitToRooms) > 0 { // direct=false and limit_to_rooms is specified
msg.OutputToRooms = utils.GetRoomIDs(action.LimitToRooms, bot)

Expand Down Expand Up @@ -487,7 +487,7 @@ func updateReaction(action models.Action, rule *models.Rule, vars map[string]str
if strings.Contains(action.Reaction, "{{") {
reaction, err := utils.Substitute(action.Reaction, vars)
if err != nil {
bot.Log.Error(err)
bot.Log.Error().Msg(err.Error())
return
}
action.Reaction = reaction
Expand All @@ -497,7 +497,7 @@ func updateReaction(action models.Action, rule *models.Rule, vars map[string]str

t, err = template.New("update_reaction").Funcs(sprig.FuncMap()).Parse(action.Reaction)
if err != nil {
bot.Log.Errorf("Failed to update Reaction %s", rule.Reaction)
bot.Log.Error().Msgf("Failed to update Reaction %s", rule.Reaction)
return
}
buf := new(bytes.Buffer)
Expand Down
Loading