fix: make the function handler timeout 5 seconds (#1348)

Co-authored-by: Eden Zimbelman <[email protected]>

Author: WilliamBergamin

slack_bolt/app/app.py

@@ -946,7 +946,9 @@ def reverse_string(ack: Ack, inputs: dict, complete: Complete, fail: Fail):
         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)
+            return self._register_listener(
+                functions, primary_matcher, matchers, middleware, auto_acknowledge, acknowledgement_timeout=5
+            )
 
         return __call__
 
@@ -1422,6 +1424,7 @@ def _register_listener(
         matchers: Optional[Sequence[Callable[..., bool]]],
         middleware: Optional[Sequence[Union[Callable, Middleware]]],
         auto_acknowledgement: bool = False,
+        acknowledgement_timeout: int = 3,
     ) -> Optional[Callable[..., Optional[BoltResponse]]]:
         value_to_return = None
         if not isinstance(functions, list):
@@ -1452,6 +1455,7 @@ def _register_listener(
                 matchers=listener_matchers,
                 middleware=listener_middleware,
                 auto_acknowledgement=auto_acknowledgement,
+                acknowledgement_timeout=acknowledgement_timeout,
                 base_logger=self._base_logger,
             )
         )

slack_bolt/app/async_app.py

@@ -976,7 +976,9 @@ 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)
+            return self._register_listener(
+                functions, primary_matcher, matchers, middleware, auto_acknowledge, acknowledgement_timeout=5
+            )
 
         return __call__
 
@@ -1456,6 +1458,7 @@ def _register_listener(
         matchers: Optional[Sequence[Callable[..., Awaitable[bool]]]],
         middleware: Optional[Sequence[Union[Callable, AsyncMiddleware]]],
         auto_acknowledgement: bool = False,
+        acknowledgement_timeout: int = 3,
     ) -> Optional[Callable[..., Awaitable[Optional[BoltResponse]]]]:
         value_to_return = None
         if not isinstance(functions, list):
@@ -1491,6 +1494,7 @@ def _register_listener(
                 matchers=listener_matchers,
                 middleware=listener_middleware,
                 auto_acknowledgement=auto_acknowledgement,
+                acknowledgement_timeout=acknowledgement_timeout,
                 base_logger=self._base_logger,
             )
         )

slack_bolt/listener/async_listener.py

@@ -15,6 +15,7 @@ class AsyncListener(metaclass=ABCMeta):
     ack_function: Callable[..., Awaitable[BoltResponse]]
     lazy_functions: Sequence[Callable[..., Awaitable[None]]]
     auto_acknowledgement: bool
