feat: surface ack_timeout on the handler (#1351)

Author: WilliamBergamin

slack_bolt/app/app.py

@@ -59,6 +59,7 @@
     info_default_oauth_settings_loaded,
     error_installation_store_required_for_builtin_listeners,
     warning_unhandled_by_global_middleware,
+    warning_ack_timeout_has_no_effect,
 )
 from slack_bolt.middleware import (
     Middleware,
@@ -912,6 +913,7 @@ def function(
         matchers: Optional[Sequence[Callable[..., bool]]] = None,
         middleware: Optional[Sequence[Union[Callable, Middleware]]] = None,
         auto_acknowledge: bool = True,
+        ack_timeout: int = 3,
     ) -> Callable[..., Optional[Callable[..., Optional[BoltResponse]]]]:
         """Registers a new Function listener.
         This method can be used as either a decorator or a method.
@@ -940,15 +942,17 @@ def reverse_string(ack: Ack, inputs: dict, complete: Complete, fail: Fail):
                 Only when all the middleware call `next()` method, the listener function can be invoked.
         """
 
+        if auto_acknowledge is True:
+            if ack_timeout != 3:
+                self._framework_logger.warning(warning_ack_timeout_has_no_effect(callback_id, ack_timeout))
+
         matchers = list(matchers) if matchers else []
         middleware = list(middleware) if middleware else []
 
         def __call__(*args, **kwargs):
             functions = self._to_listener_functions(kwargs) if kwargs else list(args)
             primary_matcher = builtin_matchers.function_executed(callback_id=callback_id, base_logger=self._base_logger)
-            return self._register_listener(
-                functions, primary_matcher, matchers, middleware, auto_acknowledge, acknowledgement_timeout=5
-            )
+            return self._register_listener(functions, primary_matcher, matchers, middleware, auto_acknowledge, ack_timeout)
 
         return __call__
 
@@ -1424,7 +1428,7 @@ def _register_listener(
         matchers: Optional[Sequence[Callable[..., bool]]],
         middleware: Optional[Sequence[Union[Callable, Middleware]]],
         auto_acknowledgement: bool = False,
-        acknowledgement_timeout: int = 3,
+        ack_timeout: int = 3,
     ) -> Optional[Callable[..., Optional[BoltResponse]]]:
         value_to_return = None
         if not isinstance(functions, list):
@@ -1455,7 +1459,7 @@ def _register_listener(
                 matchers=listener_matchers,
                 middleware=listener_middleware,
                 auto_acknowledgement=auto_acknowledgement,
-                acknowledgement_timeout=acknowledgement_timeout,
+                ack_timeout=ack_timeout,
                 base_logger=self._base_logger,
             )
         )

slack_bolt/app/async_app.py

@@ -68,6 +68,7 @@
     info_default_oauth_settings_loaded,
     error_installation_store_required_for_builtin_listeners,
     warning_unhandled_by_global_middleware,
+    warning_ack_timeout_has_no_effect,
 )
 from slack_bolt.lazy_listener.asyncio_runner import AsyncioLazyListenerRunner
 from slack_bolt.listener.async_listener import AsyncListener, AsyncCustomListener
@@ -940,6 +941,7 @@ def function(
         matchers: Optional[Sequence[Callable[..., Awaitable[bool]]]] = None,
         middleware: Optional[Sequence[Union[Callable, AsyncMiddleware]]] = None,
         auto_acknowledge: bool = True,
+        ack_timeout: int = 3,
     ) -> Callable[..., Optional[Callable[..., Awaitable[BoltResponse]]]]:
         """Registers a new Function listener.
         This method can be used as either a decorator or a method.
@@ -967,6 +969,9 @@ async def reverse_string(ack: AsyncAck, inputs: dict, complete: AsyncComplete, f
             middleware: A list of lister middleware functions.
                 Only when all the middleware call `next()` method, the listener function can be invoked.
         """
+        if auto_acknowledge is True:
+            if ack_timeout != 3:
+                self._framework_logger.warning(warning_ack_timeout_has_no_effect(callback_id, ack_timeout))
 
         matchers = list(matchers) if matchers else []
         middleware = list(middleware) if middleware else []
@@ -976,9 +981,7 @@ def __call__(*args, **kwargs):
             primary_matcher = builtin_matchers.function_executed(
                 callback_id=callback_id, base_logger=self._base_logger, asyncio=True
             )
-            return self._register_listener(
-                functions, primary_matcher, matchers, middleware, auto_acknowledge, acknowledgement_timeout=5
-            )
+            return self._register_listener(functions, primary_matcher, matchers, middleware, auto_acknowledge, ack_timeout)
 
         return __call__
 
@@ -1458,7 +1461,7 @@ def _register_listener(
         matchers: Optional[Sequence[Callable[..., Awaitable[bool]]]],
         middleware: Optional[Sequence[Union[Callable, AsyncMiddleware]]],
         auto_acknowledgement: bool = False,
-        acknowledgement_timeout: int = 3,
+        ack_timeout: int = 3,
     ) -> Optional[Callable[..., Awaitable[Optional[BoltResponse]]]]:
         value_to_return = None
         if not isinstance(functions, list):
