Merge pull request #16 from facundobatista/error-messages

Added error report support (CRAFT-103).

craft_cli/errors.py

@@ -0,0 +1,59 @@
+#
+# Copyright 2021 Canonical Ltd.
+#
+# This program is free software; you can redistribute it and/or
+# modify it under the terms of the GNU Lesser General Public
+# License version 3 as published by the Free Software Foundation.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+# Lesser General Public License for more details.
+#
+# You should have received a copy of the GNU Lesser General Public License
+# along with this program; if not, write to the Free Software Foundation,
+# Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
+
+"""Error classes."""
+
+from typing import Optional
+
+
+class CraftError(Exception):
+    """Signal a program error with a lot of information to report.
+
+    :ivar message: the main message to the user, to be shown as first line (and
+      probably only that, according to the different modes); note that in some
+      cases the log location will be attached to this message.
+
+    :ivar details: the full error details received from a third party which
+      originated the error situation
+
+    :ivar resolution: an extra line indicating to the user how the error may be
+      fixed or avoided (to be shown together with 'message')
+
+    :ivar docs_url: an URL to point the user to documentation (to be shown
+      together with 'message')
+
+    :ivar reportable: if an error report should be sent to some error-handling
+      backend (like Sentry)
+
+    :ivar retcode: the code to return when the application finishes
+    """
+
+    def __init__(
+        self,
+        message: str,
+        *,
+        details: Optional[str] = None,
+        resolution: Optional[str] = None,
+        docs_url: Optional[str] = None,
+        reportable: bool = True,
+        retcode: int = 1,
+    ):
+        super().__init__(message)
+        self.details = details
+        self.resolution = resolution
+        self.docs_url = docs_url
+        self.reportable = reportable
+        self.retcode = retcode

craft_cli/messages.py

@@ -28,12 +28,15 @@
 import sys
 import threading
 import time
+import traceback
 from dataclasses import dataclass, field
 from datetime import datetime
 from typing import Literal, Optional, TextIO, Union
 
 import appdirs
 
+from craft_cli import errors
+
 
 @dataclass
 class _MessageInfo:  # pylint: disable=too-many-instance-attributes
@@ -105,6 +108,14 @@ def _get_log_filepath(appname: str) -> pathlib.Path:
     return basedir / filename
 
 
+def _get_traceback_lines(exc: BaseException):
+    """Get the traceback lines (if any) from an exception."""
+    tback_lines = traceback.format_exception(type(exc), exc, exc.__traceback__)
+    for tback_line in tback_lines:
+        for real_line in tback_line.rstrip().split("\n"):
+            yield real_line
+
+
 class _Spinner(threading.Thread):
     """A supervisor thread that will repeat long-standing messages with a spinner besides it.
 
@@ -655,3 +666,40 @@ def open_stream(self, text: str):
     def ended_ok(self) -> None:
         """Finish the messaging system gracefully."""
         self._printer.stop()  # type: ignore
+
+    def _report_error(self, error: errors.CraftError) -> None:
+        """Report the different message lines from a CraftError."""
+        if self._mode == EmitterMode.QUIET or self._mode == EmitterMode.NORMAL:
+            use_timestamp = False
+            full_stream = None
+        else:
+            use_timestamp = True
+            full_stream = sys.stderr
+
+        # the initial message
+        self._printer.show(sys.stderr, str(error), use_timestamp=use_timestamp, end_line=True)  # type: ignore
+
+        # detailed information and/or original exception
+        if error.details:
+            text = f"Detailed information: {error.details}"
+            self._printer.show(full_stream, text, use_timestamp=use_timestamp, end_line=True)  # type: ignore
+        if error.__cause__:
+            for line in _get_traceback_lines(error.__cause__):
+                self._printer.show(full_stream, line, use_timestamp=use_timestamp, end_line=True)  # type: ignore
+
+        # hints for the user to know more
+        if error.resolution:
+            text = f"Recommended resolution: {error.resolution}"
+            self._printer.show(sys.stderr, text, use_timestamp=use_timestamp, end_line=True)  # type: ignore
+        if error.docs_url:
+            text = f"For more information, check out: {error.docs_url}"
+            self._printer.show(sys.stderr, text, use_timestamp=use_timestamp, end_line=True)  # type: ignore
+
+        text = f"Full execution log: {str(self._log_filepath)!r}"
+        self._printer.show(sys.stderr, text, use_timestamp=use_timestamp, end_line=True)  # type: ignore
+
+    @_init_guard
+    def error(self, error: errors.CraftError) -> None:
+        """Handle the system's indicated error and stop machinery."""
+        self._report_error(error)
+        self._printer.stop()  # type: ignore

tests/unit/test_messages_emitter.py

@@ -23,6 +23,7 @@
 import pytest
 
 from craft_cli import messages
+from craft_cli.errors import CraftError
 from craft_cli.messages import Emitter, EmitterMode, _Handler
 
 
@@ -390,12 +391,237 @@ def test_openstream_in_verboseish_modes(get_initiated_emitter, mode):
     ]
 
 
-# -- tests for stopping the machinery
+# -- tests for stopping the machinery ok
 
 
 def test_ended_ok(get_initiated_emitter):
-    """Finish everything."""
+    """Finish everything ok."""
     emitter = get_initiated_emitter(EmitterMode.QUIET)
     emitter.ended_ok()
 
     assert emitter.printer_calls == [call().stop()]