+    acknowledgement_timeout: int
 
     async def async_matches(
         self,
@@ -87,6 +88,7 @@ class AsyncCustomListener(AsyncListener):
     matchers: Sequence[AsyncListenerMatcher]
     middleware: Sequence[AsyncMiddleware]
     auto_acknowledgement: bool
+    acknowledgement_timeout: int
     arg_names: MutableSequence[str]
     logger: Logger
 
@@ -99,6 +101,7 @@ def __init__(
         matchers: Sequence[AsyncListenerMatcher],
         middleware: Sequence[AsyncMiddleware],
         auto_acknowledgement: bool = False,
+        acknowledgement_timeout: int = 3,
         base_logger: Optional[Logger] = None,
     ):
         self.app_name = app_name
@@ -107,6 +110,7 @@ def __init__(
         self.matchers = matchers
         self.middleware = middleware
         self.auto_acknowledgement = auto_acknowledgement
+        self.acknowledgement_timeout = acknowledgement_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 <= 3:
+            while ack.response is None and time.time() - starting_time <= listener.acknowledgement_timeout:
                 await asyncio.sleep(0.01)
 
             if response is None and ack.response is None:

slack_bolt/listener/custom_listener.py

@@ -18,6 +18,7 @@ class CustomListener(Listener):
     matchers: Sequence[ListenerMatcher]
     middleware: Sequence[Middleware]
     auto_acknowledgement: bool
+    acknowledgement_timeout: int = 3
     arg_names: MutableSequence[str]
     logger: Logger
 
@@ -30,6 +31,7 @@ def __init__(
         matchers: Sequence[ListenerMatcher],
         middleware: Sequence[Middleware],
         auto_acknowledgement: bool = False,
+        acknowledgement_timeout: int = 3,
         base_logger: Optional[Logger] = None,
     ):
         self.app_name = app_name
@@ -38,6 +40,7 @@ def __init__(
         self.matchers = matchers
         self.middleware = middleware
         self.auto_acknowledgement = auto_acknowledgement
+        self.acknowledgement_timeout = acknowledgement_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,6 +13,7 @@ class Listener(metaclass=ABCMeta):
     ack_function: Callable[..., BoltResponse]
     lazy_functions: Sequence[Callable[..., None]]
     auto_acknowledgement: bool
+    acknowledgement_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 <= 3:
+            while ack.response is None and time.time() - starting_time <= listener.acknowledgement_timeout:
                 time.sleep(0.01)
 
             if response is None and ack.response is None:

tests/scenario_tests/test_function.py

@@ -1,6 +1,7 @@
 import json
 import time
 import pytest
+from unittest.mock import Mock
 
 from slack_sdk.signature import SignatureVerifier
 from slack_sdk.web import WebClient
@@ -51,6 +52,10 @@ def build_request_from_body(self, message_body: dict) -> BoltRequest:
         timestamp, body = str(int(time.time())), json.dumps(message_body)
         return BoltRequest(body=body, headers=self.build_headers(timestamp, body))
 
+    def setup_time_mocks(self, *, monkeypatch: pytest.MonkeyPatch, time_mock: Mock, sleep_mock: Mock):
+        monkeypatch.setattr(time, "time", time_mock)
+        monkeypatch.setattr(time, "sleep", sleep_mock)
+
     def test_valid_callback_id_success(self):
         app = App(
             client=self.web_client,
@@ -124,20 +129,48 @@ def test_auto_acknowledge_false_with_acknowledging(self):
         assert response.status == 200
         assert_auth_test_count(self, 1)
 
-    def test_auto_acknowledge_false_without_acknowledging(self, caplog):
+    def test_auto_acknowledge_false_without_acknowledging(self, caplog, monkeypatch):
         app = App(
             client=self.web_client,
             signing_secret=self.signing_secret,
         )
         app.function("reverse", auto_acknowledge=False)(just_no_ack)
 
         request = self.build_request_from_body(function_body)
+        self.setup_time_mocks(
+            monkeypatch=monkeypatch,
+            time_mock=Mock(side_effect=[current_time for current_time in range(100)]),
+            sleep_mock=Mock(),
+        )
         response = app.dispatch(request)
 
         assert response.status == 404
         assert_auth_test_count(self, 1)
         assert f"WARNING {just_no_ack.__name__} didn't call ack()" in caplog.text
 
+    def test_function_handler_timeout(self, monkeypatch):
+        app = App(
+            client=self.web_client,
+            signing_secret=self.signing_secret,
+        )
+        app.function("reverse", auto_acknowledge=False)(just_no_ack)
+        request = self.build_request_from_body(function_body)
+
+        sleep_mock = Mock()
+        self.setup_time_mocks(
+            monkeypatch=monkeypatch,
+            time_mock=Mock(side_effect=[current_time for current_time in range(100)]),
+            sleep_mock=sleep_mock,
+        )
+
+        response = app.dispatch(request)
+
+        assert response.status == 404
+        assert_auth_test_count(self, 1)
+        assert (
+            sleep_mock.call_count == 5
+        ), f"Expected handler to time out after calling time.sleep 5 times, but it was called {sleep_mock.call_count} times"
+
 
 function_body = {
     "token": "verification_token",

tests/scenario_tests_async/test_function.py

@@ -3,6 +3,7 @@
 import time
 
 import pytest
+from unittest.mock import Mock, MagicMock
 from slack_sdk.signature import SignatureVerifier
 from slack_sdk.web.async_client import AsyncWebClient
 
@@ -17,6 +18,10 @@
 from tests.utils import remove_os_env_temporarily, restore_os_env
 
 
+async def fake_sleep(seconds):
+    pass
+
+
 class TestAsyncFunction:
     signing_secret = "secret"
     valid_token = "xoxb-valid"
@@ -56,6 +61,10 @@ def build_request_from_body(self, message_body: dict) -> AsyncBoltRequest:
         timestamp, body = str(int(time.time())), json.dumps(message_body)
         return AsyncBoltRequest(body=body, headers=self.build_headers(timestamp, body))
 
+    def setup_time_mocks(self, *, monkeypatch: pytest.MonkeyPatch, time_mock: Mock, sleep_mock: MagicMock):
+        monkeypatch.setattr(time, "time", time_mock)
+        monkeypatch.setattr(asyncio, "sleep", sleep_mock)
+
     @pytest.mark.asyncio
     async def test_mock_server_is_running(self):
         resp = await self.web_client.api_test()
@@ -130,19 +139,49 @@ async def test_auto_acknowledge_false_with_acknowledging(self):
         await assert_auth_test_count_async(self, 1)
 
     @pytest.mark.asyncio
-    async def test_auto_acknowledge_false_without_acknowledging(self, caplog):
+    async def test_auto_acknowledge_false_without_acknowledging(self, caplog, monkeypatch):
         app = AsyncApp(
             client=self.web_client,
             signing_secret=self.signing_secret,
         )
         app.function("reverse", auto_acknowledge=False)(just_no_ack)
-
         request = self.build_request_from_body(function_body)
+
+        self.setup_time_mocks(
+            monkeypatch=monkeypatch,
+            time_mock=Mock(side_effect=[current_time for current_time in range(100)]),
+            sleep_mock=MagicMock(side_effect=fake_sleep),
+        )
+
         response = await app.async_dispatch(request)
         assert response.status == 404
         await assert_auth_test_count_async(self, 1)
         assert f"WARNING {just_no_ack.__name__} didn't call ack()" in caplog.text
 
+    @pytest.mark.asyncio
+    async def test_function_handler_timeout(self, monkeypatch):
+        app = AsyncApp(
+            client=self.web_client,
+            signing_secret=self.signing_secret,
+        )
+        app.function("reverse", auto_acknowledge=False)(just_no_ack)
+        request = self.build_request_from_body(function_body)
+
+        sleep_mock = MagicMock(side_effect=fake_sleep)
+        self.setup_time_mocks(
+            monkeypatch=monkeypatch,
+            time_mock=Mock(side_effect=[current_time for current_time in range(100)]),
+            sleep_mock=sleep_mock,
+        )
+
+        response = await app.async_dispatch(request)
+
+        assert response.status == 404
+        await assert_auth_test_count_async(self, 1)
+        assert (
+            sleep_mock.call_count == 5
+        ), f"Expected handler to time out after calling time.sleep 5 times, but it was called {sleep_mock.call_count} times"
+
 
 function_body = {
     "token": "verification_token",