diff --git a/.github/workflows/pytype.yml b/.github/workflows/pytype.yml index 6acf4b2b5..f13674516 100644 --- a/.github/workflows/pytype.yml +++ b/.github/workflows/pytype.yml @@ -8,10 +8,10 @@ on: jobs: build: runs-on: ubuntu-latest - timeout-minutes: 15 + timeout-minutes: 20 strategy: matrix: - python-version: ['3.8'] + python-version: ['3.9'] steps: - uses: actions/checkout@v2 - name: Set up Python ${{ matrix.python-version }} diff --git a/pytest.ini b/pytest.ini index 48ce6a5fe..27f7ad257 100644 --- a/pytest.ini +++ b/pytest.ini @@ -6,3 +6,4 @@ log_date_format = %Y-%m-%d %H:%M:%S filterwarnings = ignore:"@coroutine" decorator is deprecated since Python 3.8, use "async def" instead:DeprecationWarning ignore:The loop argument is deprecated since Python 3.8, and scheduled for removal in Python 3.10.:DeprecationWarning +asyncio_mode = auto \ No newline at end of file diff --git a/scripts/run_pytype.sh b/scripts/run_pytype.sh index 273ce37f4..267fb8efe 100755 --- a/scripts/run_pytype.sh +++ b/scripts/run_pytype.sh @@ -5,5 +5,5 @@ script_dir=$(dirname $0) cd ${script_dir}/.. && \ pip install -e ".[async]" && \ pip install -e ".[adapter]" && \ - pip install "pytype==2022.2.23" && \ + pip install "pytype==2022.3.8" && \ pytype slack_bolt/ diff --git a/slack_bolt/adapter/aws_lambda/chalice_handler.py b/slack_bolt/adapter/aws_lambda/chalice_handler.py index a1edd158c..cad222a72 100644 --- a/slack_bolt/adapter/aws_lambda/chalice_handler.py +++ b/slack_bolt/adapter/aws_lambda/chalice_handler.py @@ -21,7 +21,9 @@ class ChaliceSlackRequestHandler: def __init__(self, app: App, chalice: Chalice, lambda_client: Optional[BaseClient] = None): # type: ignore self.app = app self.chalice = chalice - self.logger = get_bolt_app_logger(app.name, ChaliceSlackRequestHandler) + self.logger = get_bolt_app_logger( + app.name, ChaliceSlackRequestHandler, app.logger + ) if getenv("AWS_CHALICE_CLI_MODE") == "true" and lambda_client is None: try: diff --git a/slack_bolt/adapter/aws_lambda/handler.py b/slack_bolt/adapter/aws_lambda/handler.py index 9037ac397..bb24742e6 100644 --- a/slack_bolt/adapter/aws_lambda/handler.py +++ b/slack_bolt/adapter/aws_lambda/handler.py @@ -14,7 +14,7 @@ class SlackRequestHandler: def __init__(self, app: App): # type: ignore self.app = app - self.logger = get_bolt_app_logger(app.name, SlackRequestHandler) + self.logger = get_bolt_app_logger(app.name, SlackRequestHandler, app.logger) self.app.listener_runner.lazy_listener_runner = LambdaLazyListenerRunner( self.logger ) diff --git a/slack_bolt/app/app.py b/slack_bolt/app/app.py index baaf85fca..7ee3fb096 100644 --- a/slack_bolt/app/app.py +++ b/slack_bolt/app/app.py @@ -189,6 +189,11 @@ def message_hello(message, say): self._verification_token: Optional[str] = verification_token or os.environ.get( "SLACK_VERIFICATION_TOKEN", None ) + # If a logger is explicitly passed when initializing, the logger works as the base logger. + # The base logger's logging settings will be propagated to all the loggers created by bolt-python. + self._base_logger = logger + # The framework logger is supposed to be used for the internal logging. + # Also, it's accessible via `app.logger` as the app's singleton logger. self._framework_logger = logger or get_bolt_logger(App) self._raise_error_for_unhandled_request = raise_error_for_unhandled_request @@ -356,10 +361,15 @@ def _init_middleware_list( return if ssl_check_enabled is True: self._middleware_list.append( - SslCheck(verification_token=self._verification_token) + SslCheck( + verification_token=self._verification_token, + base_logger=self._base_logger, + ) ) if request_verification_enabled is True: - self._middleware_list.append(RequestVerification(self._signing_secret)) + self._middleware_list.append( + RequestVerification(self._signing_secret, base_logger=self._base_logger) + ) # As authorize is required for making a Bolt app function, we don't offer the flag to disable this if self._oauth_flow is None: @@ -370,24 +380,33 @@ def _init_middleware_list( # This API call is for eagerly validating the token auth_test_result = self._client.auth_test(token=self._token) self._middleware_list.append( - SingleTeamAuthorization(auth_test_result=auth_test_result) + SingleTeamAuthorization( + auth_test_result=auth_test_result, + base_logger=self._base_logger, + ) ) except SlackApiError as err: raise BoltError(error_auth_test_failure(err.response)) elif self._authorize is not None: self._middleware_list.append( - MultiTeamsAuthorization(authorize=self._authorize) + MultiTeamsAuthorization( + authorize=self._authorize, base_logger=self._base_logger + ) ) else: raise BoltError(error_token_required()) else: self._middleware_list.append( - MultiTeamsAuthorization(authorize=self._authorize) + MultiTeamsAuthorization( + authorize=self._authorize, base_logger=self._base_logger + ) ) if ignoring_self_events_enabled is True: - self._middleware_list.append(IgnoringSelfEvents()) + self._middleware_list.append( + IgnoringSelfEvents(base_logger=self._base_logger) + ) if url_verification_enabled is True: - self._middleware_list.append(UrlVerification()) + self._middleware_list.append(UrlVerification(base_logger=self._base_logger)) self._init_middleware_list_done = True # ------------------------- @@ -616,7 +635,11 @@ def middleware_func(logger, body, next): self._middleware_list.append(middleware) elif isinstance(middleware_or_callable, Callable): self._middleware_list.append( - CustomMiddleware(app_name=self.name, func=middleware_or_callable) + CustomMiddleware( + app_name=self.name, + func=middleware_or_callable, + base_logger=self._base_logger, + ) ) return middleware_or_callable else: @@ -677,9 +700,10 @@ def step( edit=edit, save=save, execute=execute, + base_logger=self._base_logger, ) elif isinstance(step, WorkflowStepBuilder): - step = step.build() + step = step.build(base_logger=self._base_logger) elif not isinstance(step, WorkflowStep): raise BoltError(f"Invalid step object ({type(step)})") @@ -759,7 +783,9 @@ def ask_for_introduction(event, say): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.event(event) + primary_matcher = builtin_matchers.event( + event, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware, True ) @@ -814,7 +840,7 @@ def __call__(*args, **kwargs): ), } primary_matcher = builtin_matchers.message_event( - keyword=keyword, constraints=constraints + keyword=keyword, constraints=constraints, base_logger=self._base_logger ) middleware.insert(0, MessageListenerMatches(keyword)) return self._register_listener( @@ -859,7 +885,9 @@ def repeat_text(ack, say, command): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.command(command) + primary_matcher = builtin_matchers.command( + command, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -908,7 +936,9 @@ def open_modal(ack, body, client): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.shortcut(constraints) + primary_matcher = builtin_matchers.shortcut( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -925,7 +955,9 @@ def global_shortcut( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.global_shortcut(callback_id) + primary_matcher = builtin_matchers.global_shortcut( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -942,7 +974,9 @@ def message_shortcut( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.message_shortcut(callback_id) + primary_matcher = builtin_matchers.message_shortcut( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -984,7 +1018,9 @@ def update_message(ack): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.action(constraints) + primary_matcher = builtin_matchers.action( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1003,7 +1039,9 @@ def block_action( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.block_action(constraints) + primary_matcher = builtin_matchers.block_action( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1021,7 +1059,9 @@ def attachment_action( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.attachment_action(callback_id) + primary_matcher = builtin_matchers.attachment_action( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1039,7 +1079,9 @@ def dialog_submission( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_submission(callback_id) + primary_matcher = builtin_matchers.dialog_submission( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1057,7 +1099,9 @@ def dialog_cancellation( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_cancellation(callback_id) + primary_matcher = builtin_matchers.dialog_cancellation( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1110,7 +1154,9 @@ def handle_submission(ack, body, client, view): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view(constraints) + primary_matcher = builtin_matchers.view( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1128,7 +1174,9 @@ def view_submission( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view_submission(constraints) + primary_matcher = builtin_matchers.view_submission( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1146,7 +1194,9 @@ def view_closed( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view_closed(constraints) + primary_matcher = builtin_matchers.view_closed( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1199,7 +1249,9 @@ def show_menu_options(ack): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.options(constraints) + primary_matcher = builtin_matchers.options( + constraints, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1216,7 +1268,9 @@ def block_suggestion( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.block_suggestion(action_id) + primary_matcher = builtin_matchers.block_suggestion( + action_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1234,7 +1288,9 @@ def dialog_suggestion( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_suggestion(callback_id) + primary_matcher = builtin_matchers.dialog_suggestion( + callback_id, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1265,7 +1321,9 @@ def enable_token_revocation_listeners(self) -> None: # ------------------------- def _init_context(self, req: BoltRequest): - req.context["logger"] = get_bolt_app_logger(self.name) + req.context["logger"] = get_bolt_app_logger( + app_name=self.name, base_logger=self._base_logger + ) req.context["token"] = self._token if self._token is not None: # This WebClient instance can be safely singleton @@ -1311,7 +1369,10 @@ def _register_listener( value_to_return = functions[0] listener_matchers = [ - CustomListenerMatcher(app_name=self.name, func=f) for f in (matchers or []) + CustomListenerMatcher( + app_name=self.name, func=f, base_logger=self._base_logger + ) + for f in (matchers or []) ] listener_matchers.insert(0, primary_matcher) listener_middleware = [] @@ -1319,7 +1380,11 @@ def _register_listener( if isinstance(m, Middleware): listener_middleware.append(m) elif isinstance(m, Callable): - listener_middleware.append(CustomMiddleware(app_name=self.name, func=m)) + listener_middleware.append( + CustomMiddleware( + app_name=self.name, func=m, base_logger=self._base_logger + ) + ) else: raise ValueError(error_unexpected_listener_middleware(type(m))) @@ -1331,6 +1396,7 @@ def _register_listener( matchers=listener_matchers, middleware=listener_middleware, auto_acknowledgement=auto_acknowledgement, + base_logger=self._base_logger, ) ) return value_to_return diff --git a/slack_bolt/app/async_app.py b/slack_bolt/app/async_app.py index 0a6939390..aafdfb4b0 100644 --- a/slack_bolt/app/async_app.py +++ b/slack_bolt/app/async_app.py @@ -194,6 +194,11 @@ async def message_hello(message, say): # async function self._verification_token: Optional[str] = verification_token or os.environ.get( "SLACK_VERIFICATION_TOKEN", None ) + # If a logger is explicitly passed when initializing, the logger works as the base logger. + # The base logger's logging settings will be propagated to all the loggers created by bolt-python. + self._base_logger = logger + # The framework logger is supposed to be used for the internal logging. + # Also, it's accessible via `app.logger` as the app's singleton logger. self._framework_logger = logger or get_bolt_logger(AsyncApp) self._raise_error_for_unhandled_request = raise_error_for_unhandled_request @@ -376,31 +381,46 @@ def _init_async_middleware_list( return if ssl_check_enabled is True: self._async_middleware_list.append( - AsyncSslCheck(verification_token=self._verification_token) + AsyncSslCheck( + verification_token=self._verification_token, + base_logger=self._base_logger, + ) ) if request_verification_enabled is True: self._async_middleware_list.append( - AsyncRequestVerification(self._signing_secret) + AsyncRequestVerification( + self._signing_secret, base_logger=self._base_logger + ) ) # As authorize is required for making a Bolt app function, we don't offer the flag to disable this if self._async_oauth_flow is None: if self._token: - self._async_middleware_list.append(AsyncSingleTeamAuthorization()) + self._async_middleware_list.append( + AsyncSingleTeamAuthorization(base_logger=self._base_logger) + ) elif self._async_authorize is not None: self._async_middleware_list.append( - AsyncMultiTeamsAuthorization(authorize=self._async_authorize) + AsyncMultiTeamsAuthorization( + authorize=self._async_authorize, base_logger=self._base_logger + ) ) else: raise BoltError(error_token_required()) else: self._async_middleware_list.append( - AsyncMultiTeamsAuthorization(authorize=self._async_authorize) + AsyncMultiTeamsAuthorization( + authorize=self._async_authorize, base_logger=self._base_logger + ) ) if ignoring_self_events_enabled is True: - self._async_middleware_list.append(AsyncIgnoringSelfEvents()) + self._async_middleware_list.append( + AsyncIgnoringSelfEvents(base_logger=self._base_logger) + ) if url_verification_enabled is True: - self._async_middleware_list.append(AsyncUrlVerification()) + self._async_middleware_list.append( + AsyncUrlVerification(base_logger=self._base_logger) + ) self._init_middleware_list_done = True # ------------------------- @@ -662,7 +682,9 @@ async def middleware_func(logger, body, next): elif isinstance(middleware_or_callable, Callable): self._async_middleware_list.append( AsyncCustomMiddleware( - app_name=self.name, func=middleware_or_callable + app_name=self.name, + func=middleware_or_callable, + base_logger=self._base_logger, ) ) return middleware_or_callable @@ -730,9 +752,10 @@ def step( edit=edit, save=save, execute=execute, + base_logger=self._base_logger, ) elif isinstance(step, AsyncWorkflowStepBuilder): - step = step.build() + step = step.build(base_logger=self._base_logger) elif not isinstance(step, AsyncWorkflowStep): raise BoltError(f"Invalid step object ({type(step)})") @@ -817,7 +840,9 @@ async def ask_for_introduction(event, say): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.event(event, True) + primary_matcher = builtin_matchers.event( + event, True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware, True ) @@ -872,7 +897,10 @@ def __call__(*args, **kwargs): ), } primary_matcher = builtin_matchers.message_event( - constraints=constraints, keyword=keyword, asyncio=True + constraints=constraints, + keyword=keyword, + asyncio=True, + base_logger=self._base_logger, ) middleware.insert(0, AsyncMessageListenerMatches(keyword)) return self._register_listener( @@ -917,7 +945,9 @@ async def repeat_text(ack, say, command): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.command(command, True) + primary_matcher = builtin_matchers.command( + command, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -966,7 +996,9 @@ async def open_modal(ack, body, client): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.shortcut(constraints, True) + primary_matcher = builtin_matchers.shortcut( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -983,7 +1015,9 @@ def global_shortcut( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.global_shortcut(callback_id, True) + primary_matcher = builtin_matchers.global_shortcut( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1000,7 +1034,9 @@ def message_shortcut( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.message_shortcut(callback_id, True) + primary_matcher = builtin_matchers.message_shortcut( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1042,7 +1078,9 @@ async def update_message(ack): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.action(constraints, True) + primary_matcher = builtin_matchers.action( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1061,7 +1099,9 @@ def block_action( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.block_action(constraints, True) + primary_matcher = builtin_matchers.block_action( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1079,7 +1119,9 @@ def attachment_action( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.attachment_action(callback_id, True) + primary_matcher = builtin_matchers.attachment_action( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1097,7 +1139,9 @@ def dialog_submission( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_submission(callback_id, True) + primary_matcher = builtin_matchers.dialog_submission( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1115,7 +1159,9 @@ def dialog_cancellation( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_cancellation(callback_id, True) + primary_matcher = builtin_matchers.dialog_cancellation( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1168,7 +1214,9 @@ async def handle_submission(ack, body, client, view): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view(constraints, True) + primary_matcher = builtin_matchers.view( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1186,7 +1234,9 @@ def view_submission( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view_submission(constraints, True) + primary_matcher = builtin_matchers.view_submission( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1204,7 +1254,9 @@ def view_closed( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.view_closed(constraints, True) + primary_matcher = builtin_matchers.view_closed( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1257,7 +1309,9 @@ async def show_menu_options(ack): def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.options(constraints, True) + primary_matcher = builtin_matchers.options( + constraints, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1274,7 +1328,9 @@ def block_suggestion( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.block_suggestion(action_id, True) + primary_matcher = builtin_matchers.block_suggestion( + action_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1292,7 +1348,9 @@ def dialog_suggestion( def __call__(*args, **kwargs): functions = self._to_listener_functions(kwargs) if kwargs else list(args) - primary_matcher = builtin_matchers.dialog_suggestion(callback_id, True) + primary_matcher = builtin_matchers.dialog_suggestion( + callback_id, asyncio=True, base_logger=self._base_logger + ) return self._register_listener( list(functions), primary_matcher, matchers, middleware ) @@ -1323,7 +1381,9 @@ def enable_token_revocation_listeners(self) -> None: # ------------------------- def _init_context(self, req: AsyncBoltRequest): - req.context["logger"] = get_bolt_app_logger(self.name) + req.context["logger"] = get_bolt_app_logger( + app_name=self.name, base_logger=self._base_logger + ) req.context["token"] = self._token if self._token is not None: # This AsyncWebClient instance can be safely singleton @@ -1376,7 +1436,9 @@ def _register_listener( raise BoltError(error_listener_function_must_be_coro_func(name)) listener_matchers = [ - AsyncCustomListenerMatcher(app_name=self.name, func=f) + AsyncCustomListenerMatcher( + app_name=self.name, func=f, base_logger=self._base_logger + ) for f in (matchers or []) ] listener_matchers.insert(0, primary_matcher) @@ -1386,7 +1448,9 @@ def _register_listener( listener_middleware.append(m) elif isinstance(m, Callable) and inspect.iscoroutinefunction(m): listener_middleware.append( - AsyncCustomMiddleware(app_name=self.name, func=m) + AsyncCustomMiddleware( + app_name=self.name, func=m, base_logger=self._base_logger + ) ) else: raise ValueError(error_unexpected_listener_middleware(type(m))) @@ -1399,6 +1463,7 @@ def _register_listener( matchers=listener_matchers, middleware=listener_middleware, auto_acknowledgement=auto_acknowledgement, + base_logger=self._base_logger, ) ) diff --git a/slack_bolt/listener/async_listener.py b/slack_bolt/listener/async_listener.py index 9102ec160..249567c7e 100644 --- a/slack_bolt/listener/async_listener.py +++ b/slack_bolt/listener/async_listener.py @@ -101,6 +101,7 @@ def __init__( matchers: Sequence[AsyncListenerMatcher], middleware: Sequence[AsyncMiddleware], auto_acknowledgement: bool = False, + base_logger: Optional[Logger] = None, ): self.app_name = app_name self.ack_function = ack_function @@ -109,7 +110,7 @@ def __init__( self.middleware = middleware self.auto_acknowledgement = auto_acknowledgement self.arg_names = inspect.getfullargspec(ack_function).args - self.logger = get_bolt_app_logger(app_name, self.ack_function) + self.logger = get_bolt_app_logger(app_name, self.ack_function, base_logger) async def run_ack_function( self, diff --git a/slack_bolt/listener/custom_listener.py b/slack_bolt/listener/custom_listener.py index b38e80324..9822a4fa8 100644 --- a/slack_bolt/listener/custom_listener.py +++ b/slack_bolt/listener/custom_listener.py @@ -30,6 +30,7 @@ def __init__( matchers: Sequence[ListenerMatcher], middleware: Sequence[Middleware], # type: ignore auto_acknowledgement: bool = False, + base_logger: Optional[Logger] = None, ): self.app_name = app_name self.ack_function = ack_function @@ -38,7 +39,7 @@ def __init__( self.middleware = middleware self.auto_acknowledgement = auto_acknowledgement self.arg_names = inspect.getfullargspec(ack_function).args - self.logger = get_bolt_app_logger(app_name, self.ack_function) + self.logger = get_bolt_app_logger(app_name, self.ack_function, base_logger) def run_ack_function( self, diff --git a/slack_bolt/listener_matcher/async_listener_matcher.py b/slack_bolt/listener_matcher/async_listener_matcher.py index 7673081fc..19995b523 100644 --- a/slack_bolt/listener_matcher/async_listener_matcher.py +++ b/slack_bolt/listener_matcher/async_listener_matcher.py @@ -21,7 +21,7 @@ async def async_matches(self, req: AsyncBoltRequest, resp: BoltResponse) -> bool import inspect from logging import Logger -from typing import Callable, Awaitable, Sequence +from typing import Callable, Awaitable, Sequence, Optional from slack_bolt.kwargs_injection.async_utils import build_async_required_kwargs from slack_bolt.logger import get_bolt_app_logger @@ -35,11 +35,17 @@ class AsyncCustomListenerMatcher(AsyncListenerMatcher): arg_names: Sequence[str] logger: Logger - def __init__(self, *, app_name: str, func: Callable[..., Awaitable[bool]]): + def __init__( + self, + *, + app_name: str, + func: Callable[..., Awaitable[bool]], + base_logger: Optional[Logger] = None + ): self.app_name = app_name self.func = func self.arg_names = inspect.getfullargspec(func).args - self.logger = get_bolt_app_logger(self.app_name, self.func) + self.logger = get_bolt_app_logger(self.app_name, self.func, base_logger) async def async_matches(self, req: AsyncBoltRequest, resp: BoltResponse) -> bool: return await self.func( diff --git a/slack_bolt/listener_matcher/builtins.py b/slack_bolt/listener_matcher/builtins.py index 2bf582f67..043a497fa 100644 --- a/slack_bolt/listener_matcher/builtins.py +++ b/slack_bolt/listener_matcher/builtins.py @@ -2,6 +2,7 @@ import inspect import re import sys +from logging import Logger from slack_bolt.error import BoltError from slack_bolt.request.payload_utils import ( @@ -40,10 +41,15 @@ # a.k.a Union[ListenerMatcher, "AsyncListenerMatcher"] class BuiltinListenerMatcher(ListenerMatcher): - def __init__(self, *, func: Callable[..., Union[bool, Awaitable[bool]]]): + def __init__( + self, + *, + func: Callable[..., Union[bool, Awaitable[bool]]], + base_logger: Optional[Logger] = None, + ): self.func = func self.arg_names = inspect.getfullargspec(func).args - self.logger = get_bolt_logger(self.func) + self.logger = get_bolt_logger(self.func, base_logger) def matches(self, req: BoltRequest, resp: BoltResponse) -> bool: return self.func( @@ -60,6 +66,7 @@ def matches(self, req: BoltRequest, resp: BoltResponse) -> bool: def build_listener_matcher( func: Callable[..., bool], asyncio: bool, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if asyncio: from .async_builtins import AsyncBuiltinListenerMatcher @@ -67,9 +74,9 @@ def build_listener_matcher( async def async_fun(body: Dict[str, Any]) -> bool: return func(body) - return AsyncBuiltinListenerMatcher(func=async_fun) + return AsyncBuiltinListenerMatcher(func=async_fun, base_logger=base_logger) else: - return BuiltinListenerMatcher(func=func) + return BuiltinListenerMatcher(func=func, base_logger=base_logger) # ------------- @@ -83,6 +90,7 @@ def event( Dict[str, Optional[Union[str, Sequence[Optional[Union[str, Pattern]]]]]], ], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if isinstance(constraints, (str, Pattern)): event_type: Union[str, Pattern] = constraints @@ -91,7 +99,7 @@ def event( def func(body: Dict[str, Any]) -> bool: return is_event(body) and _matches(event_type, body["event"]["type"]) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) elif "type" in constraints: _verify_message_event_type(constraints["type"]) @@ -104,7 +112,7 @@ def func(body: Dict[str, Any]) -> bool: ) return False - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) raise BoltError( f"event ({constraints}: {type(constraints)}) must be any of str, Pattern, and dict" @@ -117,6 +125,7 @@ def message_event( ], keyword: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if "type" in constraints and keyword is not None: _verify_message_event_type(constraints["type"]) @@ -135,7 +144,7 @@ def func(body: Dict[str, Any]) -> bool: return True return False - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) raise BoltError(f"event ({constraints}: {type(constraints)}) must be dict") @@ -181,6 +190,7 @@ def _verify_message_event_type(event_type: str) -> None: def workflow_step_execute( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return ( @@ -190,7 +200,7 @@ def func(body: Dict[str, Any]) -> bool: and _matches(callback_id, body["event"]["callback_id"]) ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------- @@ -200,11 +210,12 @@ def func(body: Dict[str, Any]) -> bool: def command( command: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_slash_command(body) and _matches(command, body["command"]) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------- @@ -214,6 +225,7 @@ def func(body: Dict[str, Any]) -> bool: def shortcut( constraints: Union[str, Pattern, Dict[str, Union[str, Pattern]]], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if isinstance(constraints, (str, Pattern)): callback_id: Union[str, Pattern] = constraints @@ -221,7 +233,7 @@ def shortcut( def func(body: Dict[str, Any]) -> bool: return is_shortcut(body) and _matches(callback_id, body["callback_id"]) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) elif "type" in constraints and "callback_id" in constraints: if constraints["type"] == "shortcut": @@ -237,21 +249,23 @@ def func(body: Dict[str, Any]) -> bool: def global_shortcut( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_global_shortcut(body) and _matches(callback_id, body["callback_id"]) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def message_shortcut( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_message_shortcut(body) and _matches(callback_id, body["callback_id"]) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------- @@ -261,6 +275,7 @@ def func(body: Dict[str, Any]) -> bool: def action( constraints: Union[str, Pattern, Dict[str, Union[str, Pattern]]], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if isinstance(constraints, (str, Pattern)): @@ -273,7 +288,7 @@ def func(body: Dict[str, Any]) -> bool: or _workflow_step_edit(constraints, body) ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) elif "type" in constraints: action_type = constraints["type"] @@ -323,11 +338,12 @@ def _block_action( def block_action( constraints: Union[str, Pattern, Dict[str, Union[str, Pattern]]], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _block_action(constraints, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def _attachment_action( @@ -340,11 +356,12 @@ def _attachment_action( def attachment_action( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _attachment_action(callback_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def _dialog_submission( @@ -357,11 +374,12 @@ def _dialog_submission( def dialog_submission( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _dialog_submission(callback_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def _dialog_cancellation( @@ -374,11 +392,12 @@ def _dialog_cancellation( def dialog_cancellation( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _dialog_cancellation(callback_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def _workflow_step_edit( @@ -391,11 +410,12 @@ def _workflow_step_edit( def workflow_step_edit( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _workflow_step_edit(callback_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------------------- @@ -405,6 +425,7 @@ def func(body: Dict[str, Any]) -> bool: def view( constraints: Union[str, Pattern, Dict[str, Union[str, Pattern]]], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if isinstance(constraints, (str, Pattern)): return view_submission(constraints, asyncio) @@ -422,37 +443,40 @@ def view( def view_submission( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_view_submission(body) and _matches( callback_id, body["view"]["callback_id"] ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def view_closed( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_view_closed(body) and _matches( callback_id, body["view"]["callback_id"] ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def workflow_step_save( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return is_workflow_step_save(body) and _matches( callback_id, body["view"]["callback_id"] ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------- @@ -462,6 +486,7 @@ def func(body: Dict[str, Any]) -> bool: def options( constraints: Union[str, Pattern, Dict[str, Union[str, Pattern]]], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: if isinstance(constraints, (str, Pattern)): @@ -470,7 +495,7 @@ def func(body: Dict[str, Any]) -> bool: constraints, body ) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) if "action_id" in constraints: return block_suggestion(constraints["action_id"], asyncio) @@ -492,11 +517,12 @@ def _block_suggestion( def block_suggestion( action_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _block_suggestion(action_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) def _dialog_suggestion( @@ -509,11 +535,12 @@ def _dialog_suggestion( def dialog_suggestion( callback_id: Union[str, Pattern], asyncio: bool = False, + base_logger: Optional[Logger] = None, ) -> Union[ListenerMatcher, "AsyncListenerMatcher"]: def func(body: Dict[str, Any]) -> bool: return _dialog_suggestion(callback_id, body) - return build_listener_matcher(func, asyncio) + return build_listener_matcher(func, asyncio, base_logger) # ------------------------- diff --git a/slack_bolt/listener_matcher/custom_listener_matcher.py b/slack_bolt/listener_matcher/custom_listener_matcher.py index 4e07006d4..dff1c1e7b 100644 --- a/slack_bolt/listener_matcher/custom_listener_matcher.py +++ b/slack_bolt/listener_matcher/custom_listener_matcher.py @@ -1,6 +1,6 @@ import inspect from logging import Logger -from typing import Callable, Sequence +from typing import Callable, Sequence, Optional from slack_bolt.kwargs_injection import build_required_kwargs from slack_bolt.logger import get_bolt_app_logger @@ -15,11 +15,17 @@ class CustomListenerMatcher(ListenerMatcher): arg_names: Sequence[str] logger: Logger - def __init__(self, *, app_name: str, func: Callable[..., bool]): + def __init__( + self, + *, + app_name: str, + func: Callable[..., bool], + base_logger: Optional[Logger] = None + ): self.app_name = app_name self.func = func self.arg_names = inspect.getfullargspec(func).args - self.logger = get_bolt_app_logger(self.app_name, self.func) + self.logger = get_bolt_app_logger(self.app_name, self.func, base_logger) def matches(self, req: BoltRequest, resp: BoltResponse) -> bool: return self.func( diff --git a/slack_bolt/logger/__init__.py b/slack_bolt/logger/__init__.py index 25f076a9a..77e26a983 100644 --- a/slack_bolt/logger/__init__.py +++ b/slack_bolt/logger/__init__.py @@ -2,24 +2,45 @@ import logging from logging import Logger -from typing import Any +from typing import Any, Optional -def get_bolt_logger(cls: Any) -> Logger: +def get_bolt_logger(cls: Any, base_logger: Optional[Logger] = None) -> Logger: logger = logging.getLogger(f"slack_bolt.{cls.__name__}") - logger.disabled = logging.root.disabled - logger.level = logging.root.level + if base_logger is not None: + _configure_from_base_logger(logger, base_logger) + else: + _configure_from_root(logger) return logger -def get_bolt_app_logger(app_name: str, cls: object = None) -> Logger: - if cls and hasattr(cls, "__name__"): - logger = logging.getLogger(f"{app_name}:{cls.__name__}") - logger.disabled = logging.root.disabled - logger.level = logging.root.level - return logger +def get_bolt_app_logger( + app_name: str, cls: object = None, base_logger: Optional[Logger] = None +) -> Logger: + logger: Logger = ( + logging.getLogger(f"{app_name}:{cls.__name__}") + if cls and hasattr(cls, "__name__") + else logging.getLogger(app_name) + ) + + if base_logger is not None: + _configure_from_base_logger(logger, base_logger) else: - logger = logging.getLogger(app_name) - logger.disabled = logging.root.disabled - logger.level = logging.root.level - return logger + _configure_from_root(logger) + return logger + + +def _configure_from_base_logger(new_logger: Logger, base_logger: Logger): + new_logger.disabled = base_logger.disabled + new_logger.level = base_logger.level + if len(new_logger.handlers) == 0: + for h in base_logger.handlers: + new_logger.addHandler(h) + if len(new_logger.filters) == 0: + for f in base_logger.filters: + new_logger.addFilter(f) + + +def _configure_from_root(new_logger: Logger): + new_logger.disabled = logging.root.disabled + new_logger.level = logging.root.level diff --git a/slack_bolt/middleware/async_custom_middleware.py b/slack_bolt/middleware/async_custom_middleware.py index d967f188e..a46219917 100644 --- a/slack_bolt/middleware/async_custom_middleware.py +++ b/slack_bolt/middleware/async_custom_middleware.py @@ -1,6 +1,6 @@ import inspect from logging import Logger -from typing import Callable, Awaitable, Any, Sequence +from typing import Callable, Awaitable, Any, Sequence, Optional from slack_bolt.kwargs_injection.async_utils import build_async_required_kwargs from slack_bolt.logger import get_bolt_app_logger @@ -16,7 +16,13 @@ class AsyncCustomMiddleware(AsyncMiddleware): arg_names: Sequence[str] logger: Logger - def __init__(self, *, app_name: str, func: Callable[..., Awaitable[Any]]): + def __init__( + self, + *, + app_name: str, + func: Callable[..., Awaitable[Any]], + base_logger: Optional[Logger] = None, + ): self.app_name = app_name if inspect.iscoroutinefunction(func): self.func = func @@ -24,7 +30,7 @@ def __init__(self, *, app_name: str, func: Callable[..., Awaitable[Any]]): raise ValueError("Async middleware function must be an async function") self.arg_names = inspect.getfullargspec(func).args - self.logger = get_bolt_app_logger(self.app_name, self.func) + self.logger = get_bolt_app_logger(self.app_name, self.func, base_logger) async def async_process( self, diff --git a/slack_bolt/middleware/authorization/async_multi_teams_authorization.py b/slack_bolt/middleware/authorization/async_multi_teams_authorization.py index 85c56cc33..1a62b5b5a 100644 --- a/slack_bolt/middleware/authorization/async_multi_teams_authorization.py +++ b/slack_bolt/middleware/authorization/async_multi_teams_authorization.py @@ -1,3 +1,4 @@ +from logging import Logger from typing import Callable, Optional, Awaitable from slack_sdk.errors import SlackApiError @@ -14,14 +15,17 @@ class AsyncMultiTeamsAuthorization(AsyncAuthorization): authorize: AsyncAuthorize - def __init__(self, authorize: AsyncAuthorize): + def __init__(self, authorize: AsyncAuthorize, base_logger: Optional[Logger] = None): """Multi-workspace authorization. Args: authorize: The function to authorize incoming requests from Slack. + base_logger: The base logger """ self.authorize = authorize - self.logger = get_bolt_logger(AsyncMultiTeamsAuthorization) + self.logger = get_bolt_logger( + AsyncMultiTeamsAuthorization, base_logger=base_logger + ) async def async_process( self, diff --git a/slack_bolt/middleware/authorization/async_single_team_authorization.py b/slack_bolt/middleware/authorization/async_single_team_authorization.py index 0c9ff9cd9..72f4992cc 100644 --- a/slack_bolt/middleware/authorization/async_single_team_authorization.py +++ b/slack_bolt/middleware/authorization/async_single_team_authorization.py @@ -1,3 +1,4 @@ +from logging import Logger from typing import Callable, Awaitable, Optional from slack_bolt.logger import get_bolt_logger @@ -12,10 +13,12 @@ class AsyncSingleTeamAuthorization(AsyncAuthorization): - def __init__(self): + def __init__(self, base_logger: Optional[Logger] = None): """Single-workspace authorization.""" self.auth_test_result: Optional[AsyncSlackResponse] = None - self.logger = get_bolt_logger(AsyncSingleTeamAuthorization) + self.logger = get_bolt_logger( + AsyncSingleTeamAuthorization, base_logger=base_logger + ) async def async_process( self, diff --git a/slack_bolt/middleware/authorization/multi_teams_authorization.py b/slack_bolt/middleware/authorization/multi_teams_authorization.py index 7aeacf259..dd7c9ad3e 100644 --- a/slack_bolt/middleware/authorization/multi_teams_authorization.py +++ b/slack_bolt/middleware/authorization/multi_teams_authorization.py @@ -1,3 +1,4 @@ +from logging import Logger from typing import Callable, Optional from slack_sdk.errors import SlackApiError @@ -22,14 +23,16 @@ def __init__( self, *, authorize: Authorize, + base_logger: Optional[Logger] = None, ): """Multi-workspace authorization. Args: authorize: The function to authorize incoming requests from Slack. + base_logger: The base logger """ self.authorize = authorize - self.logger = get_bolt_logger(MultiTeamsAuthorization) + self.logger = get_bolt_logger(MultiTeamsAuthorization, base_logger=base_logger) def process( self, diff --git a/slack_bolt/middleware/authorization/single_team_authorization.py b/slack_bolt/middleware/authorization/single_team_authorization.py index 084f21141..b567b4299 100644 --- a/slack_bolt/middleware/authorization/single_team_authorization.py +++ b/slack_bolt/middleware/authorization/single_team_authorization.py @@ -1,3 +1,4 @@ +from logging import Logger from typing import Callable, Optional from slack_bolt.logger import get_bolt_logger @@ -16,14 +17,20 @@ class SingleTeamAuthorization(Authorization): - def __init__(self, *, auth_test_result: Optional[SlackResponse] = None): + def __init__( + self, + *, + auth_test_result: Optional[SlackResponse] = None, + base_logger: Optional[Logger] = None, + ): """Single-workspace authorization. Args: auth_test_result: The initial `auth.test` API call result. + base_logger: The base logger """ self.auth_test_result = auth_test_result - self.logger = get_bolt_logger(SingleTeamAuthorization) + self.logger = get_bolt_logger(SingleTeamAuthorization, base_logger=base_logger) def process( self, diff --git a/slack_bolt/middleware/custom_middleware.py b/slack_bolt/middleware/custom_middleware.py index 6b52b5897..3b7699cfd 100644 --- a/slack_bolt/middleware/custom_middleware.py +++ b/slack_bolt/middleware/custom_middleware.py @@ -1,6 +1,6 @@ import inspect from logging import Logger -from typing import Callable, Any, Sequence +from typing import Callable, Any, Sequence, Optional from slack_bolt.kwargs_injection import build_required_kwargs from slack_bolt.logger import get_bolt_app_logger @@ -16,11 +16,13 @@ class CustomMiddleware(Middleware): arg_names: Sequence[str] logger: Logger - def __init__(self, *, app_name: str, func: Callable): + def __init__( + self, *, app_name: str, func: Callable, base_logger: Optional[Logger] = None + ): self.app_name = app_name self.func = func self.arg_names = inspect.getfullargspec(func).args - self.logger = get_bolt_app_logger(self.app_name, self.func) + self.logger = get_bolt_app_logger(self.app_name, self.func, base_logger) def process( self, diff --git a/slack_bolt/middleware/ignoring_self_events/ignoring_self_events.py b/slack_bolt/middleware/ignoring_self_events/ignoring_self_events.py index 06642b301..bd825330d 100644 --- a/slack_bolt/middleware/ignoring_self_events/ignoring_self_events.py +++ b/slack_bolt/middleware/ignoring_self_events/ignoring_self_events.py @@ -1,5 +1,5 @@ import logging -from typing import Callable, Dict, Any +from typing import Callable, Dict, Any, Optional from slack_bolt.authorization import AuthorizeResult from slack_bolt.logger import get_bolt_logger @@ -9,9 +9,9 @@ class IgnoringSelfEvents(Middleware): - def __init__(self): + def __init__(self, base_logger: Optional[logging.Logger] = None): """Ignores the events generated by this bot user itself.""" - self.logger = get_bolt_logger(IgnoringSelfEvents) + self.logger = get_bolt_logger(IgnoringSelfEvents, base_logger=base_logger) def process( self, diff --git a/slack_bolt/middleware/request_verification/request_verification.py b/slack_bolt/middleware/request_verification/request_verification.py index ebbf803e3..072901521 100644 --- a/slack_bolt/middleware/request_verification/request_verification.py +++ b/slack_bolt/middleware/request_verification/request_verification.py @@ -1,4 +1,5 @@ -from typing import Callable, Dict, Any +from logging import Logger +from typing import Callable, Dict, Any, Optional from slack_sdk.signature import SignatureVerifier @@ -9,7 +10,7 @@ class RequestVerification(Middleware): # type: ignore - def __init__(self, signing_secret: str): + def __init__(self, signing_secret: str, base_logger: Optional[Logger] = None): """Verifies an incoming request by checking the validity of `x-slack-signature`, `x-slack-request-timestamp`, and its body data. @@ -17,9 +18,10 @@ def __init__(self, signing_secret: str): Args: signing_secret: The signing secret + base_logger: The base logger """ self.verifier = SignatureVerifier(signing_secret=signing_secret) - self.logger = get_bolt_logger(RequestVerification) + self.logger = get_bolt_logger(RequestVerification, base_logger=base_logger) def process( self, diff --git a/slack_bolt/middleware/ssl_check/ssl_check.py b/slack_bolt/middleware/ssl_check/ssl_check.py index e02ec7881..d8c92c72d 100644 --- a/slack_bolt/middleware/ssl_check/ssl_check.py +++ b/slack_bolt/middleware/ssl_check/ssl_check.py @@ -11,16 +11,21 @@ class SslCheck(Middleware): # type: ignore verification_token: Optional[str] logger: Logger - def __init__(self, verification_token: Optional[str] = None): + def __init__( + self, + verification_token: Optional[str] = None, + base_logger: Optional[Logger] = None, + ): """Handles `ssl_check` requests. Refer to https://api.slack.com/interactivity/slash-commands for details. Args: verification_token: The verification token to check (optional as it's already deprecated - https://api.slack.com/authentication/verifying-requests-from-slack#verification_token_deprecation) + base_logger: The base logger """ self.verification_token = verification_token - self.logger = get_bolt_logger(SslCheck) + self.logger = get_bolt_logger(SslCheck, base_logger=base_logger) def process( self, diff --git a/slack_bolt/middleware/url_verification/async_url_verification.py b/slack_bolt/middleware/url_verification/async_url_verification.py index 91b4f2b63..2371bc3a4 100644 --- a/slack_bolt/middleware/url_verification/async_url_verification.py +++ b/slack_bolt/middleware/url_verification/async_url_verification.py @@ -1,4 +1,5 @@ -from typing import Callable, Awaitable +from logging import Logger +from typing import Callable, Awaitable, Optional from slack_bolt.logger import get_bolt_logger from .url_verification import UrlVerification @@ -8,8 +9,8 @@ class AsyncUrlVerification(UrlVerification, AsyncMiddleware): - def __init__(self): - self.logger = get_bolt_logger(AsyncUrlVerification) + def __init__(self, base_logger: Optional[Logger] = None): + self.logger = get_bolt_logger(AsyncUrlVerification, base_logger=base_logger) async def async_process( self, diff --git a/slack_bolt/middleware/url_verification/url_verification.py b/slack_bolt/middleware/url_verification/url_verification.py index 591838e31..a8afc1baa 100644 --- a/slack_bolt/middleware/url_verification/url_verification.py +++ b/slack_bolt/middleware/url_verification/url_verification.py @@ -1,4 +1,5 @@ -from typing import Callable +from logging import Logger +from typing import Callable, Optional from slack_bolt.logger import get_bolt_logger from slack_bolt.middleware.middleware import Middleware @@ -7,12 +8,15 @@ class UrlVerification(Middleware): # type: ignore - def __init__(self): + def __init__(self, base_logger: Optional[Logger] = None): """Handles url_verification requests. Refer to https://api.slack.com/events/url_verification for details. + + Args: + base_logger: The base logger """ - self.logger = get_bolt_logger(UrlVerification) + self.logger = get_bolt_logger(UrlVerification, base_logger=base_logger) def process( self, diff --git a/slack_bolt/workflows/step/async_step.py b/slack_bolt/workflows/step/async_step.py index b445962d0..113c6c346 100644 --- a/slack_bolt/workflows/step/async_step.py +++ b/slack_bolt/workflows/step/async_step.py @@ -1,4 +1,5 @@ from functools import wraps +from logging import Logger from typing import Callable, Union, Optional, Awaitable, Sequence, List, Pattern from slack_sdk.web.async_client import AsyncWebClient @@ -31,6 +32,7 @@ class AsyncWorkflowStepBuilder: """ callback_id: Union[str, Pattern] + _base_logger: Optional[Logger] _edit: Optional[AsyncListener] _save: Optional[AsyncListener] _execute: Optional[AsyncListener] @@ -39,6 +41,7 @@ def __init__( self, callback_id: Union[str, Pattern], app_name: Optional[str] = None, + base_logger: Optional[Logger] = None, ): """This builder is supposed to be used as decorator. @@ -61,9 +64,11 @@ async def execute_my_step(step, complete, fail): Args: callback_id: The callback_id for the workflow app_name: The application name mainly for logging + base_logger: The base logger """ self.callback_id = callback_id self.app_name = app_name or __name__ + self._base_logger = base_logger self._edit = None self._save = None self._execute = None @@ -217,7 +222,7 @@ async def _wrapper(*args, **kwargs): return _inner - def build(self) -> "AsyncWorkflowStep": + def build(self, base_logger: Optional[Logger] = None) -> "AsyncWorkflowStep": """Constructs a WorkflowStep object. This method may raise an exception if the builder doesn't have enough configurations to build the object. @@ -237,6 +242,7 @@ def build(self) -> "AsyncWorkflowStep": save=self._save, execute=self._execute, app_name=self.app_name, + base_logger=base_logger, ) # --------------------------------------- @@ -257,6 +263,7 @@ def _to_listener( name=name, matchers=self.to_listener_matchers(self.app_name, matchers), middleware=self.to_listener_middleware(self.app_name, middleware), + base_logger=self._base_logger, ) @staticmethod @@ -319,16 +326,39 @@ def __init__( Callable[..., Awaitable[BoltResponse]], AsyncListener, Sequence[Callable] ], app_name: Optional[str] = None, + base_logger: Optional[Logger] = None, ): self.callback_id = callback_id app_name = app_name or __name__ - self.edit = self.build_listener(callback_id, app_name, edit, "edit") - self.save = self.build_listener(callback_id, app_name, save, "save") - self.execute = self.build_listener(callback_id, app_name, execute, "execute") + self.edit = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=edit, + name="edit", + base_logger=base_logger, + ) + self.save = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=save, + name="save", + base_logger=base_logger, + ) + self.execute = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=execute, + name="execute", + base_logger=base_logger, + ) @classmethod - def builder(cls, callback_id: Union[str, Pattern]) -> AsyncWorkflowStepBuilder: - return AsyncWorkflowStepBuilder(callback_id) + def builder( + cls, + callback_id: Union[str, Pattern], + base_logger: Optional[Logger] = None, + ) -> AsyncWorkflowStepBuilder: + return AsyncWorkflowStepBuilder(callback_id, base_logger=base_logger) @classmethod def build_listener( @@ -339,6 +369,7 @@ def build_listener( name: str, matchers: Optional[List[AsyncListenerMatcher]] = None, middleware: Optional[List[AsyncMiddleware]] = None, + base_logger: Optional[Logger] = None, ): if listener_or_functions is None: raise BoltError(f"{name} listener is required (callback_id: {callback_id})") @@ -350,9 +381,13 @@ def build_listener( return listener_or_functions elif isinstance(listener_or_functions, list): matchers = matchers if matchers else [] - matchers.insert(0, cls._build_primary_matcher(name, callback_id)) + matchers.insert( + 0, cls._build_primary_matcher(name, callback_id, base_logger) + ) middleware = middleware if middleware else [] - middleware.insert(0, cls._build_single_middleware(name, callback_id)) + middleware.insert( + 0, cls._build_single_middleware(name, callback_id, base_logger) + ) functions = listener_or_functions ack_function = functions.pop(0) return AsyncCustomListener( @@ -362,6 +397,7 @@ def build_listener( ack_function=ack_function, lazy_functions=functions, auto_acknowledgement=name == "execute", + base_logger=base_logger, ) else: raise BoltError( @@ -370,25 +406,39 @@ def build_listener( @classmethod def _build_primary_matcher( - cls, name: str, callback_id: str + cls, + name: str, + callback_id: str, + base_logger: Optional[Logger] = None, ) -> AsyncListenerMatcher: if name == "edit": - return workflow_step_edit(callback_id, asyncio=True) + return workflow_step_edit( + callback_id, asyncio=True, base_logger=base_logger + ) elif name == "save": - return workflow_step_save(callback_id, asyncio=True) + return workflow_step_save( + callback_id, asyncio=True, base_logger=base_logger + ) elif name == "execute": - return workflow_step_execute(callback_id, asyncio=True) + return workflow_step_execute( + callback_id, asyncio=True, base_logger=base_logger + ) else: raise ValueError(f"Invalid name {name}") @classmethod - def _build_single_middleware(cls, name: str, callback_id: str) -> AsyncMiddleware: + def _build_single_middleware( + cls, + name: str, + callback_id: str, + base_logger: Optional[Logger] = None, + ) -> AsyncMiddleware: if name == "edit": - return _build_edit_listener_middleware(callback_id) + return _build_edit_listener_middleware(callback_id, base_logger) elif name == "save": - return _build_save_listener_middleware() + return _build_save_listener_middleware(base_logger) elif name == "execute": - return _build_execute_listener_middleware() + return _build_execute_listener_middleware(base_logger) else: raise ValueError(f"Invalid name {name}") @@ -398,7 +448,10 @@ def _build_single_middleware(cls, name: str, callback_id: str) -> AsyncMiddlewar ####################### -def _build_edit_listener_middleware(callback_id: str) -> AsyncMiddleware: +def _build_edit_listener_middleware( + callback_id: str, + base_logger: Optional[Logger] = None, +) -> AsyncMiddleware: async def edit_listener_middleware( context: AsyncBoltContext, client: AsyncWebClient, @@ -412,7 +465,11 @@ async def edit_listener_middleware( ) return await next() - return AsyncCustomMiddleware(app_name=__name__, func=edit_listener_middleware) + return AsyncCustomMiddleware( + app_name=__name__, + func=edit_listener_middleware, + base_logger=base_logger, + ) ####################### @@ -420,7 +477,9 @@ async def edit_listener_middleware( ####################### -def _build_save_listener_middleware() -> AsyncMiddleware: +def _build_save_listener_middleware( + base_logger: Optional[Logger] = None, +) -> AsyncMiddleware: async def save_listener_middleware( context: AsyncBoltContext, client: AsyncWebClient, @@ -433,7 +492,11 @@ async def save_listener_middleware( ) return await next() - return AsyncCustomMiddleware(app_name=__name__, func=save_listener_middleware) + return AsyncCustomMiddleware( + app_name=__name__, + func=save_listener_middleware, + base_logger=base_logger, + ) ####################### @@ -441,7 +504,9 @@ async def save_listener_middleware( ####################### -def _build_execute_listener_middleware() -> AsyncMiddleware: +def _build_execute_listener_middleware( + base_logger: Optional[Logger] = None, +) -> AsyncMiddleware: async def execute_listener_middleware( context: AsyncBoltContext, client: AsyncWebClient, @@ -458,4 +523,8 @@ async def execute_listener_middleware( ) return await next() - return AsyncCustomMiddleware(app_name=__name__, func=execute_listener_middleware) + return AsyncCustomMiddleware( + app_name=__name__, + func=execute_listener_middleware, + base_logger=base_logger, + ) diff --git a/slack_bolt/workflows/step/step.py b/slack_bolt/workflows/step/step.py index 692ee5d1e..dd17289fe 100644 --- a/slack_bolt/workflows/step/step.py +++ b/slack_bolt/workflows/step/step.py @@ -1,4 +1,5 @@ from functools import wraps +from logging import Logger from typing import Callable, Union, Optional, Sequence, Pattern, List from slack_bolt.context.context import BoltContext @@ -26,6 +27,7 @@ class WorkflowStepBuilder: """ callback_id: Union[str, Pattern] + _base_logger: Optional[Logger] _edit: Optional[Listener] _save: Optional[Listener] _execute: Optional[Listener] @@ -34,6 +36,7 @@ def __init__( self, callback_id: Union[str, Pattern], app_name: Optional[str] = None, + base_logger: Optional[Logger] = None, ): """This builder is supposed to be used as decorator. @@ -56,9 +59,11 @@ def execute_my_step(step, complete, fail): Args: callback_id: The callback_id for the workflow app_name: The application name mainly for logging + base_logger: The base logger """ self.callback_id = callback_id self.app_name = app_name or __name__ + self._base_logger = base_logger self._edit = None self._save = None self._execute = None @@ -207,7 +212,7 @@ def _wrapper(*args, **kwargs): return _inner - def build(self) -> "WorkflowStep": + def build(self, base_logger: Optional[Logger] = None) -> "WorkflowStep": """Constructs a WorkflowStep object. This method may raise an exception if the builder doesn't have enough configurations to build the object. @@ -227,6 +232,7 @@ def build(self) -> "WorkflowStep": save=self._save, execute=self._execute, app_name=self.app_name, + base_logger=base_logger, ) # --------------------------------------- @@ -243,14 +249,20 @@ def _to_listener( app_name=self.app_name, listener_or_functions=listener_or_functions, name=name, - matchers=self.to_listener_matchers(self.app_name, matchers), - middleware=self.to_listener_middleware(self.app_name, middleware), + matchers=self.to_listener_matchers( + self.app_name, matchers, self._base_logger + ), + middleware=self.to_listener_middleware( + self.app_name, middleware, self._base_logger + ), + base_logger=self._base_logger, ) @staticmethod def to_listener_matchers( app_name: str, matchers: Optional[List[Union[Callable[..., bool], ListenerMatcher]]], + base_logger: Optional[Logger] = None, ) -> List[ListenerMatcher]: _matchers = [] if matchers is not None: @@ -258,14 +270,22 @@ def to_listener_matchers( if isinstance(m, ListenerMatcher): _matchers.append(m) elif isinstance(m, Callable): - _matchers.append(CustomListenerMatcher(app_name=app_name, func=m)) + _matchers.append( + CustomListenerMatcher( + app_name=app_name, + func=m, + base_logger=base_logger, + ) + ) else: raise ValueError(f"Invalid matcher: {type(m)}") return _matchers # type: ignore @staticmethod def to_listener_middleware( - app_name: str, middleware: Optional[List[Union[Callable, Middleware]]] + app_name: str, + middleware: Optional[List[Union[Callable, Middleware]]], + base_logger: Optional[Logger] = None, ) -> List[Middleware]: _middleware = [] if middleware is not None: @@ -273,7 +293,13 @@ def to_listener_middleware( if isinstance(m, Middleware): _middleware.append(m) elif isinstance(m, Callable): - _middleware.append(CustomMiddleware(app_name=app_name, func=m)) + _middleware.append( + CustomMiddleware( + app_name=app_name, + func=m, + base_logger=base_logger, + ) + ) else: raise ValueError(f"Invalid middleware: {type(m)}") return _middleware # type: ignore @@ -303,16 +329,40 @@ def __init__( Callable[..., Optional[BoltResponse]], Listener, Sequence[Callable] ], app_name: Optional[str] = None, + base_logger: Optional[Logger] = None, ): self.callback_id = callback_id app_name = app_name or __name__ - self.edit = self.build_listener(callback_id, app_name, edit, "edit") - self.save = self.build_listener(callback_id, app_name, save, "save") - self.execute = self.build_listener(callback_id, app_name, execute, "execute") + self.edit = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=edit, + name="edit", + base_logger=base_logger, + ) + self.save = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=save, + name="save", + base_logger=base_logger, + ) + self.execute = self.build_listener( + callback_id=callback_id, + app_name=app_name, + listener_or_functions=execute, + name="execute", + base_logger=base_logger, + ) @classmethod - def builder(cls, callback_id: Union[str, Pattern]) -> WorkflowStepBuilder: - return WorkflowStepBuilder(callback_id) + def builder( + cls, callback_id: Union[str, Pattern], base_logger: Optional[Logger] = None + ) -> WorkflowStepBuilder: + return WorkflowStepBuilder( + callback_id, + base_logger=base_logger, + ) @classmethod def build_listener( @@ -323,6 +373,7 @@ def build_listener( name: str, matchers: Optional[List[ListenerMatcher]] = None, middleware: Optional[List[Middleware]] = None, + base_logger: Optional[Logger] = None, ) -> Listener: if listener_or_functions is None: raise BoltError(f"{name} listener is required (callback_id: {callback_id})") @@ -334,9 +385,23 @@ def build_listener( return listener_or_functions elif isinstance(listener_or_functions, list): matchers = matchers if matchers else [] - matchers.insert(0, cls._build_primary_matcher(name, callback_id)) + matchers.insert( + 0, + cls._build_primary_matcher( + name, + callback_id, + base_logger=base_logger, + ), + ) middleware = middleware if middleware else [] - middleware.insert(0, cls._build_single_middleware(name, callback_id)) + middleware.insert( + 0, + cls._build_single_middleware( + name, + callback_id, + base_logger=base_logger, + ), + ) functions = listener_or_functions ack_function = functions.pop(0) return CustomListener( @@ -346,6 +411,7 @@ def build_listener( ack_function=ack_function, lazy_functions=functions, auto_acknowledgement=name == "execute", + base_logger=base_logger, ) else: raise BoltError( @@ -353,24 +419,34 @@ def build_listener( ) @classmethod - def _build_primary_matcher(cls, name, callback_id) -> ListenerMatcher: + def _build_primary_matcher( + cls, + name: str, + callback_id: Union[str, Pattern], + base_logger: Optional[Logger] = None, + ) -> ListenerMatcher: if name == "edit": - return workflow_step_edit(callback_id) + return workflow_step_edit(callback_id, base_logger=base_logger) elif name == "save": - return workflow_step_save(callback_id) + return workflow_step_save(callback_id, base_logger=base_logger) elif name == "execute": - return workflow_step_execute(callback_id) + return workflow_step_execute(callback_id, base_logger=base_logger) else: raise ValueError(f"Invalid name {name}") @classmethod - def _build_single_middleware(cls, name, callback_id) -> Middleware: + def _build_single_middleware( + cls, + name: str, + callback_id: Union[str, Pattern], + base_logger: Optional[Logger] = None, + ) -> Middleware: if name == "edit": - return _build_edit_listener_middleware(callback_id) + return _build_edit_listener_middleware(callback_id, base_logger=base_logger) elif name == "save": - return _build_save_listener_middleware() + return _build_save_listener_middleware(base_logger=base_logger) elif name == "execute": - return _build_execute_listener_middleware() + return _build_execute_listener_middleware(base_logger=base_logger) else: raise ValueError(f"Invalid name {name}") @@ -380,7 +456,9 @@ def _build_single_middleware(cls, name, callback_id) -> Middleware: ####################### -def _build_edit_listener_middleware(callback_id: str) -> Middleware: +def _build_edit_listener_middleware( + callback_id: str, base_logger: Optional[Logger] = None +) -> Middleware: def edit_listener_middleware( context: BoltContext, client: WebClient, @@ -394,7 +472,11 @@ def edit_listener_middleware( ) return next() - return CustomMiddleware(app_name=__name__, func=edit_listener_middleware) + return CustomMiddleware( + app_name=__name__, + func=edit_listener_middleware, + base_logger=base_logger, + ) ####################### @@ -402,7 +484,7 @@ def edit_listener_middleware( ####################### -def _build_save_listener_middleware() -> Middleware: +def _build_save_listener_middleware(base_logger: Optional[Logger] = None) -> Middleware: def save_listener_middleware( context: BoltContext, client: WebClient, @@ -415,7 +497,11 @@ def save_listener_middleware( ) return next() - return CustomMiddleware(app_name=__name__, func=save_listener_middleware) + return CustomMiddleware( + app_name=__name__, + func=save_listener_middleware, + base_logger=base_logger, + ) ####################### @@ -423,7 +509,9 @@ def save_listener_middleware( ####################### -def _build_execute_listener_middleware() -> Middleware: +def _build_execute_listener_middleware( + base_logger: Optional[Logger] = None, +) -> Middleware: def execute_listener_middleware( context: BoltContext, client: WebClient, @@ -440,4 +528,8 @@ def execute_listener_middleware( ) return next() - return CustomMiddleware(app_name=__name__, func=execute_listener_middleware) + return CustomMiddleware( + app_name=__name__, + func=execute_listener_middleware, + base_logger=base_logger, + ) diff --git a/tests/scenario_tests/test_app.py b/tests/scenario_tests/test_app.py index 86e89c9e9..61d86659c 100644 --- a/tests/scenario_tests/test_app.py +++ b/tests/scenario_tests/test_app.py @@ -1,3 +1,5 @@ +import logging +import time from concurrent.futures import Executor from ssl import SSLContext @@ -259,26 +261,6 @@ def test_proxy_ssl_for_respond(self): ), ) - event_body = { - "token": "verification_token", - "team_id": "T111", - "enterprise_id": "E111", - "api_app_id": "A111", - "event": { - "client_msg_id": "9cbd4c5b-7ddf-4ede-b479-ad21fca66d63", - "type": "app_mention", - "text": "<@W111> Hi there!", - "user": "W222", - "ts": "1595926230.009600", - "team": "T111", - "channel": "C111", - "event_ts": "1595926230.009600", - }, - "type": "event_callback", - "event_id": "Ev111", - "event_time": 1595926230, - } - result = {"called": False} @app.event("app_mention") @@ -289,7 +271,84 @@ def handle(context: BoltContext, respond): assert respond.ssl == ssl result["called"] = True - req = BoltRequest(body=event_body, headers={}, mode="socket_mode") + req = BoltRequest(body=app_mention_event_body, headers={}, mode="socket_mode") response = app.dispatch(req) assert response.status == 200 assert result["called"] is True + + def test_argument_logger_propagation(self): + custom_logger = logging.getLogger(f"{__name__}-{time.time()}-logger-test") + custom_logger.setLevel(logging.INFO) + added_handler = logging.NullHandler() + custom_logger.addHandler(added_handler) + added_filter = logging.Filter() + custom_logger.addFilter(added_filter) + + app = App( + signing_secret="valid", + client=WebClient( + token=self.valid_token, + base_url=self.mock_api_server_base_url, + ), + authorize=lambda: AuthorizeResult( + enterprise_id="E111", + team_id="T111", + ), + logger=custom_logger, + ) + result = {"called": False} + + def _verify_logger(logger: logging.Logger): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + assert logger.handlers[-1] == custom_logger.handlers[-1] + assert len(logger.filters) == len(custom_logger.filters) + assert logger.filters[-1] == custom_logger.filters[-1] + + @app.use + def global_middleware(logger, next): + _verify_logger(logger) + next() + + def listener_middleware(logger, next): + _verify_logger(logger) + next() + + def listener_matcher(logger): + _verify_logger(logger) + return True + + @app.event( + "app_mention", + middleware=[listener_middleware], + matchers=[listener_matcher], + ) + def handle(logger: logging.Logger): + _verify_logger(logger) + result["called"] = True + + req = BoltRequest(body=app_mention_event_body, headers={}, mode="socket_mode") + response = app.dispatch(req) + assert response.status == 200 + assert result["called"] is True + + +app_mention_event_body = { + "token": "verification_token", + "team_id": "T111", + "enterprise_id": "E111", + "api_app_id": "A111", + "event": { + "client_msg_id": "9cbd4c5b-7ddf-4ede-b479-ad21fca66d63", + "type": "app_mention", + "text": "<@W111> Hi there!", + "user": "W222", + "ts": "1595926230.009600", + "team": "T111", + "channel": "C111", + "event_ts": "1595926230.009600", + }, + "type": "event_callback", + "event_id": "Ev111", + "event_time": 1595926230, +} diff --git a/tests/scenario_tests/test_workflow_steps.py b/tests/scenario_tests/test_workflow_steps.py index 38cc803c3..95fc0379f 100644 --- a/tests/scenario_tests/test_workflow_steps.py +++ b/tests/scenario_tests/test_workflow_steps.py @@ -1,4 +1,5 @@ import json +import logging import time as time_module from time import time from urllib.parse import quote @@ -168,6 +169,65 @@ def test_execute_process_before_response(self): response = app.dispatch(request) assert response.status == 404 + def test_custom_logger_propagation(self): + custom_logger = logging.getLogger(f"{__name__}-{time()}-logger-test") + custom_logger.setLevel(logging.INFO) + added_handler = logging.NullHandler() + custom_logger.addHandler(added_handler) + added_filter = logging.Filter() + custom_logger.addFilter(added_filter) + + app = App( + client=self.web_client, + signing_secret=self.signing_secret, + logger=custom_logger, + ) + + def verify_logger_is_properly_passed(ack: Ack, logger: logging.Logger): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + assert logger.handlers[-1] == custom_logger.handlers[-1] + assert len(logger.filters) == len(custom_logger.filters) + assert logger.filters[-1] == custom_logger.filters[-1] + ack() + + app.step( + callback_id="copy_review", + edit=verify_logger_is_properly_passed, + save=verify_logger_is_properly_passed, + execute=verify_logger_is_properly_passed, + ) + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(edit_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(save_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), json.dumps(execute_payload) + headers = { + "content-type": ["application/json"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + edit_payload = { "type": "workflow_step_edit", diff --git a/tests/scenario_tests/test_workflow_steps_decorator_with_args.py b/tests/scenario_tests/test_workflow_steps_decorator_with_args.py index 32f334c14..2d4ea5907 100644 --- a/tests/scenario_tests/test_workflow_steps_decorator_with_args.py +++ b/tests/scenario_tests/test_workflow_steps_decorator_with_args.py @@ -1,4 +1,5 @@ import json +import logging import time as time_module from time import time from urllib.parse import quote @@ -97,6 +98,44 @@ def test_execute(self): response = self.app.dispatch(request) assert response.status == 404 + def test_logger_propagation(self): + app = App( + client=self.web_client, + signing_secret=self.signing_secret, + logger=custom_logger, + ) + app.step(logger_test_step) + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(edit_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(save_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), json.dumps(execute_payload) + headers = { + "content-type": ["application/json"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: BoltRequest = BoltRequest(body=body, headers=headers) + response = app.dispatch(request) + assert response.status == 200 + edit_payload = { "type": "workflow_step_edit", @@ -273,6 +312,10 @@ def test_execute(self): } +# +# The normal pattern tests +# + # https://api.slack.com/tutorials/workflow-builder-steps @@ -427,3 +470,64 @@ def execute(step: dict, client: WebClient, complete: Complete, fail: Fail): ) except Exception as err: fail(error={"message": f"Something wrong! {err}"}) + + +# +# Logger propagation tests +# + +custom_logger = logging.getLogger(f"{__name__}-{time()}-logger-test") +custom_logger.setLevel(logging.INFO) +added_handler = logging.NullHandler() +custom_logger.addHandler(added_handler) +added_filter = logging.Filter() +custom_logger.addFilter(added_filter) + +logger_test_step = WorkflowStep.builder( + "copy_review", + base_logger=custom_logger, # to pass this logger to middleware / middleware matchers +) + + +def _verify_logger(logger: logging.Logger): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + assert logger.handlers[-1] == custom_logger.handlers[-1] + assert len(logger.filters) == len(custom_logger.filters) + assert logger.filters[-1] == custom_logger.filters[-1] + + +def logger_middleware(next, logger): + _verify_logger(logger) + next() + + +def logger_matcher(logger): + _verify_logger(logger) + return True + + +@logger_test_step.edit( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +def edit_for_logger_test(ack: Ack, logger: logging.Logger): + _verify_logger(logger) + ack() + + +@logger_test_step.save( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +def save_for_logger_test(ack: Ack, logger: logging.Logger): + _verify_logger(logger) + ack() + + +@logger_test_step.execute( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +def execute_for_logger_test(logger: logging.Logger): + _verify_logger(logger) diff --git a/tests/scenario_tests_async/test_app.py b/tests/scenario_tests_async/test_app.py index 7486027fe..3a756d533 100644 --- a/tests/scenario_tests_async/test_app.py +++ b/tests/scenario_tests_async/test_app.py @@ -1,4 +1,5 @@ import asyncio +import logging from ssl import SSLContext import pytest @@ -193,45 +194,17 @@ def test_installation_store_conflicts(self): @pytest.mark.asyncio async def test_proxy_ssl_for_respond(self): ssl = SSLContext() - web_client = AsyncWebClient( - token=self.valid_token, - base_url=self.mock_api_server_base_url, - proxy="http://proxy-host:9000/", - ssl=ssl, - ) - - async def my_authorize(): - return AuthorizeResult( - enterprise_id="E111", - team_id="T111", - ) - app = AsyncApp( signing_secret="valid", - client=web_client, + client=AsyncWebClient( + token=self.valid_token, + base_url=self.mock_api_server_base_url, + proxy="http://proxy-host:9000/", + ssl=ssl, + ), authorize=my_authorize, ) - event_body = { - "token": "verification_token", - "team_id": "T111", - "enterprise_id": "E111", - "api_app_id": "A111", - "event": { - "client_msg_id": "9cbd4c5b-7ddf-4ede-b479-ad21fca66d63", - "type": "app_mention", - "text": "<@W111> Hi there!", - "user": "W222", - "ts": "1595926230.009600", - "team": "T111", - "channel": "C111", - "event_ts": "1595926230.009600", - }, - "type": "event_callback", - "event_id": "Ev111", - "event_time": 1595926230, - } - result = {"called": False} @app.event("app_mention") @@ -242,8 +215,102 @@ async def handle(context: AsyncBoltContext, respond): assert respond.ssl == ssl result["called"] = True - req = AsyncBoltRequest(body=event_body, headers={}, mode="socket_mode") + req = AsyncBoltRequest( + body=app_mention_event_body, headers={}, mode="socket_mode" + ) response = await app.async_dispatch(req) assert response.status == 200 await asyncio.sleep(0.5) # wait a bit after auto ack() assert result["called"] is True + + @pytest.mark.asyncio + async def test_argument_logger_propagation(self): + import time + + custom_logger = logging.getLogger(f"{__name__}-{time.time()}-async-logger-test") + custom_logger.setLevel(logging.INFO) + added_handler = logging.NullHandler() + custom_logger.addHandler(added_handler) + added_filter = logging.Filter() + custom_logger.addFilter(added_filter) + + app = AsyncApp( + signing_secret="valid", + client=AsyncWebClient( + token=self.valid_token, + base_url=self.mock_api_server_base_url, + ), + authorize=my_authorize, + logger=custom_logger, + ) + + result = {"called": False} + + def _verify_logger(logger: logging.Logger): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + # TODO: this assertion fails only with codecov + # assert logger.handlers[-1] == custom_logger.handlers[-1] + assert logger.handlers[-1].name == custom_logger.handlers[-1].name + assert len(logger.filters) == len(custom_logger.filters) + # TODO: this assertion fails only with codecov + # assert logger.filters[-1] == custom_logger.filters[-1] + assert logger.filters[-1].name == custom_logger.filters[-1].name + + @app.use + async def global_middleware(logger, next): + _verify_logger(logger) + await next() + + async def listener_middleware(logger, next): + _verify_logger(logger) + await next() + + async def listener_matcher(logger): + _verify_logger(logger) + return True + + @app.event( + "app_mention", + middleware=[listener_middleware], + matchers=[listener_matcher], + ) + async def handle(logger: logging.Logger): + _verify_logger(logger) + result["called"] = True + + req = AsyncBoltRequest( + body=app_mention_event_body, headers={}, mode="socket_mode" + ) + response = await app.async_dispatch(req) + assert response.status == 200 + await asyncio.sleep(0.5) # wait a bit after auto ack() + assert result["called"] is True + + +async def my_authorize(): + return AuthorizeResult( + enterprise_id="E111", + team_id="T111", + ) + + +app_mention_event_body = { + "token": "verification_token", + "team_id": "T111", + "enterprise_id": "E111", + "api_app_id": "A111", + "event": { + "client_msg_id": "9cbd4c5b-7ddf-4ede-b479-ad21fca66d63", + "type": "app_mention", + "text": "<@W111> Hi there!", + "user": "W222", + "ts": "1595926230.009600", + "team": "T111", + "channel": "C111", + "event_ts": "1595926230.009600", + }, + "type": "event_callback", + "event_id": "Ev111", + "event_time": 1595926230, +} diff --git a/tests/scenario_tests_async/test_workflow_steps.py b/tests/scenario_tests_async/test_workflow_steps.py index cf88d46b4..ca3390ac3 100644 --- a/tests/scenario_tests_async/test_workflow_steps.py +++ b/tests/scenario_tests_async/test_workflow_steps.py @@ -1,5 +1,6 @@ import asyncio import json +import logging from time import time from urllib.parse import quote @@ -188,6 +189,68 @@ async def test_execute_process_before_response(self): response = await app.async_dispatch(request) assert response.status == 404 + @pytest.mark.asyncio + async def test_custom_logger_propagation(self): + custom_logger = logging.getLogger(f"{__name__}-{time()}-async-logger-test") + custom_logger.setLevel(logging.INFO) + added_handler = logging.NullHandler() + custom_logger.addHandler(added_handler) + added_filter = logging.Filter() + custom_logger.addFilter(added_filter) + + app = AsyncApp( + client=self.web_client, + signing_secret=self.signing_secret, + logger=custom_logger, + ) + + async def verify_logger_is_properly_passed( + ack: AsyncAck, logger: logging.Logger + ): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + assert logger.handlers[-1] == custom_logger.handlers[-1] + assert len(logger.filters) == len(custom_logger.filters) + assert logger.filters[-1] == custom_logger.filters[-1] + await ack() + + app.step( + callback_id="copy_review", + edit=verify_logger_is_properly_passed, + save=verify_logger_is_properly_passed, + execute=verify_logger_is_properly_passed, + ) + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(edit_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: AsyncBoltRequest = AsyncBoltRequest(body=body, headers=headers) + response = await app.async_dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(save_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: AsyncBoltRequest = AsyncBoltRequest(body=body, headers=headers) + response = await app.async_dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), json.dumps(execute_payload) + headers = { + "content-type": ["application/json"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request: AsyncBoltRequest = AsyncBoltRequest(body=body, headers=headers) + response = await app.async_dispatch(request) + assert response.status == 200 + edit_payload = { "type": "workflow_step_edit", diff --git a/tests/scenario_tests_async/test_workflow_steps_decorator_with_args.py b/tests/scenario_tests_async/test_workflow_steps_decorator_with_args.py index 1db6c8b2d..759b8de8c 100644 --- a/tests/scenario_tests_async/test_workflow_steps_decorator_with_args.py +++ b/tests/scenario_tests_async/test_workflow_steps_decorator_with_args.py @@ -1,5 +1,6 @@ import asyncio import json +import logging from time import time from urllib.parse import quote @@ -118,6 +119,46 @@ async def test_execute(self): response = await self.app.async_dispatch(request) assert response.status == 404 + @pytest.mark.asyncio + async def test_logger_propagation(self): + app = AsyncApp( + client=self.web_client, + signing_secret=self.signing_secret, + logger=custom_logger, + ) + app.step(logger_test_step) + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(edit_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request = AsyncBoltRequest(body=body, headers=headers) + response = await self.app.async_dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), f"payload={quote(json.dumps(save_payload))}" + headers = { + "content-type": ["application/x-www-form-urlencoded"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request = AsyncBoltRequest(body=body, headers=headers) + response = await self.app.async_dispatch(request) + assert response.status == 200 + + timestamp, body = str(int(time())), json.dumps(execute_payload) + headers = { + "content-type": ["application/json"], + "x-slack-signature": [self.generate_signature(body, timestamp)], + "x-slack-request-timestamp": [timestamp], + } + request = AsyncBoltRequest(body=body, headers=headers) + response = await self.app.async_dispatch(request) + assert response.status == 200 + await asyncio.sleep(0.5) # wait for the completion + edit_payload = { "type": "workflow_step_edit", @@ -293,6 +334,9 @@ async def test_execute(self): "event_time": 1601541373, } +# +# The normal pattern tests +# # https://api.slack.com/tutorials/workflow-builder-steps @@ -449,3 +493,64 @@ async def execute( ) except Exception as err: await fail(error={"message": f"Something wrong! {err}"}) + + +# +# Logger propagation tests +# + +custom_logger = logging.getLogger(f"{__name__}-{time()}-async-logger-test") +custom_logger.setLevel(logging.INFO) +added_handler = logging.NullHandler() +custom_logger.addHandler(added_handler) +added_filter = logging.Filter() +custom_logger.addFilter(added_filter) + +logger_test_step = AsyncWorkflowStep.builder( + "copy_review", + base_logger=custom_logger, # to pass this logger to middleware / middleware matchers +) + + +def _verify_logger(logger: logging.Logger): + assert logger.level == custom_logger.level + assert len(logger.handlers) == len(custom_logger.handlers) + assert logger.handlers[-1] == custom_logger.handlers[-1] + assert len(logger.filters) == len(custom_logger.filters) + assert logger.filters[-1] == custom_logger.filters[-1] + + +async def logger_middleware(next, logger): + _verify_logger(logger) + await next() + + +async def logger_matcher(logger): + _verify_logger(logger) + return True + + +@logger_test_step.edit( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +async def edit_for_logger_test(ack: AsyncAck, logger: logging.Logger): + _verify_logger(logger) + await ack() + + +@logger_test_step.save( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +async def save_for_logger_test(ack: AsyncAck, logger: logging.Logger): + _verify_logger(logger) + await ack() + + +@logger_test_step.execute( + middleware=[logger_middleware], + matchers=[logger_matcher], +) +async def execute_for_logger_test(logger: logging.Logger): + _verify_logger(logger)