Skip to content

Commit dd7a9be

Browse files
authored
Make the aiohttp-based SocketModeClient's debug logging more consistent with the built-in one (#1122) (#1134)
1 parent 1de0d2a commit dd7a9be

1 file changed

Lines changed: 54 additions & 41 deletions

File tree

slack_sdk/socket_mode/aiohttp/__init__.py

Lines changed: 54 additions & 41 deletions
Original file line numberDiff line numberDiff line change
@@ -164,16 +164,18 @@ async def monitor_current_session(self) -> None:
164164
)
165165
break
166166
try:
167-
# The logging here is for detailed trouble shooting of potential issues in this client.
168-
# If you don't see this log for a while, it means that
169-
# this receive_messages execution is no longer working for some reason.
170-
counter_for_logging = (counter_for_logging + 1) % logging_interval
171-
if counter_for_logging == 0:
172-
log_message = (
173-
f"{logging_interval} session verification executed after the previous same log"
174-
f" ({session_id})"
175-
)
176-
self.logger.debug(log_message)
167+
if self.trace_enabled and self.logger.level <= logging.DEBUG:
168+
# The logging here is for detailed investigation on potential issues in this client.
169+
# If you don't see this log for a while, it means that
170+
# this receive_messages execution is no longer working for some reason.
171+
counter_for_logging += 1
172+
if counter_for_logging >= logging_interval:
173+
counter_for_logging = 0
174+
log_message = (
175+
"#monitor_current_session method has been verifying if this session is active "
176+
f"(session: {session_id}, logging interval: {logging_interval})"
177+
)
178+
self.logger.debug(log_message)
177179

178180
await asyncio.sleep(self.ping_interval)
179181

@@ -250,38 +252,41 @@ async def receive_messages(self) -> None:
250252
break
251253
try:
252254
message: WSMessage = await session.receive()
253-
if self.trace_enabled and self.logger.level <= logging.DEBUG:
254-
# The following logging prints every single received message except empty message data ones.
255-
type = WSMsgType(message.type)
256-
message_type = type.name if type is not None else message.type
257-
message_data = message.data
258-
if isinstance(message_data, bytes):
259-
message_data = message_data.decode("utf-8")
260-
if len(message_data) > 0:
261-
# To skip the empty message that Slack server-side often sends
262-
self.logger.debug(
263-
f"Received message "
264-
f"(type: {message_type}, "
265-
f"data: {message_data}, "
266-
f"extra: {message.extra}, "
267-
f"session: {session_id})"
255+
# just in case, checking if the value is not None
256+
if message is not None:
257+
if self.logger.level <= logging.DEBUG:
258+
# The following logging prints every single received message
259+
# except empty message data ones.
260+
type = WSMsgType(message.type)
261+
message_type = (
262+
type.name if type is not None else message.type
268263
)
264+
message_data = message.data
265+
if isinstance(message_data, bytes):
266+
message_data = message_data.decode("utf-8")
267+
if len(message_data) > 0:
268+
# To skip the empty message that Slack server-side often sends
269+
self.logger.debug(
270+
f"Received message "
271+
f"(type: {message_type}, "
272+
f"data: {message_data}, "
273+
f"extra: {message.extra}, "
274+
f"session: {session_id})"
275+
)
269276

270-
# The logging here is for detailed trouble shooting of potential issues in this client.
271-
# If you don't see this log for a while, it means that
272-
# this receive_messages execution is no longer working for some reason.
273-
if self.logger.level <= logging.DEBUG:
274-
counter_for_logging = (
275-
counter_for_logging + 1
276-
) % logging_interval
277-
if counter_for_logging == 0:
278-
log_message = (
279-
f"{logging_interval} WebSocket messages received "
280-
f"after the previous same log ({session_id})"
281-
)
282-
self.logger.debug(log_message)
277+
if self.trace_enabled:
278+
# The logging here is for detailed trouble shooting of potential issues in this client.
279+
# If you don't see this log for a while, it can mean that
280+
# this receive_messages execution is no longer working for some reason.
281+
counter_for_logging += 1
282+
if counter_for_logging >= logging_interval:
283+
counter_for_logging = 0
284+
log_message = (
285+
"#receive_messages method has been working without any issues "
286+
f"(session: {session_id}, logging interval: {logging_interval})"
287+
)
288+
self.logger.debug(log_message)
283289

284-
if message is not None:
285290
if message.type == WSMsgType.TEXT:
286291
message_data = message.data
287292
await self.enqueue_message(message_data)
@@ -320,7 +325,9 @@ async def receive_messages(self) -> None:
320325
f" - error : {e}, session: {session_id}"
321326
)
322327
continue
328+
323329
consecutive_error_count = 0
330+
324331
except Exception as e:
325332
consecutive_error_count += 1
326333
self.logger.error(
@@ -351,7 +358,8 @@ async def is_connected(self) -> bool:
351358
and not self.current_session.closed
352359
and not await self.is_ping_pong_failing()
353360
)
354-
if connected is False and self.logger.level <= logging.DEBUG:
361+
if self.logger.level <= logging.DEBUG and connected is False:
362+
# Prints more detailed information about the inactive connection
355363
is_ping_pong_failing = await self.is_ping_pong_failing()
356364
session_id = await self.session_id()
357365
self.logger.debug(
@@ -369,9 +377,14 @@ async def session_id(self) -> str:
369377
return self.build_session_id(self.current_session)
370378

371379
async def connect(self):
372-
old_session = None if self.current_session is None else self.current_session
380+
old_session: Optional[ClientWebSocketResponse] = (
381+
None if self.current_session is None else self.current_session
382+
)
373383
if self.wss_uri is None:
384+
# If the underlying WSS URL does not exist,
385+
# acquiring a new active WSS URL from the server-side first
374386
self.wss_uri = await self.issue_new_wss_url()
387+
375388
self.current_session = await self.aiohttp_client_session.ws_connect(
376389
self.wss_uri,
377390
autoping=False,

0 commit comments

Comments
 (0)