Socket Mode: ENOTSOCK every 300 minutes on Windows #1055
Description
Edit: updated reproducible versions to latest.
Functionality is not impacted; the reconnect happens properly. This bug is about log spam.
Reproducible in:
slack-sdk-3.7.0
slack-bolt-1.6.1
Python 3.7.8
MINGW64_NT-10.0-18363
Microsoft Windows [Version 10.0.18363.1621]
Steps to reproduce:
app = slack_bolt.App(token=<OAUTH_TOKEN>, signing_secret=<SIGN_SECRET>, logger=...)
handler = slack_bolt.adapter.socket_mode.SocketModeHandler(app, <APP_TOKEN>)Run, then wait 300 minutes.
Actual result:
Every 300 minutes, this error is logged.
2021-07-06 18:53:32,090 S.Sok ERROR on_error invoked (session id: 2585b6bb-07ea-470e-be5c-449bf120f013, error: OSError, message: [WinError 10038] An operation was attempted on something that is not a socket)
Traceback (most recent call last):
File "...\slack_sdk\socket_mode\builtin\connection.py", line 289, in run_until_completion
all_message_trace_enabled=self.all_message_trace_enabled,
File "...\slack_sdk\socket_mode\builtin\internals.py", line 235, in _receive_messages
logger=logger,
File "...\slack_sdk\socket_mode\builtin\internals.py", line 251, in _fetch_messages
remaining_bytes = receive()
File "...\slack_sdk\socket_mode\builtin\internals.py", line 226, in receive
raise e
File "...\slack_sdk\socket_mode\builtin\internals.py", line 217, in receive
received_bytes = sock.recv(size)
File "C:\python3\lib\ssl.py", line 1058, in recv
return super().recv(buflen, flags)
OSError: [WinError 10038] An operation was attempted on something that is not a socket
Analysis
10038 is WSAENOTSOCK and (in Python on Windows) also errno.ENOTSOCK. It's roughly comparable to EBADF (see for example https://bugs.python.org/issue13344) Should it be caught in _fetch_messages?
except OSError as e:
if e.errno == errno.EBADF: # if e.errno in (errno.EBADF, errno.ENOTSOCK)
logger.debug("The connection seems to be already closed.")
return bytes()Other info
Every now and then (~25% of the time?) this error is logged immediately afterwards.
2021-07-06 18:53:35,412 S.Sok ERROR Failed to establish a connection (session id: f1c1ee8e-a386-4e8a-8bd4-81b911c4a813, error: The read operation timed out)
Traceback (most recent call last):
File "...\slack_sdk\socket_mode\builtin\connection.py", line 139, in connect
status, headers, text = _parse_handshake_response(sock)
File "...\slack_sdk\socket_mode\builtin\internals.py", line 150, in _parse_handshake_response
line = _read_http_response_line(sock)
File "...\slack_sdk\socket_mode\builtin\internals.py", line 129, in _read_http_response_line
c: str = sock.recv(1).decode("utf-8")
File "C:\python3\lib\ssl.py", line 1056, in recv
return self.read(buflen)
File "C:\python3\lib\ssl.py", line 931, in read
return self._sslobj.read(len)
socket.timeout: The read operation timed out