From 3b7a2960b2b5ea4e61747ae73a6759402894108b Mon Sep 17 00:00:00 2001 From: David May <1301201+wass3r@users.noreply.github.com> Date: Tue, 20 Jul 2021 21:42:08 +0000 Subject: [PATCH] enhance: various logging and docs fixes (#183) --- .env.example | 9 ++- README.md | 2 +- core/configure.go | 53 ++++++++++------ core/configure_test.go | 11 +--- core/matcher.go | 47 +++++++------- core/matcher_test.go | 4 +- core/outputs.go | 8 +-- core/prommetric.go | 6 +- core/remotes.go | 8 +-- core/rules.go | 22 +++---- handlers/http.go | 12 +++- handlers/http_test.go | 17 ++--- handlers/script.go | 14 ++--- remote/cli/remote.go | 2 +- remote/discord/helper.go | 16 ++--- remote/discord/remote.go | 34 +++++----- remote/scheduler/remote.go | 14 ++--- remote/slack/helper.go | 124 ++++++++++++++++++------------------- remote/slack/remote.go | 35 ++++++----- remote/telegram/remote.go | 6 +- utils/access_check.go | 24 +++---- utils/path.go | 2 +- utils/rooms.go | 2 +- 23 files changed, 251 insertions(+), 221 deletions(-) diff --git a/.env.example b/.env.example index 159a86c7..2215df5c 100644 --- a/.env.example +++ b/.env.example @@ -1,2 +1,9 @@ SLACK_TOKEN= -SLACK_SIGNING_SECRET= \ No newline at end of file +SLACK_APP_TOKEN= +SLACK_SIGNING_SECRET= +SLACK_EVENTS_CALLBACK_PATH= + +DISCORD_TOKEN= +DISCORD_SERVER_ID= + +TELEGRAM_TOKEN= \ No newline at end of file diff --git a/README.md b/README.md index e5cdc074..524315d8 100644 --- a/README.md +++ b/README.md @@ -86,4 +86,4 @@ Inspired by [Hexbot.io](https://github.com/mmcquillan/hex) ## Contributors -* [List of contributors](/target/flottbot/graphs/contributors) +* [List of contributors](https://github.com/target/flottbot/graphs/contributors) diff --git a/core/configure.go b/core/configure.go index f16b2a07..67940531 100644 --- a/core/configure.go +++ b/core/configure.go @@ -1,6 +1,7 @@ package core import ( + "io" "os" "strings" @@ -16,7 +17,7 @@ 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().Msg("Configuring bot...") + log.Info().Msg("configuring bot...") initLogger(bot) @@ -24,16 +25,28 @@ func Configure(bot *models.Bot) { configureChatApplication(bot) - bot.Log.Info().Msgf("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 = zerolog.New(os.Stdout).Level(zerolog.ErrorLevel) + var out io.Writer + var level zerolog.Level + + // defaults + out = os.Stdout + level = zerolog.InfoLevel + + // for CLI, use zerolog's ConsoleWriter + if b.CLI { + out = zerolog.ConsoleWriter{Out: os.Stderr} + } if b.Debug { - b.Log = zerolog.New(os.Stdout).Level(zerolog.DebugLevel) + level = zerolog.DebugLevel } + + b.Log = zerolog.New(out).With().Timestamp().Logger().Level(level) } // configureChatApplication configures a user's specified chat application @@ -57,7 +70,7 @@ func configureChatApplication(bot *models.Bot) { // Discord bot token token, err := utils.Substitute(bot.DiscordToken, emptyMap) if err != nil { - bot.Log.Error().Msgf("could not set discord_token: %s", err.Error()) + bot.Log.Error().Msgf("could not set 'discord_token': %s", err.Error()) bot.RunChat = false } @@ -67,14 +80,14 @@ 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, emptyMap) if err != nil { - bot.Log.Error().Msgf("could not set discord_server_id: %s", err.Error()) + bot.Log.Error().Msgf("could not set 'discord_server_id': %s", err.Error()) bot.RunChat = false } bot.DiscordServerID = serverID if !isSet(token, serverID) { - bot.Log.Error().Msg("bot is not configured correctly for discord - check that discord_token and discord_server_id are set") + bot.Log.Error().Msg("bot is not configured correctly for discord - check that 'discord_token' and 'discord_server_id' are set") bot.RunChat = false } @@ -84,12 +97,12 @@ func configureChatApplication(bot *models.Bot) { case "telegram": token, err := utils.Substitute(bot.TelegramToken, emptyMap) if err != nil { - bot.Log.Error().Msgf("could not set telegram_token: %s", err.Error()) + bot.Log.Error().Msgf("could not set 'telegram_token': %s", err.Error()) bot.RunChat = false } if !isSet(token) { - bot.Log.Error().Msg("bot is not configured correctly for telegram - check that telegram_token is set") + bot.Log.Error().Msg("bot is not configured correctly for telegram - check that 'telegram_token' is set") bot.RunChat = false } @@ -110,7 +123,7 @@ func configureSlackBot(bot *models.Bot) { // slack_token token, err := utils.Substitute(bot.SlackToken, emptyMap) if err != nil { - bot.Log.Error().Msgf("could not set slack_token: %s", err.Error()) + bot.Log.Error().Msgf("could not set 'slack_token': %s", err.Error()) } bot.SlackToken = token @@ -118,7 +131,7 @@ func configureSlackBot(bot *models.Bot) { // slack_app_token appToken, err := utils.Substitute(bot.SlackAppToken, emptyMap) if err != nil { - bot.Log.Warn().Msgf("could not set slack_app_token: %s", err.Error()) + bot.Log.Warn().Msgf("could not set 'slack_app_token': %s", err.Error()) } bot.SlackAppToken = appToken @@ -126,7 +139,7 @@ func configureSlackBot(bot *models.Bot) { // slack_signing_secret signingSecret, err := utils.Substitute(bot.SlackSigningSecret, emptyMap) if err != nil { - bot.Log.Warn().Msgf("could not set slack_signing_secret: %s", err.Error()) + bot.Log.Warn().Msgf("could not set 'slack_signing_secret': %s", err.Error()) } bot.SlackSigningSecret = signingSecret @@ -134,7 +147,7 @@ func configureSlackBot(bot *models.Bot) { // slack_events_callback_path eCallbackPath, err := utils.Substitute(bot.SlackEventsCallbackPath, emptyMap) if err != nil { - bot.Log.Warn().Msgf("could not set slack_events_callback_path: %s", err.Error()) + bot.Log.Warn().Msgf("could not set 'slack_events_callback_path': %s", err.Error()) } bot.SlackEventsCallbackPath = eCallbackPath @@ -142,7 +155,7 @@ func configureSlackBot(bot *models.Bot) { // slack_interactions_callback_path iCallbackPath, err := utils.Substitute(bot.SlackInteractionsCallbackPath, emptyMap) if err != nil { - bot.Log.Warn().Msgf("could not set slack_interactions_callback_path: %s", err.Error()) + bot.Log.Warn().Msgf("could not set 'slack_interactions_callback_path': %s", err.Error()) } bot.SlackInteractionsCallbackPath = iCallbackPath @@ -150,12 +163,12 @@ func configureSlackBot(bot *models.Bot) { // slack_listener_port lPort, err := utils.Substitute(bot.SlackListenerPort, emptyMap) if err != nil { - bot.Log.Warn().Msgf("could not set slack_listener_port: %s", err.Error()) + bot.Log.Warn().Msgf("could not set 'slack_listener_port': %s", err.Error()) } // set slack http listener port from config file or default if !isSet(lPort) { - bot.Log.Warn().Msgf("slack_listener_port not set: %s", lPort) + bot.Log.Warn().Msgf("'slack_listener_port' not set: %s", lPort) bot.Log.Info().Str("defaultSlackListenerPort", defaultSlackListenerPort).Msg("using default slack listener port.") lPort = defaultSlackListenerPort } @@ -169,7 +182,7 @@ func configureSlackBot(bot *models.Bot) { isSocketMode := isSet(token, appToken) isEventsAPI := isSet(token, signingSecret, eCallbackPath) if !isSocketMode && !isEventsAPI { - bot.Log.Error().Msg("bot is not configured correctly for slack - check that either slack_token and slack_app_token OR slack_token, slack_signing_secret, and slack_events_callback_path are set") + bot.Log.Error().Msg("must have either 'slack_token', 'slack_app_token' or 'slack_token', 'slack_signing_secret', and 'slack_events_callback_path' set") bot.RunChat = false } } @@ -184,18 +197,18 @@ func validateRemoteSetup(bot *models.Bot) { } if !bot.CLI && bot.ChatApplication == "" { - bot.Log.Fatal().Msgf("No chat_application specified and cli mode is not enabled. Exiting...") + bot.Log.Error().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().Msg("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().Msg("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 } } diff --git a/core/configure_test.go b/core/configure_test.go index dee9ca2b..13d121c2 100644 --- a/core/configure_test.go +++ b/core/configure_test.go @@ -12,25 +12,20 @@ func TestInitLogger(t *testing.T) { bot *models.Bot } - testBot := new(models.Bot) - // Test setting the error and debug level flags levelTests := []struct { name string args args want string }{ - {"error level set", args{testBot}, "error"}, - {"debug level set", args{testBot}, "debug"}, + {"error level set", args{bot: &models.Bot{}}, "info"}, + {"debug level set", args{bot: &models.Bot{Debug: true}}, "debug"}, } for _, tt := range levelTests { - if tt.want == "debug" { - testBot.Debug = true - } t.Run(tt.name, func(t *testing.T) { initLogger(tt.args.bot) 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()) + t.Errorf("initLogger() wanted level set at '%s', but got '%s'", tt.want, tt.args.bot.Log.GetLevel().String()) } }) } diff --git a/core/matcher.go b/core/matcher.go index 94081380..54d906cd 100644 --- a/core/matcher.go +++ b/core/matcher.go @@ -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.Debug().Msgf("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.Debug().Msgf("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().Msg("Response suppressed due to 'ignore_threads' being set") + bot.Log.Debug().Msg("response suppressed due to 'ignore_threads' being set") return true, true } @@ -93,7 +93,7 @@ func handleChatServiceRule(outputMsgs chan<- models.Message, message models.Mess } if hit { - bot.Log.Debug().Msgf("Found rule match '%s' for input '%s'", rule.Name, message.Input) + bot.Log.Info().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 @@ -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().Msg("Bot was addressed, but no rule matched. Showing help") + bot.Log.Info().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 @@ -167,8 +167,9 @@ func isValidHitChatRule(message *models.Message, rule models.Rule, processedInpu if !canRunRule { message.Output = fmt.Sprintf("You are not allowed to run the '%s' rule.", rule.Name) // forcing direct message - message.DirectMessageOnly = true + // message.DirectMessageOnly = true message.Type = models.MsgTypeDirect + message.IsEphemeral = true return false } // If this wasn't a 'hear' rule, handle the args @@ -189,29 +190,25 @@ func isValidHitChatRule(message *models.Message, rule models.Rule, processedInpu } if varArgs > 1 { // error, can ony have 1 - msg := fmt.Sprintf("You cannot specify more than 1 variable argument") - message.Output = msg + message.Output = "you cannot specify more than 1 variable argument" return false } if len(rule.Args) > 0 && strings.HasSuffix(rule.Args[len(rule.Args)-1], "+") { if optionalArgs > 0 { // error, cannot combine optional and varargs - msg := fmt.Sprintf("You cannot combine optional arguments with variable arguments") - message.Output = msg + message.Output = "you cannot combine optional arguments with variable arguments" return false } } else if varArgs == 1 { // error, vararg but not in last position - msg := fmt.Sprintf("You must specify the variable argument in the last argument position") - message.Output = msg + message.Output = "you must specify the variable argument in the last argument position" return false } // ensure we only require args that don't end with '?' requiredArgs = len(rule.Args) - optionalArgs // Are we expecting a number of args but don't have as many as the rule defines? Send a helpful message if len(rule.Args) > 0 && requiredArgs > len(args) { - msg := fmt.Sprintf("You might be missing an argument or two. This is what I'm looking for\n```%s```", rule.HelpText) - message.Output = msg + message.Output = fmt.Sprintf("you might be missing an argument or two - this is what i'm looking for\n```%s```", rule.HelpText) return false } // Go through the supplied args and make them available as variables @@ -250,15 +247,15 @@ func doRuleActions(message models.Message, outputMsgs chan<- models.Message, rul switch strings.ToLower(action.Type) { // HTTP actions. case "get", "post", "put": - bot.Log.Debug().Msgf("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.Debug().Msgf("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.Debug().Msgf("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" { @@ -269,7 +266,7 @@ func doRuleActions(message models.Message, outputMsgs chan<- models.Message, rul err = handleMessage(action, outputMsgs, ©, directive, rule.StartMessageThread, hitRule, bot) // Fallback to error if action type is invalid default: - bot.Log.Error().Msgf("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 @@ -332,7 +329,7 @@ func craftResponse(rule models.Rule, msg models.Message, bot *models.Bot) (strin // Simple warning that we will ignore 'output_to_rooms' when 'direct_message_only' is set if rule.DirectMessageOnly && len(rule.OutputToRooms) > 0 { - bot.Log.Debug().Msgf("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 @@ -384,19 +381,19 @@ func handleHTTP(action models.Action, msg *models.Message, bot *models.Bot) erro return fmt.Errorf("no URL was supplied for the '%s' action named: %s", action.Type, action.Name) } - resp, err := handlers.HTTPReq(action, msg) + resp, err := handlers.HTTPReq(action, msg, bot) if err != nil { - msg.Error = fmt.Sprintf("Error in request made by action '%s'. See bot admin for more information", action.Name) + msg.Error = fmt.Sprintf("error in request made by action '%s' - see bot admin for more information", action.Name) return err } // Just a friendly debugger warning on failed requests if resp.Status >= 400 { - 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) + 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.Debug().Msgf("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) @@ -454,7 +451,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.Debug().Msgf("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("'direct_message_only' is set - '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) @@ -497,7 +494,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.Error().Msgf("Failed to update Reaction %s", rule.Reaction) + bot.Log.Error().Msgf("failed to update reaction '%s'", rule.Reaction) return } buf := new(bytes.Buffer) diff --git a/core/matcher_test.go b/core/matcher_test.go index 98ae50d8..d5df5fc6 100644 --- a/core/matcher_test.go +++ b/core/matcher_test.go @@ -754,10 +754,10 @@ func Test_handleChatServiceRule(t *testing.T) { {"respond rule - hit false", args{rule: rule, hit: false}, false, false, "", map[string]string{}}, {"respond rule - hit true - valid", args{rule: rule, hit: true, bot: testBot, message: testMessage, processedInput: "arg1 arg2"}, true, true, "hmm, the 'format_output' field in your configuration is empty", map[string]string{"arg1": "arg1", "arg2": "arg2"}}, {"respond rule - hit true - bot not mentioned", args{rule: rule, hit: true, bot: testBot, message: testMessageBotNotMentioned, processedInput: "arg1 arg2"}, false, false, "", map[string]string{}}, - {"respond rule - hit true - valid - not enough args", args{rule: rule, hit: true, bot: testBot, message: testMessageNotEnoughArgs, processedInput: "arg1"}, true, true, "You might be missing an argument or two. This is what I'm looking for\n```foo ```", map[string]string{}}, + {"respond rule - hit true - valid - not enough args", args{rule: rule, hit: true, bot: testBot, message: testMessageNotEnoughArgs, processedInput: "arg1"}, true, true, "you might be missing an argument or two - this is what i'm looking for\n```foo ```", map[string]string{}}, {"respond rule - hit true - valid optional arg", args{rule: ruleOpt, hit: true, bot: testBot, message: testMessageOptionalArgs, processedInput: "arg1"}, true, true, "", map[string]string{"arg1": "arg1"}}, {"respond rule - hit true - valid vargs", args{rule: ruleVarg, hit: true, bot: testBot, message: testMessageVargs, processedInput: "arg1 arg2 arg3 arg4"}, true, true, "", map[string]string{"arg1": "arg1", "argv": "arg2 arg3 arg4"}}, - {"respond rule - hit true - invalid", args{rule: rule, hit: true, bot: testBot, message: testMessage}, true, true, "You might be missing an argument or two. This is what I'm looking for\n```foo ```", map[string]string{}}, + {"respond rule - hit true - invalid", args{rule: rule, hit: true, bot: testBot, message: testMessage}, true, true, "you might be missing an argument or two - this is what i'm looking for\n```foo ```", map[string]string{}}, {"hear rule - ignore thread", args{rule: ruleIgnoreThread, hit: true, bot: testBot, message: testMessageIgnoreThread}, true, true, "", map[string]string{}}, } for _, tt := range tests { diff --git a/core/outputs.go b/core/outputs.go index d7c2fc42..8adf3a50 100644 --- a/core/outputs.go +++ b/core/outputs.go @@ -23,7 +23,7 @@ func Outputs(outputMsgs <-chan models.Message, hitRule <-chan models.Rule, bot * switch chatApp { case "discord": if service == models.MsgServiceScheduler { - bot.Log.Warn().Msg("Scheduler does not currently support Discord") + bot.Log.Warn().Msg("scheduler does not currently support discord") break } remoteDiscord := &discord.Client{Token: bot.DiscordToken} @@ -50,15 +50,15 @@ func Outputs(outputMsgs <-chan models.Message, hitRule <-chan models.Rule, bot * } remoteTelegram.Send(message, bot) default: - bot.Log.Debug().Msgf("Chat application %s is not supported", chatApp) + bot.Log.Error().Msgf("chat application '%s' is not supported", chatApp) } case models.MsgServiceCLI: remoteCLI := &cli.Client{} remoteCLI.Send(message, bot) case models.MsgServiceUnknown: - bot.Log.Error().Msg("Found unknown service") + bot.Log.Error().Msg("found unknown service") default: - bot.Log.Error().Msg("No service found") + bot.Log.Error().Msg("no service found") } } } diff --git a/core/prommetric.go b/core/prommetric.go index 2d9b75ef..4d9dd8e4 100644 --- a/core/prommetric.go +++ b/core/prommetric.go @@ -31,11 +31,11 @@ func Prommetric(input string, bot *models.Bot) { // metrics health check handler promHealthHandle := func(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodGet { - bot.Log.Error().Msgf("Prometheus Server: invalid method %s", r.Method) + bot.Log.Error().Msgf("prometheus server: invalid method '%s'", r.Method) w.WriteHeader(http.StatusMethodNotAllowed) return } - bot.Log.Info().Msg("Prometheus Server: health check hit!") + bot.Log.Debug().Msg("prometheus server: health check hit!") w.WriteHeader(http.StatusOK) w.Write([]byte("OK")) } @@ -47,7 +47,7 @@ func Prommetric(input string, bot *models.Bot) { // start prometheus server go http.ListenAndServe(":8080", promRouter) - bot.Log.Info().Msg("Prometheus Server: serving metrics at /metrics") + bot.Log.Info().Msg("prometheus server: serving metrics at /metrics") } else { botResponseCollector.With(prometheus.Labels{"rulename": input}).Inc() } diff --git a/core/remotes.go b/core/remotes.go index e00ebf3e..91f61a4d 100644 --- a/core/remotes.go +++ b/core/remotes.go @@ -30,7 +30,7 @@ func Remotes(inputMsgs chan<- models.Message, rules map[string]models.Rule, bot // Run a chat application if bot.RunChat { chatApp := strings.ToLower(bot.ChatApplication) - bot.Log.Info().Msgf("Running %s on %s", bot.Name, strings.Title(chatApp)) + bot.Log.Info().Msgf("running '%s' on '%s'", bot.Name, strings.Title(chatApp)) switch chatApp { // Setup remote to use the Discord client to read from Discord case "discord": @@ -59,13 +59,13 @@ func Remotes(inputMsgs chan<- models.Message, rules map[string]models.Rule, bot // Read messages from Telegram go remoteTelegram.Read(inputMsgs, rules, bot) default: - bot.Log.Error().Msgf("Chat application '%s' is not supported", chatApp) + bot.Log.Error().Msgf("chat application '%s' is not supported", chatApp) } } // Run CLI mode if bot.RunCLI { - bot.Log.Info().Msgf("Running CLI mode for %s", bot.Name) + bot.Log.Info().Msgf("running cli mode for '%s'", bot.Name) remoteCLI := &cli.Client{} go remoteCLI.Read(inputMsgs, rules, bot) } @@ -73,7 +73,7 @@ func Remotes(inputMsgs chan<- models.Message, rules map[string]models.Rule, bot // Run Scheduler // CAUTION: Will not work properly when multiple instances of your bot are deployed (i.e. will get duplicated scheduled output) if bot.RunScheduler { - bot.Log.Info().Msgf("Running Scheduler for %s", bot.Name) + bot.Log.Info().Msgf("running scheduler for '%s'", bot.Name) remoteScheduler := &scheduler.Client{} go remoteScheduler.Read(inputMsgs, rules, bot) } diff --git a/core/rules.go b/core/rules.go index d93d3ccd..37c1890b 100644 --- a/core/rules.go +++ b/core/rules.go @@ -19,14 +19,14 @@ import ( // The rules map is used to dictate the bots behavior and response patterns. func Rules(rules *map[string]models.Rule, bot *models.Bot) { // Check if the rules directory even exists - bot.Log.Debug().Msg("Looking for rules directory...") + bot.Log.Debug().Msg("looking for rules directory...") searchDir, err := utils.PathExists(path.Join("config", "rules")) if err != nil { - bot.Log.Fatal().Msgf("Could not parse rules: %s", err) + bot.Log.Error().Msgf("could not parse rules: %v", err) } // Loop through the rules directory and create a list of rules - bot.Log.Debug().Msg("Fetching all rule files...") + bot.Log.Info().Msg("fetching all rule files...") fileList := []string{} err = filepath.Walk(searchDir, func(path string, f os.FileInfo, err error) error { if !f.IsDir() { @@ -35,39 +35,39 @@ func Rules(rules *map[string]models.Rule, bot *models.Bot) { return nil }) if err != nil { - bot.Log.Fatal().Msgf("Could not parse rules: %s", err) + bot.Log.Error().Msgf("could not parse rules: %v", err) } // If the rules directory is empty, log a warning and exit the function if len(fileList) == 0 { - bot.Log.Warn().Msg("Looks like there aren't any rules") + bot.Log.Warn().Msg("looks like there aren't any rules") return } // Loop through the list of rules, creating a Rule object // for each rule, then populate the map of Rule objects - bot.Log.Debug().Msg("Reading and parsing rule files...") + bot.Log.Debug().Msg("reading and parsing rule files...") for _, ruleFile := range fileList { ruleConf := viper.New() ruleConf.SetConfigFile(ruleFile) err := ruleConf.ReadInConfig() if err != nil { - bot.Log.Error().Msgf("Error while reading rule file '%s': %s", ruleFile, err) + bot.Log.Error().Msgf("error while reading rule file '%s': %v", ruleFile, err) } rule := models.Rule{} err = ruleConf.Unmarshal(&rule) if err != nil { - log.Fatal().Msg(err.Error()) + log.Error().Msg(err.Error()) } err = validateRule(bot, &rule) if err != nil { - log.Fatal().Msg(err.Error()) + log.Error().Msg(err.Error()) } (*rules)[ruleFile] = rule } - bot.Log.Info().Msgf("Configured '%s' rules!", bot.Name) + bot.Log.Info().Msgf("configured '%s' rules!", bot.Name) } // Validate applies any environmental changes @@ -76,7 +76,7 @@ func validateRule(bot *models.Bot, r *models.Rule) error { for i := range r.OutputToRooms { token, err := utils.Substitute(r.OutputToRooms[i], map[string]string{}) if err != nil { - return fmt.Errorf("Could not configure output room: %s", err.Error()) + return fmt.Errorf("could not configure output room: %s", err.Error()) } r.OutputToRooms[i] = token diff --git a/handlers/http.go b/handlers/http.go index 4d1e7eab..91eb9ebf 100644 --- a/handlers/http.go +++ b/handlers/http.go @@ -15,7 +15,8 @@ import ( ) // HTTPReq handles 'http' actions for rules -func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, error) { +func HTTPReq(args models.Action, msg *models.Message, bot *models.Bot) (*models.HTTPResponse, error) { + bot.Log.Info().Msgf("executing http request for action '%s'", args.Name) if args.Timeout == 0 { // Default HTTP Timeout of 10 seconds args.Timeout = 10 @@ -28,6 +29,7 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err // check the URL string from defined action has a variable, try to substitute it url, err := utils.Substitute(args.URL, msg.Vars) if err != nil { + bot.Log.Error().Msg("failed substituting variables in url parameter") return nil, err } @@ -38,11 +40,13 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err url, payload, err := prepRequestData(url, args.Type, args.QueryData, msg) if err != nil { + bot.Log.Error().Msg("failed preparing the request data for the http request") return nil, err } req, err := http.NewRequest(args.Type, url, payload) if err != nil { + bot.Log.Error().Msg("failed to create a new http request") return nil, err } req.Close = true @@ -51,6 +55,7 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err for k, v := range args.CustomHeaders { value, err := utils.Substitute(v, msg.Vars) if err != nil { + bot.Log.Error().Msg("failed substituting variables in custom headers") return nil, err } req.Header.Add(k, value) @@ -58,6 +63,7 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err resp, err := client.Do(req) if err != nil { + bot.Log.Error().Msg("failed to execute the http request") return nil, err } @@ -65,11 +71,13 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err bodyBytes, err := ioutil.ReadAll(resp.Body) if err != nil { + bot.Log.Error().Msg("failed to read response from http request") return nil, err } fields, err := extractFields(bodyBytes) if err != nil { + bot.Log.Error().Msg("failed to extract the fields from the http response") return nil, err } @@ -79,6 +87,8 @@ func HTTPReq(args models.Action, msg *models.Message) (*models.HTTPResponse, err Data: fields, } + bot.Log.Info().Msgf("http request for action '%s' completed", args.Name) + return &result, nil } diff --git a/handlers/http_test.go b/handlers/http_test.go index cc5809d8..d8b779fc 100644 --- a/handlers/http_test.go +++ b/handlers/http_test.go @@ -49,8 +49,11 @@ func TestHTTPReq(t *testing.T) { type args struct { args models.Action msg *models.Message + bot *models.Bot } + bot := new(models.Bot) + tsOK := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(http.StatusOK) })) @@ -116,16 +119,16 @@ func TestHTTPReq(t *testing.T) { want *models.HTTPResponse wantErr bool }{ - {"HTTPReq GET", args{args: TestGETAction, msg: &TestMessage}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, - {"HTTPReq POST", args{args: TestPOSTAction, msg: &TestMessage}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, - {"HTTPReq No Query", args{args: TestEmptyQueryAction, msg: &TestMessage}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, - {"HTTPReq Error Response", args{args: TestErrorResponseAction, msg: &TestMessage}, &models.HTTPResponse{Status: 502, Raw: "", Data: ""}, false}, - {"HTTPReq with Sub", args{args: TestQueryWithSubsAction, msg: &TestMessage}, nil, true}, - {"HTTPReq with Error", args{args: TestWithError, msg: &TestMessage}, nil, true}, + {"HTTPReq GET", args{args: TestGETAction, msg: &TestMessage, bot: bot}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, + {"HTTPReq POST", args{args: TestPOSTAction, msg: &TestMessage, bot: bot}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, + {"HTTPReq No Query", args{args: TestEmptyQueryAction, msg: &TestMessage, bot: bot}, &models.HTTPResponse{Status: 200, Raw: "", Data: ""}, false}, + {"HTTPReq Error Response", args{args: TestErrorResponseAction, msg: &TestMessage, bot: bot}, &models.HTTPResponse{Status: 502, Raw: "", Data: ""}, false}, + {"HTTPReq with Sub", args{args: TestQueryWithSubsAction, msg: &TestMessage, bot: bot}, nil, true}, + {"HTTPReq with Error", args{args: TestWithError, msg: &TestMessage, bot: bot}, nil, true}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - got, err := HTTPReq(tt.args.args, tt.args.msg) + got, err := HTTPReq(tt.args.args, tt.args.msg, tt.args.bot) if (err != nil) != tt.wantErr { t.Errorf("HTTPReq() error = %v, wantErr %v", err, tt.wantErr) return diff --git a/handlers/script.go b/handlers/script.go index a0719569..c8a78b39 100644 --- a/handlers/script.go +++ b/handlers/script.go @@ -15,7 +15,7 @@ import ( // ScriptExec handles 'exec' actions; script executions for rules func ScriptExec(args models.Action, msg *models.Message, bot *models.Bot) (*models.ScriptResponse, error) { - bot.Log.Debug().Msgf("Executing process for action '%s'", args.Name) + bot.Log.Info().Msgf("executing process for action '%s'", args.Name) // Default timeout of 20 seconds for any script execution, modifyable in rule file if args.Timeout == 0 { args.Timeout = 20 @@ -31,9 +31,9 @@ func ScriptExec(args models.Action, msg *models.Message, bot *models.Bot) (*mode defer cancel() // Deal with variable substitution in command - bot.Log.Debug().Msgf("Command is: [%s]", args.Cmd) + bot.Log.Debug().Msgf("command is: [%s]", args.Cmd) cmdProcessed, err := utils.Substitute(args.Cmd, msg.Vars) - bot.Log.Debug().Msgf("Substituted: [%s]", cmdProcessed) + bot.Log.Debug().Msgf("substituted: [%s]", cmdProcessed) if err != nil { return result, err } @@ -58,16 +58,16 @@ func ScriptExec(args models.Action, msg *models.Message, bot *models.Bot) (*mode case *exec.ExitError: ws := err.(*exec.ExitError).Sys().(syscall.WaitStatus) stderr := strings.Trim(string(err.(*exec.ExitError).Stderr), " \n") - bot.Log.Debug().Msgf("Process for action '%s' exited with status %d: %s", args.Name, ws.ExitStatus(), stderr) + bot.Log.Debug().Msgf("process for action '%s' exited with status '%d': %s", args.Name, ws.ExitStatus(), stderr) result.Status = ws.ExitStatus() result.Output = stderr case *os.PathError: - bot.Log.Debug().Msgf("Process for action '%s' exited with status %d: %s", args.Name, result.Status, err) + bot.Log.Debug().Msgf("process for action '%s' exited with status '%d': %v", args.Name, result.Status, err) result.Status = 127 result.Output = err.Error() default: // this should rarely/never get hit - bot.Log.Debug().Msgf("Couldn't get exit status for action '%s'", args.Name) + bot.Log.Debug().Msgf("couldn't get exit status for action '%s'", args.Name) result.Output = strings.Trim(err.Error(), " \n") } // if something was printed to stdout before the error, use that as output @@ -79,7 +79,7 @@ func ScriptExec(args models.Action, msg *models.Message, bot *models.Bot) (*mode } // should be exit code 0 here - bot.Log.Debug().Msgf("Process finished for action '%s'", args.Name) + bot.Log.Info().Msgf("process finished for action '%s'", args.Name) ws := cmd.ProcessState.Sys().(syscall.WaitStatus) result.Status = ws.ExitStatus() result.Output = strings.Trim(string(out), " \n") diff --git a/remote/cli/remote.go b/remote/cli/remote.go index d615b742..68cc4549 100644 --- a/remote/cli/remote.go +++ b/remote/cli/remote.go @@ -60,7 +60,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R } } if err := scanner.Err(); err != nil { - bot.Log.Debug().Msgf("Error reading standard input: %s", err) + bot.Log.Error().Msgf("Error reading standard input: %v", err) } } diff --git a/remote/discord/helper.go b/remote/discord/helper.go index 559deae9..696f442f 100644 --- a/remote/discord/helper.go +++ b/remote/discord/helper.go @@ -26,7 +26,7 @@ func populateMessage(message models.Message, msgType models.MessageType, channel if msgType != models.MsgTypeDirect { name, ok := findKey(bot.Rooms, channel) if !ok { - bot.Log.Warn().Msgf("Could not find name of channel '%s'.", channel) + bot.Log.Error().Msgf("could not find name of channel '%s'", channel) } message.ChannelName = name @@ -55,12 +55,12 @@ func send(dg *discordgo.Session, message models.Message, bot *models.Bot) { if message.DirectMessageOnly { err := handleDirectMessage(dg, message, bot) if err != nil { - bot.Log.Error().Msgf("Problem sending message: %s", err) + bot.Log.Error().Msgf("problem sending message: %v", err) } } else { err := handleNonDirectMessage(dg, message, bot) if err != nil { - bot.Log.Error().Msgf("Problem sending message: %s", err) + bot.Log.Error().Msgf("problem sending message: %v", err) } } } @@ -69,14 +69,14 @@ func send(dg *discordgo.Session, message models.Message, bot *models.Bot) { func handleDirectMessage(dg *discordgo.Session, message models.Message, bot *models.Bot) error { // Is output to rooms set? if len(message.OutputToRooms) > 0 { - bot.Log.Warn().Msg("You have specified 'direct_message_only' as 'true' and provided 'output_to_rooms'." + - " Messages will not be sent to listed rooms. If you want to send messages to these rooms," + - " please set 'direct_message_only' to 'false'.") + bot.Log.Warn().Msg("you have specified 'direct_message_only' as 'true' and provided 'output_to_rooms' -" + + " messages will not be sent to listed rooms - if you want to send messages to these rooms," + + " please set 'direct_message_only' to 'false'") } // Is output to users set? if len(message.OutputToUsers) > 0 { - bot.Log.Warn().Msg("You have specified 'direct_message_only' as 'true' and provided 'output_to_users'." + - " Messages will not be sent to the listed users (other than you). If you want to send messages to other users," + + bot.Log.Warn().Msg("you have specified 'direct_message_only' as 'true' and provided 'output_to_users' -" + + " messages will not be sent to the listed users (other than you) - if you want to send messages to other users," + " please set 'direct_message_only' to 'false'.") } diff --git a/remote/discord/remote.go b/remote/discord/remote.go index b4de1267..0c15f5ea 100644 --- a/remote/discord/remote.go +++ b/remote/discord/remote.go @@ -44,11 +44,11 @@ func (c *Client) Reaction(message models.Message, rule models.Rule, bot *models. dg := c.new() // Remove bot reaction from message if err := dg.MessageReactionRemove(message.ChannelID, message.ID, rule.RemoveReaction, "@me"); err != nil { - bot.Log.Error().Msgf("Could not add reaction '%s'. Make sure to use actual emoji unicode characters.", err) + bot.Log.Error().Msgf("could not add reaction '%s' - make sure to use actual emoji unicode characters", err) return } - bot.Log.Debug().Msgf("Removed reaction '%s' for rule %s", rule.RemoveReaction, rule.Name) + bot.Log.Info().Msgf("removed reaction '%s' for rule '%s'", rule.RemoveReaction, rule.Name) } if rule.Reaction != "" { @@ -56,11 +56,11 @@ func (c *Client) Reaction(message models.Message, rule models.Rule, bot *models. dg := c.new() // React with desired reaction if err := dg.MessageReactionAdd(message.ChannelID, message.ID, rule.Reaction); err != nil { - bot.Log.Error().Msgf("Could not add reaction '%s'", err) + bot.Log.Error().Msgf("could not add reaction: %v", err) return } - bot.Log.Debug().Msgf("Added reaction '%s' for rule %s", rule.Reaction, rule.Name) + bot.Log.Info().Msgf("added reaction '%s' for rule '%s'", rule.Reaction, rule.Name) } } @@ -68,22 +68,22 @@ func (c *Client) Reaction(message models.Message, rule models.Rule, bot *models. func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.Rule, bot *models.Bot) { dg := c.new() if dg == nil { - bot.Log.Error().Msg("Failed to initialize Discord client") + bot.Log.Error().Msg("failed to initialize discord client") return } err := dg.Open() if err != nil { - bot.Log.Error().Msgf("Failed to open connection to Discord server. Error: %s", err) + bot.Log.Error().Msgf("failed to open connection to discord server - error: %v", err) return } // Wait here until CTRL-C or other term signal is received - bot.Log.Info().Msgf("Discord is now running '%s'. Press CTRL-C to exit", bot.Name) + bot.Log.Info().Msgf("discord is now running '%s' - press ctrl-c to exit", bot.Name) // get informatiom about ourself botuser, err := dg.User("@me") if err != nil { - bot.Log.Error().Msgf("Failed to get bot name from Discord. Error: %s", err) + bot.Log.Error().Msgf("failed to get bot name from discord - error: %v", err) return } @@ -101,7 +101,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R } if !foundGuild { - bot.Log.Error().Msg("Unable to find server defined in 'discord_server_id'. Has the bot been added to the server?") + bot.Log.Error().Msg("unable to find server defined in 'discord_server_id' - has the bot been added to the server?") return } @@ -112,7 +112,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // populate rooms gchans, err := dg.GuildChannels(bot.DiscordServerID) if err != nil { - bot.Log.Debug().Msgf("Unable to get channels. Error: %s", err) + bot.Log.Error().Msgf("unable to get channels - error: %v", err) } for _, gchan := range gchans { @@ -124,7 +124,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // from prev results and pass in as second param to .GuildMembers gmembers, err := dg.GuildMembers(bot.DiscordServerID, "", 1000) if err != nil { - bot.Log.Debug().Msg("Unable to get users") + bot.Log.Error().Msg("unable to get users") } for _, gmember := range gmembers { @@ -134,7 +134,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // populate user groups groles, err := dg.GuildRoles(bot.DiscordServerID) if err != nil { - bot.Log.Debug().Msg("Unable to get roles") + bot.Log.Error().Msg("unable to get roles") } for _, grole := range groles { @@ -160,7 +160,7 @@ func (c *Client) Send(message models.Message, bot *models.Bot) { case models.MsgTypeDirect, models.MsgTypeChannel: send(dg, message, bot) default: - bot.Log.Error().Msgf("Unable to send message of type %d", message.Type) + bot.Log.Error().Msgf("unable to send message of type: %d", message.Type) } } @@ -191,12 +191,12 @@ func handleDiscordMessage(bot *models.Bot, inputMsgs chan<- models.Message) inte ch, err := s.Channel(m.ChannelID) if err != nil { - bot.Log.Error().Msg("Discord Remote: Failed to retrieve channel.") + bot.Log.Error().Msg("discord: failed to retrieve channel") } t, err := m.Timestamp.Parse() if err != nil { - bot.Log.Error().Msgf("Discord Remote: Failed to parse message timestamp.") + bot.Log.Error().Msgf("discord remote: failed to parse message timestamp") } timestamp := strconv.FormatInt(t.Unix(), 10) @@ -208,13 +208,13 @@ func handleDiscordMessage(bot *models.Bot, inputMsgs chan<- models.Message) inte msgType = models.MsgTypeChannel default: msgType = models.MsgTypeChannel - bot.Log.Debug().Msgf("Discord Remote: read message from unsupported channel type '%d'. Defaulting to use channel type 0 ('GUILD_TEXT')", ch.Type) + bot.Log.Warn().Msgf("discord: read message from unsupported channel type '%d' - defaulting to use channel type 0 ('GUILD_TEXT')", ch.Type) } contents, mentioned := removeBotMention(m.Content, s.State.User.ID) message = populateMessage(message, msgType, m.ChannelID, m.Message.ID, contents, timestamp, mentioned, m.Author, bot) default: - bot.Log.Error().Msgf("Discord Remote: read message of unsupported type '%d'. Unable to populate message attributes", m.Type) + bot.Log.Error().Msgf("discord: read message of unsupported type '%d' - unable to populate message attributes", m.Type) } inputMsgs <- message } diff --git a/remote/scheduler/remote.go b/remote/scheduler/remote.go index d123b447..4c5c2c9a 100644 --- a/remote/scheduler/remote.go +++ b/remote/scheduler/remote.go @@ -30,7 +30,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R for { _nil := bot.Rooms[""] if len(bot.Rooms) > 0 { - bot.Log.Debug().Msgf("scheduler connected to %s channels: %s", strings.Title(bot.ChatApplication), _nil) + bot.Log.Info().Msgf("scheduler connected to '%s' channels: %s", strings.Title(bot.ChatApplication), _nil) break } } @@ -44,17 +44,17 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R if rule.Active && rule.Schedule != "" { // Pre-checks before executing rule as a cron job if len(rule.OutputToRooms) == 0 && len(rule.OutputToUsers) == 0 { - bot.Log.Debug().Msg("scheduling rules require the 'output_to_rooms' and/or 'output_to_users' fields to be set") + bot.Log.Error().Msg("scheduling rules require the 'output_to_rooms' and/or 'output_to_users' fields to be set") continue } else if len(rule.OutputToRooms) > 0 && len(bot.Rooms) == 0 { - bot.Log.Debug().Msgf("unable to connect scheduler to these rooms: %s", rule.OutputToRooms) + bot.Log.Error().Msgf("unable to connect scheduler to these rooms: %s", rule.OutputToRooms) continue } else if rule.Respond != "" || rule.Hear != "" { - bot.Log.Debug().Msg("scheduling rules does not allow the 'respond' and 'hear' fields") + bot.Log.Error().Msg("scheduling rules does not allow the 'respond' and 'hear' fields") continue } - bot.Log.Debug().Msgf("scheduler is adding rule '%s'", rule.Name) + bot.Log.Info().Msgf("scheduler is adding rule '%s'", rule.Name) scheduleName := rule.Name input := fmt.Sprintf("<@%s> ", bot.ID) // send message as self @@ -63,7 +63,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // prepare the job function jobFunc := func() { - bot.Log.Debug().Msgf("executing scheduler for rule '%s'", scheduleName) + bot.Log.Info().Msgf("executing scheduler for rule '%s'", scheduleName) // build the message message := models.NewMessage() message.Service = models.MsgServiceScheduler @@ -96,7 +96,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R Msgf("unable to add schedule for rule '%s': verify that the supplied schedule is supported", rule.Name) // more verbose log. note: will probably convey that spec // needs to be 6 fields, although any supported format will work. - bot.Log.Debug().Msgf("error while adding job: %s", err) + bot.Log.Debug().Msgf("error while adding job: %v", err) continue } diff --git a/remote/slack/helper.go b/remote/slack/helper.go index 68e63dba..ee612338 100644 --- a/remote/slack/helper.go +++ b/remote/slack/helper.go @@ -36,7 +36,7 @@ func constructInteractiveComponentMessage(callback slack.AttachmentActionCallbac message := models.NewMessage() messageType, err := getMessageType(callback.Channel.ID) if err != nil { - bot.Log.Debug().Msg(err.Error()) + bot.Log.Error().Msg(err.Error()) } userNames := strings.Split(callback.User.Name, ".") @@ -71,7 +71,7 @@ func constructInteractiveComponentMessage(callback slack.AttachmentActionCallbac msgType, err := getMessageType(callback.Channel.ID) if err != nil { - bot.Log.Debug().Msg(err.Error()) + bot.Log.Error().Msg(err.Error()) } if msgType == models.MsgTypePrivateChannel { @@ -86,11 +86,11 @@ func constructInteractiveComponentMessage(callback slack.AttachmentActionCallbac func getEventsAPIHealthHandler(bot *models.Bot) func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodGet { - bot.Log.Error().Msgf("getEventsAPIHealthHandler: Received invalid method: %s", r.Method) + bot.Log.Error().Msgf("received invalid method: %s", r.Method) w.WriteHeader(http.StatusMethodNotAllowed) return } - bot.Log.Info().Msg("Bot event health endpoint hit!") + bot.Log.Debug().Msg("bot event health endpoint hit") w.WriteHeader(http.StatusOK) w.Write([]byte("OK")) } @@ -118,7 +118,7 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo sendHTTPResponse(http.StatusOK, "{}", w, r) // process the event - bot.Log.Debug().Msgf("getEventsAPIEventHandler: received event '%s'", event.Type) + bot.Log.Info().Msgf("received event: %s", event.Type) switch ev := event.Data.(type) { // Ignoring app_mention events @@ -135,7 +135,7 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo // the associated user id user, err := api.GetBotInfo(ev.BotID) if err != nil { - bot.Log.Info().Msgf("unable to retrieve bot info for %s", ev.BotID) + bot.Log.Error().Msgf("unable to retrieve bot info for '%s'", ev.BotID) return } @@ -149,7 +149,7 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo channel := ev.Channel msgType, err := getMessageType(channel) if err != nil { - bot.Log.Debug().Msg(err.Error()) + bot.Log.Error().Msg(err.Error()) } text, mentioned := removeBotMention(ev.Text, bot.ID) @@ -157,7 +157,7 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo // get the full user object for the given ID user, err := api.GetUserInfo(senderID) if err != nil { - bot.Log.Error().Msgf("getEventsAPIEventHandler: error getting Slack user info: %s", err) + bot.Log.Error().Msgf("error getting slack user info: %v", err) } timestamp := ev.TimeStamp @@ -166,7 +166,7 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo // get the link to the message, will be empty string if there's an error link, err := api.GetPermalink(&slack.PermalinkParameters{Channel: channel, Ts: timestamp}) if err != nil { - bot.Log.Error().Msgf("unable to retrieve link to message: %s", err.Error()) + bot.Log.Error().Msgf("unable to retrieve link to message: '%s'", err.Error()) } inputMsgs <- populateMessage(models.NewMessage(), msgType, channel, text, timestamp, threadTimestamp, link, mentioned, user, bot) @@ -177,15 +177,15 @@ func handleCallBack(api *slack.Client, event slackevents.EventsAPIInnerEvent, bo // look up channel info, since 'ev' only gives us ID channel, err := api.GetConversationInfo(ev.Channel, false) if err != nil { - bot.Log.Debug().Msgf("unable to fetch channel info for channel joined event: %v", err) + bot.Log.Error().Msgf("unable to fetch channel info for channel joined event: %v", err) } // add the room to the lookup bot.Rooms[channel.Name] = channel.ID - bot.Log.Debug().Msgf("joined new channel. %s (%s) added to lookup", channel.Name, channel.ID) + bot.Log.Info().Msgf("joined new channel - %s (%s) added to lookup", channel.Name, channel.ID) } default: - bot.Log.Debug().Msgf("getEventsAPIEventHandler: unrecognized event type: %v", ev) + bot.Log.Debug().Msgf("unrecognized event type: %v", ev) } } @@ -194,7 +194,7 @@ func getEventsAPIEventHandler(api *slack.Client, signingSecret string, inputMsgs return func(w http.ResponseWriter, r *http.Request) { // silently throw away anything that's not a POST if r.Method != http.MethodPost { - bot.Log.Error().Msg("Slack API Server: method not allowed") + bot.Log.Error().Msg("slack: method not allowed") sendHTTPResponse(http.StatusMethodNotAllowed, "method not allowed", w, r) return } @@ -202,7 +202,7 @@ func getEventsAPIEventHandler(api *slack.Client, signingSecret string, inputMsgs // read in the body of the incoming payload body, err := ioutil.ReadAll(r.Body) if err != nil { - bot.Log.Error().Msg("Slack API Server: error reading request body") + bot.Log.Error().Msg("slack: error reading request body") sendHTTPResponse(http.StatusBadRequest, "error reading request body", w, r) return } @@ -211,21 +211,21 @@ func getEventsAPIEventHandler(api *slack.Client, signingSecret string, inputMsgs // the request header and signing secret sv, err := slack.NewSecretsVerifier(r.Header, signingSecret) if err != nil { - bot.Log.Error().Msg("Slack API Server: error creating secrets verifier") + bot.Log.Error().Msg("slack: error creating secrets verifier") sendHTTPResponse(http.StatusBadRequest, "error creating secrets verifier", w, r) return } // write the request body's hash if _, err := sv.Write(body); err != nil { - bot.Log.Error().Msg("Slack API Server: error while writing body") + bot.Log.Error().Msg("slack: error while writing body") sendHTTPResponse(http.StatusInternalServerError, "error while writing body", w, r) return } // validate signing secret with computed hash if err := sv.Ensure(); err != nil { - bot.Log.Error().Msg("Slack API Server: request unauthorized") + bot.Log.Error().Msg("slack: request unauthorized") sendHTTPResponse(http.StatusUnauthorized, "request unauthorized", w, r) return } @@ -233,14 +233,14 @@ func getEventsAPIEventHandler(api *slack.Client, signingSecret string, inputMsgs // parse the event from the request eventsAPIEvent, err := slackevents.ParseEvent(json.RawMessage(body), slackevents.OptionNoVerifyToken()) if err != nil { - bot.Log.Error().Msg("Slack API Server: error while parsing event") + bot.Log.Error().Msg("slack: error while parsing event") sendHTTPResponse(http.StatusInternalServerError, "error while parsing event", w, r) return } // validate a URLVerification event with signing secret if eventsAPIEvent.Type == slackevents.URLVerification { - bot.Log.Debug().Msg("Slack API Server: received Slack challenge request. sending challenge response.") + bot.Log.Debug().Msg("slack: received slack challenge request - sending challenge response...") handleURLVerification(body, w, r) } @@ -256,11 +256,11 @@ func getEventsAPIEventHandler(api *slack.Client, signingSecret string, inputMsgs func getInteractiveComponentHealthHandler(bot *models.Bot) func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodGet { - bot.Log.Error().Msgf("getInteractiveComponentHealthHandler: Received invalid method %s", r.Method) + bot.Log.Error().Msgf("received invalid method: %s", r.Method) w.WriteHeader(http.StatusMethodNotAllowed) return } - bot.Log.Info().Msg("Bot interaction health endpoint hit!") + bot.Log.Debug().Msg("bot interaction health endpoint hit") w.WriteHeader(http.StatusOK) w.Write([]byte("OK")) } @@ -270,7 +270,7 @@ func getInteractiveComponentHealthHandler(bot *models.Bot) func(w http.ResponseW func getInteractiveComponentRuleHandler(signingSecret string, inputMsgs chan<- models.Message, message *models.Message, rule models.Rule, bot *models.Bot) func(w http.ResponseWriter, r *http.Request) { return func(w http.ResponseWriter, r *http.Request) { if r.Method != http.MethodPost { - bot.Log.Error().Msgf("getInteractiveComponentRuleHandler: Received invalid method: %s", r.Method) + bot.Log.Error().Msgf("received invalid method: %s", r.Method) w.WriteHeader(http.StatusMethodNotAllowed) w.Header().Set("Content-Type", "text/plain") w.Write([]byte("Oops! I encountered an unexpected HTTP verb")) @@ -279,17 +279,17 @@ func getInteractiveComponentRuleHandler(signingSecret string, inputMsgs chan<- m buff, err := ioutil.ReadAll(r.Body) if err != nil { - bot.Log.Error().Msgf("getInteractiveComponentRuleHandler: Failed to read request body: %s", err) + bot.Log.Error().Msgf("failed to read request body: %v", err) } contents, err := sanitizeContents(buff) if err != nil { - bot.Log.Debug().Msgf("failed to sanitize content: %s", err) + bot.Log.Error().Msgf("failed to sanitize content: %v", err) } var callback slack.AttachmentActionCallback if err := json.Unmarshal([]byte(contents), &callback); err != nil { - bot.Log.Error().Msgf("getInteractiveComponentRuleHandler: Failed to decode callback json %s because %s", contents, err) + bot.Log.Error().Msgf("failed to decode callback json '%s': %v", contents, err) w.WriteHeader(http.StatusInternalServerError) w.Header().Set("Content-Type", "text/plain") w.Write([]byte("Oops! Looks like I failed to decode some JSON in the backend. Please contact admins for more info!")) @@ -298,7 +298,7 @@ func getInteractiveComponentRuleHandler(signingSecret string, inputMsgs chan<- m // Only accept message from slack with valid token if callback.Token != bot.SlackSigningSecret { - bot.Log.Error().Msgf("getInteractiveComponentRuleHandler: Invalid token %s", callback.Token) + bot.Log.Error().Msg("invalid 'slack_signing_secret'") w.WriteHeader(http.StatusUnauthorized) w.Header().Set("Content-Type", "text/plain") w.Write([]byte("Sorry, but I didn't recognize your signing secret! Perhaps check if it's a valid secret.")) @@ -314,7 +314,7 @@ func getInteractiveComponentRuleHandler(signingSecret string, inputMsgs chan<- m w.Header().Set("Content-Type", "text/plain") w.Write([]byte("Rodger that!")) - bot.Log.Debug().Msgf("getInteractiveComponentRuleHandler: triggering rule: %s", rule.Name) + bot.Log.Info().Msgf("triggering rule: %s", rule.Name) } } @@ -379,7 +379,7 @@ func getUserID(email string, users []slack.User, bot *models.Bot) string { return u.ID } } - bot.Log.Error().Msgf("Could not find user '%s'", email) + bot.Log.Error().Msgf("could not find user '%s'", email) return "" } @@ -387,15 +387,15 @@ func getUserID(email string, users []slack.User, bot *models.Bot) string { func handleDirectMessage(api *slack.Client, message models.Message, bot *models.Bot) error { // Is output to rooms set? if len(message.OutputToRooms) > 0 { - bot.Log.Warn().Msg("You have specified 'direct_message_only' as 'true' and provided 'output_to_rooms'." + - " Messages will not be sent to listed rooms. If you want to send messages to these rooms," + - " please set 'direct_message_only' to 'false'.") + bot.Log.Warn().Msg("you have specified 'direct_message_only' as 'true' and provided 'output_to_rooms' -" + + " messages will not be sent to listed rooms - if you want to send messages to these rooms," + + " please set 'direct_message_only' to 'false'") } // Is output to users set? if len(message.OutputToUsers) > 0 { - bot.Log.Warn().Msg("You have specified 'direct_message_only' as 'true' and provided 'output_to_users'." + - " Messages will not be sent to the listed users (other than you). If you want to send messages to other users," + - " please set 'direct_message_only' to 'false'.") + bot.Log.Warn().Msg("you have specified 'direct_message_only' as 'true' and provided 'output_to_users' -" + + " messages will not be sent to the listed users (other than you) - if you want to send messages to other users," + + " please set 'direct_message_only' to 'false'") } // Respond back to user via direct message return sendDirectMessage(api, message.Vars["_user.id"], message) @@ -422,7 +422,7 @@ func handleNonDirectMessage(api *slack.Client, users []slack.User, message model if userID != "" { // If 'direct_message_only' is 'false' but the user listed himself in the 'output_to_users' if userID == message.Vars["_user.id"] && !message.DirectMessageOnly { - bot.Log.Warn().Msg("You have specified 'direct_message_only' as 'false' but listed yourself in 'output_to_users'") + bot.Log.Warn().Msg("you have specified 'direct_message_only' as 'false' but listed yourself in 'output_to_users'") } // Respond back to these users via direct message err := sendDirectMessage(api, userID, message) @@ -488,7 +488,7 @@ func populateMessage(message models.Message, msgType models.MessageType, channel if msgType != models.MsgTypeDirect { name, ok := findKey(bot.Rooms, channel) if !ok { - bot.Log.Warn().Msgf("populateMessage: Could not find name of channel '%s'.", channel) + bot.Log.Error().Msgf("could not find name of channel '%s'", channel) } message.ChannelName = name } @@ -531,7 +531,7 @@ func populateMessage(message models.Message, msgType models.MessageType, channel return message default: - bot.Log.Debug().Msgf("Read message of unsupported type '%T'. Unable to populate message attributes", msgType) + bot.Log.Debug().Msgf("read message of unsupported type '%T' - unable to populate message attributes", msgType) return message } } @@ -542,7 +542,7 @@ func processInteractiveComponentRule(rule models.Rule, message *models.Message, // Get slack attachments from hit rule and append to outgoing message config := rule.Remotes.Slack if config.Attachments != nil { - bot.Log.Debug().Msgf("Found attachment for rule '%s'", rule.Name) + bot.Log.Debug().Msgf("found attachment for rule '%s'", rule.Name) config.Attachments[0].CallbackID = message.ID if len(config.Attachments[0].Actions) > 0 { for i, action := range config.Attachments[0].Actions { @@ -596,7 +596,7 @@ func readFromEventsAPI(api *slack.Client, vToken string, inputMsgs chan<- models // Start listening to Slack events maskedPort := fmt.Sprintf(":%s", bot.SlackListenerPort) go http.ListenAndServe(maskedPort, router) - bot.Log.Info().Msgf("Slack Events API server is listening to %s on port %s", + bot.Log.Info().Msgf("slack events api server is listening to '%s' on port '%s'", bot.SlackEventsCallbackPath, bot.SlackListenerPort) } @@ -606,10 +606,7 @@ func readFromEventsAPI(api *slack.Client, vToken string, inputMsgs chan<- models // nolint:gocyclo // needs refactor func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot *models.Bot) { // setup the client - client := socketmode.New( - sm, - socketmode.OptionDebug(bot.Debug), - ) + client := socketmode.New(sm) // spawn anonymous goroutine go func() { @@ -621,7 +618,7 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * case socketmode.EventTypeEventsAPI: eventsAPIEvent, ok := evt.Data.(slackevents.EventsAPIEvent) if !ok { - bot.Log.Warn().Msgf("ignored: %+v", evt) + bot.Log.Error().Msgf("ignored: %+v", evt) continue } @@ -646,7 +643,7 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * // the associated user id user, err := sm.GetBotInfo(ev.BotID) if err != nil { - bot.Log.Info().Msgf("unable to retrieve bot info for %s", ev.BotID) + bot.Log.Error().Msgf("unable to retrieve bot info for '%s'", ev.BotID) return } @@ -662,7 +659,7 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * // determine the message type msgType, err := getMessageType(channel) if err != nil { - bot.Log.Debug().Msg(err.Error()) + bot.Log.Error().Msg(err.Error()) } // remove the bot mention from the user input @@ -671,7 +668,7 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * // get information on the user user, err := sm.GetUserInfo(senderID) if err != nil { - bot.Log.Error().Msgf("did not get Slack user info: %s", err.Error()) + bot.Log.Error().Msgf("did not get slack user info: %s", err.Error()) } timestamp := ev.TimeStamp @@ -691,23 +688,23 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * // look up channel info, since 'ev' only gives us ID channel, err := sm.GetConversationInfo(ev.Channel, false) if err != nil { - bot.Log.Debug().Msgf("unable to fetch channel info for channel joined event: %v", err) + bot.Log.Error().Msgf("unable to fetch channel info for channel joined event: %v", err) } // add the room to the lookup bot.Rooms[channel.Name] = channel.ID - bot.Log.Debug().Msgf("joined new channel. %s (%s) added to lookup", channel.Name, channel.ID) + bot.Log.Info().Msgf("joined new channel - %s (%s) added to lookup", channel.Name, channel.ID) } } default: - bot.Log.Warn().Msgf("unsupported events API event received: %s", eventsAPIEvent.Type) + bot.Log.Warn().Msgf("unsupported events api event received: %s", eventsAPIEvent.Type) } case socketmode.EventTypeConnecting: - bot.Log.Info().Msg("connecting to Slack via Socket Mode...") + bot.Log.Info().Msg("connecting to slack via socket mode...") case socketmode.EventTypeConnectionError: bot.Log.Error().Msg("connection failed - retrying later...") case socketmode.EventTypeConnected: - bot.Log.Info().Msg("connected to Slack with Socket Mode.") + bot.Log.Info().Msg("connected to slack with socket mode") // get users users, err := sm.GetUsers() @@ -743,17 +740,17 @@ func readFromSocketMode(sm *slack.Client, inputMsgs chan<- models.Message, bot * func send(api *slack.Client, message models.Message, bot *models.Bot) { users, err := getSlackUsers(api, message) if err != nil { - bot.Log.Error().Msgf("Problem sending message: %s", err) + bot.Log.Error().Msgf("problem sending message: %v", err) } if message.DirectMessageOnly { err := handleDirectMessage(api, message, bot) if err != nil { - bot.Log.Error().Msgf("Problem sending message: %s", err) + bot.Log.Error().Msgf("problem sending message: %v", err) } } else { err := handleNonDirectMessage(api, users, message, bot) if err != nil { - bot.Log.Error().Msgf("Problem sending message: %s", err) + bot.Log.Error().Msgf("problem sending message: %v", err) } } } @@ -784,19 +781,22 @@ func sendDirectMessage(api *slack.Client, userID string, message models.Message) // sendMessage - does the final send to Slack; adds any Slack-specific message parameters to the message to be sent out func sendMessage(api *slack.Client, ephemeral bool, channel, userID, text, threadTimeStamp string, attachments []slack.Attachment) error { - // send ephemeral message is indicated - if ephemeral { - opt := slack.MsgOptionAttachments(attachments...) - _, err := api.PostEphemeral(channel, userID, opt) - return err - } - + // prepare the message options opts := []slack.MsgOption{ slack.MsgOptionText(text, false), slack.MsgOptionAsUser(true), slack.MsgOptionAttachments(attachments...), slack.MsgOptionTS(threadTimeStamp), } + + // send as ephemeral + if ephemeral { + _, err := api.PostEphemeral(channel, userID, opts...) + return err + } + + // send as regular post _, _, err := api.PostMessage(channel, opts...) + return err } diff --git a/remote/slack/remote.go b/remote/slack/remote.go index e4e52850..035fadf7 100644 --- a/remote/slack/remote.go +++ b/remote/slack/remote.go @@ -1,6 +1,7 @@ package slack import ( + "log" "net/http" "github.com/gorilla/mux" @@ -41,10 +42,10 @@ func (c *Client) Reaction(message models.Message, rule models.Rule, bot *models. msgRef := slack.NewRefToMessage(message.ChannelID, message.Timestamp) // Remove bot reaction from message if err := api.RemoveReaction(rule.RemoveReaction, msgRef); err != nil { - bot.Log.Error().Msgf("Could not add reaction '%s'", err) + bot.Log.Error().Msgf("could not add reaction: %v", err) return } - bot.Log.Debug().Msgf("Removed reaction '%s' for rule %s", rule.RemoveReaction, rule.Name) + bot.Log.Info().Msgf("removed reaction '%s' for rule '%s'", rule.RemoveReaction, rule.Name) } if rule.Reaction != "" { // Init api client @@ -53,10 +54,10 @@ func (c *Client) Reaction(message models.Message, rule models.Rule, bot *models. msgRef := slack.NewRefToMessage(message.ChannelID, message.Timestamp) // React with desired reaction if err := api.AddReaction(rule.Reaction, msgRef); err != nil { - bot.Log.Error().Msgf("Could not add reaction '%s'", err) + bot.Log.Error().Msgf("could not add reaction: %v", err) return } - bot.Log.Debug().Msgf("Added reaction '%s' for rule %s", rule.Reaction, rule.Name) + bot.Log.Info().Msgf("added reaction '%s' for rule '%s'", rule.Reaction, rule.Name) } } @@ -72,7 +73,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // get bot id rat, err := api.AuthTest() if err != nil { - bot.Log.Error().Msg("the slack_token that was provided was invalid or is unauthorized - closing Slack message reader") + bot.Log.Error().Msg("the 'slack_token' that was provided was invalid or is unauthorized - closing slack message reader") return } @@ -85,10 +86,14 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // assuming Socket Mode if slack_app_token is provided sm := slack.New( bot.SlackToken, - slack.OptionDebug(true), - slack.OptionAppLevelToken(bot.SlackAppToken), + slack.OptionDebug(bot.Debug), + slack.OptionAppLevelToken(c.AppToken), + // pass our custom logger through to slack + slack.OptionLog(log.New(bot.Log, "", 0)), ) + // move the above inside readFromSocketMode below :o + readFromSocketMode(sm, inputMsgs, bot) } else if c.SigningSecret != "" { // handle Events API setup @@ -99,13 +104,13 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R // slack is not configured correctly and cli is set to false // TODO: move this out of the remote setup if c.AppToken == "" && c.SigningSecret == "" && !bot.CLI { - bot.Log.Fatal().Msg("CLI mode is disabled and tokens are not set up correctly to run the bot") + bot.Log.Error().Msg("cli mode is disabled and tokens are not set up correctly to run the bot") } } // Send implementation to satisfy remote interface func (c *Client) Send(message models.Message, bot *models.Bot) { - bot.Log.Debug().Msgf("Sending message %s", message.ID) + bot.Log.Debug().Msgf("sending message '%s'", message.ID) api := c.new() @@ -124,7 +129,7 @@ func (c *Client) Send(message models.Message, bot *models.Bot) { case models.MsgTypeDirect, models.MsgTypeChannel, models.MsgTypePrivateChannel: send(api, message, bot) default: - bot.Log.Warn().Msg("Received unknown message type - no message to send") + bot.Log.Warn().Msg("received unknown message type - no message to send") } } @@ -136,8 +141,8 @@ var interactionsRouter *mux.Router func (c *Client) InteractiveComponents(inputMsgs chan<- models.Message, message *models.Message, rule models.Rule, bot *models.Bot) { if bot.InteractiveComponents && c.SigningSecret != "" { if bot.SlackInteractionsCallbackPath == "" { - bot.Log.Error().Msg("Need to specify a callback path for the 'slack_interactions_callback_path' field in the bot.yml (e.g. \"/slack_events/v1/mybot_dev-v1_interactions\")") - bot.Log.Warn().Msg("Closing interactions reader (will not be able to read interactive components)") + bot.Log.Error().Msg("need to specify a callback path for the 'slack_interactions_callback_path' field in the bot.yml (e.g. \"/slack_events/v1/mybot_dev-v1_interactions\")") + bot.Log.Warn().Msg("closing interactions reader (will not be able to read interactive components)") return } if interactionsRouter == nil { @@ -153,15 +158,15 @@ func (c *Client) InteractiveComponents(inputMsgs chan<- models.Message, message // We use regex for interactions routing for any bot using this framework // e.g. /slack_events/v1/mybot_dev-v1_interactions if !isValidPath(bot.SlackInteractionsCallbackPath) { - bot.Log.Error().Msg("Invalid events path. Please double check your path value/syntax (e.g. \"/slack_events/v1/mybot_dev-v1_interactions\")") - bot.Log.Warn().Msg("Closing interaction components reader (will not be able to read interactive components)") + bot.Log.Error().Msg(`invalid events path - please double check your path value/syntax (e.g. "/slack_events/v1/mybot_dev-v1_interactions")`) + bot.Log.Warn().Msg("closing interaction components reader (will not be able to read interactive components)") return } interactionsRouter.HandleFunc(bot.SlackInteractionsCallbackPath, ruleHandle).Methods("POST") // start Interactive Components server go http.ListenAndServe(":4000", interactionsRouter) - bot.Log.Info().Msgf("Slack Interactive Components server is listening to %s", bot.SlackInteractionsCallbackPath) + bot.Log.Info().Msgf("slack interactive components server is listening to '%s'", bot.SlackInteractionsCallbackPath) } // Process the hit rule for Interactive Components, e.g. interactive messages diff --git a/remote/telegram/remote.go b/remote/telegram/remote.go index 6a92d4e3..2d0b7e24 100644 --- a/remote/telegram/remote.go +++ b/remote/telegram/remote.go @@ -46,7 +46,7 @@ func (c *Client) Read(inputMsgs chan<- models.Message, rules map[string]models.R botuser, err := telegramAPI.GetMe() if err != nil { - bot.Log.Error().Msg("Failed to initialize Telegram client") + bot.Log.Error().Msg("failed to initialize telegram client") return } bot.Name = botuser.UserName @@ -123,7 +123,7 @@ func (c *Client) Send(message models.Message, bot *models.Bot) { telegramAPI := c.new() chatID, err := strconv.ParseInt(message.ChannelID, 10, 64) if err != nil { - bot.Log.Error().Msgf("unable to retrieve chat ID %s", message.ChannelID) + bot.Log.Error().Msgf("unable to retrieve chat id '%s'", message.ChannelID) return } @@ -132,7 +132,7 @@ func (c *Client) Send(message models.Message, bot *models.Bot) { if message.DirectMessageOnly { chatID, err = strconv.ParseInt(message.Vars["_user.id"], 10, 64) if err != nil { - bot.Log.Error().Msgf("unable to retrieve user ID %s for direct message", message.Vars["_user.id"]) + bot.Log.Error().Msgf("unable to retrieve user id '%s' for direct message", message.Vars["_user.id"]) return } } diff --git a/utils/access_check.go b/utils/access_check.go index fee86b3f..2c53e42b 100644 --- a/utils/access_check.go +++ b/utils/access_check.go @@ -20,7 +20,7 @@ func CanTrigger(currentUserName string, currentUserID string, rule models.Rule, // are they ignored directly? deny for _, name := range rule.IgnoreUsers { if name == currentUserName { - bot.Log.Debug().Msgf("'%s' is on the ignore_users list for rule: '%s'", currentUserName, rule.Name) + bot.Log.Info().Msgf("'%s' is on the 'ignore_users' list for rule: '%s'", currentUserName, rule.Name) return false } } @@ -33,8 +33,8 @@ func CanTrigger(currentUserName string, currentUserID string, rule models.Rule, } if isIgnored { - bot.Log.Debug(). - Msgf("'%s' is part of a group in ignore_usergroups: %s", currentUserName, strings.Join(rule.IgnoreUserGroups, ", ")) + bot.Log.Info(). + Msgf("'%s' is part of a group in ignore_usergroups: '%s'", currentUserName, strings.Join(rule.IgnoreUserGroups, ", ")) return false } @@ -73,18 +73,18 @@ func CanTrigger(currentUserName string, currentUserID string, rule models.Rule, if !canRunRule { if len(rule.AllowUsers) > 0 { - bot.Log.Debug(). - Msgf("'%s' is not part of allow_users: %s", currentUserName, strings.Join(rule.AllowUsers, ", ")) + bot.Log.Info(). + Msgf("'%s' is not part of allow_users: '%s'", currentUserName, strings.Join(rule.AllowUsers, ", ")) } if len(rule.AllowUserIds) > 0 { - bot.Log.Debug(). - Msgf("'%s' is not part of allow_userids: %s", currentUserID, strings.Join(rule.AllowUserIds, ", ")) + bot.Log.Info(). + Msgf("'%s' is not part of allow_userids: '%s'", currentUserID, strings.Join(rule.AllowUserIds, ", ")) } if len(rule.AllowUserGroups) > 0 { - bot.Log.Debug(). - Msgf("'%s' is not part of any groups in allow_usergroups: %s", currentUserName, strings.Join(rule.AllowUserGroups, ", ")) + bot.Log.Info(). + Msgf("'%s' is not part of any groups in allow_usergroups: '%s'", currentUserName, strings.Join(rule.AllowUserGroups, ", ")) } } @@ -111,7 +111,7 @@ func isMemberOfGroup(currentUserID string, userGroups []string, bot *models.Bot) usr, err = dg.GuildMember(bot.DiscordServerID, currentUserID) if err != nil { - bot.Log.Debug().Msgf("Error while searching for user. Error: %s", err) + bot.Log.Error().Msgf("error while searching for user - error: %v", err) return false, nil } @@ -135,7 +135,7 @@ func isMemberOfGroup(currentUserID string, userGroups []string, bot *models.Bot) // Get the members of the group userGroupMembers, err := api.GetUserGroupMembers(knownUserGroupID) if err != nil { - bot.Log.Debug().Msgf("Unable to retrieve user group members, %s", err) + bot.Log.Error().Msgf("unable to retrieve user group members, %v", err) } // Check if any of the members are the current user for _, userGroupMemberID := range userGroupMembers { @@ -151,7 +151,7 @@ func isMemberOfGroup(currentUserID string, userGroups []string, bot *models.Bot) return false, nil default: - bot.Log.Error().Msgf("Chat application %s is not supported", capp) + bot.Log.Error().Msgf("chat application '%s' is not supported", capp) return false, nil } } diff --git a/utils/path.go b/utils/path.go index 77ae77fb..24888f94 100644 --- a/utils/path.go +++ b/utils/path.go @@ -28,7 +28,7 @@ func PathExists(p string) (string, error) { if os.IsNotExist(err) { return "", fmt.Errorf(errPathNotExists.Error(), p, fullPath) } - return "", fmt.Errorf("%s: %s", errPathOther.Error(), err) + return "", fmt.Errorf("%s: %v", errPathOther.Error(), err) } return fullPath, nil diff --git a/utils/rooms.go b/utils/rooms.go index 112b1bda..c1ed31eb 100644 --- a/utils/rooms.go +++ b/utils/rooms.go @@ -15,7 +15,7 @@ func GetRoomIDs(wantRooms []string, bot *models.Bot) []string { if roomMatch != "" { rooms = append(rooms, roomMatch) } else { - bot.Log.Debug().Msgf("Room '%s' does not exist", room) + bot.Log.Error().Msgf("room '%s' does not exist", room) } }