Merge pull request #569 from mwhudson/error-report-5

generate crash reports

snapcraft.yaml

@@ -49,6 +49,7 @@ parts:
       - libsystemd0
       - iso-codes
       - lsb-release
+      - python3-apport
       - python3-distutils-extra
       - python3-urwid
       - python3-requests

subiquity/cmd/tui.py

@@ -109,7 +109,7 @@ def main():
         LOGDIR = ".subiquity"
         if opts.snaps_from_examples is None:
             opts.snaps_from_examples = True
-    setup_logger(dir=LOGDIR)
+    LOGFILE = setup_logger(dir=LOGDIR)
 
     logger = logging.getLogger('subiquity')
     logger.info("Starting SUbiquity v{}".format(VERSION))
@@ -142,6 +142,8 @@ def main():
 
     subiquity_interface = Subiquity(opts, block_log_dir)
 
+    subiquity_interface.note_file_for_apport("InstallerLog", LOGFILE)
+
     subiquity_interface.run()
 
 

subiquity/controllers/error.py

@@ -0,0 +1,166 @@
+# Copyright 2019 Canonical, Ltd.
+#
+# This program is free software: you can redistribute it and/or modify
+# it under the terms of the GNU Affero General Public License as
+# published by the Free Software Foundation, either version 3 of the
+# License, or (at your option) any later version.
+#
+# 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 Affero General Public License for more details.
+#
+# You should have received a copy of the GNU Affero General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+import enum
+import json
+import logging
+import os
+import time
+
+import apport
+import apport.crashdb
+import apport.hookutils
+
+import attr
+
+from subiquitycore.controller import BaseController
+
+
+log = logging.getLogger('subiquity.controllers.error')
+
+
+class ErrorReportState(enum.Enum):
+    INCOMPLETE = _("INCOMPLETE")
+    DONE = _("DONE")
+    ERROR = _("ERROR")
+
+
+class ErrorReportKind(enum.Enum):
+    BLOCK_PROBE_FAIL = _("Block device probe failure")
+    DISK_PROBE_FAIL = _("Disk probe failure")
+    INSTALL_FAIL = _("Install failure")
+    UI = _("Installer crash")
+    UNKNOWN = _("Unknown error")
+
+
+@attr.s(cmp=False)
+class ErrorReport:
+    controller = attr.ib()
+    base = attr.ib()
+    pr = attr.ib()
+    state = attr.ib()
+    _file = attr.ib()
+
+    meta = attr.ib(default=attr.Factory(dict))
+
+    @classmethod
+    def new(cls, controller, kind):
+        base = "installer.{:.9f}.{}".format(time.time(), kind.name.lower())
+        crash_file = open(
+            os.path.join(controller.crash_directory, base + ".crash"),
+            'wb')
+
+        pr = apport.Report('Bug')
+        pr['CrashDB'] = repr(controller.crashdb_spec)
+
+        r = cls(
+            controller=controller, base=base, pr=pr, file=crash_file,
+            state=ErrorReportState.INCOMPLETE)
+        r.set_meta("kind", kind.name)
+        return r
+
+    def add_info(self, _bg_attach_hook, wait=False):
+        log.debug("begin adding info for report %s", self.base)
+
+        def _bg_add_info():
+            _bg_attach_hook()
+            # Add basic info to report.
+            self.pr.add_proc_info()
+            self.pr.add_os_info()
+            self.pr.add_hooks_info(None)
+            apport.hookutils.attach_hardware(self.pr)
+            # Because apport-cli will in general be run on a different
+            # machine, we make some slightly obscure alterations to the report
+            # to make this go better.
+
+            # apport-cli gets upset if neither of these are present.
+            self.pr['Package'] = 'subiquity ' + os.environ.get(
+                "SNAP_REVISION", "SNAP_REVISION")
+            self.pr['SourcePackage'] = 'subiquity'
+
+            # If ExecutableTimestamp is present, apport-cli will try to check
+            # that ExecutablePath hasn't changed. But it won't be there.
+            del self.pr['ExecutableTimestamp']
+            # apport-cli gets upset at the probert C extensions it sees in
+            # here.  /proc/maps is very unlikely to be interesting for us
+            # anyway.
+            del self.pr['ProcMaps']
+            self.pr.write(self._file)
+
+        def added_info(fut):
+            log.debug("done adding info for report %s", self.base)
+            try:
+                fut.result()
+            except Exception:
+                self.state = ErrorReportState.ERROR
+                log.exception("adding info to problem report failed")
+            else:
+                self.state = ErrorReportState.DONE
+            self._file.close()
+            self._file = None
+        if wait:
+            _bg_add_info()
+        else:
+            self.controller.run_in_bg(_bg_add_info, added_info)
+
+    def _path_with_ext(self, ext):
+        return os.path.join(
+            self.controller.crash_directory, self.base + '.' + ext)
+
+    @property
+    def meta_path(self):
+        return self._path_with_ext('meta')
+
+    @property
+    def path(self):
+        return self._path_with_ext('crash')
+
+    def set_meta(self, key, value):
+        self.meta[key] = value
+        with open(self.meta_path, 'w') as fp:
+            json.dump(self.meta, fp, indent=4)
+
+    @property
+    def kind(self):
+        k = self.meta.get("kind", "UNKNOWN")
+        return getattr(ErrorReportKind, k, ErrorReportKind.UNKNOWN)
+
+
+class ErrorController(BaseController):
+
+    def __init__(self, app):
+        super().__init__(app)
+        self.crash_directory = os.path.join(self.app.root, 'var/crash')
+        self.crashdb_spec = {
+            'impl': 'launchpad',
+            'project': 'subiquity',
+            }
+        if self.app.opts.dry_run:
+            self.crashdb_spec['launchpad_instance'] = 'staging'
+        self.reports = []
+
+    def start(self):
+        os.makedirs(self.crash_directory, exist_ok=True)
+
+    def create_report(self, kind):
+        r = ErrorReport.new(self, kind)
+        self.reports.insert(0, r)
+        return r
+
+    def start_ui(self):
+        pass
+
+    def cancel(self):
+        pass

