diff --git a/zerver/lib/outgoing_webhook.py b/zerver/lib/outgoing_webhook.py index a28e70c883..2a15d49a95 100644 --- a/zerver/lib/outgoing_webhook.py +++ b/zerver/lib/outgoing_webhook.py @@ -1,5 +1,5 @@ from __future__ import absolute_import -from typing import Any, Iterable, Dict, Tuple, Callable, Text, Mapping, Optional +from typing import Any, AnyStr, Iterable, Dict, Tuple, Callable, Text, Mapping, Optional import requests import json @@ -157,8 +157,45 @@ def fail_with_message(event, failure_message): failure_message = "Failure! " + failure_message send_response_message(event['user_profile_id'], event['message'], failure_message) -def request_retry(event, failure_message): - # type: (Dict[str, Any], Text) -> None +def get_message_url(event, request_data): + # type: (Dict[str, Any], Dict[str, Any]) -> Text + bot_user = get_user_profile_by_id(event['user_profile_id']) + message = event['message'] + if message['type'] == 'stream': + message_url = ("%(server)s/#narrow/stream/%(stream)s/subject/%(subject)s/near/%(id)s" + % {'server': bot_user.realm.uri, + 'stream': message['display_recipient'], + 'subject': message['subject'], + 'id': str(message['id'])}) + else: + recipient_emails = ','.join([recipient['email'] for recipient in message['display_recipient']]) + recipient_email_encoded = urllib.parse.quote(recipient_emails).replace('.', '%2E').replace('%', '.') + message_url = ("%(server)s/#narrow/pm-with/%(recipient_emails)s/near/%(id)s" + % {'server': bot_user.realm.uri, + 'recipient_emails': recipient_email_encoded, + 'id': str(message['id'])}) + return message_url + +def notify_bot_owner(event, request_data, status_code=None, response_content=None, exception=None): + # type: (Dict[str, Any], Dict[str, Any], Optional[int], Optional[AnyStr], Optional[Any]) -> None + message_url = get_message_url(event, request_data) + bot_id = event['user_profile_id'] + bot_owner = get_user_profile_by_id(bot_id).bot_owner + message_info = {'display_recipient': [{'email': bot_owner.email}], + 'type': 'private'} + notification_message = "[A message](%s) triggered an outgoing webhook." % (message_url,) + if status_code: + notification_message += "\nThe webhook got a response with status code *%s*." % (status_code,) + if response_content: + notification_message += "\nThe response contains the following payload:\n" \ + "```\n%s\n```" % (response_content,) + if exception: + notification_message += "\nWhen trying to send a request to the webhook service, an exception " \ + "of type %s occured:\n```\n%s\n```" % (type(exception).__name__, str(exception)) + send_response_message(bot_id, message_info, notification_message) + +def request_retry(event, request_data, failure_message): + # type: (Dict[str, Any], Dict[str, Any], Text) -> None def failure_processor(event): # type: (Dict[str, Any]) -> None """ @@ -168,6 +205,7 @@ def request_retry(event, failure_message): """ bot_user = get_user_profile_by_id(event['user_profile_id']) fail_with_message(event, "Maximum retries exceeded! " + failure_message) + notify_bot_owner(event, request_data) logging.warning("Maximum retries exceeded for trigger:%s event:%s" % (bot_user.email, event['command'])) retry_event('outgoing_webhooks', event, failure_processor) @@ -185,8 +223,6 @@ def do_rest_call(rest_operation, request_data, event, service_handler, timeout=N if error: raise JsonableError(error) - bot_user = get_user_profile_by_id(event['user_profile_id']) - http_method = rest_operation['method'] final_url = urllib.parse.urljoin(rest_operation['base_url'], rest_operation['relative_url_path']) request_kwargs = rest_operation['request_kwargs'] @@ -199,29 +235,26 @@ def do_rest_call(rest_operation, request_data, event, service_handler, timeout=N if response_message is not None: succeed_with_message(event, response_message) else: - message_url = ("%(server)s/#narrow/stream/%(stream)s/subject/%(subject)s/near/%(id)s" - % {'server': bot_user.realm.uri, - 'stream': event['message']['display_recipient'], - 'subject': event['message']['subject'], - 'id': str(event['message']['id'])}) logging.warning("Message %(message_url)s triggered an outgoing webhook, returning status " "code %(status_code)s.\n Content of response (in quotes): \"" "%(response)s\"" - % {'message_url': message_url, + % {'message_url': get_message_url(event, request_data), 'status_code': response.status_code, 'response': response.content}) # On 50x errors, try retry if str(response.status_code).startswith('5'): - request_retry(event, "Internal Server error at third party.") + request_retry(event, request_data, "Internal Server error at third party.") else: failure_message = "Third party responded with %d" % (response.status_code) fail_with_message(event, failure_message) + notify_bot_owner(event, request_data, response.status_code, response.content) except requests.exceptions.Timeout: logging.info("Trigger event %s on %s timed out. Retrying" % (event["command"], event['service_name'])) - request_retry(event, 'Unable to connect with the third party.') + request_retry(event, request_data, 'Unable to connect with the third party.') except requests.exceptions.RequestException as e: response_message = "An exception occured for message `%s`! See the logs for more information." % (event["command"],) logging.exception("Outhook trigger failed:\n %s" % (e,)) fail_with_message(event, response_message) + notify_bot_owner(event, request_data, exception=e) diff --git a/zerver/tests/test_outgoing_webhook_system.py b/zerver/tests/test_outgoing_webhook_system.py index 2e74eaa8bd..97f9fa43fb 100644 --- a/zerver/tests/test_outgoing_webhook_system.py +++ b/zerver/tests/test_outgoing_webhook_system.py @@ -2,6 +2,7 @@ from __future__ import absolute_import from __future__ import print_function +import logging import mock import requests from typing import Any, Dict, Tuple, Text, Optional @@ -21,11 +22,11 @@ class ResponseMock(object): def request_exception_error(http_method, final_url, data, **request_kwargs): # type: (Any, Any, Any, **Any) -> Any - raise requests.exceptions.RequestException + raise requests.exceptions.RequestException("I'm a generic exception :(") def timeout_error(http_method, final_url, data, **request_kwargs): # type: (Any, Any, Any, **Any) -> Any - raise requests.exceptions.Timeout + raise requests.exceptions.Timeout() class MockServiceHandler(OutgoingWebhookServiceInterface): def process_success(self, response, event): @@ -39,17 +40,25 @@ class DoRestCallTests(ZulipTestCase): # type: () -> None realm = get_realm("zulip") user_profile = get_user("outgoing-webhook@zulip.com", realm) - self.mock_event = {'message': {'display_recipient': '', - 'subject': '', - 'id': ''}, - 'user_profile_id': user_profile.id, - 'command': '', - 'service_name': ''} + self.mock_event = { + # In the tests there is no active queue processor, so retries don't get processed. + # Therefore, we need to emulate `retry_event` in the last stage when the maximum + # retries have been exceeded. + 'failed_tries': 3, + 'message': {'display_recipient': 'Verona', + 'subject': 'Foo', + 'id': '', + 'type': 'stream'}, + 'user_profile_id': user_profile.id, + 'command': '', + 'service_name': ''} self.rest_operation = {'method': "POST", 'relative_url_path': "", 'request_kwargs': {}, 'base_url': ""} + self.bot_user = self.example_user('outgoing_webhook_bot') + logging.disable(logging.WARNING) @mock.patch('zerver.lib.outgoing_webhook.succeed_with_message') def test_successful_request(self, mock_succeed_with_message): @@ -59,13 +68,18 @@ class DoRestCallTests(ZulipTestCase): do_rest_call(self.rest_operation, None, self.mock_event, service_handler, None) self.assertTrue(mock_succeed_with_message.called) - @mock.patch('zerver.lib.outgoing_webhook.request_retry') - def test_retry_request(self, mock_request_retry): + def test_retry_request(self): # type: (mock.Mock) -> None response = ResponseMock(500, {"message": "testing"}, '') + + self.mock_event['failed_tries'] = 3 with mock.patch('requests.request', return_value=response): do_rest_call(self.rest_operation, None, self.mock_event, service_handler, None) - self.assertTrue(mock_request_retry.called) + bot_owner_notification = self.get_last_message() + self.assertEqual(bot_owner_notification.content, + "[A message](http://testserver/#narrow/stream/Verona/subject/Foo/near/) triggered an outgoing webhook.") + self.assertEqual(bot_owner_notification.recipient_id, self.bot_user.bot_owner.id) + self.mock_event['failed_tries'] = 0 @mock.patch('zerver.lib.outgoing_webhook.fail_with_message') def test_fail_request(self, mock_fail_with_message): @@ -73,15 +87,22 @@ class DoRestCallTests(ZulipTestCase): response = ResponseMock(400, {"message": "testing"}, '') with mock.patch('requests.request', return_value=response): do_rest_call(self.rest_operation, None, self.mock_event, service_handler, None) + bot_owner_notification = self.get_last_message() self.assertTrue(mock_fail_with_message.called) + self.assertEqual(bot_owner_notification.content, + '''[A message](http://testserver/#narrow/stream/Verona/subject/Foo/near/) triggered an outgoing webhook. +The webhook got a response with status code *400*.''') + self.assertEqual(bot_owner_notification.recipient_id, self.bot_user.bot_owner.id) @mock.patch('logging.info') @mock.patch('requests.request', side_effect=timeout_error) - @mock.patch('zerver.lib.outgoing_webhook.request_retry') - def test_timeout_request(self, mock_request_retry, mock_requests_request, mock_logger): + def test_timeout_request(self, mock_requests_request, mock_logger): # type: (mock.Mock, mock.Mock, mock.Mock) -> None do_rest_call(self.rest_operation, None, self.mock_event, service_handler, None) - self.assertTrue(mock_request_retry.called) + bot_owner_notification = self.get_last_message() + self.assertEqual(bot_owner_notification.content, + '''[A message](http://testserver/#narrow/stream/Verona/subject/Foo/near/) triggered an outgoing webhook.''') + self.assertEqual(bot_owner_notification.recipient_id, self.bot_user.bot_owner.id) @mock.patch('logging.exception') @mock.patch('requests.request', side_effect=request_exception_error) @@ -89,4 +110,12 @@ class DoRestCallTests(ZulipTestCase): def test_request_exception(self, mock_fail_with_message, mock_requests_request, mock_logger): # type: (mock.Mock, mock.Mock, mock.Mock) -> None do_rest_call(self.rest_operation, None, self.mock_event, service_handler, None) + bot_owner_notification = self.get_last_message() self.assertTrue(mock_fail_with_message.called) + self.assertEqual(bot_owner_notification.content, + '''[A message](http://testserver/#narrow/stream/Verona/subject/Foo/near/) triggered an outgoing webhook. +When trying to send a request to the webhook service, an exception of type RequestException occured: +``` +I'm a generic exception :( +```''') + self.assertEqual(bot_owner_notification.recipient_id, self.bot_user.bot_owner.id)