Botkube doesn't respond when a message comes from an other bot

[pkosiec]

Description

On Socket Slack, Botkube ignores mentiones by other bots.

For example, when Slack workflows are triggering a @Botkube ... command, this piece of code ignores the execution:

case *slackevents.AppMentionEvent:
	if ev.BotID != "" {
		b.log.Infof("Not reacting to own messages, or anything from other bots")
		continue
	}

botkube/pkg/bot/slack_socket.go

Line 189 in 17e2715

if ev.BotID != "" {

and it results in the message like:

{"bot":"SocketSlack","commGroup":"default-group","level":"info","msg":"Not reacting to own messages, or anything from other bots","time":"2024-01-24T15:49:03Z"}

AC

• Check both Socket Slack and Cloud Slack with e.g. Slack workflows
• Ensure this issue doesn't occur for Cloud Slack
• Fix it for Socket Slack

Expected behavior

Botkube should respond when other bots (other than Botkube itself) are mentioning it.
On all supported platforms.

Steps to reproduce

Use Slack workflows to set up an automation for triggering a given Botkube command.

Additional context

Here's the full thread of a conversation with Jack Johnson, who reported the issue: https://botkube.slack.com/archives/C01CR1KS55K/p1706018155098419
Thank you, Jack!

Details

Hey 👋 I'm running botkube 1.1.1 on a GKE cluster, at the moment only using the SocketSlack integration and the kubectl plugin. After deploying, the connection between the Cluster <--> Slack seems to be working fine, but kubectl commands are getting this error: grpc: the client connection is closing.
Digging into the debug logs, it seems that it might be because the kubectl plugin is having issues? Any ideas why this might be happening?
│ time="2024-01-23T13:08:48Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: E │
│ time="2024-01-23T13:08:48Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.1.1_kubectl pid=28 plugin=botkube/kubectl │
│ time="2024-01-23T13:08:48Z" level=debug msg="plugin exited" plugin=botkube/kubectl
image.png

image.png

👀
1

20 replies

Jack Johnson
1 day ago
I have this same setup running on a different GKE cluster, and I don't have this issue :thinking_face:

Pawel Kosiec
1 day ago
Hi
@Jack Johnson
👋 Can you try setting the following envs to see if you have any errors?
LOG_LEVEL_EXECUTOR_BOTKUBE_KUBECTL="debug"
and BOTKUBE_SETTINGS_LOG_LEVEL="debug"
However, I'd strongly suggest updating Botkube to the latest version (1.7), as we smashed a lot of bugs between 1.1 and 1.7, and 1.1 is already an archived version. Perhaps the problem you're experiencing is already solved there? (edited)

Pawel Kosiec
1 day ago
One of the useful features we introduced is automatic plugin restart: https://docs.botkube.io/configuration/executor/#restart-policy-and-health-check-interval
but again, the kubectl plugin had multiple changes over time anyway, so it's worth upgrading 👍

Jack Johnson
1 day ago
cheers just got finished upgrading to 1.7 and it looks to be working now 👍 (edited)

Pawel Kosiec
1 day ago
Great to hear that! 🚀 Let us know if you have any other questions 👍
🙏
1

Jack Johnson
17 hours ago
Hey
@Pawel Kosiec
one last thing. With 1.1.1 we've always had a Slack workflow which runs a command via botkube every morning and it's always worked fine. But since upgrading to 1.7 it stopped working, I saw this in the logs:
│ {"bot":"SocketSlack","commGroup":"default-group","level":"info","msg":"Not reacting to own messages, or anything from other bots","time":"2024-01-24T │
Did something change to cause that?

Pawel Kosiec
17 hours ago
Hi
@Jack Johnson
, the log message you posted is related to one of the recent features - Botkube reacts with 👀 and ✅ to highlight that it is processing or already processed a given command.
You can fix this with an updated Socket Slack manifest: https://docs.botkube.io/installation/slack/socket-slack#create-slack-app
But I believe the log message is unrelated to the action itself :thinking_face: however, you can try updating the manifest, reinstalling the app and seeing if that helps 🙂

Pawel Kosiec
17 hours ago
Also, Botkube debug mode can be useful (see the envs I posted before) 👍

Jack Johnson
17 hours ago
Sure will give it a go, thanks 🙂
👍
1

Jack Johnson
17 hours ago
Nothing helpful in the debug logs for this issue:
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:55:36Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:55:46Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:55:56Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"info","msg":"Not reacting to own messages, or anything from other bots","time":"2024-01-24T │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:56:06Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:56:16Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T14:56:26Z"}
Will see how it goes once the Slack admins have approved my Slack app changes. But don't think gaining reactions: write will make much difference :thinking_face:

Pawel Kosiec
16 hours ago
yeah... are you sure the action is enabled? can you run @botkube list actions?

Jack Johnson
16 hours ago
yes it's definitely enabled, because it works when I run the same thing manually:
image.png

image.png

Jack Johnson
16 hours ago
See the workflow is ignored, and then I get the response

Pawel Kosiec
16 hours ago
ah, sorry, you meant Slack workflow, not Botkube action (built-in automation based on events). Then it is out of the Botkube app scope. From the logs it seems that the command wasn't triggered at all, so I'd look into a problem with the Slack workflow itself.

Jack Johnson
16 hours ago
Okay sure, it worked with botkube 1.1.1 though. I guess I'll look at alternatives to slack workflows

Pawel Kosiec
16 hours ago
I hear you, but it shouldn't really matter, as Slack workflows just execute a given command pinging the bot, is that correct? Anyway, there's no specific mechanism in Botkube responsible for Slack workflows or something like this, so I'd double check the handle the Slack workflow is using if this is correct :thinking_face:

Jack Johnson
16 hours ago
Yes just a mention by the workflow. That's why I was surprised that it stopped working. No handle definitely correct, and nothing changed other than upgrading from 1.1.1 to 1.7 . I'll keep looking into it

Pawel Kosiec
16 hours ago
are you running Botkube in the debug mode currently (BOTKUBE_SETTINGS_LOG_LEVEL="debug")? Because you should get a log "Slack incoming Request: %s", request even if it doesn't contain the mention :thinking_face: For now it seems like Botkube doesn't receive the Slack events

Jack Johnson
16 hours ago
yeah so this is me manually running the command:
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T15:41:26Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"debug","msg":"Got app mention slackevents.EventsAPIInnerEvent{\n Type: "app_mention",\n Data: \u0026slackevents.AppMentionEvent{\n Type: "app_mention",\n User │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"debug","msg":"Slack incoming Request: current-scale","time":"2024-01-24T15:41:29Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","error":"missing_scope","level":"warning","messages":null,"msg":"Cannot mark message as received.","time":"2024-01-24T15:41:29Z"} │
│ {"component":"Executor","expandedRawCmd":"kubectl get cm -n sre-tools current-cluster-scale -o jsonpath='{..data}{"\n"}'","level":"debug","msg":"Expanding aliases from command...","rawCmd":"current-scale","time":"2024-01-24T1 │
│ {"bindings":["k8s-default-tools","bins-management","ai","flux"],"command":"kubectl get cm -n sre-tools current-cluster-scale -o jsonpath='{..data}{"\n"}'","component":"Botkube Plugin Executor","level":"debug","msg":"Handling │
│ {"component":"Botkube Plugin Executor","input":{"Channel":"jack-testing"},"level":"debug","msg":"Generating Kubeconfig...","time":"2024-01-24T15:41:29Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"debug","msg":"Sending message to channel "REMOVED_ID": {Header: Description:kubectl get cm -n sre-tools current-cluster-scale -o jsonpath='{..data}{\"\\n\"}' on `ppl │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"debug","msg":"Message successfully sent to channel "REMOVED_ID"","time":"2024-01-24T15:41:30Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","error":"missing_scope","level":"warning","messages":null,"msg":"Cannot mark message as processed.","time":"2024-01-24T15:41:30Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T15:41:36Z"} │
and this is the slack workflow running it:
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T15:48:56Z"} │
│ {"bot":"SocketSlack","commGroup":"default-group","level":"info","msg":"Not reacting to own messages, or anything from other bots","time":"2024-01-24T15:49:03Z"} │
│ {"component":"Plugin Manager","level":"debug","msg":"Plugin "botkube/kubectl" is responding.","time":"2024-01-24T15:49:06Z"} │
Saved for later • 2 minutes ago

Pawel Kosiec
15 hours ago
Ah... ok, so I've checked this log in our code: {"bot":"SocketSlack","commGroup":"default-group","level":"info","msg":"Not reacting to own messages, or anything from other bots","time":"2024-01-24T15:49:03Z"}
It comes from this code snippet:
case *slackevents.AppMentionEvent:
if ev.BotID != "" {
b.log.Infof("Not reacting to own messages, or anything from other bots")
continue
}
And as you can see, we ignore messages from other bots, not only Botkube bot itself 😕 I'm not 100% sure why, consulted that internally and probably it's because botID is different from userID and we would need to handle the different IDs in other parts of the code too. So it's just a missing case that we should handle, and change the condition to compare Botkube bot ID.
I'll create an issue for it tomorrow morning and hope we'll fix it in the next milestone 🤞 Thanks for reporting this problem! (edited)