search

kubeshop / botkube

An app that helps you monitor your Kubernetes cluster, debug critical deployments & gives recommendations for standard practices
https://botkube.io
MIT License
2.11k stars 289 forks source link

Botkube connects to Mattermost instance and then dies immediately (due to wrong websocket connection URL) #1037

Closed tchellomello closed 1 year ago

tchellomello commented 1 year ago

Description

Botkube connects to Mattermost instance and then dies immediately. 

botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Using API Key starting with \"xUd\"..." component="Analytics reporter"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Executor plugin defined but not enabled." groupName=k8s-default-tools pluginKey=botkube/helm
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking executor plugin as enabled" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined but not enabled." groupName=prometheus pluginKey=botkube/prometheus
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Starting Plugin Manager for all enabled plugins" component="Plugin Manager" enabledExecutors=botkube/kubectl enabledSources=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Binary \"kubectl\" found locally. Skipping..." component="Plugin Manager"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Executor plugin registered successfully." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager" plugin=botkube/kubectl version=v1.0.0
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Explicitly using Info level as custom log level was not set by \"LOG_LEVEL_EXECUTOR_BOTKUBE_KUBECTL\" environment variable" component="Plugin Manager"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubectl
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Source plugin registered successfully." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager" plugin=botkube/kubernetes version=v1.0.0
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="starting plugin" args="[/tmp/botkube/source_v1.0.0_kubernetes]" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="plugin started" path=/tmp/botkube/source_v1.0.0_kubernetes pid=36 plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="using plugin" plugin=botkube/kubernetes version=1
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="plugin address" address=/tmp/plugin1165005629 network=unix plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.source_v1.0.0_kubernetes timestamp="2023-04-06T06:43:30.559Z"
botkube-7d9bc7d997-7b5r2 botkube W0406 06:43:30.560585       1 client_config.go:617] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Starting server on address \":2114\"" component="Health server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Starting server on address \":2112\"" component="Metrics server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Executor plugin defined but not enabled." component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/helm
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking executor plugin as enabled" component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined but not enabled." component="Help Executor" groupName=prometheus pluginKey=botkube/prometheus
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Skipping waiting for Config Watcher sync..." component="Config Watcher Sync"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Starting bot" bot=Mattermost commGroup=default-group
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Starting server on address \":2113\"" component="Lifecycle server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Sending message to channel \"8jcpsdXXXXXXXXX\": {Header: Description:Botkube is now active for \"toca\" cluster :rocket: Metadata:<nil>

image

Then dies:

botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Botkube connected to Mattermost!" bot=Mattermost commGroup=default-group
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Shutdown requested. Finishing..." component="Metrics server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Shutdown requested. Finishing..." component="Lifecycle server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="Shutdown requested. Finishing..." component="Health server"
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="Message successfully sent to channel \"8jcpsds79jyoucmt4sgrxjmzqe\"" bot=Mattermost commGroup=default-group
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.stdio
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_kubectl pid=20 plugin=botkube/kubectl
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg="plugin process exited" path=/tmp/botkube/source_v1.0.0_kubernetes pid=36 plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=debug msg="plugin exited" plugin=botkube/kubernetes
botkube-7d9bc7d997-7b5r2 botkube time="2023-04-06T06:43:30Z" level=info msg=Closing... component="Analytics reporter"
botkube-7d9bc7d997-7b5r2 botkube 2023/04/06 06:43:30 while sending initial help message: while creating the ConfigMap with help details: client rate limiter Wait returned an error: context canceled

Expected behavior

Should work as expected

Actual behavior

Kubebot connects and then dies

Steps to reproduce

  1. Followed the steps at https://docs.botkube.io/installation/mattermost/
$ kubectl get pods 
NAME                       READY   STATUS             RESTARTS      AGE
botkube-7d9bc7d997-7b5r2   1/2     CrashLoopBackOff   6 (54s ago)   6m41s

$ kubectl images
[Summary]: 1 namespaces, 1 pods, 2 containers and 2 different images
+--------------------------+-------------+----------------------------------------------------+
|           Pod            |  Container  |                       Image                        |
+--------------------------+-------------+----------------------------------------------------+
| botkube-7d9bc7d997-7b5r2 | botkube     | ghcr.io/kubeshop/botkube:v1.0.0                    |
+                          +-------------+----------------------------------------------------+
|                          | cfg-watcher | ghcr.io/kubeshop/k8s-sidecar:ignore-initial-events |
+--------------------------+-------------+----------------------------------------------------+

