Added status_set and logs to upgrade-charm hook

When running an upgrade of the keystone charm in a large environment,
the upgrade process can take more than 30 minutes.

Prior to this change, the user would only see 'Installing apt packages'
during most of the process.

This change adds status_set and log messages to the upgrade charm hook
so that end users can see what is the status of the upgrade.

Change-Id: I1eade73fad551310ceec0bb8dcbccb777737faeb
Closes-Bug: #1782004

hooks/keystone_hooks.py

@@ -655,13 +655,18 @@ def configure_https():
 @restart_on_change(restart_map(), stopstart=True)
 @harden()
 def upgrade_charm():
-    status_set('maintenance', 'Installing apt packages')
-    apt_install(filter_installed_packages(determine_packages()))
+    packages_to_install = filter_installed_packages(determine_packages())
+    if packages_to_install:
+        log('Installing apt packages')
+        status_set('maintenance', 'Installing apt packages')
+        apt_install(packages_to_install)
     packages_removed = remove_old_packages()
 
     if run_in_apache():
         disable_unused_apache_sites()
 
+    log('Regenerating configuration files')
+    status_set('maintenance', 'Regenerating configuration files')
     CONFIGS.write_all()
 
     # See LP bug 1519035
@@ -670,6 +675,7 @@ def upgrade_charm():
     update_nrpe_config()
 
     if packages_removed:
+        status_set('maintenance', 'Restarting services')
         log("Package purge detected, restarting services", "INFO")
         for s in services():
             service_restart(s)
@@ -691,6 +697,8 @@ def update_status():
             'nrpe-external-master-relation-changed')
 def update_nrpe_config():
     # python-dbus is used by check_upstart_job
+    log('Updating NRPE configuration')
+    status_set('maintenance', 'Updating NRPE configuration')
     apt_install('python-dbus')
     hostname = nrpe.get_nagios_hostname()
     current_unit = nrpe.get_nagios_unit_name()

hooks/keystone_utils.py

@@ -95,6 +95,7 @@ from charmhelpers.core.hookenv import (
     INFO,
     ERROR,
     WARNING,
+    status_set,
 )
 
 from charmhelpers.fetch import (
@@ -607,6 +608,8 @@ def disable_unused_apache_sites():
         if os.path.exists(apache_site_file):
             try:
                 # Try it cleanly
+                log('Disabling unused apache configs')
+                status_set('maintenance', 'Disabling unused apache configs')
                 subprocess.check_call(['a2dissite', apache_site])
             except subprocess.CalledProcessError:
                 # Remove the file
@@ -681,12 +684,14 @@ def determine_purge_packages():
 
 
 def remove_old_packages():
-    '''Purge any packages that need ot be removed.
+    '''Purge any packages that need to be removed.
 
     :returns: bool Whether packages were removed.
     '''
     installed_packages = filter_missing_packages(determine_purge_packages())
     if installed_packages:
+        log('Removing apt packages')
+        status_set('maintenance', 'Removing apt packages')
         apt_purge(installed_packages, fatal=True)
         apt_autoremove(purge=True, fatal=True)
     return bool(installed_packages)
@@ -772,6 +777,7 @@ def keystone_service():
 def migrate_database():
     """Runs keystone-manage to initialize a new database or migrate existing"""
     log('Migrating the keystone database.', level=INFO)
+    status_set('maintenance', 'Migrating the keystone database')
     if snap_install_requested():
         service_stop('snap.keystone.*')
     else:
@@ -1834,6 +1840,9 @@ def ensure_valid_service(service):
 
 
 def add_endpoint(region, service, publicurl, adminurl, internalurl):
+    status_message = 'Updating endpoint for {}'.format(service)
+    log(status_message)
+    status_set('maintenance', status_message)
     desc = valid_services[service]["desc"]
     service_type = valid_services[service]["type"]
     create_service_entry(service, service_type, desc)

unit_tests/test_keystone_hooks.py

@@ -559,7 +559,7 @@ class KeystoneRelationTests(CharmTestCase):
         self.remove_old_packages.return_value = True
         self.services.return_value = ['apache2']
 
-        self.filter_installed_packages.return_value = []
+        self.filter_installed_packages.return_value = ['something']
         hooks.upgrade_charm()
         self.assertTrue(self.apt_install.called)
         self.assertTrue(update.called)
@@ -567,6 +567,36 @@ class KeystoneRelationTests(CharmTestCase):
         self.service_restart.assert_called_with('apache2')
         mock_stop_manager_instance.assert_called_once_with()
 
+    @patch.object(hooks, 'update_all_identity_relation_units')
+    @patch.object(utils, 'os_release')
+    @patch.object(hooks, 'is_db_ready')
+    @patch.object(hooks, 'is_db_initialised')
+    @patch('keystone_utils.log')
+    @patch('keystone_utils.relation_ids')
+    @patch.object(hooks, 'stop_manager_instance')
+    def test_upgrade_charm_leader_no_packages(self,
+                                              mock_stop_manager_instance,
+                                              mock_relation_ids,
+                                              mock_log,
+                                              mock_is_db_initialised,
+                                              mock_is_db_ready,
+                                              os_release,
+                                              update):
+        os_release.return_value = 'havana'
+        mock_is_db_initialised.return_value = True
+        mock_is_db_ready.return_value = True
+        mock_relation_ids.return_value = []
+        self.remove_old_packages.return_value = True
+        self.services.return_value = ['apache2']
+
+        self.filter_installed_packages.return_value = []
+        hooks.upgrade_charm()
+        self.assertFalse(self.apt_install.called)
+        self.assertTrue(update.called)
+        self.remove_old_packages.assert_called_once_with()
+        self.service_restart.assert_called_with('apache2')
+        mock_stop_manager_instance.assert_called_once_with()
+
     @patch.object(hooks, 'update_all_identity_relation_units')
     @patch.object(hooks, 'is_db_initialised')
     def test_leader_init_db_if_ready(self, is_db_initialized,
@@ -719,7 +749,7 @@ class KeystoneRelationTests(CharmTestCase):
                                       os_release, update):
         os_release.return_value = 'havana'
 
-        self.filter_installed_packages.return_value = []
+        self.filter_installed_packages.return_value = ['something']
         self.is_elected_leader.return_value = False
         hooks.upgrade_charm()
         self.assertTrue(self.apt_install.called)
@@ -727,6 +757,26 @@ class KeystoneRelationTests(CharmTestCase):
         self.assertFalse(update.called)
         mock_stop_manager_instance.assert_called_once()
 
+    @patch.object(hooks, 'update_all_identity_relation_units')
+    @patch.object(utils, 'os_release')
+    @patch('keystone_utils.log')
+    @patch('keystone_utils.relation_ids')
+    @patch.object(hooks, 'stop_manager_instance')
+    def test_upgrade_charm_not_leader_no_packages(self,
+                                                  mock_stop_manager_instance,
+                                                  mock_relation_ids,
+                                                  mock_log,
+                                                  os_release, update):
+        os_release.return_value = 'havana'
+
+        self.filter_installed_packages.return_value = []
+        self.is_elected_leader.return_value = False
+        hooks.upgrade_charm()
+        self.assertFalse(self.apt_install.called)
+        self.assertTrue(self.log.called)
+        self.assertFalse(update.called)
+        mock_stop_manager_instance.assert_called_once()
+
     def test_domain_backend_changed_v2(self):
         self.get_api_version.return_value = 2
         hooks.domain_backend_changed()