Merge lp:~julian-edwards/maas/import-fail-bug-1386914 into lp:~maas-committers/maas/trunk

[Julian Edwards]

Put a persistent error message on the web pages if the image importer is unable to connect to any of the defined boot sources. Previously, the import service just crashed and the user was unaware.

I've deliberately only caught errors from when descriptions are downloaded as this is basically where URLs are verified, which is the cause of the original bug.

We may decide to later extend this validation to more parts of the code, but this is a 1.7 backport candidate so keeping it short.

[Blake Rouse (blake-rouse)]

There is an issue with this.

The cache is only updated every hour. If an update occurs and it fails it will show this error for a whole hour, until it tries again. The import process does not update the cache its completely seperate, it doesn't even us the cache, the cache is for the UI only.

Only way I can think around this is to update the cache before each import, if not then this error message can exist while it has imported and completed successfully.

[Julian Edwards (julian-edwards)]

On Thursday 30 Oct 2014 15:46:23 you wrote:
> There is an issue with this.
>
> The cache is only updated every hour. If an update occurs and it fails it
> will show this error for a whole hour, until it tries again. The import
> process does not update the cache its completely seperate, it doesn't even
> us the cache, the cache is for the UI only.

Ok this is useful info, thanks.

> Only way I can think around this is to update the cache before each import,
> if not then this error message can exist while it has imported and
> completed successfully.

That seems like something I'd expect to happen anyway, so great. Can you
point me at the relevant area that needs changing?

Also would you please consider a technical overview write-up of this whole
import process? It seems that a few of us don't fully understand the changes
you made.

J

[Blake Rouse (blake-rouse)]

> On Thursday 30 Oct 2014 15:46:23 you wrote:
> > There is an issue with this.
> >
> > The cache is only updated every hour. If an update occurs and it fails it
> > will show this error for a whole hour, until it tries again. The import
> > process does not update the cache its completely seperate, it doesn't even
> > us the cache, the cache is for the UI only.
>
> Ok this is useful info, thanks.
>
> > Only way I can think around this is to update the cache before each import,
> > if not then this error message can exist while it has imported and
> > completed successfully.
>
> That seems like something I'd expect to happen anyway, so great. Can you
> point me at the relevant area that needs changing?

You would need to start the update in maasserver/bootresources.py:_import_resources. If you do add this, then you probably could remove the cache updating service, since the importing is a service as well.

>
> Also would you please consider a technical overview write-up of this whole
> import process? It seems that a few of us don't fully understand the changes
> you made.

I will work on adding a doc in the dev section to give an overview of how it all works.

>
> J

[Julian Edwards (julian-edwards)]

I've made changes as suggested and it all seems to work well on my test rig. I'm also catching IOError — Simplestreams has zero documentation about what exceptions it raises and I didn't see that it raises this one as well, depending on the error.

Please have another look.

[Julian Edwards (julian-edwards)]

Forgot to say, I renamed:

 _cache_boot_sources() → cache_boot_sources()
 cache_boot_source() → cache_boot_sources_in_thread()

The latter is still required because a post-save signal causes it to run, and it cannot run synchronously in that case.

[Blake Rouse (blake-rouse)]

Other then the error message, that I commented on inline. Looks good.

review: Approve

[Julian Edwards (julian-edwards)]

Thanks for the (re-)review!

On Monday 03 November 2014 18:47:14 you wrote:
> > + sources)
> > + except (IOError, ConnectionError) as e:
> > + source_errors.append(
> > + "Failed to import images from boot source %s: %s"
> > % ( + source.url, unicode(e)))
>
> This isn't importing images, its just downloading metadata.

That used to be the case, but it's now a prerequisite to the actual download,
so the error message is pretty accurate in that it's failed to download the
image.

It would look a little weird to say "failed to download image descriptions" or
the like, most users have no idea what those are unless they're familiar with
simplestreams.