Secret looks like:

 15 comm_config.yaml: |
 14   # Communication settings
 13   communications:
 12     default-group:
 11       mattermost:
 10         botName: botkube
  9         channels:
  8           default:
  7             bindings:
  6               executors:
  5               - k8s-default-tools
  4               sources:
  3               - k8s-err-events
  2               - k8s-recommendation-events
  1             name: notifications
16              notification:                                                                                                                                                          
  1               disabled: false
  2         enabled: true
  3         team: k8s
  4         token: XXXXXXXXXX
  5         url: https://XXXXXXXXXXXXXXX

Deployment:

$ kubectl print-env pod botkube-7d9bc7d997-7b5r2
BOTKUBE_CONFIG_PATHS=/config/global_config.yaml,/config/comm_config.yaml,/config/_runtime_state.yaml,/startup-config/_startup_state.yaml
BOTKUBE_SETTINGS_METRICS__PORT=2112
BOTKUBE_SETTINGS_SYSTEM__CONFIG__MAP_NAMESPACE=botkube
BOTKUBE_SETTINGS_PERSISTENT__CONFIG_RUNTIME_CONFIG__MAP_NAMESPACE=botkube
BOTKUBE_SETTINGS_PERSISTENT__CONFIG_STARTUP_CONFIG__MAP_NAMESPACE=botkube
BOTKUBE_CONFIG__WATCHER_DEPLOYMENT_NAMESPACE=botkube
BOTKUBE_CONFIG__WATCHER_DEPLOYMENT_NAME=botkube
CONFIG_PROVIDER_ENDPOINT=https://api.botkube.io/graphql
LOG_LEVEL_SOURCE_BOTKUBE_KUBERNETES=debug
FOLDER=/tmp/watched-cfg/
RESOURCE=both
LOG_LEVEL=DEBUG
NAMESPACE=botkube
LABEL=botkube.io/config-watch
LABEL_VALUE=true
REQ_URL=http://botkube:2113/reload
REQ_IGNORE_INITIAL_EVENT=true
REQ_METHOD=POST
IGNORE_ALREADY_PROCESSED=true
pkosiec commented 1 year ago

Hi @tchellomello, could you please enable debug logging for the problematic plugin?

--set 'settings.log.level=debug' \ # debug logging for Botkube Core
--set='sources.k8s-err-events.botkube/kubernetes.config.log.level=debug' \ # debug logging on plugin side for the `k8s-err-events` config
--set='sources.k8s-recommendation-events.botkube/kubernetes.config.log.level=debug' \ # debug logging on plugin side for the `k8s-recommendation-events` config
--set='extraEnv[0].name=LOG_LEVEL_SOURCE_BOTKUBE_KUBERNETES' \ # enable debug logging for kubernetes plugin to print stdout debug logs from plugins - part 1
--set='extraEnv[0].value=debug' # enable debug logging for kubernetes plugin to print stdout debug logs from plugins - part 2

Please post the logs once you upgrade your Botkube Helm release. Thanks!

tchellomello commented 1 year ago

@pkosiec here goes:

botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=info msg="Using API Key starting with \"xUd\"..." component="Analytics reporter"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Marking executor plugin as enabled" groupName=k8s-default-tools pluginKey=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Marking executor plugin as enabled" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Source plugin defined but not enabled." groupName=prometheus pluginKey=botkube/prometheus
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=info msg="Starting Plugin Manager for all enabled plugins" component="Plugin Manager" enabledExecutors="botkube/helm,botkube/kubectl" enabledSources=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=debug msg="Downloading repository index" component="Plugin Manager" forceUpdate=false repo=botkube url="https://github.com/kubeshop/botkube/releases/download/v1.0.0/plugins-index.yaml"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:44Z" level=info msg="Downloading plugin..." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager" url="https://github.com/kubeshop/botkube/releases/download/v1.0.0/executor_helm_linux_amd64"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:45Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:45Z" level=info msg="Downloading dependency..." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager" dependencyName=helm dependencyUrl="https://get.helm.sh/helm-v3.6.3-linux-amd64.tar.gz//linux-amd64"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:46Z" level=info msg="Executor plugin registered successfully." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager" plugin=botkube/helm version=v1.0.0
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:46Z" level=info msg="Downloading plugin..." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager" url="https://github.com/kubeshop/botkube/releases/download/v1.0.0/executor_kubectl_linux_amd64"
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.078299+00:00", "level": "INFO", "msg": "Starting collector"}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.078446+00:00", "level": "WARNING", "msg": "No folder annotation was provided, defaulting to k8s-sidecar-target-directory"}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.078528+00:00", "level": "DEBUG", "msg": "Filter labels with value: true"}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.078611+00:00", "level": "DEBUG", "msg": "Selected resource type: ('secret', 'configmap')"}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.078735+00:00", "level": "INFO", "msg": "Loading incluster config ..."}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.079300+00:00", "level": "INFO", "msg": "Config for cluster api at 'https://10.96.0.1:443' loaded..."}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.079402+00:00", "level": "INFO", "msg": "Unique filenames will not be enforced."}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.079481+00:00", "level": "INFO", "msg": "5xx response content will not be enabled."}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.097873+00:00", "level": "DEBUG", "msg": "response body: {\n  \"major\": \"1\",\n  \"minor\": \"26\",\n  \"gitVersion\": \"v1.26.1\",\n  \"gitCommit\": \"8f94681cd294aa8cfd3407b8191f6c70214973a4\",\n  \"gitTreeState\": \"clean\",\n  \"buildDate\": \"2023-01-18T15:51:25Z\",\n  \"goVersion\": \"go1.19.5\",\n  \"compiler\": \"gc\",\n  \"platform\": \"linux/amd64\"\n}"}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.098335+00:00", "level": "INFO", "msg": "Ignore already processed resource version will be enabled."}
botkube-77f978d678-jb65n cfg-watcher {"time": "2023-04-12T16:04:46.098428+00:00", "level": "DEBUG", "msg": "Initial list or first event for a given resource will skip requests to a given URL."}
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=info msg="Downloading dependency..." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager" dependencyName=kubectl dependencyUrl="https://dl.k8s.io/release/v1.26.0/bin/linux/amd64/kubectl"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=info msg="Executor plugin registered successfully." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager" plugin=botkube/kubectl version=v1.0.0
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="starting plugin" args="[/tmp/botkube/executor_v1.0.0_helm]" path=/tmp/botkube/executor_v1.0.0_helm plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="plugin started" path=/tmp/botkube/executor_v1.0.0_helm pid=23 plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/executor_v1.0.0_helm plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="plugin address" address=/tmp/plugin432654523 network=unix plugin=botkube/helm subsystem_name=botkube/helm.executor_v1.0.0_helm timestamp="2023-04-12T16:04:47.881Z"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="using plugin" plugin=botkube/helm version=1
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="starting plugin" args="[/tmp/botkube/executor_v1.0.0_kubectl]" path=/tmp/botkube/executor_v1.0.0_kubectl plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="plugin started" path=/tmp/botkube/executor_v1.0.0_kubectl pid=38 plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/executor_v1.0.0_kubectl plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="plugin address" address=/tmp/plugin3747991002 network=unix plugin=botkube/kubectl subsystem_name=botkube/kubectl.executor_v1.0.0_kubectl timestamp="2023-04-12T16:04:47.899Z"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=debug msg="using plugin" plugin=botkube/kubectl version=1
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:47Z" level=info msg="Downloading plugin..." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager" url="https://github.com/kubeshop/botkube/releases/download/v1.0.0/source_kubernetes_linux_amd64"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Source plugin registered successfully." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager" plugin=botkube/kubernetes version=v1.0.0
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="starting plugin" args="[/tmp/botkube/source_v1.0.0_kubernetes]" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="plugin started" path=/tmp/botkube/source_v1.0.0_kubernetes pid=52 plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="plugin address" address=/tmp/plugin1387473373 network=unix plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.source_v1.0.0_kubernetes timestamp="2023-04-12T16:04:48.846Z"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="using plugin" plugin=botkube/kubernetes version=1
botkube-77f978d678-jb65n botkube W0412 16:04:48.854265       1 client_config.go:617] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Starting server on address \":2114\"" component="Health server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Starting server on address \":2112\"" component="Metrics server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Marking executor plugin as enabled" component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Marking executor plugin as enabled" component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Source plugin defined but not enabled." component="Help Executor" groupName=prometheus pluginKey=botkube/prometheus
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Source plugin defined and enabled but not used by any platform or standalone action" component="Help Executor" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Skipping waiting for Config Watcher sync..." component="Config Watcher Sync"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Starting server on address \":2113\"" component="Lifecycle server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Starting bot" bot=Mattermost commGroup=default-group
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=debug msg="Sending message to channel \"8jcpsds79jyoucmt4sgrxjmzqe\": {Header: Description:Botkube is now active for \"toca\" cluster :rocket: Metadata:<nil> Message:{Type: BaseBody:{CodeBlock: Plaintext:} Timestamp:0001-01-01 00:00:00 +0000 UTC Sections:[{Base:{Header:Using multiple instances Description:If you are running multiple Botkube instances in the same channel to interact with toca, make sure to specify the cluster name when typing commands. Body:{CodeBlock:--cluster-name=toca\n Plaintext:}} Buttons:[] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Ping your cluster Description:Check the status of connected Kubernetes cluster(s). Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} ping Name:Check status Command:{{BotName}} ping URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Manage incoming notifications Description: Body:{CodeBlock:{{BotName}} [enable|disable|status] notifications\n Plaintext:}} Buttons:[{Description: Name:Enable notifications Command:{{BotName}} enable notifications URL: Style:} {Description: Name:Disable notifications Command:{{BotName}} disable notifications URL: Style:} {Description: Name:Get status Command:{{BotName}} status notifications URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Notification settings for this channel Description:By default, Botkube will notify only about cluster errors and recommendations. Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} edit SourceBindings Name:Adjust notifications Command:{{BotName}} edit SourceBindings URL: Style:primary}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Manage automated actions Description: Body:{CodeBlock:{{BotName}} [list|enable|disable] action [action name]\n Plaintext:}} Buttons:[{Description: Name:List available actions Command:{{BotName}} list actions URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:View current Botkube configuration Description: Body:{CodeBlock:{{BotName}} show config\n Plaintext:}} Buttons:[{Description: Name:Display configuration Command:{{BotName}} show config URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:List executors and aliases Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} list executors Name:List executors Command:{{BotName}} list executors URL: Style:} {Description:{{BotName}} list aliases Name:List executor aliases Command:{{BotName}} list aliases URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Run Helm commands Description:You can run Helm commands directly from Mattermost! Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} helm help Name:Show help Command:{{BotName}} helm help URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Run kubectl commands (if enabled) Description:You can run kubectl commands directly from Mattermost! Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} kubectl get services Name:Run command Command:{{BotName}} kubectl get services URL: Style:} {Description:{{BotName}} kubectl get pods Name:Run command Command:{{BotName}} kubectl get pods URL: Style:} {Description:{{BotName}} kubectl get deployments Name:Run command Command:{{BotName}} kubectl get deployments URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Angry? Amazed? Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} feedback Name:Give feedback Command: URL:https://feedback.botkube.io Style:primary}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header: Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description: Name:Read our docs Command: URL:https://docs.botkube.io Style:} {Description: Name:Join our Slack Command: URL:https://join.botkube.io Style:} {Description: Name:Follow us on Twitter Command: URL:https://twitter.com/botkube_io Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]}] PlaintextInputs:[] OnlyVisibleForYou:false ReplaceOriginal:false}}" bot=Mattermost commGroup=default-group
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Botkube connected to Mattermost!" bot=Mattermost commGroup=default-group
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Shutdown requested. Finishing..." component="Metrics server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Shutdown requested. Finishing..." component="Lifecycle server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:48Z" level=info msg="Shutdown requested. Finishing..." component="Health server"
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="Message successfully sent to channel \"8jcpsds79jyoucmt4sgrxjmzqe\"" bot=Mattermost commGroup=default-group
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.stdio
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubectl subsystem_name=botkube/kubectl.stdio
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/helm subsystem_name=botkube/helm.stdio
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=info msg="plugin process exited" path=/tmp/botkube/source_v1.0.0_kubernetes pid=52 plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="plugin exited" plugin=botkube/kubernetes
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_helm pid=23 plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_kubectl pid=38 plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="plugin exited" plugin=botkube/helm
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=debug msg="plugin exited" plugin=botkube/kubectl
botkube-77f978d678-jb65n botkube time="2023-04-12T16:04:49Z" level=info msg=Closing... component="Analytics reporter"
botkube-77f978d678-jb65n botkube 2023/04/12 16:04:49 while sending initial help message: while creating the ConfigMap with help details: client rate limiter Wait returned an error: context canceled
tchellomello commented 1 year ago