+
+
+# -- tests for error reporting
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.QUIET, EmitterMode.NORMAL])
+def test_reporterror_simple_message_only_quietish(mode, get_initiated_emitter):
+    """Report just a simple message, in silent modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=False, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.VERBOSE, EmitterMode.TRACE])
+def test_reporterror_simple_message_only_verboseish(mode, get_initiated_emitter):
+    """Report just a simple message, in more verbose modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.QUIET, EmitterMode.NORMAL])
+def test_reporterror_detailed_info_quietish(mode, get_initiated_emitter):
+    """Report an error having detailed information, in silent modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", details="boom")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=False, end_line=True),
+        call().show(None, "Detailed information: boom", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=False, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.VERBOSE, EmitterMode.TRACE])
+def test_reporterror_detailed_info_verboseish(mode, get_initiated_emitter):
+    """Report an error having detailed information, in more verbose modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", details="boom")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "Detailed information: boom", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.QUIET, EmitterMode.NORMAL])
+def test_reporterror_chained_exception_quietish(mode, get_initiated_emitter):
+    """Report an error that was originated after other exception, in silent modes."""
+    emitter = get_initiated_emitter(mode)
+    try:
+        try:
+            raise ValueError("original")
+        except ValueError as err:
+            orig_exception = err
+            raise CraftError("test message") from err
+    except CraftError as err:
+        error = err
+
+    with patch("craft_cli.messages._get_traceback_lines") as tblines_mock:
+        tblines_mock.return_value = ["traceback line 1", "traceback line 2"]
+        emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=False, end_line=True),
+        call().show(None, "traceback line 1", use_timestamp=False, end_line=True),
+        call().show(None, "traceback line 2", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=False, end_line=True),
+        call().stop(),
+    ]
+
+    # check the traceback lines are generated using the original exception
+    tblines_mock.assert_called_with(orig_exception)  # type: ignore
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.VERBOSE, EmitterMode.TRACE])
+def test_reporterror_chained_exception_verboseish(mode, get_initiated_emitter):
+    """Report an error that was originated after other exception, in more verbose modes."""
+    emitter = get_initiated_emitter(mode)
+    try:
+        try:
+            raise ValueError("original")
+        except ValueError as err:
+            orig_exception = err
+            raise CraftError("test message") from err
+    except CraftError as err:
+        error = err
+
+    with patch("craft_cli.messages._get_traceback_lines") as tblines_mock:
+        tblines_mock.return_value = ["traceback line 1", "traceback line 2"]
+        emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "traceback line 1", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "traceback line 2", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]
+
+    # check the traceback lines are generated using the original exception
+    tblines_mock.assert_called_with(orig_exception)  # type: ignore
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.QUIET, EmitterMode.NORMAL])
+def test_reporterror_with_resolution_quietish(mode, get_initiated_emitter):
+    """Report an error with a recommended resolution, in silent modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", resolution="run")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, "Recommended resolution: run", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=False, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.VERBOSE, EmitterMode.TRACE])
+def test_reporterror_with_resolution_verboseish(mode, get_initiated_emitter):
+    """Report an error with a recommended resolution, in more verbose modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", resolution="run")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "Recommended resolution: run", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.QUIET, EmitterMode.NORMAL])
+def test_reporterror_with_docs_quietish(mode, get_initiated_emitter):
+    """Report including a docs url, in silent modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", docs_url="https://charmhub.io/docs/whatever")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    full_docs_message = "For more information, check out: https://charmhub.io/docs/whatever"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_docs_message, use_timestamp=False, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=False, end_line=True),
+        call().stop(),
+    ]
+
+
+@pytest.mark.parametrize("mode", [EmitterMode.VERBOSE, EmitterMode.TRACE])
+def test_reporterror_with_docs_verboseish(mode, get_initiated_emitter):
+    """Report including a docs url, in more verbose modes."""
+    emitter = get_initiated_emitter(mode)
+    error = CraftError("test message", docs_url="https://charmhub.io/docs/whatever")
+    emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    full_docs_message = "For more information, check out: https://charmhub.io/docs/whatever"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_docs_message, use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]
+
+
+def test_reporterror_full_complete(get_initiated_emitter):
+    """Sanity case to check order between the different parts."""
+    emitter = get_initiated_emitter(EmitterMode.TRACE)
+    try:
+        try:
+            raise ValueError("original")
+        except ValueError as err:
+            raise CraftError(
+                "test message",
+                details="boom",
+                resolution="run",
+                docs_url="https://charmhub.io/docs/whatever",
+            ) from err
+    except CraftError as err:
+        error = err
+
+    with patch("craft_cli.messages._get_traceback_lines") as tblines_mock:
+        tblines_mock.return_value = ["traceback line 1", "traceback line 2"]
+        emitter.error(error)
+
+    full_log_message = f"Full execution log: {repr(emitter._log_filepath)}"
+    full_docs_message = "For more information, check out: https://charmhub.io/docs/whatever"
+    assert emitter.printer_calls == [
+        call().show(sys.stderr, "test message", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "Detailed information: boom", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "traceback line 1", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "traceback line 2", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, "Recommended resolution: run", use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_docs_message, use_timestamp=True, end_line=True),
+        call().show(sys.stderr, full_log_message, use_timestamp=True, end_line=True),
+        call().stop(),
+    ]