Summary
Throughout Socket Mode, debug logs are guarded like this:
if self.logger.level <= logging.DEBUG:
self.logger.debug(f"... {expensive_call()} ...")The guard exists to avoid building the message string when debug is off (the f-string argument is evaluated eagerly, before debug() can no-op it). That's a valid goal — e.g. builtin/client.py calls debug_redacted_message_string(message), and client.py calls self.message_queue.qsize() inside the message.
But logger.level is the wrong check: it's only the level explicitly set on that exact logger, defaulting to NOTSET (0). These loggers are created with logging.getLogger(__name__) and setLevel() is never called on them. So with the usual logging.basicConfig(level=logging.INFO) (which configures the root logger), logger.level stays 0, 0 <= 10 is always True, and the guard passes anyway — the expensive string still gets built. The optimization silently does nothing in the most common setup.
Suggested change
Replace:
if self.logger.level <= logging.DEBUG:
with:
if self.logger.isEnabledFor(logging.DEBUG):
isEnabledFor() uses the effective level (walking up the logger hierarchy via getEffectiveLevel()), so it correctly short-circuits when logging is configured at the root/parent — which is what the guard was meant to do.
Where the guarded message is cheap (e.g. it only interpolates an already-computed value), the guard could simply be dropped instead.
Scope
Spotted in slack_sdk/socket_mode/, but the same logger.level <= logging.DEBUG idiom appears ~88 times across ~23 files in slack_sdk/ (webhook, scim, web, audit_logs, rtm, oauth, …). isEnabledFor is currently used nowhere. Worth deciding whether to fix Socket Mode only or apply the change project-wide.
Summary
Throughout Socket Mode, debug logs are guarded like this:
The guard exists to avoid building the message string when debug is off (the f-string argument is evaluated eagerly, before
debug()can no-op it). That's a valid goal — e.g.builtin/client.pycallsdebug_redacted_message_string(message), andclient.pycallsself.message_queue.qsize()inside the message.But
logger.levelis the wrong check: it's only the level explicitly set on that exact logger, defaulting toNOTSET(0). These loggers are created withlogging.getLogger(__name__)andsetLevel()is never called on them. So with the usuallogging.basicConfig(level=logging.INFO)(which configures the root logger),logger.levelstays0,0 <= 10is alwaysTrue, and the guard passes anyway — the expensive string still gets built. The optimization silently does nothing in the most common setup.Suggested change
Replace:
with:
isEnabledFor()uses the effective level (walking up the logger hierarchy viagetEffectiveLevel()), so it correctly short-circuits when logging is configured at the root/parent — which is what the guard was meant to do.Where the guarded message is cheap (e.g. it only interpolates an already-computed value), the guard could simply be dropped instead.
Scope
Spotted in
slack_sdk/socket_mode/, but the samelogger.level <= logging.DEBUGidiom appears ~88 times across ~23 files inslack_sdk/(webhook, scim, web, audit_logs, rtm, oauth, …).isEnabledForis currently used nowhere. Worth deciding whether to fix Socket Mode only or apply the change project-wide.