Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 8 additions & 0 deletions codecov.yml
Original file line number Diff line number Diff line change
@@ -0,0 +1,8 @@
coverage:
status:
project:
default:
threshold: 0.3%
patch:
default:
target: 50%
20 changes: 19 additions & 1 deletion slack_bolt/app/app.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@
import json
import logging
import os
import time
from concurrent.futures.thread import ThreadPoolExecutor
from http.server import SimpleHTTPRequestHandler, HTTPServer
from typing import List, Union, Pattern, Callable, Dict, Optional, Sequence
Expand Down Expand Up @@ -42,6 +43,7 @@
error_client_invalid_type,
error_authorize_conflicts,
warning_bot_only_conflicts,
debug_return_listener_middleware_response,
)
from slack_bolt.middleware import (
Middleware,
Expand Down Expand Up @@ -323,6 +325,7 @@ def dispatch(self, req: BoltRequest) -> BoltResponse:
:param req: An incoming request from Slack.
:return: The response generated by this Bolt app.
"""
starting_time = time.time()
self._init_context(req)

resp: BoltResponse = BoltResponse(status=200, body="")
Expand All @@ -348,12 +351,27 @@ def middleware_next():
self._framework_logger.debug(debug_checking_listener(listener_name))
if listener.matches(req=req, resp=resp):
# run all the middleware attached to this listener first
resp, next_was_not_called = listener.run_middleware(req=req, resp=resp)
middleware_resp, next_was_not_called = listener.run_middleware(
req=req, resp=resp
)
if next_was_not_called:
if middleware_resp is not None:
if self._framework_logger.level <= logging.DEBUG:
debug_message = debug_return_listener_middleware_response(
listener_name,
middleware_resp.status,
middleware_resp.body,
starting_time,
)
self._framework_logger.debug(debug_message)
return middleware_resp
# The last listener middleware didn't call next() method.
# This means the listener is not for this incoming request.
continue

if middleware_resp is not None:

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This would be the case when a listener middleware sets the response but also calls next, right?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, it is 👍

resp = middleware_resp

self._framework_logger.debug(debug_running_listener(listener_name))
listener_response: Optional[BoltResponse] = self._listener_runner.run(
request=req,
Expand Down
23 changes: 20 additions & 3 deletions slack_bolt/app/async_app.py
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
import inspect
import logging
import os
import time
from typing import Optional, List, Union, Callable, Pattern, Dict, Awaitable, Sequence

from aiohttp import web
Expand Down Expand Up @@ -39,6 +40,7 @@
error_oauth_settings_invalid_type_async,
error_oauth_flow_invalid_type_async,
warning_bot_only_conflicts,
debug_return_listener_middleware_response,
)
from slack_bolt.lazy_listener.asyncio_runner import AsyncioLazyListenerRunner
from slack_bolt.listener.async_listener import AsyncListener, AsyncCustomListener
Expand Down Expand Up @@ -359,6 +361,7 @@ async def async_dispatch(self, req: AsyncBoltRequest) -> BoltResponse:
:param req: An incoming request from Slack.
:return: The response generated by this Bolt app.
"""
starting_time = time.time()

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Debug logs used to track only the time spent in a listener function. Starting here is more accurate.

self._init_context(req)

resp: BoltResponse = BoltResponse(status=200, body="")
Expand Down Expand Up @@ -386,14 +389,28 @@ async def async_middleware_next():
self._framework_logger.debug(debug_checking_listener(listener_name))
if await listener.async_matches(req=req, resp=resp):
# run all the middleware attached to this listener first
resp, next_was_not_called = await listener.run_async_middleware(
req=req, resp=resp
)
(
middleware_resp,
next_was_not_called,
) = await listener.run_async_middleware(req=req, resp=resp)
if next_was_not_called:
if middleware_resp is not None:
if self._framework_logger.level <= logging.DEBUG:
debug_message = debug_return_listener_middleware_response(

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

An example log message:

DEBUG    slack_bolt.App:app.py:366 Responding with listener middleware's response - listener: handle, status: 200, body: listener middleware (3 millis)

listener_name,
middleware_resp.status,
middleware_resp.body,
starting_time,
)
self._framework_logger.debug(debug_message)
return middleware_resp
# The last listener middleware didn't call next() method.
# This means the listener is not for this incoming request.
continue

if middleware_resp is not None:
resp = middleware_resp

self._framework_logger.debug(debug_running_listener(listener_name))
listener_response: Optional[
BoltResponse
Expand Down
2 changes: 1 addition & 1 deletion slack_bolt/listener/async_listener.py
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ async def run_async_middleware(
*,
req: AsyncBoltRequest,
resp: BoltResponse,
) -> Tuple[BoltResponse, bool]:
) -> Tuple[Optional[BoltResponse], bool]:
"""Runs an async middleware.

:param req: The incoming request
Expand Down
3 changes: 2 additions & 1 deletion slack_bolt/listener/asyncio_runner.py
Original file line number Diff line number Diff line change
Expand Up @@ -42,9 +42,10 @@ async def run(
response: BoltResponse,
listener_name: str,
listener: AsyncListener,
starting_time: Optional[float] = None,
) -> Optional[BoltResponse]:
ack = request.context.ack
starting_time = time.time()
starting_time = starting_time if starting_time is not None else time.time()
if self.process_before_response:
if not request.lazy_only:
try:
Expand Down
4 changes: 2 additions & 2 deletions slack_bolt/listener/listener.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
from abc import abstractmethod, ABCMeta
from typing import Callable, Tuple, Sequence
from typing import Callable, Tuple, Sequence, Optional

from slack_bolt.listener_matcher import ListenerMatcher
from slack_bolt.middleware import Middleware
Expand Down Expand Up @@ -32,7 +32,7 @@ def run_middleware(
*,
req: BoltRequest,
resp: BoltResponse,
) -> Tuple[BoltResponse, bool]:
) -> Tuple[Optional[BoltResponse], bool]:
"""

:param req: the incoming request
Expand Down
3 changes: 2 additions & 1 deletion slack_bolt/listener/thread_runner.py
Original file line number Diff line number Diff line change
Expand Up @@ -43,9 +43,10 @@ def run( # type: ignore
response: BoltResponse,
listener_name: str,
listener: Listener,
starting_time: Optional[float] = None,
) -> Optional[BoltResponse]:
ack = request.context.ack
starting_time = time.time()
starting_time = starting_time if starting_time is not None else time.time()
if self.process_before_response:
if not request.lazy_only:
try:
Expand Down
8 changes: 8 additions & 0 deletions slack_bolt/logger/messages.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import time
from typing import Union

from slack_sdk.web import SlackResponse
Expand Down Expand Up @@ -111,3 +112,10 @@ def debug_running_lazy_listener(func_name: str) -> str:

def debug_responding(status: int, body: str, millis: int) -> str:
return f'Responding with status: {status} body: "{body}" ({millis} millis)'


def debug_return_listener_middleware_response(
listener_name: str, status: int, body: str, starting_time: float
) -> str:
millis = int((time.time() - starting_time) * 1000)
return f"Responding with listener middleware's response - listener: {listener_name}, status: {status}, body: {body} ({millis} millis)"
4 changes: 2 additions & 2 deletions slack_bolt/middleware/async_middleware.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
from abc import ABCMeta, abstractmethod
from typing import Callable, Awaitable
from typing import Callable, Awaitable, Optional

from slack_bolt.request.async_request import AsyncBoltRequest
from slack_bolt.response import BoltResponse
Expand All @@ -13,7 +13,7 @@ async def async_process(
req: AsyncBoltRequest,
resp: BoltResponse,
next: Callable[[], Awaitable[BoltResponse]],
) -> BoltResponse:
) -> Optional[BoltResponse]:
raise NotImplementedError()

