logging_util: Remove dependence on get_current_request.

Pass the HttpRequest explicitly through the two webhooks that log to
the webhook loggers.

get_current_request is now unused, so remove it (in the same commit
for test coverage reasons).

Signed-off-by: Anders Kaseorg <anders@zulip.com>
This commit is contained in:
Anders Kaseorg 2023-07-10 16:17:30 -04:00 committed by Tim Abbott
parent f66e2c3112
commit 63be67af80
9 changed files with 85 additions and 95 deletions

View File

@ -299,23 +299,25 @@ def access_user_by_api_key(
return user_profile
def log_unsupported_webhook_event(summary: str) -> None:
def log_unsupported_webhook_event(request: HttpRequest, summary: str) -> None:
# This helper is primarily used by some of our more complicated
# webhook integrations (e.g. GitHub) that need to log an unsupported
# event based on attributes nested deep within a complicated JSON
# payload. In such cases, the error message we want to log may not
# really fit what a regular UnsupportedWebhookEventTypeError exception
# represents.
webhook_unsupported_events_logger.exception(summary, stack_info=True)
extra = {"request": request}
webhook_unsupported_events_logger.exception(summary, stack_info=True, extra=extra)
def log_exception_to_webhook_logger(err: Exception) -> None:
def log_exception_to_webhook_logger(request: HttpRequest, err: Exception) -> None:
extra = {"request": request}
if isinstance(err, AnomalousWebhookPayloadError):
webhook_anomalous_payloads_logger.exception(str(err), stack_info=True)
webhook_anomalous_payloads_logger.exception(str(err), stack_info=True, extra=extra)
elif isinstance(err, UnsupportedWebhookEventTypeError):
webhook_unsupported_events_logger.exception(str(err), stack_info=True)
webhook_unsupported_events_logger.exception(str(err), stack_info=True, extra=extra)
else:
webhook_logger.exception(str(err), stack_info=True)
webhook_logger.exception(str(err), stack_info=True, extra=extra)
def full_webhook_client_name(raw_client_name: Optional[str] = None) -> Optional[str]:
@ -369,7 +371,7 @@ def webhook_view(
err.webhook_name = webhook_client_name
if isinstance(err, UnsupportedWebhookEventTypeError):
capture_exception(err)
log_exception_to_webhook_logger(err)
log_exception_to_webhook_logger(request, err)
raise err
# Store the event types registered for this webhook as an attribute, which can be access
@ -780,7 +782,7 @@ def authenticated_rest_api_view(
err.webhook_name = webhook_client_name
if isinstance(err, UnsupportedWebhookEventTypeError):
capture_exception(err)
log_exception_to_webhook_logger(err)
log_exception_to_webhook_logger(request, err)
raise err
return _wrapped_func_arguments

View File

@ -11,6 +11,7 @@ from typing import Optional, Tuple, Union
import orjson
from django.conf import settings
from django.core.cache import cache
from django.http import HttpRequest
from django.utils.timezone import now as timezone_now
@ -222,10 +223,8 @@ class ZulipWebhookFormatter(ZulipFormatter):
return "\n".join(multiline)
def format(self, record: logging.LogRecord) -> str:
from zerver.lib.request import get_current_request
request = get_current_request()
if not request:
request: Optional[HttpRequest] = getattr(record, "request", None)
if request is None:
record.user = None
record.client = None
record.url = None

View File

@ -1,4 +1,3 @@
import threading
from collections import defaultdict
from dataclasses import dataclass, field
from functools import wraps
@ -490,25 +489,3 @@ def has_request_variables(
return return_value
return _wrapped_req_func
local = threading.local()
def get_current_request() -> Optional[HttpRequest]:
"""Returns the current HttpRequest object; this should only be used by
logging frameworks, which have no other access to the current
request. All other codepaths should pass through the current
request object, rather than rely on this thread-local global.
"""
return getattr(local, "request", None)
def set_request(req: HttpRequest) -> None:
local.request = req
def unset_request() -> None:
if hasattr(local, "request"):
del local.request

View File

@ -33,7 +33,7 @@ from zerver.lib.exceptions import ErrorCode, JsonableError, MissingAuthenticatio
from zerver.lib.html_to_text import get_content_description
from zerver.lib.markdown import get_markdown_requests, get_markdown_time
from zerver.lib.rate_limiter import RateLimitResult
from zerver.lib.request import REQ, RequestNotes, has_request_variables, set_request, unset_request
from zerver.lib.request import REQ, RequestNotes, has_request_variables
from zerver.lib.response import (
AsynchronousResponse,
json_response,
@ -226,15 +226,6 @@ def write_log_line(
logger.info("status=%3d, data=%s, uid=%s", status_code, error_data, requester_for_logs)
class RequestContext(MiddlewareMixin):
def __call__(self, request: HttpRequest) -> HttpResponseBase:
set_request(request)
try:
return self.get_response(request)
finally:
unset_request()
# We take advantage of `has_request_variables` being called multiple times
# when processing a request in order to process any `client` parameter that
# may have been sent in the request content.

View File

@ -583,7 +583,9 @@ class DecoratorLoggingTestCase(ZulipTestCase):
with self.assertRaisesRegex(UnsupportedWebhookEventTypeError, exception_msg):
my_webhook_raises_exception(request)
mock_exception.assert_called_with(exception_msg, stack_info=True)
mock_exception.assert_called_with(
exception_msg, stack_info=True, extra={"request": request}
)
def test_authenticated_rest_api_view_with_non_webhook_view(self) -> None:
@authenticated_rest_api_view()

View File

@ -1,7 +1,10 @@
from unittest.mock import MagicMock, patch
from zerver.lib.request import RequestNotes
from zerver.lib.test_classes import WebhookTestCase
from zerver.lib.test_helpers import HostRequestMock
from zerver.lib.validator import wrap_wild_value
from zerver.models import get_client
from zerver.webhooks.bitbucket2.view import get_user_info
TOPIC = "Repository name"
@ -429,7 +432,12 @@ class Bitbucket2HookTests(WebhookTestCase):
self.assert_json_success(result)
def test_get_user_info(self) -> None:
self.assertEqual(get_user_info(wrap_wild_value("request", {})), "Unknown user")
request = HostRequestMock()
request.content_type = "application/json"
request.user = self.test_user
RequestNotes.get_notes(request).client = get_client("test")
self.assertEqual(get_user_info(request, wrap_wild_value("request", {})), "Unknown user")
dct = dict(
nickname="alice",
@ -437,10 +445,10 @@ class Bitbucket2HookTests(WebhookTestCase):
display_name="Alice Smith",
)
self.assertEqual(get_user_info(wrap_wild_value("request", dct)), "Alice Smith")
self.assertEqual(get_user_info(request, wrap_wild_value("request", dct)), "Alice Smith")
del dct["display_name"]
self.assertEqual(get_user_info(wrap_wild_value("request", dct)), "alice")
self.assertEqual(get_user_info(request, wrap_wild_value("request", dct)), "alice")
del dct["nickname"]
self.assertEqual(get_user_info(wrap_wild_value("request", dct)), "Unknown user")
self.assertEqual(get_user_info(request, wrap_wild_value("request", dct)), "Unknown user")

View File

@ -94,7 +94,7 @@ def api_bitbucket2_webhook(
return json_success(request)
subjects = get_push_subjects(payload)
bodies = get_push_bodies(payload)
bodies = get_push_bodies(request, payload)
for b, s in zip(bodies, subjects):
check_send_webhook_message(
@ -104,6 +104,7 @@ def api_bitbucket2_webhook(
subject = get_subject_based_on_type(payload, type)
body_function = get_body_based_on_type(type)
body = body_function(
request,
payload,
include_title=user_specified_topic is not None,
)
@ -199,7 +200,7 @@ def get_type(request: HttpRequest, payload: WildValue) -> str:
class BodyGetter(Protocol):
def __call__(self, payload: WildValue, include_title: bool) -> str:
def __call__(self, request: HttpRequest, payload: WildValue, include_title: bool) -> str:
...
@ -209,48 +210,48 @@ def get_body_based_on_type(
return GET_SINGLE_MESSAGE_BODY_DEPENDING_ON_TYPE_MAPPER[type]
def get_push_bodies(payload: WildValue) -> List[str]:
def get_push_bodies(request: HttpRequest, payload: WildValue) -> List[str]:
messages_list = []
for change in payload["push"]["changes"]:
potential_tag = (change["new"] or change["old"])["type"].tame(check_string)
if potential_tag == "tag":
messages_list.append(get_push_tag_body(payload, change))
messages_list.append(get_push_tag_body(request, payload, change))
# if change['new'] is None, that means a branch was deleted
elif change["new"].value is None:
messages_list.append(get_remove_branch_push_body(payload, change))
messages_list.append(get_remove_branch_push_body(request, payload, change))
elif change["forced"].tame(check_bool):
messages_list.append(get_force_push_body(payload, change))
messages_list.append(get_force_push_body(request, payload, change))
else:
messages_list.append(get_normal_push_body(payload, change))
messages_list.append(get_normal_push_body(request, payload, change))
return messages_list
def get_remove_branch_push_body(payload: WildValue, change: WildValue) -> str:
def get_remove_branch_push_body(request: HttpRequest, payload: WildValue, change: WildValue) -> str:
return get_remove_branch_event_message(
get_actor_info(payload),
get_actor_info(request, payload),
change["old"]["name"].tame(check_string),
)
def get_force_push_body(payload: WildValue, change: WildValue) -> str:
def get_force_push_body(request: HttpRequest, payload: WildValue, change: WildValue) -> str:
return get_force_push_commits_event_message(
get_actor_info(payload),
get_actor_info(request, payload),
change["links"]["html"]["href"].tame(check_string),
change["new"]["name"].tame(check_string),
change["new"]["target"]["hash"].tame(check_string),
)
def get_commit_author_name(commit: WildValue) -> str:
def get_commit_author_name(request: HttpRequest, commit: WildValue) -> str:
if "user" in commit["author"]:
return get_user_info(commit["author"]["user"])
return get_user_info(request, commit["author"]["user"])
return commit["author"]["raw"].tame(check_string).split()[0]
def get_normal_push_body(payload: WildValue, change: WildValue) -> str:
def get_normal_push_body(request: HttpRequest, payload: WildValue, change: WildValue) -> str:
commits_data = [
{
"name": get_commit_author_name(commit),
"name": get_commit_author_name(request, commit),
"sha": commit["hash"].tame(check_string),
"url": commit["links"]["html"]["href"].tame(check_string),
"message": commit["message"].tame(check_string),
@ -259,7 +260,7 @@ def get_normal_push_body(payload: WildValue, change: WildValue) -> str:
]
return get_push_commits_event_message(
get_actor_info(payload),
get_actor_info(request, payload),
change["links"]["html"]["href"].tame(check_string),
change["new"]["name"].tame(check_string),
commits_data,
@ -267,19 +268,19 @@ def get_normal_push_body(payload: WildValue, change: WildValue) -> str:
)
def get_fork_body(payload: WildValue, include_title: bool) -> str:
def get_fork_body(request: HttpRequest, payload: WildValue, include_title: bool) -> str:
return BITBUCKET_FORK_BODY.format(
actor=get_user_info(payload["actor"]),
actor=get_user_info(request, payload["actor"]),
fork_name=get_repository_full_name(payload["fork"]),
fork_url=get_repository_url(payload["fork"]),
)
def get_commit_comment_body(payload: WildValue, include_title: bool) -> str:
def get_commit_comment_body(request: HttpRequest, payload: WildValue, include_title: bool) -> str:
comment = payload["comment"]
action = "[commented]({})".format(comment["links"]["html"]["href"].tame(check_string))
return get_commits_comment_action_message(
get_actor_info(payload),
get_actor_info(request, payload),
action,
comment["commit"]["links"]["html"]["href"].tame(check_string),
comment["commit"]["hash"].tame(check_string),
@ -287,7 +288,9 @@ def get_commit_comment_body(payload: WildValue, include_title: bool) -> str:
)
def get_commit_status_changed_body(payload: WildValue, include_title: bool) -> str:
def get_commit_status_changed_body(
request: HttpRequest, payload: WildValue, include_title: bool
) -> str:
commit_api_url = payload["commit_status"]["links"]["commit"]["href"].tame(check_string)
commit_id = commit_api_url.split("/")[-1]
@ -305,24 +308,26 @@ def get_commit_status_changed_body(payload: WildValue, include_title: bool) -> s
)
def get_issue_commented_body(payload: WildValue, include_title: bool) -> str:
def get_issue_commented_body(request: HttpRequest, payload: WildValue, include_title: bool) -> str:
action = "[commented]({}) on".format(
payload["comment"]["links"]["html"]["href"].tame(check_string)
)
return get_issue_action_body(payload, action, include_title)
return get_issue_action_body(request, payload, action, include_title)
def get_issue_action_body(payload: WildValue, action: str, include_title: bool) -> str:
def get_issue_action_body(
request: HttpRequest, payload: WildValue, action: str, include_title: bool
) -> str:
issue = payload["issue"]
assignee = None
message = None
if action == "created":
if issue["assignee"]:
assignee = get_user_info(issue["assignee"])
assignee = get_user_info(request, issue["assignee"])
message = issue["content"]["raw"].tame(check_string)
return get_issue_event_message(
user_name=get_actor_info(payload),
user_name=get_actor_info(request, payload),
action=action,
url=issue["links"]["html"]["href"].tame(check_string),
number=issue["id"].tame(check_int),
@ -332,7 +337,9 @@ def get_issue_action_body(payload: WildValue, action: str, include_title: bool)
)
def get_pull_request_action_body(payload: WildValue, action: str, include_title: bool) -> str:
def get_pull_request_action_body(
request: HttpRequest, payload: WildValue, action: str, include_title: bool
) -> str:
pull_request = payload["pullrequest"]
target_branch = None
base_branch = None
@ -341,7 +348,7 @@ def get_pull_request_action_body(payload: WildValue, action: str, include_title:
base_branch = pull_request["destination"]["branch"]["name"].tame(check_string)
return get_pull_request_event_message(
user_name=get_actor_info(payload),
user_name=get_actor_info(request, payload),
action=action,
url=get_pull_request_url(pull_request),
number=pull_request["id"].tame(check_int),
@ -352,15 +359,15 @@ def get_pull_request_action_body(payload: WildValue, action: str, include_title:
def get_pull_request_created_or_updated_body(
payload: WildValue, action: str, include_title: bool
request: HttpRequest, payload: WildValue, action: str, include_title: bool
) -> str:
pull_request = payload["pullrequest"]
assignee = None
if pull_request["reviewers"]:
assignee = get_user_info(pull_request["reviewers"][0])
assignee = get_user_info(request, pull_request["reviewers"][0])
return get_pull_request_event_message(
user_name=get_actor_info(payload),
user_name=get_actor_info(request, payload),
action=action,
url=get_pull_request_url(pull_request),
number=pull_request["id"].tame(check_int),
@ -377,16 +384,18 @@ def get_pull_request_created_or_updated_body(
def get_pull_request_comment_created_action_body(
request: HttpRequest,
payload: WildValue,
include_title: bool,
) -> str:
action = "[commented]({})".format(
payload["comment"]["links"]["html"]["href"].tame(check_string)
)
return get_pull_request_comment_action_body(payload, action, include_title)
return get_pull_request_comment_action_body(request, payload, action, include_title)
def get_pull_request_deleted_or_updated_comment_action_body(
request: HttpRequest,
payload: WildValue,
action: str,
include_title: bool,
@ -394,17 +403,18 @@ def get_pull_request_deleted_or_updated_comment_action_body(
action = "{} a [comment]({})".format(
action, payload["comment"]["links"]["html"]["href"].tame(check_string)
)
return get_pull_request_comment_action_body(payload, action, include_title)
return get_pull_request_comment_action_body(request, payload, action, include_title)
def get_pull_request_comment_action_body(
request: HttpRequest,
payload: WildValue,
action: str,
include_title: bool,
) -> str:
action += " on"
return get_pull_request_event_message(
user_name=get_actor_info(payload),
user_name=get_actor_info(request, payload),
action=action,
url=payload["pullrequest"]["links"]["html"]["href"].tame(check_string),
number=payload["pullrequest"]["id"].tame(check_int),
@ -413,7 +423,7 @@ def get_pull_request_comment_action_body(
)
def get_push_tag_body(payload: WildValue, change: WildValue) -> str:
def get_push_tag_body(request: HttpRequest, payload: WildValue, change: WildValue) -> str:
if change.get("new"):
tag = change["new"]
action = "pushed"
@ -422,7 +432,7 @@ def get_push_tag_body(payload: WildValue, change: WildValue) -> str:
action = "removed"
return get_push_tag_event_message(
get_actor_info(payload),
get_actor_info(request, payload),
tag["name"].tame(check_string),
tag_url=tag["links"]["html"]["href"].tame(check_string),
action=action,
@ -436,11 +446,11 @@ def append_punctuation(title: str, message: str) -> str:
return message
def get_repo_updated_body(payload: WildValue, include_title: bool) -> str:
def get_repo_updated_body(request: HttpRequest, payload: WildValue, include_title: bool) -> str:
changes = ["website", "name", "links", "language", "full_name", "description"]
body = ""
repo_name = payload["repository"]["name"].tame(check_string)
actor = get_actor_info(payload)
actor = get_actor_info(request, payload)
for change in changes:
new = payload["changes"][change]["new"]
@ -486,7 +496,7 @@ def get_repository_full_name(repository_payload: WildValue) -> str:
return repository_payload["full_name"].tame(check_string)
def get_user_info(dct: WildValue) -> str:
def get_user_info(request: HttpRequest, dct: WildValue) -> str:
# See https://developer.atlassian.com/cloud/bitbucket/bitbucket-api-changes-gdpr/
# Since GDPR, we don't get username; instead, we either get display_name
# or nickname.
@ -499,15 +509,16 @@ def get_user_info(dct: WildValue) -> str:
# We call this an unsupported_event, even though we
# are technically still sending a message.
log_unsupported_webhook_event(
request=request,
summary="Could not find display_name/nickname field",
)
return "Unknown user"
def get_actor_info(payload: WildValue) -> str:
def get_actor_info(request: HttpRequest, payload: WildValue) -> str:
actor = payload["actor"]
return get_user_info(actor)
return get_user_info(request, actor)
def get_branch_name_for_push_event(payload: WildValue) -> Optional[str]:

View File

@ -48,17 +48,17 @@ DISCUSSION_COMMENT_TEMPLATE = "{author} [commented]({comment_url}) on [discussio
class Helper:
def __init__(
self,
request: HttpRequest,
payload: WildValue,
include_title: bool,
) -> None:
self.request = request
self.payload = payload
self.include_title = include_title
def log_unsupported(self, event: str) -> None:
summary = f"The '{event}' event isn't currently supported by the GitHub webhook; ignoring"
log_unsupported_webhook_event(
summary=summary,
)
log_unsupported_webhook_event(request=self.request, summary=summary)
def get_opened_or_update_pull_request_body(helper: Helper) -> str:
@ -836,6 +836,7 @@ def api_github_webhook(
body_function = EVENT_FUNCTION_MAPPER[event]
helper = Helper(
request=request,
payload=payload,
include_title=user_specified_topic is not None,
)

View File

@ -162,7 +162,6 @@ ALLOWED_HOSTS += REALM_HOSTS.values()
MIDDLEWARE = [
"zerver.middleware.TagRequests",
"zerver.middleware.SetRemoteAddrFromRealIpHeader",
"zerver.middleware.RequestContext",
"django.contrib.sessions.middleware.SessionMiddleware",
"django.contrib.auth.middleware.AuthenticationMiddleware",
# Important: All middleware before LogRequests should be