Skip to content

Commit

Permalink
Merge pull request #6524 from drew2a/fix/6509
Browse files Browse the repository at this point in the history
Refactor the error reporting chain
  • Loading branch information
drew2a authored Nov 5, 2021
2 parents 4d3bd70 + 89c2cbc commit 8b51589
Show file tree
Hide file tree
Showing 18 changed files with 407 additions and 115 deletions.
14 changes: 14 additions & 0 deletions src/tribler-common/tribler_common/reported_error.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,14 @@
from dataclasses import dataclass
from typing import Optional


@dataclass
class ReportedError:
type: str
text: str
event: dict

long_text: str = ''
context: str = ''
should_stop: Optional[bool] = None
requires_user_consent: bool = True
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,9 @@
"""
import re

LONG_TEXT_DELIMITER = '--LONG TEXT--'
CONTEXT_DELIMITER = '--CONTEXT--'


def parse_os_environ(array):
"""Parse os.environ field.
Expand Down Expand Up @@ -52,12 +55,11 @@ def parse_stacktrace(stacktrace, delimiters=None):
Returns:
The generator of stacktrace parts.
"""
if delimiters is None:
delimiters = ['--LONG TEXT--', '--CONTEXT--']

if not stacktrace:
return

delimiters = delimiters or [LONG_TEXT_DELIMITER, CONTEXT_DELIMITER]

for part in re.split('|'.join(delimiters), stacktrace):
yield [line for line in re.split(r'\\n|\n', part) if line]

Expand Down
110 changes: 64 additions & 46 deletions src/tribler-core/tribler_core/components/reporter/exception_handler.py
Original file line number Diff line number Diff line change
@@ -1,34 +1,34 @@
import errno
import logging
import re
import sys
from io import StringIO
from socket import gaierror
from traceback import print_exception
from typing import Callable, Optional

from tribler_common.reported_error import ReportedError
from tribler_common.sentry_reporter.sentry_reporter import SentryReporter

from tribler_core.components.base import ComponentStartupException
from tribler_core.utilities.utilities import froze_it

if sys.platform == 'win32':
SOCKET_BLOCK_ERRORCODE = 10035 # WSAEWOULDBLOCK
else:
SOCKET_BLOCK_ERRORCODE = errno.EWOULDBLOCK
# There are some errors that we are ignoring.
IGNORED_ERRORS = {
# No route to host: this issue is non-critical since Tribler can still function when a request fails.
(OSError, 113): "Observed no route to host error (but ignoring)."
"This might indicate a problem with your firewall.",
IGNORED_ERRORS_BY_CODE = {
(OSError, 113), # No route to host is non-critical since Tribler can still function when a request fails.
# Socket block: this sometimes occurs on Windows and is non-critical.
(BlockingIOError, SOCKET_BLOCK_ERRORCODE): f"Unable to send data due to builtins.OSError {SOCKET_BLOCK_ERRORCODE}",
(OSError, 51): "Could not send data: network is unreachable.",
(ConnectionAbortedError, 10053): "An established connection was aborted by the software in your host machine.",
(ConnectionResetError, 10054): "Connection forcibly closed by the remote host.",
(OSError, 10022): "Failed to get address info. Error code: 10022",
(OSError, 16): "Socket error: Device or resource busy. Error code: 16",
(OSError, 0): "",
gaierror: "Unable to perform DNS lookup."
(BlockingIOError, 10035 if sys.platform == 'win32' else errno.EWOULDBLOCK),
(OSError, 51), # Could not send data: network is unreachable.
(ConnectionAbortedError, 10053), # An established connection was aborted by the software in your host machine.
(ConnectionResetError, 10054), # Connection forcibly closed by the remote host.
(OSError, 10022), # Failed to get address info.
(OSError, 16), # Socket error: Device or resource busy.
(OSError, 0)
}

IGNORED_ERRORS_BY_REGEX = {
gaierror: r'', # all gaierror is ignored
RuntimeError: r'.*invalid info-hash.*'
}


Expand All @@ -40,7 +40,34 @@ class CoreExceptionHandler:
"""

_logger = logging.getLogger("CoreExceptionHandler")
report_callback: Optional[Callable] = None
report_callback: Optional[Callable[[ReportedError], None]] = None
requires_user_consent: bool = True

@staticmethod
def _get_long_text_from(exception: Exception):
with StringIO() as buffer:
print_exception(type(exception), exception, exception.__traceback__, file=buffer)
return buffer.getvalue()

@classmethod
def _create_exception_from(cls, message: str):
text = f'Received error without exception: {message}'
cls._logger.warning(text)
return Exception(text)

@classmethod
def _is_ignored(cls, exception: Exception):
exception_class = exception.__class__
error_number = exception.errno if hasattr(exception, 'errno') else None

if (exception_class, error_number) in IGNORED_ERRORS_BY_CODE:
return True

if exception_class not in IGNORED_ERRORS_BY_REGEX:
return False

pattern = IGNORED_ERRORS_BY_REGEX[exception_class]
return re.search(pattern, str(exception)) is not None

@classmethod
def unhandled_error_observer(cls, loop, context): # pylint: disable=unused-argument
Expand All @@ -52,42 +79,33 @@ def unhandled_error_observer(cls, loop, context): # pylint: disable=unused-argu
SentryReporter.ignore_logger(cls._logger.name)

should_stop = True
exception = context.get('exception')
context = context.copy()
message = context.pop('message', 'no message')
exception = context.pop('exception', None) or cls._create_exception_from(message)
# Exception
text = str(exception)
if isinstance(exception, ComponentStartupException):
should_stop = exception.component.tribler_should_stop_on_component_error
exception = exception.__cause__

ignored_message = None
try:
ignored_message = IGNORED_ERRORS.get(
(exception.__class__, exception.errno),
IGNORED_ERRORS.get(exception.__class__))
except (ValueError, AttributeError):
pass
if ignored_message is not None:
cls._logger.error(ignored_message if ignored_message != "" else context.get('message'))
if cls._is_ignored(exception):
cls._logger.warning(exception)
return

text = str(exception or context.get('message'))
# We already have a check for invalid infohash when adding a torrent, but if somehow we get this
# error then we simply log and ignore it.
if isinstance(exception, RuntimeError) and 'invalid info-hash' in text:
cls._logger.error("Invalid info-hash found")
return

exc_type_name = exc_long_text = text
if isinstance(exception, Exception):
exc_type_name = type(exception).__name__
with StringIO() as buffer:
print_exception(type(exception), exception, exception.__traceback__, file=buffer)
exc_long_text = exc_long_text + "\n--LONG TEXT--\n" + buffer.getvalue()
exc_long_text = exc_long_text + "\n--CONTEXT--\n" + str(context)
cls._logger.error("Unhandled exception occurred! %s", exc_long_text, exc_info=None)

sentry_event = SentryReporter.event_from_exception(exception)
long_text = cls._get_long_text_from(exception)
cls._logger.error(f"Unhandled exception occurred! {exception}\n{long_text}")

if cls.report_callback is not None:
cls.report_callback(exc_type_name, exc_long_text, sentry_event, should_stop=should_stop) # pylint: disable=not-callable
reported_error = ReportedError(
type=exception.__class__.__name__,
text=text,
long_text=long_text,
context=str(context),
event=SentryReporter.event_from_exception(exception) or {},
requires_user_consent=cls.requires_user_consent,
should_stop=should_stop
)
if cls.report_callback:
cls.report_callback(reported_error) # pylint: disable=not-callable

except Exception as ex:
SentryReporter.capture_exception(ex)
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,103 @@
from socket import gaierror
from unittest.mock import MagicMock, patch

import pytest

from tribler_common.sentry_reporter import sentry_reporter
from tribler_common.sentry_reporter.sentry_reporter import SentryReporter