=== modified file 'src/maasserver/bootresources.py'
--- src/maasserver/bootresources.py	2014-10-30 18:24:50 +0000
+++ src/maasserver/bootresources.py	2014-11-03 03:01:27 +0000
@@ -39,6 +39,7 @@
 from django.shortcuts import get_object_or_404
 from maasserver import locks
 from maasserver.bootsources import (
+    cache_boot_sources,
     ensure_boot_source_definition,
     get_boot_sources,
     )
@@ -883,6 +884,9 @@
         maaslog.debug("Skipping import as another import is already running.")
         return
 
+    # Keep the descriptions cache up-to-date.
+    cache_boot_sources()
+
     # If we're not being forced, don't sync unless we've already done it once
     # before, i.e. we've been asked to explicitly sync by a user.
     if not force and not has_synced_resources():

=== modified file 'src/maasserver/bootsources.py'
--- src/maasserver/bootsources.py	2014-09-30 20:22:58 +0000
+++ src/maasserver/bootsources.py	2014-11-03 03:01:27 +0000
@@ -17,11 +17,15 @@
     "get_boot_sources",
     "get_os_info_from_boot_sources",
     "cache_boot_sources",
-    "BootSourceCacheService",
+    "cache_boot_sources_in_thread",
 ]
 
-
 from maasserver import locks
+from maasserver.components import (
+    discard_persistent_error,
+    register_persistent_error,
+    )
+from maasserver.enum import COMPONENT
 from maasserver.models import (
     BootSource,
     BootSourceCache,
@@ -37,10 +41,9 @@
 from provisioningserver.logger import get_maas_logger
 from provisioningserver.utils.env import environment_variables
 from provisioningserver.utils.fs import tempdir
-from twisted.application.internet import TimerService
+from requests.exceptions import ConnectionError
 from twisted.internet import reactor
 from twisted.internet.threads import deferToThread
-from twisted.python import log
 
 
 maaslog = get_maas_logger("bootsources")
@@ -101,12 +104,14 @@
 
 
 @transactional
-def _cache_boot_sources():
+def cache_boot_sources():
     """Cache all image information in boot sources."""
     # If the lock is already held, then cache is already running.
     if locks.cache_sources.is_locked():
         return
 
+    source_errors = []
+
     # Hold the lock while performing the cache
     with locks.cache_sources:
         env = get_simplestreams_env()
@@ -114,7 +119,14 @@
             for source in BootSource.objects.all():
                 sources = write_all_keyrings(
                     keyrings_path, [source.to_dict_without_selections()])
-                image_descriptions = download_all_image_descriptions(sources)
+                try:
+                    image_descriptions = download_all_image_descriptions(
+                        sources)
+                except (IOError, ConnectionError) as e:
+                    source_errors.append(
+                        "Failed to import images from boot source %s: %s" % (
+                            source.url, unicode(e)))
+                    continue
 
                 # We clear the cache once the information has been retrieved,
                 # because if an error occurs getting the information then the
@@ -133,8 +145,15 @@
                             )
         maaslog.info("Updated boot sources cache.")
 
