From f99cce91bf974bbc325f305c95ff05ef3cf265ea Mon Sep 17 00:00:00 2001 From: Anders Kaseorg Date: Wed, 4 Oct 2023 11:45:34 -0700 Subject: [PATCH] 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 --- zerver/middleware.py | 55 +++++++++++---------- zerver/openapi/openapi.py | 3 -- zerver/tests/test_health.py | 7 +-- zerver/tests/test_integrations_dev_panel.py | 20 +++++--- zerver/tests/test_push_notifications.py | 18 ++++--- zerver/views/development/integrations.py | 2 +- 6 files changed, 56 insertions(+), 49 deletions(-) diff --git a/zerver/middleware.py b/zerver/middleware.py index a021cc0c9b..33e814f3d6 100644 --- a/zerver/middleware.py +++ b/zerver/middleware.py @@ -7,6 +7,7 @@ from urllib.parse import urlencode, urljoin from django.conf import settings from django.conf.urls.i18n import is_language_prefix_patterns_used +from django.core import signals from django.db import connection from django.http import HttpRequest, HttpResponse, HttpResponseRedirect from django.http.response import HttpResponseBase @@ -383,35 +384,35 @@ class JsonErrorHandler(MiddlewareMixin): if isinstance(exception, JsonableError): response = json_response_from_error(exception) - if response.status_code >= 500: - # 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 - - if RequestNotes.get_notes(request).error_format == "JSON" and not settings.TEST_SUITE: + if response.status_code < 500: + return response + elif RequestNotes.get_notes(request).error_format == "JSON" and not settings.TEST_SUITE: response = json_response(res_type="error", msg=_("Internal server error"), status=500) - log_response( - "%s: %s", - response.reason_phrase, - request.path, - response=response, - request=request, - exception=exception, - ) - return response + else: + return None - 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): diff --git a/zerver/openapi/openapi.py b/zerver/openapi/openapi.py index d123b27edb..ae1cdaa02f 100644 --- a/zerver/openapi/openapi.py +++ b/zerver/openapi/openapi.py @@ -373,9 +373,6 @@ def validate_against_openapi_schema( # This first set of checks are primarily training wheels that we # 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"]: endpoint = find_openapi_endpoint(path) # If it doesn't match it hasn't been documented yet. diff --git a/zerver/tests/test_health.py b/zerver/tests/test_health.py index 7b284a51f1..321699f94a 100644 --- a/zerver/tests/test_health.py +++ b/zerver/tests/test_health.py @@ -16,9 +16,10 @@ class HealthTest(ZulipTestCase): with mock.patch( "zerver.views.health.check_database", side_effect=ServerNotReadyError("Cannot query postgresql"), - ), self.assertLogs(level="ERROR") as logs: - result = self.client_get("/health") - self.assert_json_error(result, "Cannot query postgresql", status_code=500) + ), self.assertLogs(level="ERROR") as logs, self.assertRaisesRegex( + ServerNotReadyError, r"^Cannot query postgresql$" + ): + self.client_get("/health") self.assertIn( "zerver.lib.exceptions.ServerNotReadyError: Cannot query postgresql", logs.output[0] ) diff --git a/zerver/tests/test_integrations_dev_panel.py b/zerver/tests/test_integrations_dev_panel.py index 8970172d99..cf1ae3ba4b 100644 --- a/zerver/tests/test_integrations_dev_panel.py +++ b/zerver/tests/test_integrations_dev_panel.py @@ -1,6 +1,7 @@ from unittest.mock import MagicMock, patch import orjson +from django.core.exceptions import ValidationError from zerver.lib.test_classes import ZulipTestCase from zerver.models import Message, Stream, get_realm, get_user @@ -21,16 +22,14 @@ class TestIntegrationsDevPanel(ZulipTestCase): "custom_headers": "{}", "is_json": "true", } - with self.assertLogs(level="ERROR") as logs, self.settings(TEST_SUITE=False): - response = self.client_post(target_url, data) - - self.assertEqual(response.status_code, 500) # Since the response would be forwarded. - expected_response = {"result": "error", "msg": "Internal server error"} - self.assertEqual(orjson.loads(response.content), expected_response) + with self.assertLogs(level="ERROR") as logs, self.settings( + TEST_SUITE=False + ), self.assertRaises(ValidationError): + self.client_post(target_url, data) # Intention of this test looks like to trigger ValidationError # 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( logs.output[0].startswith( "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( + 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: bot = get_user("webhook-bot@zulip.com", self.zulip_realm) diff --git a/zerver/tests/test_push_notifications.py b/zerver/tests/test_push_notifications.py index 4a35093c74..62b47c7b31 100644 --- a/zerver/tests/test_push_notifications.py +++ b/zerver/tests/test_push_notifications.py @@ -563,12 +563,11 @@ class PushBouncerNotificationTest(BouncerTestCase): URL = settings.PUSH_NOTIFICATION_BOUNCER_URL + "/api/v1/remotes/push/register" with responses.RequestsMock() as resp, self.assertLogs(level="ERROR") as error_log: resp.add(responses.POST, URL, body=ConnectionError(), status=502) - result = self.client_post(endpoint, {"token": token}, subdomain="zulip") - self.assert_json_error( - result, - "ConnectionError while trying to connect to push notification bouncer", - 502, - ) + with self.assertRaisesRegex( + PushNotificationBouncerRetryLaterError, + r"^ConnectionError while trying to connect to push notification bouncer$", + ): + self.client_post(endpoint, {"token": token}, subdomain="zulip") self.assertIn( f"ERROR:django.request:Bad Gateway: {endpoint}\nTraceback", error_log.output[0], @@ -576,8 +575,11 @@ class PushBouncerNotificationTest(BouncerTestCase): with responses.RequestsMock() as resp, self.assertLogs(level="WARNING") as warn_log: resp.add(responses.POST, URL, body=orjson.dumps({"msg": "error"}), status=500) - result = self.client_post(endpoint, {"token": token}, subdomain="zulip") - self.assert_json_error(result, "Received 500 from push notification bouncer", 502) + with self.assertRaisesRegex( + PushNotificationBouncerRetryLaterError, + r"Received 500 from push notification bouncer$", + ): + self.client_post(endpoint, {"token": token}, subdomain="zulip") self.assertEqual( warn_log.output[0], "WARNING:root:Received 500 from push notification bouncer", diff --git a/zerver/views/development/integrations.py b/zerver/views/development/integrations.py index c89f3a3ffd..6ba0f006bd 100644 --- a/zerver/views/development/integrations.py +++ b/zerver/views/development/integrations.py @@ -120,7 +120,7 @@ def check_send_webhook_fixture_message( if response.status_code == 200: responses = [{"status_code": response.status_code, "message": response.content.decode()}] return json_success(request, data={"responses": responses}) - else: + else: # nocoverage return response