Merge pull request #3247 from rtfd/improve-task-error-reporting

Improve error reporting to users

Author: ericholscher

readthedocs/doc_builder/environments.py

@@ -421,7 +421,11 @@ def update_build(self, state=None):
                 self.build['error'] = str(self.failure)
             else:
                 self.build['error'] = ugettext_noop(
-                    "An unexpected error occurred")
+                    "There was a problem with Read the Docs while building your documentation. "
+                    "Please report this to us with your build id ({build_id}).".format(
+                        build_id=self.build['pk']
+                    )
+                )
 
         # Attempt to stop unicode errors on build reporting
         for key, val in list(self.build.items()):

readthedocs/projects/tasks.py

@@ -108,20 +108,48 @@ def _log(self, msg):
                          version=self.version.slug,
                          msg=msg))
 
+    # pylint: disable=arguments-differ
     def run(self, pk, version_pk=None, build_pk=None, record=True,
             docker=False, search=True, force=False, localmedia=True, **__):
-        # pylint: disable=arguments-differ
-        self.project = self.get_project(pk)
-        self.version = self.get_version(self.project, version_pk)
-        self.build = self.get_build(build_pk)
-        self.build_search = search
-        self.build_localmedia = localmedia
-        self.build_force = force
-        self.config = None
+        """
+        Run a documentation build.
 
-        setup_successful = self.run_setup(record=record)
-        if setup_successful:
-            self.run_build(record=record, docker=docker)
+        This is fully wrapped in exception handling to account for a number of failure cases.
+        """
+        try:
+            self.project = self.get_project(pk)
+            self.version = self.get_version(self.project, version_pk)
+            self.build = self.get_build(build_pk)
+            self.build_search = search
+            self.build_localmedia = localmedia
+            self.build_force = force
+            self.config = None
+
+            setup_successful = self.run_setup(record=record)
+            if setup_successful:
+                self.run_build(record=record, docker=docker)
+            failure = self.setup_env.failure or self.build_env.failure
+        except Exception as e:  # noqa
+            log.exception('Top-level build exception has been raised', extra={'build': build_pk})
+            failure = str(e)
+
+        # **Always** report build status.
+        # This can still fail if the API Is totally down, but should catch more failures
+        result = {}
+        error = _('Unknown error encountered. '
+                  'Please include the build id ({build_id}) in any bug reports.'.format(
+                      build_id=build_pk
+                  ))
+        build_updates = {'state': BUILD_STATE_FINISHED}
+        build_data = {}
+        if hasattr(self, 'build'):
+            build_data.update(self.build)
+        if failure:
+            build_updates['success'] = False
+            build_updates['error'] = error
+        build_data.update(build_updates)
+        result = api_v2.build(build_pk).patch(build_updates)
+        return result
 
     def run_setup(self, record=True):
         """Run setup in the local environment.
@@ -166,7 +194,6 @@ def run_setup(self, record=True):
             if not isinstance(self.setup_env.failure, vcs_support_utils.LockTimeout):
                 self.send_notifications()
 
-            self.setup_env.update_build(state=BUILD_STATE_FINISHED)
             return False
 
         if self.setup_env.successful and not self.project.has_valid_clone:
@@ -230,14 +257,11 @@ def run_build(self, docker=False, record=True):
             self.send_notifications()
         build_complete.send(sender=Build, build=self.build_env.build)
 
-        self.build_env.update_build(state=BUILD_STATE_FINISHED)
-
     @staticmethod
     def get_project(project_pk):
         """Get project from API"""
         project_data = api_v2.project(project_pk).get()
-        project = APIProject(**project_data)
-        return project
+        return APIProject(**project_data)
 
     @staticmethod
     def get_version(project, version_pk):

readthedocs/restapi/client.py

@@ -4,7 +4,7 @@
 import logging
 
 from slumber import API, serialize
-from requests import Session
+import requests
 from django.conf import settings
 from rest_framework.renderers import JSONRenderer
 from rest_framework.parsers import JSONParser
@@ -32,8 +32,10 @@ def dumps(self, data):
 
 
 def setup_api():
-    session = Session()
+    session = requests.Session()
     session.headers.update({'Host': PRODUCTION_DOMAIN})
+    retry_adapter = requests.adapters.HTTPAdapter(max_retries=3)
+    session.mount(API_HOST, retry_adapter)
     api_config = {
         'base_url': '%s/api/v2/' % API_HOST,
         'serializer': serialize.Serializer(

readthedocs/rtd_tests/tests/test_celery.py

@@ -64,10 +64,9 @@ def test_clear_artifacts(self):
         self.assertTrue(result.successful())
         self.assertFalse(exists(directory))
 
-    @patch('readthedocs.projects.tasks.UpdateDocsTask.build_docs',
-           new=MagicMock)
-    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_vcs',
-           new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_environment', new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.build_docs', new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_vcs', new=MagicMock)
     def test_update_docs(self):
         build = get(Build, project=self.project,
                     version=self.project.versions.first())
@@ -80,11 +79,11 @@ def test_update_docs(self):
                 intersphinx=False)
         self.assertTrue(result.successful())
 
-    @patch('readthedocs.projects.tasks.UpdateDocsTask.build_docs',
-           new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_environment', new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.build_docs', new=MagicMock)
+    @patch('readthedocs.doc_builder.environments.BuildEnvironment.update_build', new=MagicMock)
     @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_vcs')
-    @patch('readthedocs.doc_builder.environments.BuildEnvironment.update_build')
-    def test_update_docs_unexpected_setup_exception(self, mock_update_build, mock_setup_vcs):
+    def test_update_docs_unexpected_setup_exception(self, mock_setup_vcs):
         exc = Exception()
         mock_setup_vcs.side_effect = exc
         build = get(Build, project=self.project,
@@ -97,13 +96,12 @@ def test_update_docs_unexpected_setup_exception(self, mock_update_build, mock_se
                 record=False,
                 intersphinx=False)
         self.assertTrue(result.successful())
-        mock_update_build.assert_called_once_with(state=BUILD_STATE_FINISHED)
 
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_environment', new=MagicMock)
+    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_vcs', new=MagicMock)
+    @patch('readthedocs.doc_builder.environments.BuildEnvironment.update_build', new=MagicMock)
     @patch('readthedocs.projects.tasks.UpdateDocsTask.build_docs')
-    @patch('readthedocs.projects.tasks.UpdateDocsTask.setup_vcs',
-           new=MagicMock)
-    @patch('readthedocs.doc_builder.environments.BuildEnvironment.update_build')
-    def test_update_docs_unexpected_build_exception(self, mock_update_build, mock_build_docs):
+    def test_update_docs_unexpected_build_exception(self, mock_build_docs):
         exc = Exception()
         mock_build_docs.side_effect = exc
         build = get(Build, project=self.project,
@@ -116,7 +114,6 @@ def test_update_docs_unexpected_build_exception(self, mock_update_build, mock_bu
                 record=False,
                 intersphinx=False)
         self.assertTrue(result.successful())
-        mock_update_build.assert_called_with(state=BUILD_STATE_FINISHED)
 
     def test_update_imported_doc(self):
         with mock_api(self.repo):

readthedocs/settings/base.py

@@ -355,15 +355,14 @@ def INSTALLED_APPS(self):  # noqa
             },
         },
         'loggers': {
-            'readthedocs': {
+            '': {  # root logger
                 'handlers': ['debug', 'console'],
-                'level': 'DEBUG',
-                'propagate': True,
+                'level': 'DEBUG',  # Always send from the root, handlers can filter levels
             },
-            '': {
+            'readthedocs': {
                 'handlers': ['debug', 'console'],
                 'level': 'DEBUG',
-                'propagate': True,
+                'propagate': False,  # Don't double log at the root logger for these.
             },
         },
     }

readthedocs/settings/dev.py

@@ -56,8 +56,6 @@ def DATABASES(self):  # noqa
     def LOGGING(self):  # noqa - avoid pep8 N802
         logging = super(CommunityDevSettings, self).LOGGING
         logging['formatters']['default']['format'] = '[%(asctime)s] ' + self.LOG_FORMAT
-        # Remove double logging
-        logging['loggers']['']['handlers'] = []
         return logging