middleware: Send got_request_exception signal for JSON 500 errors.

This is ordinarily emitted by Django at
  https://github.com/django/django/blob/4.2.6/django/core/handlers/exception.py#L139
and received by Sentry at
  https://github.com/getsentry/sentry-python/blob/1.31.0/sentry_sdk/integrations/django/__init__.py#L166

Signed-off-by: Anders Kaseorg <anders@zulip.com>
This commit is contained in:
Anders Kaseorg 2023-10-04 11:45:34 -07:00 committed by Tim Abbott
parent f71e2c8247
commit f99cce91bf
6 changed files with 56 additions and 49 deletions

View File

@ -7,6 +7,7 @@ from urllib.parse import urlencode, urljoin
from django.conf import settings from django.conf import settings
from django.conf.urls.i18n import is_language_prefix_patterns_used from django.conf.urls.i18n import is_language_prefix_patterns_used
from django.core import signals
from django.db import connection from django.db import connection
from django.http import HttpRequest, HttpResponse, HttpResponseRedirect from django.http import HttpRequest, HttpResponse, HttpResponseRedirect
from django.http.response import HttpResponseBase from django.http.response import HttpResponseBase
@ -383,35 +384,35 @@ class JsonErrorHandler(MiddlewareMixin):
if isinstance(exception, JsonableError): if isinstance(exception, JsonableError):
response = json_response_from_error(exception) response = json_response_from_error(exception)
if response.status_code >= 500: if response.status_code < 500:
# Here we use Django's log_response the way Django uses return response
# it normally to log error responses. However, we make the small elif RequestNotes.get_notes(request).error_format == "JSON" and not settings.TEST_SUITE:
# modification of including the traceback to make the log message
# more helpful. log_response takes care of knowing not to duplicate
# the logging, so Django won't generate a second log message.
log_response(
"%s: %s",
response.reason_phrase,
request.path,
response=response,
request=request,
exception=exception,
)
return response
if RequestNotes.get_notes(request).error_format == "JSON" and not settings.TEST_SUITE:
response = json_response(res_type="error", msg=_("Internal server error"), status=500) response = json_response(res_type="error", msg=_("Internal server error"), status=500)
log_response( else:
"%s: %s", return None
response.reason_phrase,
request.path,
response=response,
request=request,
exception=exception,
)
return response
return None # Send the same signal that Django sends for an unhandled exception.
# This is received by Sentry to log exceptions, and also by the Django
# test HTTP client to show better error messages.
try:
raise exception # Ensure correct sys.exc_info().
except BaseException:
signals.got_request_exception.send(sender=None, request=request)
# Here we use Django's log_response the way Django uses
# it normally to log error responses. However, we make the small
# modification of including the traceback to make the log message
# more helpful. log_response takes care of knowing not to duplicate
# the logging, so Django won't generate a second log message.
log_response(
"%s: %s",
response.reason_phrase,
request.path,
response=response,
request=request,
exception=exception,
)
return response
class TagRequests(MiddlewareMixin): class TagRequests(MiddlewareMixin):

View File

@ -373,9 +373,6 @@ def validate_against_openapi_schema(
# This first set of checks are primarily training wheels that we # This first set of checks are primarily training wheels that we
# hope to eliminate over time as we improve our API documentation. # hope to eliminate over time as we improve our API documentation.
# No 500 responses have been documented, so skip them
if status_code.startswith("5"):
return False
if path not in openapi_spec.openapi()["paths"]: if path not in openapi_spec.openapi()["paths"]:
endpoint = find_openapi_endpoint(path) endpoint = find_openapi_endpoint(path)
# If it doesn't match it hasn't been documented yet. # If it doesn't match it hasn't been documented yet.

View File

@ -16,9 +16,10 @@ class HealthTest(ZulipTestCase):
with mock.patch( with mock.patch(
"zerver.views.health.check_database", "zerver.views.health.check_database",
side_effect=ServerNotReadyError("Cannot query postgresql"), side_effect=ServerNotReadyError("Cannot query postgresql"),
), self.assertLogs(level="ERROR") as logs: ), self.assertLogs(level="ERROR") as logs, self.assertRaisesRegex(
result = self.client_get("/health") ServerNotReadyError, r"^Cannot query postgresql$"
self.assert_json_error(result, "Cannot query postgresql", status_code=500) ):
self.client_get("/health")
self.assertIn( self.assertIn(
"zerver.lib.exceptions.ServerNotReadyError: Cannot query postgresql", logs.output[0] "zerver.lib.exceptions.ServerNotReadyError: Cannot query postgresql", logs.output[0]
) )

View File

@ -1,6 +1,7 @@
from unittest.mock import MagicMock, patch from unittest.mock import MagicMock, patch
import orjson import orjson
from django.core.exceptions import ValidationError
from zerver.lib.test_classes import ZulipTestCase from zerver.lib.test_classes import ZulipTestCase
from zerver.models import Message, Stream, get_realm, get_user from zerver.models import Message, Stream, get_realm, get_user
@ -21,16 +22,14 @@ class TestIntegrationsDevPanel(ZulipTestCase):
"custom_headers": "{}", "custom_headers": "{}",
"is_json": "true", "is_json": "true",
} }
with self.assertLogs(level="ERROR") as logs, self.settings(TEST_SUITE=False): with self.assertLogs(level="ERROR") as logs, self.settings(
response = self.client_post(target_url, data) TEST_SUITE=False
), self.assertRaises(ValidationError):
self.assertEqual(response.status_code, 500) # Since the response would be forwarded. self.client_post(target_url, data)
expected_response = {"result": "error", "msg": "Internal server error"}
self.assertEqual(orjson.loads(response.content), expected_response)
# Intention of this test looks like to trigger ValidationError # Intention of this test looks like to trigger ValidationError
# so just testing ValidationError is printed along with Traceback in logs # so just testing ValidationError is printed along with Traceback in logs
self.assert_length(logs.output, 1) self.assert_length(logs.output, 2)
self.assertTrue( self.assertTrue(
logs.output[0].startswith( logs.output[0].startswith(
"ERROR:django.request:Internal Server Error: /api/v1/external/airbrake\n" "ERROR:django.request:Internal Server Error: /api/v1/external/airbrake\n"
@ -38,6 +37,13 @@ class TestIntegrationsDevPanel(ZulipTestCase):
) )
) )
self.assertTrue("ValidationError" in logs.output[0]) self.assertTrue("ValidationError" in logs.output[0])
self.assertTrue(
logs.output[1].startswith(
"ERROR:django.request:Internal Server Error: /devtools/integrations/check_send_webhook_fixture_message\n"
"Traceback (most recent call last):\n"
)
)
self.assertTrue("ValidationError" in logs.output[1])
def test_check_send_webhook_fixture_message_for_success_without_headers(self) -> None: def test_check_send_webhook_fixture_message_for_success_without_headers(self) -> None:
bot = get_user("webhook-bot@zulip.com", self.zulip_realm) bot = get_user("webhook-bot@zulip.com", self.zulip_realm)

View File

@ -563,12 +563,11 @@ class PushBouncerNotificationTest(BouncerTestCase):
URL = settings.PUSH_NOTIFICATION_BOUNCER_URL + "/api/v1/remotes/push/register" URL = settings.PUSH_NOTIFICATION_BOUNCER_URL + "/api/v1/remotes/push/register"
with responses.RequestsMock() as resp, self.assertLogs(level="ERROR") as error_log: with responses.RequestsMock() as resp, self.assertLogs(level="ERROR") as error_log:
resp.add(responses.POST, URL, body=ConnectionError(), status=502) resp.add(responses.POST, URL, body=ConnectionError(), status=502)
result = self.client_post(endpoint, {"token": token}, subdomain="zulip") with self.assertRaisesRegex(
self.assert_json_error( PushNotificationBouncerRetryLaterError,
result, r"^ConnectionError while trying to connect to push notification bouncer$",
"ConnectionError while trying to connect to push notification bouncer", ):
502, self.client_post(endpoint, {"token": token}, subdomain="zulip")
)
self.assertIn( self.assertIn(
f"ERROR:django.request:Bad Gateway: {endpoint}\nTraceback", f"ERROR:django.request:Bad Gateway: {endpoint}\nTraceback",
error_log.output[0], error_log.output[0],
@ -576,8 +575,11 @@ class PushBouncerNotificationTest(BouncerTestCase):
with responses.RequestsMock() as resp, self.assertLogs(level="WARNING") as warn_log: with responses.RequestsMock() as resp, self.assertLogs(level="WARNING") as warn_log:
resp.add(responses.POST, URL, body=orjson.dumps({"msg": "error"}), status=500) resp.add(responses.POST, URL, body=orjson.dumps({"msg": "error"}), status=500)
result = self.client_post(endpoint, {"token": token}, subdomain="zulip") with self.assertRaisesRegex(
self.assert_json_error(result, "Received 500 from push notification bouncer", 502) PushNotificationBouncerRetryLaterError,
r"Received 500 from push notification bouncer$",
):
self.client_post(endpoint, {"token": token}, subdomain="zulip")
self.assertEqual( self.assertEqual(
warn_log.output[0], warn_log.output[0],
"WARNING:root:Received 500 from push notification bouncer", "WARNING:root:Received 500 from push notification bouncer",

View File

@ -120,7 +120,7 @@ def check_send_webhook_fixture_message(
if response.status_code == 200: if response.status_code == 200:
responses = [{"status_code": response.status_code, "message": response.content.decode()}] responses = [{"status_code": response.status_code, "message": response.content.decode()}]
return json_success(request, data={"responses": responses}) return json_success(request, data={"responses": responses})
else: else: # nocoverage
return response return response