@pkosiec I was debugging this and I believe the issue could be related with the websocket.

On my private mattermost instance, I have it hosted under a particular URL http://my-endpoint/mymattermost and looking at some logs, it seems the botkube is not respecting the baseURL for it.

Below are the logs from my ingress controller

ingress-nginx-public-controller-65cfbff6cc-q6jlq controller 174.247.0.213 - - [13/Apr/2023:05:28:50 +0000] "GET /mattermost/api/v4/websocket?connection_id=mhgu8g4kgbb8tycy&sequence_number=5 HTTP/1.1" 101 530 "-" "okhttp/4.10.0" 433 3.592 [mattermost-mmtatu-8065] [] 10.223.28.173:8065 0 3.592 101 746ccaa7cd542ea782f740fccbd39e03

## ^above you can see the mattermost android client worked and respected the URL namespace

ingress-nginx-public-controller-65cfbff6cc-q6jlq controller 10.223.28.130 - - [13/Apr/2023:05:29:03 +0000] "GET /api/v4/websocket HTTP/1.1" 404 146 "-" "Go-http-client/1.1" 209 0.000 [upstream-default-backend] [] 127.0.0.1:8181 146 0.000 404 f4313ecba6d052d9a256580e98e356d9

^^^ here is the `botkube` POD which is not respecting it.