@@ -1494,7 +1497,7 @@ def _register_listener(
                 matchers=listener_matchers,
                 middleware=listener_middleware,
                 auto_acknowledgement=auto_acknowledgement,
-                acknowledgement_timeout=acknowledgement_timeout,
+                ack_timeout=ack_timeout,
                 base_logger=self._base_logger,
             )
         )

slack_bolt/listener/async_listener.py

@@ -15,7 +15,7 @@ class AsyncListener(metaclass=ABCMeta):
     ack_function: Callable[..., Awaitable[BoltResponse]]
     lazy_functions: Sequence[Callable[..., Awaitable[None]]]
     auto_acknowledgement: bool
-    acknowledgement_timeout: int
+    ack_timeout: int
 
     async def async_matches(
         self,
@@ -88,7 +88,7 @@ class AsyncCustomListener(AsyncListener):
     matchers: Sequence[AsyncListenerMatcher]
     middleware: Sequence[AsyncMiddleware]
     auto_acknowledgement: bool
-    acknowledgement_timeout: int
+    ack_timeout: int
     arg_names: MutableSequence[str]
     logger: Logger
 
@@ -101,7 +101,7 @@ def __init__(
         matchers: Sequence[AsyncListenerMatcher],
         middleware: Sequence[AsyncMiddleware],
         auto_acknowledgement: bool = False,
-        acknowledgement_timeout: int = 3,
+        ack_timeout: int = 3,
         base_logger: Optional[Logger] = None,
     ):
         self.app_name = app_name
@@ -110,7 +110,7 @@ def __init__(
         self.matchers = matchers
         self.middleware = middleware
         self.auto_acknowledgement = auto_acknowledgement
-        self.acknowledgement_timeout = acknowledgement_timeout
+        self.ack_timeout = ack_timeout
         self.arg_names = get_arg_names_of_callable(ack_function)
         self.logger = get_bolt_app_logger(app_name, self.ack_function, base_logger)
 

slack_bolt/listener/asyncio_runner.py

@@ -149,7 +149,7 @@ async def run_ack_function_asynchronously(
                     self._start_lazy_function(lazy_func, request)
 
             # await for the completion of ack() in the async listener execution
-            while ack.response is None and time.time() - starting_time <= listener.acknowledgement_timeout:
+            while ack.response is None and time.time() - starting_time <= listener.ack_timeout:
                 await asyncio.sleep(0.01)
 
             if response is None and ack.response is None:

slack_bolt/listener/custom_listener.py

@@ -18,7 +18,7 @@ class CustomListener(Listener):
     matchers: Sequence[ListenerMatcher]
     middleware: Sequence[Middleware]
     auto_acknowledgement: bool
-    acknowledgement_timeout: int = 3
+    ack_timeout: int = 3
     arg_names: MutableSequence[str]
     logger: Logger
 
@@ -31,7 +31,7 @@ def __init__(
         matchers: Sequence[ListenerMatcher],
         middleware: Sequence[Middleware],
         auto_acknowledgement: bool = False,
-        acknowledgement_timeout: int = 3,
+        ack_timeout: int = 3,
         base_logger: Optional[Logger] = None,
     ):
         self.app_name = app_name
@@ -40,7 +40,7 @@ def __init__(
         self.matchers = matchers
         self.middleware = middleware
         self.auto_acknowledgement = auto_acknowledgement
-        self.acknowledgement_timeout = acknowledgement_timeout
+        self.ack_timeout = ack_timeout
         self.arg_names = get_arg_names_of_callable(ack_function)
         self.logger = get_bolt_app_logger(app_name, self.ack_function, base_logger)
 

slack_bolt/listener/listener.py

@@ -13,7 +13,7 @@ class Listener(metaclass=ABCMeta):
     ack_function: Callable[..., BoltResponse]
     lazy_functions: Sequence[Callable[..., None]]
     auto_acknowledgement: bool
-    acknowledgement_timeout: int = 3
+    ack_timeout: int = 3
 
     def matches(
         self,

slack_bolt/listener/thread_runner.py

@@ -160,7 +160,7 @@ def run_ack_function_asynchronously():
                     self._start_lazy_function(lazy_func, request)
 
             # await for the completion of ack() in the async listener execution
-            while ack.response is None and time.time() - starting_time <= listener.acknowledgement_timeout:
+            while ack.response is None and time.time() - starting_time <= listener.ack_timeout:
                 time.sleep(0.01)
 
             if response is None and ack.response is None:

slack_bolt/logger/messages.py

@@ -1,3 +1,4 @@
+from re import Pattern
 import time
 from typing import Union, Dict, Any, Optional
 
@@ -331,6 +332,11 @@ def warning_skip_uncommon_arg_name(arg_name: str) -> str:
     )
 
 
+def warning_ack_timeout_has_no_effect(identifier: Union[str, Pattern], ack_timeout: int) -> str:
+    handler_example = f'@app.function("{identifier}")' if isinstance(identifier, str) else f"@app.function({identifier})"
+    return f"On {handler_example}, as `auto_acknowledge` is `True`, " f"`ack_timeout={ack_timeout}` you gave will be unused"
+
+
 # -------------------------------
 # Info
 # -------------------------------

tests/scenario_tests/test_function.py

@@ -1,4 +1,5 @@
 import json
+import re
 import time
 import pytest
 from unittest.mock import Mock
@@ -149,11 +150,12 @@ def test_auto_acknowledge_false_without_acknowledging(self, caplog, monkeypatch)
         assert f"WARNING {just_no_ack.__name__} didn't call ack()" in caplog.text
 
     def test_function_handler_timeout(self, monkeypatch):
+        timeout = 5
         app = App(
             client=self.web_client,
             signing_secret=self.signing_secret,
         )
-        app.function("reverse", auto_acknowledge=False)(just_no_ack)
+        app.function("reverse", auto_acknowledge=False, ack_timeout=timeout)(just_no_ack)
         request = self.build_request_from_body(function_body)
 
         sleep_mock = Mock()
@@ -168,9 +170,34 @@ def test_function_handler_timeout(self, monkeypatch):
         assert response.status == 404
         assert_auth_test_count(self, 1)
         assert (
-            sleep_mock.call_count == 5
+            sleep_mock.call_count == timeout
         ), f"Expected handler to time out after calling time.sleep 5 times, but it was called {sleep_mock.call_count} times"
 
+    def test_warning_when_timeout_improperly_set(self, caplog):
+        app = App(
+            client=self.web_client,
+            signing_secret=self.signing_secret,
+        )
+        app.function("reverse")(just_no_ack)
+        assert "WARNING" not in caplog.text
+
+        timeout_argument_name = "ack_timeout"
+        kwargs = {timeout_argument_name: 5}
+
+        callback_id = "reverse1"
+        app.function(callback_id, **kwargs)(just_no_ack)
+        assert (
+            f'WARNING On @app.function("{callback_id}"), as `auto_acknowledge` is `True`, `{timeout_argument_name}={kwargs[timeout_argument_name]}` you gave will be unused'
+            in caplog.text
+        )
+
+        callback_id = re.compile(r"hello \w+")
+        app.function(callback_id, **kwargs)(just_no_ack)
+        assert (
+            f"WARNING On @app.function({callback_id}), as `auto_acknowledge` is `True`, `{timeout_argument_name}={kwargs[timeout_argument_name]}` you gave will be unused"
+            in caplog.text
+        )
+
 
 function_body = {
     "token": "verification_token",

tests/scenario_tests_async/test_function.py

@@ -1,5 +1,6 @@
 import asyncio
 import json
+import re
 import time
 
 import pytest
@@ -160,11 +161,12 @@ async def test_auto_acknowledge_false_without_acknowledging(self, caplog, monkey
 
     @pytest.mark.asyncio
     async def test_function_handler_timeout(self, monkeypatch):
+        timeout = 5
         app = AsyncApp(
             client=self.web_client,
             signing_secret=self.signing_secret,
         )
-        app.function("reverse", auto_acknowledge=False)(just_no_ack)
+        app.function("reverse", auto_acknowledge=False, ack_timeout=timeout)(just_no_ack)
         request = self.build_request_from_body(function_body)
 
         sleep_mock = MagicMock(side_effect=fake_sleep)
@@ -179,9 +181,35 @@ async def test_function_handler_timeout(self, monkeypatch):
         assert response.status == 404
         await assert_auth_test_count_async(self, 1)
         assert (
-            sleep_mock.call_count == 5
+            sleep_mock.call_count == timeout
         ), f"Expected handler to time out after calling time.sleep 5 times, but it was called {sleep_mock.call_count} times"
 
+    @pytest.mark.asyncio
+    async def test_warning_when_timeout_improperly_set(self, caplog):
+        app = AsyncApp(
+            client=self.web_client,
+            signing_secret=self.signing_secret,
+        )
+        app.function("reverse")(just_no_ack)
+        assert "WARNING" not in caplog.text
+
+        timeout_argument_name = "ack_timeout"
+        kwargs = {timeout_argument_name: 5}
+
+        callback_id = "reverse1"
+        app.function(callback_id, **kwargs)(just_no_ack)
+        assert (
+            f'WARNING On @app.function("{callback_id}"), as `auto_acknowledge` is `True`, `{timeout_argument_name}={kwargs[timeout_argument_name]}` you gave will be unused'
+            in caplog.text
+        )
+
+        callback_id = re.compile(r"hello \w+")
+        app.function(callback_id, **kwargs)(just_no_ack)
+        assert (
+            f"WARNING On @app.function({callback_id}), as `auto_acknowledge` is `True`, `{timeout_argument_name}={kwargs[timeout_argument_name]}` you gave will be unused"
+            in caplog.text
+        )
+
 
 function_body = {
     "token": "verification_token",