@property
Expand Down
4 changes: 2 additions & 2 deletions slack_bolt/middleware/middleware.py
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
from abc import ABCMeta, abstractmethod
from typing import Callable
from typing import Callable, Optional

from slack_bolt.request import BoltRequest
from slack_bolt.response import BoltResponse
Expand All @@ -13,7 +13,7 @@ def process(
req: BoltRequest,
resp: BoltResponse,
next: Callable[[], BoltResponse],
) -> BoltResponse:
) -> Optional[BoltResponse]:
raise NotImplementedError()

@property
Expand Down
2 changes: 1 addition & 1 deletion slack_bolt/workflows/step/step_middleware.py
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,7 @@ def process(
req: BoltRequest,
resp: BoltResponse,
next: Callable[[], BoltResponse],
) -> BoltResponse:
) -> Optional[BoltResponse]:

if self.step.edit.matches(req=req, resp=resp):
resp = self._run(self.step.edit, req, resp)
Expand Down
102 changes: 102 additions & 0 deletions tests/scenario_tests/test_listener_middleware.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
import json
from time import time

from slack_sdk.signature import SignatureVerifier
from slack_sdk.web import WebClient

from slack_bolt import BoltResponse
from slack_bolt.app import App
from slack_bolt.request import BoltRequest
from tests.mock_web_api_server import (
setup_mock_web_api_server,
cleanup_mock_web_api_server,
)
from tests.utils import remove_os_env_temporarily, restore_os_env


class TestListenerMiddleware:
signing_secret = "secret"
valid_token = "xoxb-valid"
mock_api_server_base_url = "http://localhost:8888"
signature_verifier = SignatureVerifier(signing_secret)
web_client = WebClient(
token=valid_token,
base_url=mock_api_server_base_url,
)

def setup_method(self):
self.old_os_env = remove_os_env_temporarily()
setup_mock_web_api_server(self)

def teardown_method(self):
cleanup_mock_web_api_server(self)
restore_os_env(self.old_os_env)

body = {
"type": "shortcut",
"token": "verification_token",
"action_ts": "111.111",
"team": {
"id": "T111",
"domain": "workspace-domain",
"enterprise_id": "E111",
"enterprise_name": "Org Name",
},
"user": {"id": "W111", "username": "primary-owner", "team_id": "T111"},
"callback_id": "test-shortcut",
"trigger_id": "111.111.xxxxxx",
}

def build_request(self) -> BoltRequest:
timestamp, body = str(int(time())), json.dumps(self.body)
return BoltRequest(
body=body,
headers={
"content-type": ["application/json"],
"x-slack-signature": [
self.signature_verifier.generate_signature(
body=body,
timestamp=timestamp,
)
],
"x-slack-request-timestamp": [timestamp],
},
)

def test_return_response(self):
app = App(
client=self.web_client,
signing_secret=self.signing_secret,
)

@app.shortcut(
constraints="test-shortcut",
middleware=[listener_middleware_returning_response],
)
def handle(ack):
ack()

response = app.dispatch(self.build_request())
assert response.status == 200
assert response.body == "listener middleware"

def test_next(self):
app = App(
client=self.web_client,
signing_secret=self.signing_secret,
)

@app.shortcut(constraints="test-shortcut", middleware=[just_next])
def handle(ack):
ack()

response = app.dispatch(self.build_request())
assert response.status == 200


def listener_middleware_returning_response():
return BoltResponse(status=200, body="listener middleware")


def just_next(next):
next()
Loading