However, for the initial message, I do see the URL being respected by botkube

ingress-nginx-public-controller-65cfbff6cc-q6jlq controller 10.223.28.130 - - [13/Apr/2023:04:26:58 +0000] "POST /mattermost/api/v4/teams/search HTTP/2.0" 200 395 "-" "Go-http-client/2.0" 110 0.002 [mattermost-mmtatu-8065] [] 10.223.28.173:8065 395 0.003 200 98a9309af71673ab2ae342effae6bcc5

It seems that the websocket is not using the serverURL and I cannot configure it neither.

https://github.com/kubeshop/botkube/blob/a69f7cfccc768877f7a6027817b720442987dffc/pkg/bot/mattermost.go#L86-L90

https://github.com/kubeshop/botkube/blob/a69f7cfccc768877f7a6027817b720442987dffc/pkg/bot/mattermost.go#L155-L170

Which then following the code it seems to hit the following snippet https://github.com/kubeshop/botkube/blob/a69f7cfccc768877f7a6027817b720442987dffc/pkg/bot/mattermost.go#L155-L170

tchellomello commented 1 year ago

So I've changed my external ingress controller to also map the websocket for my Mattermost instance and I see it a 302 now, however I'm still cannot use botkube. 

botkube-75b88bd7bb-dqw65   1/2     Running             2 (19s ago)   26s   10.223.28.130   p53.XXXXX   <none>           <none>
botkube-75b88bd7bb-dqw65   1/2     Error               4 (41s ago)   98s   10.223.28.130   p53.xxxx   <none>           <none>
botkube-75b88bd7bb-dqw65   1/2     CrashLoopBackOff    4 (3s ago)    101s   10.223.28.130   p53.xxxx  <none>           <none>

ingress-nginx-public-controller-65cfbff6cc-q6jlq controller 10.223.28.130 - - [13/Apr/2023:05:48:14 +0000] "GET /api/v4/websocket HTTP/1.1" 302 51 "-" "Go-http-client/1.1" 209 0.001 [mattermost-mmtatu-8065] [] 10.223.28.173:8065 51 0.001 302 3aaeb81018c96638c039db7f3e983e8a

So yeah, besides the error still exists, it seems to be a bit in which the websocket should respect the serverURL or at least make it configurable as well.

Still it produced the logs below:

botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Using API Key starting with \"xUd\"..." component="Analytics reporter"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking executor plugin as enabled" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking executor plugin as enabled" groupName=k8s-default-tools pluginKey=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Source plugin defined but not enabled." groupName=prometheus pluginKey=botkube/prometheus
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Starting Plugin Manager for all enabled plugins" component="Plugin Manager" enabledExecutors="botkube/kubectl,botkube/helm" enabledSources=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Binary \"kubectl\" found locally. Skipping..." component="Plugin Manager"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Executor plugin registered successfully." binPath=/tmp/botkube/executor_v1.0.0_kubectl component="Plugin Manager" plugin=botkube/kubectl version=v1.0.0
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Binary \"helm\" found locally. Skipping..." component="Plugin Manager"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Executor plugin registered successfully." binPath=/tmp/botkube/executor_v1.0.0_helm component="Plugin Manager" plugin=botkube/helm version=v1.0.0
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="starting plugin" args="[/tmp/botkube/executor_v1.0.0_kubectl]" path=/tmp/botkube/executor_v1.0.0_kubectl plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin started" path=/tmp/botkube/executor_v1.0.0_kubectl pid=21 plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/executor_v1.0.0_kubectl plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="using plugin" plugin=botkube/kubectl version=1
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin address" address=/tmp/plugin2065407357 network=unix plugin=botkube/kubectl subsystem_name=botkube/kubectl.executor_v1.0.0_kubectl timestamp="2023-04-13T05:52:28.499Z"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="starting plugin" args="[/tmp/botkube/executor_v1.0.0_helm]" path=/tmp/botkube/executor_v1.0.0_helm plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin started" path=/tmp/botkube/executor_v1.0.0_helm pid=28 plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/executor_v1.0.0_helm plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin address" address=/tmp/plugin469763495 network=unix plugin=botkube/helm subsystem_name=botkube/helm.executor_v1.0.0_helm timestamp="2023-04-13T05:52:28.590Z"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="using plugin" plugin=botkube/helm version=1
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Ensuring plugin dependencies are downloaded..." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Source plugin registered successfully." binPath=/tmp/botkube/source_v1.0.0_kubernetes component="Plugin Manager" plugin=botkube/kubernetes version=v1.0.0
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=warning msg="plugin configured with a nil SecureConfig" plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="starting plugin" args="[/tmp/botkube/source_v1.0.0_kubernetes]" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin started" path=/tmp/botkube/source_v1.0.0_kubernetes pid=37 plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="waiting for RPC address" path=/tmp/botkube/source_v1.0.0_kubernetes plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="using plugin" plugin=botkube/kubernetes version=1
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin address" address=/tmp/plugin1638856606 network=unix plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.source_v1.0.0_kubernetes timestamp="2023-04-13T05:52:28.673Z"
botkube-75b88bd7bb-dqw65 botkube W0413 05:52:28.674580       1 client_config.go:617] Neither --kubeconfig nor --master was specified.  Using the inClusterConfig.  This might not work.
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Starting server on address \":2114\"" component="Health server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Starting server on address \":2112\"" component="Metrics server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking executor plugin as enabled" component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking executor plugin as enabled" component="Help Executor" groupName=k8s-default-tools pluginKey=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-err-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-err-with-logs-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-recommendation-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Source plugin defined but not enabled." component="Help Executor" groupName=prometheus pluginKey=botkube/prometheus
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-all-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Marking source plugin as enabled" component="Help Executor" groupName=k8s-create-events pluginKey=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Skipping waiting for Config Watcher sync..." component="Config Watcher Sync"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Starting bot" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Starting server on address \":2113\"" component="Lifecycle server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Sending message to channel \"8jcpsds79jyoucmt4sgrxjmzqe\": {Header: Description:Botkube is now active for \"toca\" cluster :rocket: Metadata:<nil> Message:{Type: BaseBody:{CodeBlock: Plaintext:} Timestamp:0001-01-01 00:00:00 +0000 UTC Sections:[{Base:{Header:Using multiple instances Description:If you are running multiple Botkube instances in the same channel to interact with toca, make sure to specify the cluster name when typing commands. Body:{CodeBlock:--cluster-name=toca\n Plaintext:}} Buttons:[] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Ping your cluster Description:Check the status of connected Kubernetes cluster(s). Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} ping Name:Check status Command:{{BotName}} ping URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Manage incoming notifications Description: Body:{CodeBlock:{{BotName}} [enable|disable|status] notifications\n Plaintext:}} Buttons:[{Description: Name:Enable notifications Command:{{BotName}} enable notifications URL: Style:} {Description: Name:Disable notifications Command:{{BotName}} disable notifications URL: Style:} {Description: Name:Get status Command:{{BotName}} status notifications URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Notification settings for this channel Description:By default, Botkube will notify only about cluster errors and recommendations. Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} edit SourceBindings Name:Adjust notifications Command:{{BotName}} edit SourceBindings URL: Style:primary}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Manage automated actions Description: Body:{CodeBlock:{{BotName}} [list|enable|disable] action [action name]\n Plaintext:}} Buttons:[{Description: Name:List available actions Command:{{BotName}} list actions URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:View current Botkube configuration Description: Body:{CodeBlock:{{BotName}} show config\n Plaintext:}} Buttons:[{Description: Name:Display configuration Command:{{BotName}} show config URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:List executors and aliases Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} list executors Name:List executors Command:{{BotName}} list executors URL: Style:} {Description:{{BotName}} list aliases Name:List executor aliases Command:{{BotName}} list aliases URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Run Helm commands Description:You can run Helm commands directly from Mattermost! Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} helm help Name:Show help Command:{{BotName}} helm help URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Run kubectl commands (if enabled) Description:You can run kubectl commands directly from Mattermost! Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} kubectl get services Name:Run command Command:{{BotName}} kubectl get services URL: Style:} {Description:{{BotName}} kubectl get pods Name:Run command Command:{{BotName}} kubectl get pods URL: Style:} {Description:{{BotName}} kubectl get deployments Name:Run command Command:{{BotName}} kubectl get deployments URL: Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header:Angry? Amazed? Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description:{{BotName}} feedback Name:Give feedback Command: URL:https://feedback.botkube.io Style:primary}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]} {Base:{Header: Description: Body:{CodeBlock: Plaintext:}} Buttons:[{Description: Name:Read our docs Command: URL:https://docs.botkube.io Style:} {Description: Name:Join our Slack Command: URL:https://join.botkube.io Style:} {Description: Name:Follow us on Twitter Command: URL:https://twitter.com/botkube_io Style:}] MultiSelect:{Name: Description:{CodeBlock: Plaintext:} Command: Options:[] InitialOptions:[]} Selects:{ID: Items:[]} PlaintextInputs:[] TextFields:[] BulletLists:[] Context:[]}] PlaintextInputs:[] OnlyVisibleForYou:false ReplaceOriginal:false}}" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Botkube connected to Mattermost!" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Shutdown requested. Finishing..." component="Metrics server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Shutdown requested. Finishing..." component="Lifecycle server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="Shutdown requested. Finishing..." component="Health server"
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="Message successfully sent to channel \"8jcpsds79jyoucmt4sgrxjmzqe\"" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/helm subsystem_name=botkube/helm.stdio
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.stdio
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubectl subsystem_name=botkube/kubectl.stdio
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_kubectl pid=21 plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin exited" plugin=botkube/kubectl
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="plugin process exited" path=/tmp/botkube/source_v1.0.0_kubernetes pid=37 plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin exited" plugin=botkube/kubernetes
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_helm pid=28 plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=debug msg="plugin exited" plugin=botkube/helm
botkube-75b88bd7bb-dqw65 botkube time="2023-04-13T05:52:28Z" level=info msg=Closing... component="Analytics reporter"
botkube-75b88bd7bb-dqw65 botkube 2023/04/13 05:52:29 while sending initial help message: while creating the ConfigMap with help details: client rate limiter Wait returned an error: context canceled
tchellomello commented 1 year ago

@pkosiec so good news here, I think the problem is really related with the Websocket connection.

So I've deployed a new mattermost instance which does not have any redirects (basically hosted via LoadBalancer and without a sub-path.

Using this configuration I was able to get botkube to work.

I was checking again the websocket request and I see that I received a 302 and the reason for is because my server is configured to use a sub-path and even exposing the websocket path on my nginx, that would cause the 302, however, the WS could not get established.

As a next step, I'll configure a sub-path for this testing instance to see if I can reproduce the problem.

tchellomello commented 1 year ago

@pkosiec yes, issue reproduced. Whenever the mattermost is configured to use a subpath, botkube does not work.

Mattermost configuration

image

NAME                       READY   STATUS    RESTARTS   AGE
botkube-75b88bd7bb-5zzhg   0/2     Pending   0          0s
botkube-75b88bd7bb-5zzhg   0/2     Pending   0          0s
botkube-75b88bd7bb-5zzhg   0/2     ContainerCreating   0          1s
botkube-75b88bd7bb-5zzhg   0/2     ContainerCreating   0          1s
botkube-75b88bd7bb-5zzhg   1/2     Running             0          3s
botkube-75b88bd7bb-5zzhg   1/2     Error               0          8s
botkube-75b88bd7bb-5zzhg   1/2     Error               1 (2s ago)   9s

Logs

botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Skipping waiting for Config Watcher sync..." component="Config Watcher Sync"
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Starting server on address \":2113\"" component="Lifecycle server"
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Starting bot" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Botkube connected to Mattermost!" bot=Mattermost commGroup=default-group
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Shutdown requested. Finishing..." component="Metrics server"
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Shutdown requested. Finishing..." component="Lifecycle server"
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="Shutdown requested. Finishing..." component="Health server"
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubectl subsystem_name=botkube/kubectl.stdio
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/kubernetes subsystem_name=botkube/kubernetes.stdio
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="received EOF, stopping recv loop" err="rpc error: code = Unavailable desc = error reading from server: EOF" plugin=botkube/helm subsystem_name=botkube/helm.stdio
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_helm pid=23 plugin=botkube/helm
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="plugin process exited" path=/tmp/botkube/executor_v1.0.0_kubectl pid=36 plugin=botkube/kubectl
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="plugin exited" plugin=botkube/helm
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="plugin exited" plugin=botkube/kubectl
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg="plugin process exited" path=/tmp/botkube/source_v1.0.0_kubernetes pid=50 plugin=botkube/kubernetes
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=debug msg="plugin exited" plugin=botkube/kubernetes
botkube-75b88bd7bb-5zzhg botkube time="2023-04-13T13:38:18Z" level=info msg=Closing... component="Analytics reporter"
botkube-75b88bd7bb-5zzhg botkube 2023/04/13 13:38:19 while sending initial help message: while creating the ConfigMap with help details: Post "https://10.96.0.1:443/api/v1/namespaces/botkube/configmaps": context canceled

However, if the baseURL is set to http://mattermost-test.tatu.home/ then botkube works.

image

tchellomello commented 1 year ago

Ran a quick test and I'll submit a PR shortly

package main

import (
    "fmt"
    "net/url"
)

const (
    WebSocketProtocol       = "ws://"
    WebSocketSecureProtocol = "wss://"
    httpsScheme             = "https"
)

func main() {

    URL := "https://mattermost-test.example.com"
    URL2 := "https://mattermost-test.example.com/mattermost"

    checkURL, _ := url.Parse(URL)
    fmt.Println(checkURL)

    webSocketURL := WebSocketProtocol + checkURL.Host + checkURL.Path
    fmt.Println(webSocketURL)

    checkURL, _ = url.Parse(URL2)
    fmt.Println(checkURL)
    webSocketURL2 := WebSocketProtocol + checkURL.Host + checkURL.Path
    fmt.Println(webSocketURL2)
}
❯ go run test.go
https://mattermost-test.example.com
ws://mattermost-test.example.com
https://mattermost-test.example.com/mattermost
ws://mattermost-test.example.com/mattermost
tchellomello commented 1 year ago

@pkosiec submmited https://github.com/kubeshop/botkube/pull/1040

pkosiec commented 1 year ago

Hello again @tchellomello, Thank you very much for such deep debugging, and I'm really glad you found the root cause, which wasn't so obvious.

We really appreciate your PR! It will be merged today once CI check pass and released as a part of our next release (planned ~ 3-4 weeks). In the meantime you'll be able to use the latest image built from main, or we can help building a custom image to use in the meantime.

Again, thank you very much for such a valuable contribution! 🎉 🚀

pkosiec commented 1 year ago

@tchellomello Okay, CI pipeline passed on main, so now you can use the image ghcr.io/kubeshop/botkube:v9.99.9-dev which has your bug fix 👍 You can use --set image.tag=v9.99.9-dev when installing Botkube Helm chart v1.0.0.

Remember that the image will be overriden with each commit on main, so until we have 1.1.0, you can pull it locally, retag and push in your own registry 👍

tchellomello commented 1 year ago

@pkosiec I tested with the image ghcr.io/kubeshop/pr/botkube:1040-PR and it's working now :)

❯ kubectl get pods -w
NAME                       READY   STATUS    RESTARTS   AGE
botkube-5474f55bc6-89x4t   2/2     Running   0          41s

❯ kubectl images 
[Summary]: 1 namespaces, 1 pods, 2 containers and 2 different images
+--------------------------+-------------+----------------------------------------------------+
|           Pod            |  Container  |                       Image                        |
+--------------------------+-------------+----------------------------------------------------+
| botkube-5474f55bc6-89x4t | botkube     | ghcr.io/kubeshop/pr/botkube:1040-PR                |
+                          +-------------+----------------------------------------------------+
|                          | cfg-watcher | ghcr.io/kubeshop/k8s-sidecar:ignore-initial-events |
+--------------------------+-------------+----------------------------------------------------+

I've copied and pushed it to internal registry so I can use in the meantime.

image