From 8ed9bb33ed57134636acd89fd2165c1e508d8447 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Thu, 11 Nov 2021 14:35:55 +0100 Subject: [PATCH 01/12] Suppress exception on failed write to stdout during the application shutdown --- src/tribler-gui/tribler_gui/core_manager.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/tribler-gui/tribler_gui/core_manager.py b/src/tribler-gui/tribler_gui/core_manager.py index 8ad8ce80590..f3eeb6e17f2 100644 --- a/src/tribler-gui/tribler_gui/core_manager.py +++ b/src/tribler-gui/tribler_gui/core_manager.py @@ -64,7 +64,12 @@ def on_core_read_ready(self): if b'Traceback' in raw_output: self.core_traceback = decoded_output self.core_traceback_timestamp = int(round(time.time() * 1000)) - print(decoded_output.strip()) # noqa: T001 + try: + print(decoded_output.strip()) # noqa: T001 + except OSError: + # Possible reason - cannot write to stdout as it was already closed during the application shutdown + if not self.shutting_down: + raise def on_core_finished(self, exit_code, exit_status): if self.shutting_down and self.should_stop_on_shutdown: From 43f74615c552da52f931ab14671d81d24c099092 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Thu, 11 Nov 2021 14:45:10 +0100 Subject: [PATCH 02/12] Do not report KeyboardInterrupt exception to Sentry --- .../tribler_common/sentry_reporter/sentry_reporter.py | 1 + 1 file changed, 1 insertion(+) diff --git a/src/tribler-common/tribler_common/sentry_reporter/sentry_reporter.py b/src/tribler-common/tribler_common/sentry_reporter/sentry_reporter.py index 5e43ab2dbd7..0aa9acb8235 100644 --- a/src/tribler-common/tribler_common/sentry_reporter/sentry_reporter.py +++ b/src/tribler-common/tribler_common/sentry_reporter/sentry_reporter.py @@ -118,6 +118,7 @@ def scrub_event(self, event): ThreadingIntegration(propagate_hub=True), ], before_send=SentryReporter._before_send, + ignore_errors=[KeyboardInterrupt], ) ignore_logger(SentryReporter._sentry_logger_name) From 446ef47970ded42e31743bf375d3b4bcfcbd4a5b Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Thu, 11 Nov 2021 17:16:52 +0100 Subject: [PATCH 03/12] Suppress reporting of errors to Sentry on Tribler exit (necessary when run Tribler via Application Tester) --- src/run_tribler.py | 8 +++++--- src/tribler-gui/tribler_gui/error_handler.py | 6 +++++- 2 files changed, 10 insertions(+), 4 deletions(-) diff --git a/src/run_tribler.py b/src/run_tribler.py index 7d5690b5b09..8a3bcdb3f46 100644 --- a/src/run_tribler.py +++ b/src/run_tribler.py @@ -4,15 +4,15 @@ from PyQt5.QtCore import QSettings +from tribler_common.sentry_reporter.sentry_reporter import SentryReporter, SentryStrategy +from tribler_common.sentry_reporter.sentry_scrubber import SentryScrubber + logger = logging.getLogger(__name__) CONFIG_FILE_NAME = 'triblerd.conf' # pylint: disable=import-outside-toplevel, ungrouped-imports def init_sentry_reporter(): - from tribler_common.sentry_reporter.sentry_reporter import SentryReporter, SentryStrategy - from tribler_common.sentry_reporter.sentry_scrubber import SentryScrubber - """ Initialise sentry reporter We use `sentry_url` as a URL for normal tribler mode and TRIBLER_TEST_SENTRY_URL @@ -138,4 +138,6 @@ def init_boot_logger(): # Flush all the logs to make sure it is written to file before it exits for handler in logging.getLogger().handlers: handler.flush() + + SentryReporter.global_strategy = SentryStrategy.SEND_SUPPRESSED raise diff --git a/src/tribler-gui/tribler_gui/error_handler.py b/src/tribler-gui/tribler_gui/error_handler.py index 2756b099186..dbbabd227a6 100644 --- a/src/tribler-gui/tribler_gui/error_handler.py +++ b/src/tribler-gui/tribler_gui/error_handler.py @@ -3,7 +3,7 @@ import traceback from tribler_common.reported_error import ReportedError -from tribler_common.sentry_reporter.sentry_reporter import SentryReporter +from tribler_common.sentry_reporter.sentry_reporter import SentryReporter, SentryStrategy # fmt: off from tribler_gui.dialogs.feedbackdialog import FeedbackDialog @@ -26,6 +26,10 @@ def gui_error(self, *exc_info): return info_type, info_error, tb = exc_info + if SentryReporter.global_strategy == SentryStrategy.SEND_SUPPRESSED: + self._logger.info(f'GUI error was suppressed and not sent to Sentry: {info_type.__name__}: {info_error}') + return + if info_type in self._handled_exceptions: return self._handled_exceptions.add(info_type) From 7e036c4d76094067fb81c36c30d848906cc5b0f3 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Mon, 15 Nov 2021 11:59:18 +0100 Subject: [PATCH 04/12] Remove lock file and flush logs when Tribler crashes --- src/tribler-core/tribler_core/start_core.py | 16 +++++++++------- 1 file changed, 9 insertions(+), 7 deletions(-) diff --git a/src/tribler-core/tribler_core/start_core.py b/src/tribler-core/tribler_core/start_core.py index e0fff49237b..79eed260c15 100644 --- a/src/tribler-core/tribler_core/start_core.py +++ b/src/tribler-core/tribler_core/start_core.py @@ -174,12 +174,14 @@ def start_tribler_core(base_path, api_port, api_key, root_state_dir, gui_test_mo loop = asyncio.get_event_loop() loop.set_exception_handler(CoreExceptionHandler.unhandled_error_observer) - loop.run_until_complete(core_session(config, components=list(components_gen(config)))) + try: + loop.run_until_complete(core_session(config, components=list(components_gen(config)))) + finally: + if trace_logger: + trace_logger.close() - if trace_logger: - trace_logger.close() + process_checker.remove_lock_file() - process_checker.remove_lock_file() - # Flush the logs to the file before exiting - for handler in logging.getLogger().handlers: - handler.flush() + # Flush the logs to the file before exiting + for handler in logging.getLogger().handlers: + handler.flush() From f8278c77d717f571f5a383716d61737b792998fe Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Tue, 16 Nov 2021 08:33:58 +0100 Subject: [PATCH 05/12] Handle psutil.NoSuchProcess exception when calling psutil.Process(old_pid).status() --- src/tribler-core/tribler_core/check_os.py | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/src/tribler-core/tribler_core/check_os.py b/src/tribler-core/tribler_core/check_os.py index 613960303a3..287fff41c4c 100644 --- a/src/tribler-core/tribler_core/check_os.py +++ b/src/tribler-core/tribler_core/check_os.py @@ -89,8 +89,14 @@ def should_kill_other_tribler_instances(root_state_dir): if current_pid != old_pid and old_pid > 0: # If the old process is a zombie, simply kill it and restart Tribler old_process = psutil.Process(old_pid) - logger.info(f'Old process status: {old_process.status()}') - if old_process.status() == psutil.STATUS_ZOMBIE: + try: + old_process_status = old_process.status() + except psutil.NoSuchProcess: + logger.info(f'Old process not found') + return + + logger.info(f'Old process status: {old_process_status}') + if old_process_status == psutil.STATUS_ZOMBIE: kill_tribler_process(old_process) restart_tribler_properly() return From eec8c2c776995ce92917b9c2d573d612f5ce5277 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Tue, 16 Nov 2021 10:07:46 +0100 Subject: [PATCH 06/12] Add more log messages on Tribler shutdown --- src/tribler-gui/tribler_gui/core_manager.py | 2 ++ src/tribler-gui/tribler_gui/tribler_window.py | 1 + 2 files changed, 3 insertions(+) diff --git a/src/tribler-gui/tribler_gui/core_manager.py b/src/tribler-gui/tribler_gui/core_manager.py index f3eeb6e17f2..9c7729aa5e2 100644 --- a/src/tribler-gui/tribler_gui/core_manager.py +++ b/src/tribler-gui/tribler_gui/core_manager.py @@ -202,7 +202,9 @@ def on_received_state(self, state): raise RuntimeError(state['last_exception']) def stop(self, stop_app_on_shutdown=True): + self._logger.info("Stopping Core manager") if self.core_process or self.is_core_running: + self._logger.info("Sending shutdown request to Tribler Core") self.events_manager.shutting_down = True TriblerNetworkRequest("shutdown", lambda _: None, method="PUT", priority=QNetworkRequest.HighPriority) diff --git a/src/tribler-gui/tribler_gui/tribler_window.py b/src/tribler-gui/tribler_gui/tribler_window.py index fc4c4b67112..16cc6d80325 100644 --- a/src/tribler-gui/tribler_gui/tribler_window.py +++ b/src/tribler-gui/tribler_gui/tribler_window.py @@ -1072,6 +1072,7 @@ def show_force_shutdown(): self.gui_settings.setValue("size", self.size()) if self.core_manager.use_existing_core: + self._logger.info("Quitting Tribler GUI without stopping Tribler Core") # Don't close the core that we are using QApplication.quit() From 15c4d4f85667197567bebaf382446356b0392fa5 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Tue, 16 Nov 2021 19:11:11 +0100 Subject: [PATCH 07/12] Sort hidden imports --- tribler.spec | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/tribler.spec b/tribler.spec index b70cb88635e..35f5b1ee529 100644 --- a/tribler.spec +++ b/tribler.spec @@ -93,18 +93,18 @@ hiddenimports = [ 'csv', 'dataclasses', # https://github.com/pyinstaller/pyinstaller/issues/5432 'ecdsa', - 'pyaes', 'PIL', - 'scrypt', '_scrypt', - 'sqlalchemy', 'sqlalchemy.ext.baked', 'sqlalchemy.ext.declarative', 'pkg_resources', # 'pkg_resources.py2_warn', # Workaround PyInstaller & SetupTools, https://github.com/pypa/setuptools/issues/1963 - 'requests', + 'pyaes', 'pydantic', - 'PyQt5.QtTest', 'pyqtgraph', 'pyqtgraph.graphicsItems.PlotItem.plotConfigTemplate_pyqt5', 'pyqtgraph.graphicsItems.ViewBox.axisCtrlTemplate_pyqt5', 'pyqtgraph.imageview.ImageViewTemplate_pyqt5', + 'PyQt5.QtTest', + 'requests', + 'scrypt', '_scrypt', + 'sqlalchemy', 'sqlalchemy.ext.baked', 'sqlalchemy.ext.declarative', ] + widget_files + pony_deps + get_sentry_hooks() # https://github.com/pyinstaller/pyinstaller/issues/5359 From 7e8c1d41b71948816c182ca7139349553221fa76 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Tue, 16 Nov 2021 19:16:46 +0100 Subject: [PATCH 08/12] Fix for `LookupError: unknown encoding: idna` in `resolve_addresses` --- src/run_tribler.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/src/run_tribler.py b/src/run_tribler.py index 8a3bcdb3f46..a1111d75fcd 100644 --- a/src/run_tribler.py +++ b/src/run_tribler.py @@ -1,3 +1,8 @@ +# A fix for "LookupError: unknown encoding: idna" error. +# Adding encodings.idna to hiddenimports is not enough. +# https://github.com/pyinstaller/pyinstaller/issues/1113 +import encodings.idna # pylint: disable=unused-import + import logging.config import os import sys From 0b00a1b197848f98adefd02107a1136af0f7f4a0 Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Wed, 17 Nov 2021 20:21:36 +0100 Subject: [PATCH 09/12] Add more logging on shutdown --- src/run_tribler.py | 1 + src/tribler-core/tribler_core/start_core.py | 1 + 2 files changed, 2 insertions(+) diff --git a/src/run_tribler.py b/src/run_tribler.py index a1111d75fcd..b60faecc503 100644 --- a/src/run_tribler.py +++ b/src/run_tribler.py @@ -140,6 +140,7 @@ def init_boot_logger(): logger.info("Shutting down Tribler") if trace_logger: trace_logger.close() + # Flush all the logs to make sure it is written to file before it exits for handler in logging.getLogger().handlers: handler.flush() diff --git a/src/tribler-core/tribler_core/start_core.py b/src/tribler-core/tribler_core/start_core.py index 79eed260c15..32cfc78d19e 100644 --- a/src/tribler-core/tribler_core/start_core.py +++ b/src/tribler-core/tribler_core/start_core.py @@ -180,6 +180,7 @@ def start_tribler_core(base_path, api_port, api_key, root_state_dir, gui_test_mo if trace_logger: trace_logger.close() + logger.info('Remove lock file') process_checker.remove_lock_file() # Flush the logs to the file before exiting From b4f7891ed07ea88dac4b69d800a2bad0a9c7ad0f Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Fri, 19 Nov 2021 16:29:28 +0100 Subject: [PATCH 10/12] Add typing_extensions to hiddenimports --- tribler.spec | 1 + 1 file changed, 1 insertion(+) diff --git a/tribler.spec b/tribler.spec index 35f5b1ee529..7c71479fbae 100644 --- a/tribler.spec +++ b/tribler.spec @@ -105,6 +105,7 @@ hiddenimports = [ 'requests', 'scrypt', '_scrypt', 'sqlalchemy', 'sqlalchemy.ext.baked', 'sqlalchemy.ext.declarative', + 'typing_extensions', ] + widget_files + pony_deps + get_sentry_hooks() # https://github.com/pyinstaller/pyinstaller/issues/5359 From 27efb4e8e4956162472fbe303f66b24e9cc3324b Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Fri, 19 Nov 2021 16:42:51 +0100 Subject: [PATCH 11/12] Specify version of typing_extension (temporarily in makedist_win.bat) --- build/win/makedist_win.bat | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/build/win/makedist_win.bat b/build/win/makedist_win.bat index ee4b5fef86a..957c238321a 100644 --- a/build/win/makedist_win.bat +++ b/build/win/makedist_win.bat @@ -46,7 +46,7 @@ REM Arno: When adding files here, make sure tribler.nsi actually REM packs them in the installer .EXE python3 -m pip install --upgrade --no-deps --force-reinstall pydantic --no-binary pydantic -python3 -m pip install --upgrade --no-deps --force-reinstall typing_extensions --no-binary typing_extensions +python3 -m pip install --upgrade --no-deps --force-reinstall typing_extensions==3.10.0.2 --no-binary typing_extensions %PYTHONHOME%\Scripts\pyinstaller.exe tribler.spec From fe08244bb3719fbc1b3dc74ef59c982c4890247a Mon Sep 17 00:00:00 2001 From: Alexander Kozlovsky Date: Fri, 19 Nov 2021 18:19:36 +0100 Subject: [PATCH 12/12] Tests added for better coverage --- src/run_tribler.py | 1 - src/tribler-core/tribler_core/check_os.py | 2 +- .../tribler_core/tests/test_check_os.py | 38 ++++++++++++++++++- .../tribler_gui/tests/test_core_manager.py | 16 ++++++++ .../tribler_gui/tests/test_error_handler.py | 12 ++++++ 5 files changed, 65 insertions(+), 4 deletions(-) diff --git a/src/run_tribler.py b/src/run_tribler.py index b60faecc503..166126aaa57 100644 --- a/src/run_tribler.py +++ b/src/run_tribler.py @@ -2,7 +2,6 @@ # Adding encodings.idna to hiddenimports is not enough. # https://github.com/pyinstaller/pyinstaller/issues/1113 import encodings.idna # pylint: disable=unused-import - import logging.config import os import sys diff --git a/src/tribler-core/tribler_core/check_os.py b/src/tribler-core/tribler_core/check_os.py index 287fff41c4c..a9e8b838551 100644 --- a/src/tribler-core/tribler_core/check_os.py +++ b/src/tribler-core/tribler_core/check_os.py @@ -92,7 +92,7 @@ def should_kill_other_tribler_instances(root_state_dir): try: old_process_status = old_process.status() except psutil.NoSuchProcess: - logger.info(f'Old process not found') + logger.info('Old process not found') return logger.info(f'Old process status: {old_process_status}') diff --git a/src/tribler-core/tribler_core/tests/test_check_os.py b/src/tribler-core/tribler_core/tests/test_check_os.py index 61c27e5f724..a8ed9e95e28 100644 --- a/src/tribler-core/tribler_core/tests/test_check_os.py +++ b/src/tribler-core/tribler_core/tests/test_check_os.py @@ -1,8 +1,10 @@ -from unittest.mock import patch +from unittest.mock import Mock, patch + +import psutil import pytest -from tribler_core.check_os import error_and_exit +from tribler_core.check_os import error_and_exit, should_kill_other_tribler_instances pytestmark = pytest.mark.asyncio @@ -14,3 +16,35 @@ async def test_error_and_exit(mocked_show_system_popup, mocked_sys_exit): error_and_exit('title', 'text') mocked_show_system_popup.assert_called_once_with('title', 'text') mocked_sys_exit.assert_called_once_with(1) + + +@patch('tribler_core.check_os.logger.info') +@patch('sys.argv', []) +@patch('tribler_core.check_os.get_existing_tribler_pid', Mock(return_value=100)) +@patch('os.getpid', Mock(return_value=200)) +@patch('psutil.Process', Mock(return_value=Mock(status=Mock(side_effect=psutil.NoSuchProcess(100))))) +def test_should_kill_other_tribler_instances_process_not_found( + mocked_logger_info: Mock +): + root_state_dir = Mock() + should_kill_other_tribler_instances(root_state_dir) + mocked_logger_info.assert_called_with('Old process not found') + + +@patch('tribler_core.check_os.logger.info') +@patch('sys.argv', []) +@patch('tribler_core.check_os.get_existing_tribler_pid', Mock(return_value=100)) +@patch('os.getpid', Mock(return_value=200)) +@patch('psutil.Process', Mock(return_value=Mock(status=Mock(return_value=psutil.STATUS_ZOMBIE)))) +@patch('tribler_core.check_os.kill_tribler_process') +@patch('tribler_core.check_os.restart_tribler_properly') +def test_should_kill_other_tribler_instances_zombie( + mocked_restart_tribler_properly: Mock, + mocked_kill_tribler_process: Mock, + mocked_logger_info: Mock, +): + root_state_dir = Mock() + should_kill_other_tribler_instances(root_state_dir) + mocked_logger_info.assert_called() + mocked_kill_tribler_process.assert_called_once() + mocked_restart_tribler_properly.assert_called_once() diff --git a/src/tribler-gui/tribler_gui/tests/test_core_manager.py b/src/tribler-gui/tribler_gui/tests/test_core_manager.py index dffbb4628fa..65e14e49e09 100644 --- a/src/tribler-gui/tribler_gui/tests/test_core_manager.py +++ b/src/tribler-gui/tribler_gui/tests/test_core_manager.py @@ -33,3 +33,19 @@ async def test_on_core_finished_raises_error(): with pytest.raises(CoreCrashedError): core_manager.on_core_finished(exit_code=1, exit_status='exit status') + + +@patch('tribler_gui.core_manager.EventRequestManager', new=MagicMock()) +@patch('builtins.print', MagicMock(side_effect=OSError())) +def test_on_core_read_ready(): + # test that OSError on writing to stdout is suppressed during shutting down + + core_manager = CoreManager(MagicMock(), MagicMock(), MagicMock()) + core_manager.core_process = MagicMock(read_all=MagicMock(return_value='')) + + with pytest.raises(OSError): + core_manager.on_core_read_ready() + + core_manager.shutting_down = True + # no exception during shutting down + core_manager.on_core_read_ready() diff --git a/src/tribler-gui/tribler_gui/tests/test_error_handler.py b/src/tribler-gui/tribler_gui/tests/test_error_handler.py index 8d763189017..071a6778496 100644 --- a/src/tribler-gui/tribler_gui/tests/test_error_handler.py +++ b/src/tribler-gui/tribler_gui/tests/test_error_handler.py @@ -3,6 +3,7 @@ import pytest from tribler_common.reported_error import ReportedError +from tribler_common.sentry_reporter.sentry_reporter import SentryStrategy from tribler_gui.error_handler import ErrorHandler from tribler_gui.exceptions import CoreConnectTimeoutError, CoreCrashedError @@ -31,6 +32,17 @@ async def test_gui_error_tribler_stopped(mocked_feedback_dialog: MagicMock, erro mocked_feedback_dialog.assert_not_called() +@patch('tribler_gui.error_handler.FeedbackDialog') +@patch('tribler_common.sentry_reporter.sentry_reporter.SentryReporter.global_strategy', SentryStrategy.SEND_SUPPRESSED) +async def test_gui_error_suppressed(mocked_feedback_dialog: MagicMock, error_handler: ErrorHandler): + logger_info_mock = MagicMock() + error_handler._logger = MagicMock(info=logger_info_mock) + error_handler.gui_error(AssertionError, AssertionError('error_text'), None) + mocked_feedback_dialog.assert_not_called() + assert not error_handler._handled_exceptions + logger_info_mock.assert_called_with('GUI error was suppressed and not sent to Sentry: AssertionError: error_text') + + @patch('tribler_gui.error_handler.FeedbackDialog') async def test_gui_info_type_in_handled_exceptions(mocked_feedback_dialog: MagicMock, error_handler: ErrorHandler): # test that if exception type in _handled_exceptions then FeedbackDialog is not called