from tribler_core.components.reporter.exception_handler import CoreExceptionHandler

pytestmark = pytest.mark.asyncio


# pylint: disable=protected-access
# fmt: off

def raise_error(error): # pylint: disable=inconsistent-return-statements
try:
raise error
except error.__class__ as e:
return e


async def test_is_ignored():
# test that CoreExceptionHandler ignores specific exceptions

# by type
assert CoreExceptionHandler._is_ignored(OSError(113, 'Any'))
assert CoreExceptionHandler._is_ignored(ConnectionResetError(10054, 'Any'))

# by class
assert CoreExceptionHandler._is_ignored(gaierror('Any'))

# by class and substring
assert CoreExceptionHandler._is_ignored(RuntimeError('Message that contains invalid info-hash'))


async def test_is_not_ignored():
# test that CoreExceptionHandler do not ignore exceptions out of
# IGNORED_ERRORS_BY_CODE and IGNORED_ERRORS_BY_SUBSTRING
assert not CoreExceptionHandler._is_ignored(OSError(1, 'Any'))
assert not CoreExceptionHandler._is_ignored(RuntimeError('Any'))
assert not CoreExceptionHandler._is_ignored(AttributeError())


async def test_create_exception_from():
# test that CoreExceptionHandler can create an Exception from a string
assert isinstance(CoreExceptionHandler._create_exception_from('Any'), Exception)


async def test_get_long_text_from():
# test that CoreExceptionHandler can generate stacktrace from an Exception
error = raise_error(AttributeError('Any'))
actual_string = CoreExceptionHandler._get_long_text_from(error)
assert 'raise_error' in actual_string


@patch(f'{sentry_reporter.__name__}.{SentryReporter.__name__}.{SentryReporter.event_from_exception.__name__}',
new=MagicMock(return_value={'sentry': 'event'}))
async def test_unhandled_error_observer_exception():
# test that unhandled exception, represented by Exception, reported to the GUI
context = {'exception': raise_error(AttributeError('Any')), 'Any key': 'Any value'}
CoreExceptionHandler.report_callback = MagicMock()
CoreExceptionHandler.unhandled_error_observer(None, context)
CoreExceptionHandler.report_callback.assert_called()

# get the argument that has been passed to the report_callback
reported_error = CoreExceptionHandler.report_callback.call_args_list[-1][0][0]
assert reported_error.type == 'AttributeError'
assert reported_error.text == 'Any'
assert 'raise_error' in reported_error.long_text
assert reported_error.event == {'sentry': 'event'}
assert reported_error.context == "{'Any key': 'Any value'}"
assert reported_error.should_stop
assert reported_error.requires_user_consent


async def test_unhandled_error_observer_only_message():
# test that unhandled exception, represented by message, reported to the GUI
context = {'message': 'Any'}
CoreExceptionHandler.report_callback = MagicMock()
CoreExceptionHandler.unhandled_error_observer(None, context)
CoreExceptionHandler.report_callback.assert_called()

# get the argument that has been passed to the report_callback
reported_error = CoreExceptionHandler.report_callback.call_args_list[-1][0][0]
assert reported_error.type == 'Exception'
assert reported_error.text == 'Received error without exception: Any'
assert reported_error.long_text == 'Exception: Received error without exception: Any\n'
assert not reported_error.event
assert reported_error.context == '{}'
assert reported_error.should_stop
assert reported_error.requires_user_consent


async def test_unhandled_error_observer_ignored():
# test that exception from list IGNORED_ERRORS_BY_CODE never sends to the GUI
context = {'exception': OSError(113, '')}
CoreExceptionHandler.report_callback = MagicMock()
with patch.object(CoreExceptionHandler._logger, 'warning') as mocked_warning:
CoreExceptionHandler.unhandled_error_observer(None, context)
mocked_warning.assert_called_once()
CoreExceptionHandler.report_callback.assert_not_called()
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
import json
import time
from asyncio import CancelledError
from dataclasses import asdict

