webhooks/jira: Handle anomalous payloads properly.

We recently ran into a payload in production that didn't contain
an event type at all. A payload where we can't figure out the event
type is quite rare. Instead of letting these payloads run amok, we
should raise a more informative exception for such unusual payloads.
If we encounter too many of these, then we can choose to conduct a
deeper investigation on a case-by-case basis.

With some changes by Tim Abbott.

Author: Eeshan Garg

zerver/decorator.py

@@ -28,6 +28,7 @@
 from zerver.lib.cache import cache_with_key
 from zerver.lib.exceptions import (
     AccessDeniedError,
+    AnomalousWebhookPayload,
     ErrorCode,
     InvalidAPIKeyError,
     InvalidAPIKeyFormatError,
@@ -40,6 +41,7 @@
     RealmDeactivatedError,
     UnsupportedWebhookEventType,
     UserDeactivatedError,
+    WebhookError,
 )
 from zerver.lib.queue import queue_json_publish
 from zerver.lib.rate_limiter import RateLimitedIPAddr, RateLimitedUser
@@ -62,6 +64,7 @@
 
 webhook_logger = logging.getLogger("zulip.zerver.webhooks")
 webhook_unsupported_events_logger = logging.getLogger("zulip.zerver.webhooks.unsupported")
+webhook_anomalous_payloads_logger = logging.getLogger("zulip.zerver.webhooks.anomalous")
 
 FuncT = TypeVar("FuncT", bound=Callable[..., object])
 
@@ -305,14 +308,23 @@ def access_user_by_api_key(
     return user_profile
 
 
-def log_exception_to_webhook_logger(
-    summary: str,
-    unsupported_event: bool,
-) -> None:
-    if unsupported_event:
-        webhook_unsupported_events_logger.exception(summary, stack_info=True)
+def log_unsupported_webhook_event(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 UnsupportedWebhookEventType exception
+    # represents.
+    webhook_unsupported_events_logger.exception(summary, stack_info=True)
+
+
+def log_exception_to_webhook_logger(err: Exception) -> None:
+    if isinstance(err, AnomalousWebhookPayload):
+        webhook_anomalous_payloads_logger.exception(str(err), stack_info=True)
+    elif isinstance(err, UnsupportedWebhookEventType):
+        webhook_unsupported_events_logger.exception(str(err), stack_info=True)
     else:
-        webhook_logger.exception(summary, stack_info=True)
+        webhook_logger.exception(str(err), stack_info=True)
 
 
 def full_webhook_client_name(raw_client_name: Optional[str] = None) -> Optional[str]:
@@ -357,17 +369,12 @@ def _wrapped_func_arguments(
                     from zerver.lib.webhooks.common import notify_bot_owner_about_invalid_json
 
                     notify_bot_owner_about_invalid_json(user_profile, webhook_client_name)
-                elif isinstance(err, JsonableError) and not isinstance(
-                    err, UnsupportedWebhookEventType
-                ):
+                elif isinstance(err, JsonableError) and not isinstance(err, WebhookError):
                     pass
                 else:
-                    if isinstance(err, UnsupportedWebhookEventType):
+                    if isinstance(err, WebhookError):
                         err.webhook_name = webhook_client_name
-                    log_exception_to_webhook_logger(
-                        summary=str(err),
-                        unsupported_event=isinstance(err, UnsupportedWebhookEventType),
-                    )
+                    log_exception_to_webhook_logger(err)
                 raise err
 
         _wrapped_func_arguments._all_event_types = all_event_types
@@ -693,16 +700,13 @@ def _wrapped_func_arguments(
                 if not webhook_client_name:
                     raise err
                 if isinstance(err, JsonableError) and not isinstance(
-                    err, UnsupportedWebhookEventType
+                    err, WebhookError
                 ):  # nocoverage
                     raise err
 
-                if isinstance(err, UnsupportedWebhookEventType):
+                if isinstance(err, WebhookError):
                     err.webhook_name = webhook_client_name
-                log_exception_to_webhook_logger(
-                    summary=str(err),
-                    unsupported_event=isinstance(err, UnsupportedWebhookEventType),
-                )
+                log_exception_to_webhook_logger(err)
                 raise err
 
         return _wrapped_func_arguments

zerver/lib/exceptions.py

@@ -18,6 +18,7 @@ class ErrorCode(Enum):
     STREAM_DOES_NOT_EXIST = auto()
     UNAUTHORIZED_PRINCIPAL = auto()
     UNSUPPORTED_WEBHOOK_EVENT_TYPE = auto()
+    ANOMALOUS_WEBHOOK_PAYLOAD = auto()
     BAD_EVENT_QUEUE_ID = auto()
     CSRF_FAILED = auto()
     INVITATION_FAILED = auto()
@@ -317,19 +318,61 @@ def msg_format() -> str:
         return _("Malformed API key")
 
 
-class UnsupportedWebhookEventType(JsonableError):
+class WebhookError(JsonableError):
+    """
+    Intended as a generic exception raised by specific webhook
+    integrations. This class is subclassed by more specific exceptions
+    such as UnsupportedWebhookEventType and AnomalousWebhookPayload.
+    """
+
+    data_fields = ["webhook_name"]
+
+    def __init__(self) -> None:
+        # webhook_name is often set by decorators such as webhook_view
+        # in zerver/decorator.py
+        self.webhook_name = "(unknown)"
+
+
+class UnsupportedWebhookEventType(WebhookError):
+    """Intended as an exception for event formats that we know the
+    third-party service generates but which Zulip doesn't support /
+    generate a message for.
+
+    Exceptions where we cannot parse the event type, possibly because
+    the event isn't actually from the service in question, should
+    raise AnomalousWebhookPayload.
+    """
+
     code = ErrorCode.UNSUPPORTED_WEBHOOK_EVENT_TYPE
     data_fields = ["webhook_name", "event_type"]
 
     def __init__(self, event_type: Optional[str]) -> None:
-        self.webhook_name = "(unknown)"
+        super().__init__()
         self.event_type = event_type
 
     @staticmethod
     def msg_format() -> str:
         return _("The '{event_type}' event isn't currently supported by the {webhook_name} webhook")
 
 
+class AnomalousWebhookPayload(WebhookError):
+    """Intended as an exception for incoming webhook requests that we
+    cannot recognize as having been generated by the service in
+    question. (E.g. because someone pointed a Jira server at the
+    GitHub integration URL).
+
+    If we can parse the event but don't support it, use
+    UnsupportedWebhookEventType.
+
+    """
+
+    code = ErrorCode.ANOMALOUS_WEBHOOK_PAYLOAD
+
+    @staticmethod
+    def msg_format() -> str:
+        return _("Unable to parse request: Did {webhook_name} generate this event?")
+
+
 class MissingAuthenticationError(JsonableError):
     code = ErrorCode.UNAUTHENTICATED_USER
     http_status_code = 401

zerver/webhooks/bitbucket2/view.py

@@ -7,7 +7,7 @@
 
 from django.http import HttpRequest, HttpResponse
 
-from zerver.decorator import log_exception_to_webhook_logger, webhook_view
+from zerver.decorator import log_unsupported_webhook_event, webhook_view
 from zerver.lib.exceptions import UnsupportedWebhookEventType
 from zerver.lib.request import REQ, has_request_variables
 from zerver.lib.response import json_success
@@ -477,11 +477,10 @@ def get_user_info(dct: Dict[str, Any]) -> str:
     if "nickname" in dct:
         return dct["nickname"]
 
-    log_exception_to_webhook_logger(
+    # We call this an unsupported_event, even though we
+    # are technically still sending a message.
+    log_unsupported_webhook_event(
         summary="Could not find display_name/nickname field",
-        # We call this an unsupported_event, even though we
-        # are technically still sending a message.
-        unsupported_event=True,
     )
 
     return "Unknown user"

zerver/webhooks/github/view.py

@@ -4,7 +4,7 @@
 
 from django.http import HttpRequest, HttpResponse
 
-from zerver.decorator import log_exception_to_webhook_logger, webhook_view
+from zerver.decorator import log_unsupported_webhook_event, webhook_view
 from zerver.lib.exceptions import UnsupportedWebhookEventType
 from zerver.lib.request import REQ, has_request_variables
 from zerver.lib.response import json_success
@@ -45,9 +45,8 @@ def __init__(
 
     def log_unsupported(self, event: str) -> None:
         summary = f"The '{event}' event isn't currently supported by the GitHub webhook"
-        log_exception_to_webhook_logger(
+        log_unsupported_webhook_event(
             summary=summary,
-            unsupported_event=True,
         )
 
 

zerver/webhooks/jira/fixtures/example_anomalous_payload.json

@@ -0,0 +1,4 @@
+{
+    "accountId": "1234asdfjlsweoiruoso",
+    "username": "eeshangarg"
+}

zerver/webhooks/jira/tests.py

@@ -234,3 +234,17 @@ def test_comment_event_comment_deleted(self) -> None:
         expected_topic = "SP-1: Add support for newer format Jira issue comment events"
         expected_message = """Hemanth V. Alluri deleted their comment on issue: *"Add support for newer format Jira issue comment events"*\n``` quote\n~~This is a very important issue! I’m on it!~~\n```"""
         self.check_webhook("comment_deleted", expected_topic, expected_message)
+
+    def test_anomalous_webhook_payload_error(self) -> None:
+        with self.assertRaises(AssertionError) as e:
+            self.check_webhook(
+                fixture_name="example_anomalous_payload",
+                expected_topic="",
+                expected_message="",
+                expect_noop=True,
+            )
+
+        self.assertIn(
+            "Unable to parse request: Did Jira generate this event?",
+            e.exception.args[0],
+        )

zerver/webhooks/jira/view.py

@@ -7,7 +7,7 @@
 from django.http import HttpRequest, HttpResponse
 
 from zerver.decorator import webhook_view
-from zerver.lib.exceptions import UnsupportedWebhookEventType
+from zerver.lib.exceptions import AnomalousWebhookPayload, UnsupportedWebhookEventType
 from zerver.lib.request import REQ, has_request_variables
 from zerver.lib.response import json_success
 from zerver.lib.webhooks.common import check_send_webhook_message
@@ -349,6 +349,9 @@ def api_jira_webhook(
     if event in IGNORED_EVENTS:
         return json_success()
 
+    if event is None:
+        raise AnomalousWebhookPayload()
+
     if event is not None:
         content_func = JIRA_CONTENT_FUNCTION_MAPPER.get(event)
 

zproject/computed_settings.py

@@ -717,6 +717,7 @@ def zulip_path(path: str) -> str:
 ANALYTICS_LOG_PATH = zulip_path("/var/log/zulip/analytics.log")
 ANALYTICS_LOCK_DIR = zulip_path("/home/zulip/deployments/analytics-lock-dir")
 WEBHOOK_LOG_PATH = zulip_path("/var/log/zulip/webhooks_errors.log")
+WEBHOOK_ANOMALOUS_PAYLOADS_LOG_PATH = zulip_path("/var/log/zulip/webhooks_anomalous_payloads.log")
 WEBHOOK_UNSUPPORTED_EVENTS_LOG_PATH = zulip_path("/var/log/zulip/webhooks_unsupported_events.log")
 SOFT_DEACTIVATION_LOG_PATH = zulip_path("/var/log/zulip/soft_deactivation.log")
 TRACEMALLOC_DUMP_DIR = zulip_path("/var/log/zulip/tracemalloc")
@@ -849,6 +850,12 @@ def zulip_path(path: str) -> str:
             "formatter": "webhook_request_data",
             "filename": WEBHOOK_UNSUPPORTED_EVENTS_LOG_PATH,
         },
+        "webhook_anomalous_file": {
+            "level": "DEBUG",
+            "class": "logging.handlers.WatchedFileHandler",
+            "formatter": "webhook_request_data",
+            "filename": WEBHOOK_ANOMALOUS_PAYLOADS_LOG_PATH,
+        },
     },
     "loggers": {
         # The Python logging module uses a hierarchy of logger names for config:
@@ -1003,6 +1010,11 @@ def zulip_path(path: str) -> str:
             "handlers": ["webhook_unsupported_file"],
             "propagate": False,
         },
+        "zulip.zerver.webhooks.anomalous": {
+            "level": "DEBUG",
+            "handlers": ["webhook_anomalous_file"],
+            "propagate": False,
+        },
     },
 }