-
-def cache_boot_sources():
+        # Update the component errors while still holding the lock.
+        if len(source_errors) > 0:
+            register_persistent_error(
+                COMPONENT.REGION_IMAGE_IMPORT, "\n".join(source_errors))
+        else:
+            discard_persistent_error(COMPONENT.REGION_IMAGE_IMPORT)
+
+
+def cache_boot_sources_in_thread():
     """Starts the caching of image information in boot sources.
 
     Note: This function returns immediately. It only starts the process, it
@@ -144,35 +163,4 @@
     # "OperationalError: could not serialize access due to concurrent update"
     # The wait will make sure the transaction that started the update will
     # have finished and been committed.
-    reactor.callLater(1, deferToThread, _cache_boot_sources)
-
-
-class BootSourceCacheService(TimerService, object):
-    """Service to periodically cache boot source information.
-
-    This will run immediately when it's started, then once again every hour,
-    though the interval can be overridden by passing it to the constructor.
-    """
-
-    def __init__(self, interval=(60 * 60)):
-        super(BootSourceCacheService, self).__init__(
-            interval, self.try_cache_boot_sources)
-
-    def try_cache_boot_sources(self):
-        """Attempt to cache boot sources.
-
-        Log errors on failure, but do not propagate them up; that will
-        stop the timed loop from running.
-        """
-
-        def cache_boot_sources_failed(failure):
-            # Log the error in full to the Twisted log.
-            log.err(failure)
-            # Log something concise to the MAAS log.
-            maaslog.error(
-                "Failed to update boot source cache: %s",
-                failure.getErrorMessage())
-
-        d = deferToThread(_cache_boot_sources)
-        d.addErrback(cache_boot_sources_failed)
-        return d
+    reactor.callLater(1, deferToThread, cache_boot_sources)

=== modified file 'src/maasserver/enum.py'
--- src/maasserver/enum.py	2014-10-03 10:42:35 +0000
+++ src/maasserver/enum.py	2014-11-03 03:01:27 +0000
@@ -42,6 +42,7 @@
     PSERV = 'provisioning server'
     IMPORT_PXE_FILES = 'maas-import-pxe-files script'
     CLUSTERS = 'clusters'
+    REGION_IMAGE_IMPORT = 'Image importer'
 
 
 class NODE_STATUS:

=== modified file 'src/maasserver/eventloop.py'
--- src/maasserver/eventloop.py	2014-09-26 20:19:01 +0000
+++ src/maasserver/eventloop.py	2014-11-03 03:01:27 +0000
@@ -164,11 +164,6 @@
     return bootresources.ImportResourcesService()
 
 
-def make_BootSourceCacheService():
-    from maasserver import bootsources
-    return bootsources.BootSourceCacheService()
-
-
 class RegionEventLoop:
     """An event loop running in a region controller process.
 
@@ -194,7 +189,6 @@
         ("rpc-advertise", make_RegionAdvertisingService),
         ("nonce-cleanup", make_NonceCleanupService),
         ("import-resources", make_ImportResourcesService),
-        ("cache-sources", make_BootSourceCacheService),
     )
 
     def __init__(self):

=== modified file 'src/maasserver/models/bootsource.py'
--- src/maasserver/models/bootsource.py	2014-09-30 19:48:33 +0000
+++ src/maasserver/models/bootsource.py	2014-11-03 03:01:27 +0000
@@ -106,7 +106,7 @@
     """Update the `BootSourceCache` with information for the updated
     source."""
     # Avoid circular import
-    from maasserver.bootsources import cache_boot_sources
-    cache_boot_sources()
+    from maasserver.bootsources import cache_boot_sources_in_thread
+    cache_boot_sources_in_thread()
 
 post_save.connect(update_boot_source_cache, BootSource)

=== modified file 'src/maasserver/models/tests/test_bootsource.py'
--- src/maasserver/models/tests/test_bootsource.py	2014-09-30 19:48:33 +0000
+++ src/maasserver/models/tests/test_bootsource.py	2014-11-03 03:01:27 +0000
@@ -17,7 +17,7 @@
 import os
 
 from django.core.exceptions import ValidationError
-from maasserver.bootsources import _cache_boot_sources
+from maasserver.bootsources import cache_boot_sources
 from maasserver.models import BootSource
 from maasserver.testing.factory import factory
 from maasserver.testing.testcase import MAASServerTestCase
@@ -104,4 +104,5 @@
             url="http://test.test/", keyring_data=b"1234")
         self.assertThat(
             mock_callLater,
-            MockCalledOnceWith(1, deferToThread, _cache_boot_sources))
+            MockCalledOnceWith(
+                1, deferToThread, cache_boot_sources))

=== modified file 'src/maasserver/tests/test_bootresources.py'
--- src/maasserver/tests/test_bootresources.py	2014-10-30 18:24:50 +0000
+++ src/maasserver/tests/test_bootresources.py	2014-11-03 03:01:27 +0000
@@ -1030,7 +1030,7 @@
         # lock is already held.
         self.assertThat(has_synced_resources, MockNotCalled())
 
-    def test__import_resources_exists_early_without_force(self):
+    def test__import_resources_exits_early_without_force(self):
         has_synced_resources = self.patch(
             bootresources, "has_synced_resources")
         bootresources._import_resources(force=False)
