Esempio n. 1
0
    def setUp(self) -> None:
        self.handler = AdminNotifyHandler()
        # Prevent the exceptions we're going to raise from being printed
        # You may want to disable this when debugging tests
        settings.LOGGING_ENABLED = False

        global captured_exc_info
        global captured_request
        captured_request = None
        captured_exc_info = None
Esempio n. 2
0
    def setUp(self) -> None:
        self.handler = AdminNotifyHandler()
        # Prevent the exceptions we're going to raise from being printed
        # You may want to disable this when debugging tests
        settings.LOGGING_ENABLED = False

        global captured_exc_info
        global captured_request
        captured_request = None
        captured_exc_info = None
Esempio n. 3
0
class AdminNotifyHandlerTest(ZulipTestCase):
    logger = logging.getLogger('django')

    def setUp(self) -> None:
        super().setUp()
        self.handler = AdminNotifyHandler()
        # Prevent the exceptions we're going to raise from being printed
        # You may want to disable this when debugging tests
        settings.LOGGING_ENABLED = False

        global captured_exc_info
        global captured_request
        captured_request = None
        captured_exc_info = None

    def tearDown(self) -> None:
        settings.LOGGING_ENABLED = True
        super().tearDown()

    def get_admin_zulip_handler(self) -> AdminNotifyHandler:
        return [
            h for h in logging.getLogger('').handlers
            if isinstance(h, AdminNotifyHandler)
        ][0]

    @patch('zerver.logging_handlers.try_git_describe')
    def test_basic(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A random exception passes happily through AdminNotifyHandler"""
        handler = self.get_admin_zulip_handler()
        try:
            raise Exception("Testing Error!")
        except Exception:
            exc_info = sys.exc_info()
        record = self.logger.makeRecord('name', logging.ERROR, 'function', 16,
                                        'message', {}, exc_info)
        handler.emit(record)

    def simulate_error(self) -> logging.LogRecord:
        self.login('hamlet')
        with patch("zerver.decorator.rate_limit") as rate_limit_patch:
            rate_limit_patch.side_effect = capture_and_throw
            result = self.client_get("/json/users")
            self.assert_json_error(result,
                                   "Internal server error",
                                   status_code=500)
            rate_limit_patch.assert_called_once()

        record = self.logger.makeRecord('name', logging.ERROR, 'function', 15,
                                        'message', {}, captured_exc_info)
        record.request = captured_request  # type: ignore # this field is dynamically added
        return record

    def run_handler(self, record: logging.LogRecord) -> Dict[str, Any]:
        with patch('zerver.lib.error_notify.notify_server_error'
                   ) as patched_notify:
            self.handler.emit(record)
            patched_notify.assert_called_once()
            return patched_notify.call_args[0][0]

    @patch('zerver.logging_handlers.try_git_describe')
    def test_long_exception_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A request with no stack and multi-line report.getMessage() is handled properly"""
        record = self.simulate_error()
        record.exc_info = None
        record.msg = 'message\nmoremesssage\nmore'

        report = self.run_handler(record)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)
        self.assertEqual(report['stack_trace'], 'message\nmoremesssage\nmore')
        self.assertEqual(report['message'], 'message')

    @patch('zerver.logging_handlers.try_git_describe')
    def test_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A normal request is handled properly"""
        record = self.simulate_error()

        report = self.run_handler(record)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test that `add_request_metadata` throwing an exception is fine
        with patch("zerver.logging_handlers.traceback.print_exc"):
            with patch("zerver.logging_handlers.add_request_metadata",
                       side_effect=Exception("Unexpected exception!")):
                report = self.run_handler(record)
        self.assertNotIn("user_email", report)
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"],
                         "See /var/log/zulip/errors.log")

        # Check anonymous user is handled correctly
        record.request.user = AnonymousUser(
        )  # type: ignore # this field is dynamically added
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Now simulate a DisallowedHost exception
        def get_host_error() -> None:
            raise Exception("Get Host Failure!")

        orig_get_host = record.request.get_host  # type: ignore # this field is dynamically added
        record.request.get_host = get_host_error  # type: ignore # this field is dynamically added
        report = self.run_handler(record)
        record.request.get_host = orig_get_host  # type: ignore # this field is dynamically added
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test an exception_filter exception
        with patch("zerver.logging_handlers.get_exception_reporter_filter",
                   return_value=15):
            record.request.method = "POST"  # type: ignore # this field is dynamically added
            report = self.run_handler(record)
            record.request.method = "GET"  # type: ignore # this field is dynamically added
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test the catch-all exception handler doesn't throw
        with patch('zerver.lib.error_notify.notify_server_error',
                   side_effect=Exception("queue error")):
            self.handler.emit(record)
        with self.settings(STAGING_ERROR_NOTIFICATIONS=False):
            with patch('zerver.logging_handlers.queue_json_publish',
                       side_effect=Exception("queue error")):
                self.handler.emit(record)

        # Test no exc_info
        record.exc_info = None
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"], 'No stack trace available')

        # Test arbitrary exceptions from request.user
        record.request.user = None  # type: ignore # this field is dynamically added
        with patch("zerver.logging_handlers.traceback.print_exc"):
            report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)
Esempio n. 4
0
class AdminNotifyHandlerTest(ZulipTestCase):
    logger = logging.getLogger("django")

    def setUp(self) -> None:
        super().setUp()
        self.handler = AdminNotifyHandler()
        # Prevent the exceptions we're going to raise from being printed
        # You may want to disable this when debugging tests
        settings.LOGGING_ENABLED = False

        global captured_exc_info
        global captured_request
        captured_request = None
        captured_exc_info = None

    def tearDown(self) -> None:
        settings.LOGGING_ENABLED = True
        super().tearDown()

    def get_admin_zulip_handler(self) -> AdminNotifyHandler:
        return [h for h in logging.getLogger("").handlers if isinstance(h, AdminNotifyHandler)][0]

    @patch("zerver.logging_handlers.try_git_describe")
    def test_basic(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A random exception passes happily through AdminNotifyHandler"""
        handler = self.get_admin_zulip_handler()
        try:
            raise Exception("Testing error!")
        except Exception:
            exc_info = sys.exc_info()
        record = self.logger.makeRecord(
            "name", logging.ERROR, "function", 16, "message", {}, exc_info
        )
        handler.emit(record)

    def simulate_error(self) -> logging.LogRecord:
        self.login("hamlet")
        with patch("zerver.decorator.rate_limit") as rate_limit_patch, self.assertLogs(
            "django.request", level="ERROR"
        ) as request_error_log, self.assertLogs(
            "zerver.middleware.json_error_handler", level="ERROR"
        ) as json_error_handler_log:
            rate_limit_patch.side_effect = capture_and_throw
            result = self.client_get("/json/users")
            self.assert_json_error(result, "Internal server error", status_code=500)
            rate_limit_patch.assert_called_once()
        self.assertEqual(
            request_error_log.output, ["ERROR:django.request:Internal Server Error: /json/users"]
        )
        self.assertTrue(
            "ERROR:zerver.middleware.json_error_handler:Traceback (most recent call last):"
            in json_error_handler_log.output[0]
        )
        self.assertTrue("Exception: Request error" in json_error_handler_log.output[0])

        record = self.logger.makeRecord(
            "name",
            logging.ERROR,
            "function",
            15,
            "message",
            {},
            captured_exc_info,
            extra={"request": captured_request},
        )
        return record

    def run_handler(self, record: logging.LogRecord) -> Dict[str, object]:
        with patch("zerver.lib.error_notify.notify_server_error") as patched_notify:
            self.handler.emit(record)
            patched_notify.assert_called_once()
            return patched_notify.call_args[0][0]

    @patch("zerver.logging_handlers.try_git_describe")
    def test_long_exception_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A request with no stack and multi-line report.getMessage() is handled properly"""
        record = self.simulate_error()
        record.exc_info = None
        record.msg = "message\nmoremesssage\nmore"

        report = self.run_handler(record)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)
        self.assertEqual(report["stack_trace"], "message\nmoremesssage\nmore")
        self.assertEqual(report["message"], "message")

    @patch("zerver.logging_handlers.try_git_describe")
    def test_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A normal request is handled properly"""
        record = self.simulate_error()
        assert isinstance(record, HasRequest)

        report = self.run_handler(record)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test that `add_request_metadata` throwing an exception is fine
        with patch("zerver.logging_handlers.traceback.print_exc"):
            with patch(
                "zerver.logging_handlers.add_request_metadata",
                side_effect=Exception("Unexpected exception!"),
            ):
                report = self.run_handler(record)
        self.assertNotIn("user", report)
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"], "See /var/log/zulip/errors.log")

        # Check anonymous user is handled correctly
        record.request.user = AnonymousUser()
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Put it back so we continue to test the non-anonymous case
        record.request.user = self.example_user("hamlet")

        # Now simulate a DisallowedHost exception
        def get_host_error() -> None:
            raise Exception("Get host failure!")

        orig_get_host = record.request.get_host
        record.request.get_host = get_host_error
        report = self.run_handler(record)
        record.request.get_host = orig_get_host
        self.assertIn("host", report)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test an exception_filter exception
        with patch("zerver.logging_handlers.get_exception_reporter_filter", return_value=15):
            record.request.method = "POST"
            report = self.run_handler(record)
            record.request.method = "GET"
        self.assertIn("host", report)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test the catch-all exception handler doesn't throw
        with patch(
            "zerver.lib.error_notify.notify_server_error", side_effect=Exception("queue error")
        ):
            self.handler.emit(record)
        with self.settings(STAGING_ERROR_NOTIFICATIONS=False):
            with mock_queue_publish(
                "zerver.logging_handlers.queue_json_publish", side_effect=Exception("queue error")
            ) as m:
                with patch("logging.warning") as log_mock:
                    self.handler.emit(record)
                    m.assert_called_once()
                    log_mock.assert_called_once_with(
                        "Reporting an exception triggered an exception!", exc_info=True
                    )
            with mock_queue_publish("zerver.logging_handlers.queue_json_publish") as m:
                with patch("logging.warning") as log_mock:
                    self.handler.emit(record)
                    m.assert_called_once()
                    log_mock.assert_not_called()

        # Test no exc_info
        record.exc_info = None
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"], "No stack trace available")

        # Test arbitrary exceptions from request.user
        record.request.user = None
        with patch("zerver.logging_handlers.traceback.print_exc"):
            report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user", report)
        self.assertIn("user_email", report["user"])
        self.assertIn("user_role", report["user"])
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)
Esempio n. 5
0
class AdminNotifyHandlerTest(ZulipTestCase):
    logger = logging.getLogger('django')

    def setUp(self) -> None:
        self.handler = AdminNotifyHandler()
        # Prevent the exceptions we're going to raise from being printed
        # You may want to disable this when debugging tests
        settings.LOGGING_ENABLED = False

        global captured_exc_info
        global captured_request
        captured_request = None
        captured_exc_info = None

    def tearDown(self) -> None:
        settings.LOGGING_ENABLED = True

    def get_admin_zulip_handler(self) -> AdminNotifyHandler:
        return [
            h for h in logging.getLogger('').handlers
            if isinstance(h, AdminNotifyHandler)
        ][0]

    @patch('zerver.logging_handlers.try_git_describe')
    def test_basic(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A random exception passes happily through AdminNotifyHandler"""
        handler = self.get_admin_zulip_handler()
        try:
            raise Exception("Testing Error!")
        except Exception:
            exc_info = sys.exc_info()
        record = self.logger.makeRecord('name', logging.ERROR, 'function', 16,
                                        'message', {}, exc_info)
        handler.emit(record)

    def simulate_error(self) -> logging.LogRecord:
        email = self.example_email('hamlet')
        self.login(email)
        with patch("zerver.decorator.rate_limit") as rate_limit_patch:
            rate_limit_patch.side_effect = capture_and_throw
            result = self.client_get("/json/users")
            self.assert_json_error(result, "Internal server error", status_code=500)
            rate_limit_patch.assert_called_once()

        record = self.logger.makeRecord('name', logging.ERROR, 'function', 15,
                                        'message', {}, captured_exc_info)
        record.request = captured_request  # type: ignore # this field is dynamically added
        return record

    def run_handler(self, record: logging.LogRecord) -> Dict[str, Any]:
        with patch('zerver.lib.error_notify.notify_server_error') as patched_notify:
            self.handler.emit(record)
            patched_notify.assert_called_once()
            return patched_notify.call_args[0][0]

    @patch('zerver.logging_handlers.try_git_describe')
    def test_long_exception_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A request with no stack and multi-line report.getMessage() is handled properly"""
        record = self.simulate_error()
        record.exc_info = None
        record.msg = 'message\nmoremesssage\nmore'

        report = self.run_handler(record)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)
        self.assertEqual(report['stack_trace'], 'message\nmoremesssage\nmore')
        self.assertEqual(report['message'], 'message')

    @patch('zerver.logging_handlers.try_git_describe')
    def test_request(self, mock_function: MagicMock) -> None:
        mock_function.return_value = None
        """A normal request is handled properly"""
        record = self.simulate_error()

        report = self.run_handler(record)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test that `add_request_metadata` throwing an exception is fine
        with patch("zerver.logging_handlers.traceback.print_exc"):
            with patch("zerver.logging_handlers.add_request_metadata",
                       side_effect=Exception("Unexpected exception!")):
                report = self.run_handler(record)
        self.assertNotIn("user_email", report)
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"], "See /var/log/zulip/errors.log")

        # Check anonymous user is handled correctly
        record.request.user = AnonymousUser()  # type: ignore # this field is dynamically added
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Now simulate a DisallowedHost exception
        def get_host_error() -> None:
            raise Exception("Get Host Failure!")
        orig_get_host = record.request.get_host  # type: ignore # this field is dynamically added
        record.request.get_host = get_host_error  # type: ignore # this field is dynamically added
        report = self.run_handler(record)
        record.request.get_host = orig_get_host  # type: ignore # this field is dynamically added
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test an exception_filter exception
        with patch("zerver.logging_handlers.get_exception_reporter_filter",
                   return_value=15):
            record.request.method = "POST"  # type: ignore # this field is dynamically added
            report = self.run_handler(record)
            record.request.method = "GET"  # type: ignore # this field is dynamically added
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)

        # Test the catch-all exception handler doesn't throw
        with patch('zerver.lib.error_notify.notify_server_error',
                   side_effect=Exception("queue error")):
            self.handler.emit(record)
        with self.settings(STAGING_ERROR_NOTIFICATIONS=False):
            with patch('zerver.logging_handlers.queue_json_publish',
                       side_effect=Exception("queue error")):
                self.handler.emit(record)

        # Test no exc_info
        record.exc_info = None
        report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertEqual(report["stack_trace"], 'No stack trace available')

        # Test arbitrary exceptions from request.user
        record.request.user = None  # type: ignore # this field is dynamically added
        with patch("zerver.logging_handlers.traceback.print_exc"):
            report = self.run_handler(record)
        self.assertIn("host", report)
        self.assertIn("user_email", report)
        self.assertIn("message", report)
        self.assertIn("stack_trace", report)