from aiohttp import web

Expand All @@ -12,6 +13,7 @@

from marshmallow.fields import Dict, String

from tribler_common.reported_error import ReportedError
from tribler_common.simpledefs import NTFY

from tribler_core.components.restapi.rest.rest_endpoint import RESTEndpoint, RESTStreamResponse
Expand Down Expand Up @@ -53,6 +55,8 @@ def passthrough(x):
# Report config error on startup
NTFY.REPORT_CONFIG_ERROR: passthrough,
}


# pylint: enable=line-too-long


Expand Down Expand Up @@ -92,6 +96,7 @@ def on_circuit_removed(circuit, *args):
"uptime": time.time() - circuit.creation_time
}
self.write_data({"type": NTFY.TUNNEL_REMOVE.value, "event": event})

# Tribler tunnel circuit has been removed
self.notifier.add_observer(NTFY.TUNNEL_REMOVE, on_circuit_removed)

Expand Down Expand Up @@ -123,15 +128,10 @@ async def write_data(self, message):

# An exception has occurred in Tribler. The event includes a readable
# string of the error and a Sentry event.
def on_tribler_exception(self, exc_type_name, exc_long_text, sentry_event, error_reporting_requires_user_consent,
should_stop=True):
def on_tribler_exception(self, reported_error: ReportedError):
self.write_data({
"type": NTFY.TRIBLER_EXCEPTION.value,
"exc_type_name": exc_type_name,
"exc_long_text": exc_long_text,
"sentry_event": sentry_event,
"error_reporting_requires_user_consent": error_reporting_requires_user_consent,
"should_stop": should_stop,
"error": asdict(reported_error),
})

@docs(
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,8 +8,8 @@

from tribler_common.simpledefs import NTFY, STATE_EXCEPTION, STATE_STARTED, STATE_STARTING, STATE_UPGRADING

from tribler_core.notifier import Notifier
from tribler_core.components.restapi.rest.rest_endpoint import RESTEndpoint, RESTResponse
from tribler_core.notifier import Notifier
from tribler_core.utilities.utilities import froze_it


Expand All @@ -23,7 +23,6 @@ def __init__(self,):
super().__init__()
self.tribler_state = STATE_STARTING
self.last_exception = None
self.sentry_event = None
self.notifier = None
self.readable_status = None

Expand All @@ -45,10 +44,9 @@ def on_tribler_upgrade_finished(self, *_):
def on_tribler_started(self, *_):
self.tribler_state = STATE_STARTED

def on_tribler_exception(self, exception_text, sentry_event):
def on_tribler_exception(self, exception_text):
self.tribler_state = STATE_EXCEPTION
self.last_exception = exception_text
self.sentry_event = sentry_event

@docs(
tags=["General"],
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@

import pytest

from tribler_common.reported_error import ReportedError
from tribler_common.simpledefs import NTFY

from tribler_core.components.restapi.rest.rest_manager import ApiKeyMiddleware, RESTManager, error_middleware
Expand Down Expand Up @@ -96,7 +97,7 @@ async def test_events(rest_manager, notifier):
notifier.notify(subject, *data)
else:
notifier.notify(subject)
rest_manager.root_endpoint.endpoints['/events'].on_tribler_exception("exc_type", "exc_text", None, False)
rest_manager.root_endpoint.endpoints['/events'].on_tribler_exception(ReportedError('', '', {}, False))
await events_up.wait()

event_socket_task.cancel()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,6 @@ async def test_get_state(rest_api, endpoint):
Testing whether the API returns a correct state when requested
"""
endpoint.readable_status = "Started"
endpoint.on_tribler_exception("abcd", None)
endpoint.on_tribler_exception("abcd")
expected_json = {"state": STATE_EXCEPTION, "last_exception": "abcd", "readable_state": "Started"}
await do_request(rest_api, 'state', expected_code=200, expected_json=expected_json)
Loading

0 comments on commit 8b51589

Please sign in to comment.