@@ -1059,33 +1059,37 @@
         self.assertFalse(bootresources.locks.import_images.is_locked())
 
     def test__import_resources_calls_functions_with_correct_parameters(self):
-        fake_write_all_keyrings = self.patch(
+        cache_boot_sources = self.patch(
+            bootresources, 'cache_boot_sources')
+        write_all_keyrings = self.patch(
             bootresources, 'write_all_keyrings')
-        fake_write_all_keyrings.return_value = [sentinel.source]
-        fake_image_descriptions = self.patch(
+        write_all_keyrings.return_value = [sentinel.source]
+        image_descriptions = self.patch(
             bootresources, 'download_all_image_descriptions')
         descriptions = Mock()
         descriptions.is_empty.return_value = False
-        fake_image_descriptions.return_value = descriptions
-        fake_map_products = self.patch(
+        image_descriptions.return_value = descriptions
+        map_products = self.patch(
             bootresources, 'map_products')
-        fake_map_products.return_value = sentinel.mapping
-        fake_download_all_boot_resources = self.patch(
+        map_products.return_value = sentinel.mapping
+        download_all_boot_resources = self.patch(
             bootresources, 'download_all_boot_resources')
 
         bootresources._import_resources(force=True)
 
-        self.assertThat(
-            fake_write_all_keyrings,
+        self.expectThat(
+            cache_boot_sources, MockCalledOnceWith())
+        self.expectThat(
+            write_all_keyrings,
             MockCalledOnceWith(ANY, []))
-        self.assertThat(
-            fake_image_descriptions,
+        self.expectThat(
+            image_descriptions,
             MockCalledOnceWith([sentinel.source]))
-        self.assertThat(
-            fake_map_products,
+        self.expectThat(
+            map_products,
             MockCalledOnceWith(descriptions))
-        self.assertThat(
-            fake_download_all_boot_resources,
+        self.expectThat(
+            download_all_boot_resources,
             MockCalledOnceWith([sentinel.source], sentinel.mapping))
 
     def test__import_resources_has_env_GNUPGHOME_set(self):

=== modified file 'src/maasserver/tests/test_bootsources.py'
--- src/maasserver/tests/test_bootsources.py	2014-09-30 19:48:33 +0000
+++ src/maasserver/tests/test_bootsources.py	2014-11-03 03:01:27 +0000
@@ -18,12 +18,17 @@
 
 from maasserver import bootsources
 from maasserver.bootsources import (
-    _cache_boot_sources,
     cache_boot_sources,
+    cache_boot_sources_in_thread,
     ensure_boot_source_definition,
     get_boot_sources,
     get_os_info_from_boot_sources,
     )
+from maasserver.components import (
+    get_persistent_error,
+    register_persistent_error,
+    )
+from maasserver.enum import COMPONENT
 from maasserver.models import (
     BootSource,
     BootSourceCache,
@@ -34,10 +39,14 @@
 from maasserver.testing.testcase import MAASServerTestCase
 from maastesting.matchers import MockCalledOnceWith
 from mock import MagicMock
+from provisioningserver.import_images import (
+    download_descriptions as download_descriptions_module,
+    )
 from provisioningserver.import_images.boot_image_mapping import (
     BootImageMapping,
     )
 from provisioningserver.import_images.helpers import ImageSpec
+from requests.exceptions import ConnectionError
 from testtools.matchers import HasLength
 from twisted.internet import reactor
 from twisted.internet.threads import deferToThread
@@ -170,7 +179,7 @@
         capture = (
             patch_and_capture_env_for_download_all_image_descriptions(self))
         factory.make_BootSource(keyring_data='1234')
-        _cache_boot_sources()
+        cache_boot_sources()
         self.assertEqual(
             bootsources.get_maas_user_gpghome(),
             capture.env['GNUPGHOME'])
@@ -181,7 +190,7 @@
         capture = (
             patch_and_capture_env_for_download_all_image_descriptions(self))
         factory.make_BootSource(keyring_data='1234')
-        _cache_boot_sources()
+        cache_boot_sources()
         self.assertEqual(
             (proxy_address, proxy_address),
             (capture.env['http_proxy'], capture.env['http_proxy']))
@@ -192,7 +201,7 @@
         mock_download = self.patch(
             bootsources, 'download_all_image_descriptions')
         mock_download.return_value = make_boot_image_mapping()
-        _cache_boot_sources()
+        cache_boot_sources()
         self.assertEqual(0, BootSourceCache.objects.all().count())
 
     def test__returns_adds_entries_to_cache_for_source(self):
@@ -204,7 +213,7 @@
         mock_download = self.patch(
             bootsources, 'download_all_image_descriptions')
         mock_download.return_value = make_boot_image_mapping(image_specs)
-        _cache_boot_sources()
+        cache_boot_sources()
         cached_releases = [
             cache.release
             for cache in BootSourceCache.objects.filter(boot_source=source)
@@ -213,11 +222,45 @@
         self.assertItemsEqual(releases, cached_releases)
 
 
+class TestBadConnectionHandling(MAASServerTestCase):
+
+    def test__catches_connection_errors_and_sets_component_error(self):
+        sources = [
+            factory.make_BootSource(keyring_data='1234') for _ in range(3)]
+        download_image_descriptions = self.patch(
+            download_descriptions_module, 'download_image_descriptions')
+        error_text = factory.make_name("error_text")
+        # Make two of the downloads fail.
+        download_image_descriptions.side_effect = [
+            ConnectionError(error_text),
+            BootImageMapping(),
+            IOError(error_text),
+            ]
+        cache_boot_sources()
+        base_error = "Failed to import images from boot source {url}: {err}"
+        error_part_one = base_error.format(url=sources[0].url, err=error_text)
+        error_part_two = base_error.format(url=sources[2].url, err=error_text)
+        expected_error = error_part_one + '\n' + error_part_two
+        actual_error = get_persistent_error(COMPONENT.REGION_IMAGE_IMPORT)
+        self.assertEqual(expected_error, actual_error)
+
+    def test__clears_component_error_when_successful(self):
+        register_persistent_error(
+            COMPONENT.REGION_IMAGE_IMPORT, factory.make_string())
+        [factory.make_BootSource(keyring_data='1234') for _ in range(3)]
+        download_image_descriptions = self.patch(
+            download_descriptions_module, 'download_image_descriptions')
+        # Make all of the downloads successful.
+        download_image_descriptions.return_value = BootImageMapping()
+        cache_boot_sources()
+        self.assertIsNone(get_persistent_error(COMPONENT.REGION_IMAGE_IMPORT))
+
+
 class TestCacheBootSources(MAASServerTestCase):
 
     def test__calls_callLater_in_reactor(self):
         mock_callLater = self.patch(reactor, 'callLater')
-        cache_boot_sources()
+        cache_boot_sources_in_thread()
         self.assertThat(
             mock_callLater,
-            MockCalledOnceWith(1, deferToThread, _cache_boot_sources))
+            MockCalledOnceWith(1, deferToThread, cache_boot_sources))

=== modified file 'src/maasserver/tests/test_eventloop.py'
--- src/maasserver/tests/test_eventloop.py	2014-09-26 20:19:01 +0000
+++ src/maasserver/tests/test_eventloop.py	2014-11-03 03:01:27 +0000
@@ -18,7 +18,6 @@
 from django.db import connections
 from maasserver import (
     bootresources,
-    bootsources,
     eventloop,
     nonces_cleanup,
     )
@@ -147,15 +146,6 @@
             eventloop.make_ImportResourcesService,
             {factory for _, factory in eventloop.loop.factories})
 
-    def test_make_BootSourceCacheService(self):
-        service = eventloop.make_BootSourceCacheService()
-        self.assertThat(service, IsInstance(
-            bootsources.BootSourceCacheService))
-        # It is registered as a factory in RegionEventLoop.
-        self.assertIn(
-            eventloop.make_BootSourceCacheService,
-            {factory for _, factory in eventloop.loop.factories})
-
 
 class TestDisablingDatabaseConnections(MAASTestCase):