decorators: Log webhook error payloads in authenticated_rest_api_view.

This completes the effort to ensure that all of our webhooks that do
parsing of the third-party message format log something that we can
use to debug cases where we're not parsing the payloads correctly.

zerver/decorator.py

@@ -545,8 +545,16 @@ def authenticated_rest_api_view(*, webhook_client_name: str=None,
                                            client_name=full_webhook_client_name(webhook_client_name))
             except JsonableError as e:
                 return json_unauthorized(e.msg)
-            # Apply rate limiting
-            return rate_limit()(view_func)(request, profile, *args, **kwargs)
+            try:
+                # Apply rate limiting
+                return rate_limit()(view_func)(request, profile, *args, **kwargs)
+            except Exception as err:
+                if is_webhook or webhook_client_name is not None:
+                    request_body = request.POST.get('payload')
+                    if request_body is not None:
+                        log_exception_to_webhook_logger(request, profile,
+                                                        request_body=request_body)
+                raise err
         return _wrapped_func_arguments
     return _wrapped_view_func
 

zerver/tests/test_decorators.py

@@ -1,4 +1,5 @@
 # -*- coding: utf-8 -*-
+import base64
 import mock
 import re
 import os
@@ -30,6 +31,7 @@ from zerver.lib.request import \
 from zerver.decorator import (
     api_key_only_webhook_view,
     authenticated_api_view,
+    authenticated_rest_api_view,
     authenticate_notify, cachify,
     get_client_name, internal_notify_view, is_local_addr,
     rate_limit, validate_api_key, logged_in_and_active,
@@ -328,6 +330,8 @@ body:
         with self.assertRaisesRegex(JsonableError, "This organization has been deactivated"):
             my_webhook(request)  # type: ignore # mypy doesn't seem to apply the decorator
 
+
+class DecoratorLoggingTestCase(ZulipTestCase):
     def test_authenticated_api_view_logging(self) -> None:
         @authenticated_api_view(is_webhook=True)
         def my_webhook_raises_exception(request: HttpRequest, user_profile: UserProfile) -> None:
@@ -373,6 +377,68 @@ body:
                 body=request.body,
             ))
 
+    def test_authenticated_rest_api_view_logging(self) -> None:
+        @authenticated_rest_api_view(webhook_client_name="ClientName")
+        def my_webhook_raises_exception(request: HttpRequest, user_profile: UserProfile) -> None:
+            raise Exception("raised by webhook function")
+
+        webhook_bot_email = 'webhook-bot@zulip.com'
+        webhook_bot_realm = get_realm('zulip')
+
+        request = HostRequestMock()
+        request.META['HTTP_AUTHORIZATION'] = self.encode_credentials(webhook_bot_email)
+        request.method = 'POST'
+        request.host = "zulip.testserver"
+
+        request.body = '{}'
+        request.POST['payload'] = '{}'
+        request.content_type = 'text/plain'
+
+        with mock.patch('zerver.decorator.webhook_logger.exception') as mock_exception:
+            with self.assertRaisesRegex(Exception, "raised by webhook function"):
+                my_webhook_raises_exception(request)  # type: ignore # mypy doesn't seem to apply the decorator
+
+            message = """
+user: {email} ({realm})
+client: {client_name}
+URL: {path_info}
+content_type: {content_type}
+custom_http_headers:
+{custom_headers}
+body:
+
+{body}
+                """
+            message = message.strip(' ')
+            mock_exception.assert_called_with(message.format(
+                email=webhook_bot_email,
+                realm=webhook_bot_realm.string_id,
+                client_name='ZulipClientNameWebhook',
+                path_info=request.META.get('PATH_INFO'),
+                content_type=request.content_type,
+                custom_headers=None,
+                body=request.body,
+            ))
+
+    def test_authenticated_rest_api_view_with_non_webhook_view(self) -> None:
+        @authenticated_rest_api_view()
+        def non_webhook_view_raises_exception(request: HttpRequest, user_profile: UserProfile=None) -> None:
+            raise Exception("raised by a non-webhook view")
+
+        request = HostRequestMock()
+        request.META['HTTP_AUTHORIZATION'] = self.encode_credentials("aaron@zulip.com")
+        request.method = 'POST'
+        request.host = "zulip.testserver"
+
+        request.body = '{}'
+        request.content_type = 'application/json'
+
+        with mock.patch('zerver.decorator.webhook_logger.exception') as mock_exception:
+            with self.assertRaisesRegex(Exception, "raised by a non-webhook view"):
+                non_webhook_view_raises_exception(request)
+
+            self.assertFalse(mock_exception.called)
+
 class RateLimitTestCase(TestCase):
     def errors_disallowed(self) -> mock:
         # Due to what is probably a hack in rate_limit(),