subiquity/controllers/filesystem.py

@@ -25,6 +25,7 @@ import pyudev
 from subiquitycore.controller import BaseController
 from subiquitycore.utils import run_command
 
+from subiquity.controllers.error import ErrorReportKind
 from subiquity.models.filesystem import (
     align_up,
     Bootloader,
@@ -67,6 +68,11 @@ class Probe:
         self.cb = cb
         self.state = ProbeState.NOT_STARTED
         self.result = None
+        if restricted:
+            self.kind = ErrorReportKind.DISK_PROBE_FAIL
+        else:
+            self.kind = ErrorReportKind.BLOCK_PROBE_FAIL
+        self.crash_report = None
 
     def start(self):
         block_discover_log.debug(
@@ -101,7 +107,8 @@ class Probe:
         except Exception:
             block_discover_log.exception(
                 "probing failed restricted=%s", self.restricted)
-            # Should make a crash report here!
+            self.crash_report = self.controller.app.make_apport_report(
+                self.kind, "block probing")
             self.state = ProbeState.FAILED
         else:
             block_discover_log.exception(
@@ -112,7 +119,8 @@ class Probe:
     def _check_timeout(self, loop, ud):
         if self.state != ProbeState.PROBING:
             return
-        # Should make a crash report here!
+        self.crash_report = self.controller.app.make_apport_report(
+            self.kind, "block probing timed out")
         block_discover_log.exception(
             "probing timed out restricted=%s", self.restricted)
         self.state = ProbeState.FAILED
@@ -187,16 +195,21 @@ class FilesystemController(BaseController):
             return
         if probe.restricted:
             fname = 'probe-data-restricted.json'
+            key = "ProbeDataRestricted"
         else:
             fname = 'probe-data.json'
-        with open(os.path.join(self.app.block_log_dir, fname), 'w') as fp:
+            key = "ProbeData"
+        fpath = os.path.join(self.app.block_log_dir, fname)
+        with open(fpath, 'w') as fp:
             json.dump(probe.result, fp, indent=4)
+        self.app.note_file_for_apport(key, fpath)
         try:
             self.model.load_probe_data(probe.result)
         except Exception:
             block_discover_log.exception(
                 "load_probe_data failed restricted=%s", probe.restricted)
-            # Should make a crash report here!
+            probe.crash_report = self.app.make_apport_report(
+                probe.kind, "loading probe data")
             if not probe.restricted:
                 self._start_probe(restricted=True)
             else:

subiquity/controllers/installprogress.py

@@ -26,14 +26,21 @@ import tempfile
 import time
 import traceback
 
+from curtin.commands.install import (
+    ERROR_TARFILE,
+    INSTALL_LOG,
+    )
+
 import urwid
-import yaml
 
 from systemd import journal
 
+import yaml
+
 from subiquitycore import utils
 from subiquitycore.controller import BaseController
 
+from subiquity.controllers.error import ErrorReportKind
 from subiquity.ui.views.installprogress import ProgressView
 
 
@@ -155,7 +162,7 @@ class StateMachine:
             raise
         except Exception:
             log.debug("%s failed", name)
-            self.controller.curtin_error(traceback.format_exc())
+            self.controller.curtin_error()
         else:
             log.debug("%s completed", name)
             if 'success' in self._transitions[name]:
@@ -245,12 +252,13 @@ class InstallProgressController(BaseController):
     def snap_config_done(self):
         self._step_done('snap')
 
-    def curtin_error(self, log_text=None):
+    def curtin_error(self):
-        log.debug('curtin_error: %s', log_text)
         self.install_state = InstallState.ERROR
+        self.app.make_apport_report(
+            ErrorReportKind.INSTALL_FAIL, "install failed")
         self.progress_view.spinner.stop()
-        if log_text:
+        if sys.exc_info()[0] is not None:
-            self.progress_view.add_log_line(log_text)
+            self.progress_view.add_log_line(traceback.format_exc())
         self.progress_view.set_status(('info_error',
                                        _("An error has occurred")))
         self.progress_view.show_complete(True)
@@ -334,6 +342,10 @@ class InstallProgressController(BaseController):
         self._write_config(config_location,
                            self.model.render(syslog_identifier=ident))
 
+        self.app.note_file_for_apport("CurtinConfig", config_location)
+        self.app.note_file_for_apport("CurtinLog", INSTALL_LOG)
+        self.app.note_file_for_apport("CurtinErrors", ERROR_TARFILE)
+
         return curtin_cmd
 
     def curtin_start_install(self):

subiquity/controllers/refresh.py

@@ -79,6 +79,9 @@ class RefreshController(BaseController):
         else:
             r = response.json()
             self.current_snap_version = r['result']['version']
+            for k in 'channel', 'revision', 'version':
+                self.app.note_data_for_apport(
+                    "Snap" + k.title(), r['result'][k])
             log.debug(
                 "current version of snap is: %r",
                 self.current_snap_version)

subiquity/core.py

@@ -16,9 +16,17 @@
 import logging
 import os
 import platform
+import sys
+import traceback
+
+import apport.hookutils
 
 from subiquitycore.core import Application
 
+from subiquity.controllers.error import (
+    ErrorController,
+    ErrorReportKind,
+    )
 from subiquity.models.subiquity import SubiquityModel
 from subiquity.snapd import (
     FakeSnapdConnection,
@@ -94,6 +102,18 @@ class Subiquity(Application):
             ('network-proxy-set', self._proxy_set),
             ('network-change', self._network_change),
             ])
+        self._apport_data = []
+        self._apport_files = []
+
+    def run(self):
+        try:
+            super().run()
+        except Exception:
+            print("generating crash report")
+            report = self.make_apport_report(
+                ErrorReportKind.UI, "Installer UI", wait=True)
+            print("report saved to {}".format(report.path))
+            raise
 
     def _network_change(self):
         self.signal.emit_signal('snapd-network-change')
@@ -125,3 +145,50 @@ class Subiquity(Application):
 
         self.run_command_in_foreground(
             "bash", before_hook=_before, cwd='/')
+
+    def load_controllers(self):
+        super().load_controllers()
+        self.error_controller = ErrorController(self)
+
+    def start_controllers(self):
+        super().start_controllers()
+        self.error_controller.start()
+
+    def note_file_for_apport(self, key, path):
+        self._apport_files.append((key, path))
+
+    def note_data_for_apport(self, key, value):
+        self._apport_data.append((key, value))
+
+    def make_apport_report(self, kind, thing, *, wait=False):
+        log.debug("generating crash report")
+
+        try:
+            report = self.error_controller.create_report(kind)
+        except Exception:
+            log.exception("creating crash report failed")
+            return
+
+        etype = sys.exc_info()[0]
+        if etype is not None:
+            report.pr["Title"] = "{} crashed with {}".format(
+                thing, etype.__name__)
+            report.pr['Traceback'] = traceback.format_exc()
+        else:
+            report.pr["Title"] = thing
+
+        apport_files = self._apport_files[:]
+        apport_data = self._apport_data.copy()
+
+        def _bg_attach_hook():
+            # Attach any stuff other parts of the code think we should know
+            # about.
+            for key, path in apport_files:
+                apport.hookutils.attach_file_if_exists(report.pr, path, key)
+            for key, value in apport_data:
+                report.pr[key] = value
+
+        report.add_info(_bg_attach_hook, wait)
+
+        # In the fullness of time we should do the signature thing here.
+        return report

subiquitycore/core.py

@@ -570,6 +570,12 @@ class Application:
                     orig, count)
         log.debug("load_controllers done")
 
+    def start_controllers(self):
+        log.debug("starting controllers")
+        for k in self.controllers:
+            self.controller_instances[k].start()
+        log.debug("controllers started")
+
     def load_serialized_state(self):
         for k in self.controllers:
             state_path = os.path.join(self.state_dir, 'states', k)
@@ -631,10 +637,7 @@ class Application:
                 0.05, select_initial_screen, initial_controller_index)
             self._connect_base_signals()
 
-            log.debug("starting controllers")
+            self.start_controllers()
-            for k in self.controllers:
-                self.controller_instances[k].start()
-            log.debug("controllers started")
 
             self.loop.run()
         except Exception: