Skip to content

"Failed to establish a connection (time out)" error in Socket Mode app #529

@nd-66-88

Description

@nd-66-88

Hi there,

I tested my app by sending slack command "/reserve server 1 " in slack channel and sending it to Slackbot. Sometimes it can process my command successfully, but it failed sometimes with an error '/reserve failed with the error "dispatch_failed" '. I also saw errors like 'socket "Failed to establish a connection (session id: ca57d1fd-747e-4bb6-ad52-6a49675ee84e, error: timed out)' from log. I was wondering if this is an expected behavior when using socket connection and what steps I should take to make my app more stable.

Reproducible in:

The slack_bolt version

slack-bolt==1.10.0
slack-sdk==3.12.0

Python runtime version

Python 3.6.8

OS info

(sw_vers && uname -v doesn't work on my server)

-bash-4.2$ cat /etc/os-release
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

-bash-4.2$ hostnamectl
Static hostname: pek-dbc2104
Icon name: computer-vm
Chassis: vm
Machine ID: 14e71ffbf40745ceb20af15c008d598f
Boot ID: dc2cbb33d5544e1cb29ac0420525f9a2
Virtualization: vmware
Operating System: CentOS Linux 7 (Core)
CPE OS Name: cpe:/o:centos:centos:7
Kernel: Linux 3.10.0-1160.25.1.el7.x86_64
Architecture: x86-64

Steps to reproduce:

(Share the commands to run, source code, and project settings (e.g., setup.py))

  1. my source code:

bot_slack.py:

import os
import requests
import logging
import traceback
from slack_bolt import App
from slack_bolt.adapter.socket_mode import SocketModeHandler
from slack_sdk import WebClient
from lib import log 

my_client = WebClient(token=os.environ.get("SLACK_BOT_TOKEN"))
app = App(token=os.environ.get("SLACK_BOT_TOKEN"))

def send_request(username, server, hours):
    res_code = 200
    res_msg = "sucess"
    return res_code, res_msg

@app.command("/reserve")
def reserve_server(ack, respond, command, body):
    result = "init"
    try:
        ack()
        logging.info(body)
        user_id = body["user_id"]
        result = my_client.users_info(
            user=user_id
        )
        email = result["user"]["profile"]["email"]
        logging.info(f"current user email is: {email}")
        username = email.split("@")[0]
        user_input = body["text"]
        logging.info(f"User input is: {user_input}")
        str_list = user_input.strip().split(" ")
        server = str_list[0].strip()
        hours = -1
        for s in range(1, len(str_list)):
            temp = str_list[s].strip()
            if temp.isdigit():
                hours = temp
                break
        if hours == -1:
            result = "Invalid input"
        else:
            status_code, resp_msg = send_request(username, server, hours)
            if status_code == 200:
                result = "Successfully reserve server"
            else:
                result = "Fail to reserve server"
    except Exception as e:
        logging.error(traceback.print_exc())
        result = "Fail to process your command: {}".format(e)
    finally:
        logging.info(result)
        respond(text=result)

@app.error
def custom_error_handler(error, body, logger):
    logger.exception(f"Error: {error}")
    logger.info(f"Request body: {body}")

if __name__ == "__main__":
    log.my_log('./log/reserve')
    handler = SocketModeHandler(app, os.environ["SLACK_APP_TOKEN"])
    handler.start()

lib/log.py:

import os
import logging
import logging.handlers

def my_log(log_path, level=logging.DEBUG, when="D", backup=7,
             format="%(levelname)s: %(asctime)s: %(filename)s:%(lineno)d * %(thread)d %(message)s",
             datefmt="%m-%d %h:%m:%s"):
    my_formatter = logging.Formatter(format, datefmt)
    logger = logging.getLogger()
    logger.setLevel(level)

    dir = os.path.dirname(log_path)
    if not os.path.isdir(dir):
        os.makedirs(dir)

    handler = logging.handlers.TimedRotatingFileHandler(log_path + ".log",
                                                        when=when,
                                                        backupCount=backup)
    handler.setLevel(level)
    handler.setFormatter(my_formatter)
    logger.addHandler(handler)
  1. Library I used:
# I create a virtual env
python3 -m venv .venv
# activate this env
source .venv/bin/activate
# then install library
python3 -m pip install slack_bolt
python3 -m pip install requests
python3 -m pip install slack_sdk
  1. shell script I use to start this app

start.sh:

python3 -m venv .venv
source .venv/bin/activate
export SLACK_BOT_TOKEN=xoxb-*
export SLACK_APP_TOKEN=xapp-*
export PYTHONIOENCODING=utf8
python3 bot_slack.py
  1. command to start this app:
    nohup bash start.sh &

Expected result:

When I tpye command "/reserve server 1" in slack channel where I installed my slack app or send this command to Slackbot, it's expected to process my command correctly.

Actual result:

Some times it can process my request correctly, sometimes Slacktbot returned '/reserve failed with the error "dispatch_failed"'. I checked error log and found error message like:

ERROR: 11-30 Nov:11:1638341123: connection.py:173 * 139669517891328 Failed to establish a connection (session id: 3fae03da-0a0f-454a-84fb-a020bad978ac, error: timed out)
Traceback (most recent call last):
  File "/mts-pek/home/dl/slack_bot/.venv/lib64/python3.6/site-packages/slack_sdk/socket_mode/builtin/connection.py", line 116, in connect
    trace_enabled=self.trace_enabled,
  File "/mts-pek/home/dl/slack_bot/.venv/lib64/python3.6/site-packages/slack_sdk/socket_mode/builtin/internals.py", line 100, in _establish_new_socket_connection
    sock = socket.create_connection((server_hostname, server_port), receive_timeout)
  File "/usr/lib64/python3.6/socket.py", line 724, in create_connection
    raise err
  File "/usr/lib64/python3.6/socket.py", line 713, in create_connection
    sock.connect(sa)
socket.timeout: timed out

Requirements

Please read the Contributing guidelines and Code of Conduct before creating this issue or pull request. By submitting, you are agreeing to those rules.

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions