Use oslo_log instead of alembic.util in functional tests

Instead of using alembic.utils logging functions which
prints output to stdout, lets use in functional tests
oslo_log logger to log all such commands.

This is needed to limit amount of output on stdout during
functional tests running on python3.5.

It was previously switched to use oslo_log in this migration
scripts always by [1] but because of issue in OSA we had to
revert this patch in [2].
So now let's try to change it only in functional tests.

[1] https://review.openstack.org/#/c/625555/
[2] https://review.openstack.org/#/c/626565/

Change-Id: I88fde6d107a1f1b5c48c5c89cd2e1c07fd12c755

neutron/db/migration/cli.py

@@ -60,6 +60,11 @@ CONF = cfg.ConfigOpts()
 migration_cli.register_db_cli_opts(CONF)
 
 
+log_error = alembic_util.err
+log_warning = alembic_util.warn
+log_info = alembic_util.msg
+
+
 def do_alembic_command(config, cmd, revision=None, desc=None, **kwargs):
     args = []
     if revision:
@@ -67,21 +72,21 @@ def do_alembic_command(config, cmd, revision=None, desc=None, **kwargs):
 
     project = config.get_main_option('neutron_project')
     if desc:
-        alembic_util.msg(_('Running %(cmd)s (%(desc)s) for %(project)s ...') %
-                         {'cmd': cmd, 'desc': desc, 'project': project})
+        log_info(_('Running %(cmd)s (%(desc)s) for %(project)s ...') %
+                 {'cmd': cmd, 'desc': desc, 'project': project})
     else:
-        alembic_util.msg(_('Running %(cmd)s for %(project)s ...') %
-                         {'cmd': cmd, 'project': project})
+        log_info(_('Running %(cmd)s for %(project)s ...') %
+                 {'cmd': cmd, 'project': project})
     try:
         getattr(alembic_command, cmd)(config, *args, **kwargs)
     except alembic_util.CommandError as e:
-        alembic_util.err(six.text_type(e))
-    alembic_util.msg(_('OK'))
+        log_error(six.text_type(e))
+    log_info(_('OK'))
 
 
 def _get_alembic_entrypoint(project):
     if project not in migration_cli.migration_entrypoints:
-        alembic_util.err(_('Sub-project %s not installed.') % project)
+        log_error(_('Sub-project %s not installed.') % project)
     return migration_cli.migration_entrypoints[project]
 
 
@@ -248,14 +253,14 @@ def _compare_labels(revision, expected_labels):
         bad_labels_with_release = (revision.branch_labels -
                                    _get_release_labels(expected_labels))
         if not bad_labels_with_release:
-            alembic_util.warn(
+            log_warning(
                 _('Release aware branch labels (%s) are deprecated. '
                   'Please switch to expand@ and contract@ '
                   'labels.') % bad_labels)
             return
 
         script_name = os.path.basename(revision.path)
-        alembic_util.err(
+        log_error(
             _('Unexpected label for script %(script_name)s: %(labels)s') %
             {'script_name': script_name,
              'labels': bad_labels}
@@ -297,7 +302,7 @@ def validate_revisions(config):
     branchpoints = _get_branch_points(script_dir)
     if len(branchpoints) > 1:
         branchpoints = ', '.join(p.revision for p in branchpoints)
-        alembic_util.err(
+        log_error(
             _('Unexpected number of alembic branch points: %(branchpoints)s') %
             {'branchpoints': branchpoints}
         )
@@ -335,7 +340,7 @@ def _check_head(branch_name, head_file, head):
         pass
     else:
         if observed_head != head:
-            alembic_util.err(
+            log_error(
                 _('%(branch)s HEAD file does not match migration timeline '
                   'head, expected: %(head)s') % {'branch': branch_name.title(),
                                                  'head': head})
@@ -346,8 +351,8 @@ def validate_head_files(config):
     contract_head = _get_contract_head_file_path(config)
     expand_head = _get_expand_head_file_path(config)
     if not os.path.exists(contract_head) or not os.path.exists(expand_head):
-        alembic_util.warn(_("Repository does not contain HEAD files for "
-                            "contract and expand branches."))
+        log_warning(_("Repository does not contain HEAD files for "
+                      "contract and expand branches."))
         return
     head_map = _get_heads_map(config)
     _check_head(CONTRACT_BRANCH, contract_head, head_map[CONTRACT_BRANCH])
@@ -387,11 +392,11 @@ def has_offline_migrations(config, cmd):
         # it means we should shut down all neutron-server instances before
         # proceeding with upgrade.
         project = config.get_main_option('neutron_project')
-        alembic_util.msg(_('Need to apply migrations from %(project)s '
-                           'contract branch. This will require all Neutron '
-                           'server instances to be shutdown before '
-                           'proceeding with the upgrade.') %
-            {"project": project})
+        log_info(_('Need to apply migrations from %(project)s '
+                   'contract branch. This will require all Neutron '
+                   'server instances to be shutdown before '
+                   'proceeding with the upgrade.') %
+                 {"project": project})
         return True
     return False
 
@@ -464,7 +469,7 @@ def _get_package_root_dir(config):
     root_module = importutils.try_import(_get_project_base(config))
     if not root_module:
         project = config.get_main_option('neutron_project')
-        alembic_util.err(_("Failed to locate source for %s.") % project)
+        log_error(_("Failed to locate source for %s.") % project)
     # The root_module.__file__ property is a path like
     #    '/opt/stack/networking-foo/networking_foo/__init__.py'
     # We return just
@@ -542,7 +547,7 @@ def _set_version_locations(config):
 def _get_installed_entrypoint(subproject):
     '''Get the entrypoint for the subproject, which must be installed.'''
     if subproject not in migration_cli.migration_entrypoints:
-        alembic_util.err(_('Package %s not installed') % subproject)
+        log_error(_('Package %s not installed') % subproject)
     return migration_cli.migration_entrypoints[subproject]
 
 
@@ -651,6 +656,6 @@ def main():
         return_val |= bool(CONF.command.func(config, CONF.command.name))
 
     if CONF.command.name == 'has_offline_migrations' and not return_val:
-        alembic_util.msg(_('No offline migrations pending.'))
+        log_info(_('No offline migrations pending.'))
 
     return return_val

neutron/tests/functional/db/test_migrations.py

@@ -21,6 +21,7 @@ from alembic import script as alembic_script
 from oslo_config import cfg
 from oslo_config import fixture as config_fixture
 from oslo_db.sqlalchemy import test_migrations
+from oslo_log import log as logging
 from oslotest import base as oslotest_base
 import six
 import sqlalchemy
@@ -55,6 +56,14 @@ DROP_OPERATIONS = {
                 )
 }
 
+LOG = logging.getLogger(__name__)
+
+# NOTE(slaweq): replace alembic_util logging functions used normally with
+# olso_log logger to limit output on stdout
+migration.log_error = LOG.error
+migration.log_warning = LOG.warning
+migration.log_info = LOG.info
+
 
 def upgrade(engine, alembic_config, branch_name='heads'):
     cfg.CONF.set_override('connection', engine.url, group='database')

neutron/tests/unit/db/test_migration.py

@@ -122,8 +122,8 @@ class TestCli(base.BaseTestCase):
         super(TestCli, self).setUp()
         self.do_alembic_cmd_p = mock.patch.object(cli, 'do_alembic_command')
         self.do_alembic_cmd = self.do_alembic_cmd_p.start()
-        self.mock_alembic_err = mock.patch('alembic.util.err').start()
-        self.mock_alembic_warn = mock.patch('alembic.util.warn').start()
+        self.mock_alembic_err = mock.patch.object(cli, "log_error").start()
+        self.mock_alembic_warn = mock.patch.object(cli, "log_warning").start()
         self.mock_alembic_err.side_effect = SystemExit
 
         def mocked_root_dir(cfg):