Initialize global data separately and run_once in WSGI app init

NOTE(melwitt): This is a combination of two changes to avoid
intermittent test failure that was introduced by the original bug fix,
and was fixed by change I2bd360dcc6501feea7baf02d4510b282205fc061.

We have discovered that if an exception is raised at any point during
the running of the init_application WSGI script in an apache/mod_wsgi
Daemon Mode environment, it will prompt apache/mod_wsgi to re-run the
script without starting a fresh python process. Because we initialize
global data structures during app init, subsequent runs of the script
blow up as some global data do *not* support re-initialization. It is
anyway not safe to assume that init of global data is safe to run
multiple times.

This mod_wsgi behavior appears to be a special situation that does not
behave the same as a normal reload in Daemon Mode as the script file is
being reloaded upon failure instead of the daemon process being
shutdown and restarted as described in the documentation [1].

In order to handle this situation, we can move the initialization of
global data structures to a helper method that is decorated to run only
once per python interpreter instance. This way, we will not attempt to
re-initialize global data that are not safe to init more than once.

Co-Authored-By: Michele Baldessari <[email protected]>
Co-Authored-By: melanie witt <[email protected]>

Conflicts:
    nova/api/openstack/wsgi_app.py

NOTE(melwitt): The conflict is because change
If4783adda92da33d512d7c2834f0bb2e2a9b9654 (Support sys.argv in wsgi
app) is not in Victoria.

Closes-Bug: #1882094

[1] https://modwsgi.readthedocs.io/en/develop/user-guides/reloading-source-code.html#reloading-in-daemon-mode

Reset global wsgi app state in unit test

Since I2bd360dcc6501feea7baf02d4510b282205fc061 there is a global state
set during the wsgi_app init making our unit test cases
non-deterministic based on the order of them. This patch makes sure
that the global state is reset for each test case.

Closes-Bug: #1921098
(cherry picked from commit bc2c19b)

Change-Id: I2bd360dcc6501feea7baf02d4510b282205fc061
(cherry picked from commit 7c9edc0)

Author: 4383

nova/api/openstack/wsgi_app.py

@@ -29,6 +29,8 @@
 
 CONFIG_FILES = ['api-paste.ini', 'nova.conf']
 
+LOG = logging.getLogger(__name__)
+
 objects.register_all()
 
 
@@ -77,8 +79,12 @@ def application(environ, start_response):
     return application
 
 
-def init_application(name):
-    conf_files = _get_config_files()
+@utils.run_once('Global data already initialized, not re-initializing.',
+                LOG.info)
+def init_global_data(conf_files):
+    # NOTE(melwitt): parse_args initializes logging and calls global rpc.init()
+    # and db_api.configure(). The db_api.configure() call does not initiate any
+    # connection to the database.
     config.parse_args([], default_config_files=conf_files)
 
     logging.setup(CONF, "nova")
@@ -93,11 +99,25 @@ def init_application(name):
             logging.getLogger(__name__),
             logging.DEBUG)
 
+
+def init_application(name):
+    conf_files = _get_config_files()
+
+    # NOTE(melwitt): The init_application method can be called multiple times
+    # within a single python interpreter instance if any exception is raised
+    # during it (example: DBConnectionError while setting up the service) and
+    # apache/mod_wsgi reloads the init_application script. So, we initialize
+    # global data separately and decorate the method to run only once in a
+    # python interpreter instance.
+    init_global_data(conf_files)
+
     try:
         _setup_service(CONF.host, name)
     except exception.ServiceTooOld as exc:
         return error_application(exc, name)
 
+    # This global init is safe because if we got here, we already successfully
+    # set up the service and setting up the profile cannot fail.
     service.setup_profiler(name, CONF.host)
 
     conf = conf_files[0]

nova/test.py

@@ -54,6 +54,7 @@
 from sqlalchemy.dialects import sqlite
 import testtools
 
+from nova.api.openstack import wsgi_app
 from nova.compute import rpcapi as compute_rpcapi
 from nova import context
 from nova.db.sqlalchemy import api as sqlalchemy_api
@@ -285,6 +286,10 @@ def setUp(self):
 
         self.useFixture(nova_fixtures.GenericPoisonFixture())
 
+        # make sure that the wsgi app is fully initialized for all testcase
+        # instead of only once initialized for test worker
+        wsgi_app.init_global_data.reset()
+
     def _setup_cells(self):
         """Setup a normal cellsv2 environment.
 

nova/tests/unit/api/openstack/test_wsgi_app.py

@@ -0,0 +1,85 @@
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+import tempfile
+
+import fixtures
+import mock
+from oslo_config import fixture as config_fixture
+from oslotest import base
+
+from nova.api.openstack import wsgi_app
+from nova import test
+from nova.tests import fixtures as nova_fixtures
+
+
+class WSGIAppTest(base.BaseTestCase):
+
+    _paste_config = """
+[app:nova-api]
+use = egg:Paste#static
+document_root = /tmp
+    """
+
+    def setUp(self):
+        # Ensure BaseTestCase's ConfigureLogging fixture is disabled since
+        # we're using our own (StandardLogging).
+        with fixtures.EnvironmentVariable('OS_LOG_CAPTURE', '0'):
+            super(WSGIAppTest, self).setUp()
+        self.stdlog = self.useFixture(nova_fixtures.StandardLogging())
+        self.conf = tempfile.NamedTemporaryFile(mode='w+t')
+        self.conf.write(self._paste_config.lstrip())
+        self.conf.seek(0)
+        self.conf.flush()
+        self.addCleanup(self.conf.close)
+        # Use of this fixture takes care of cleaning up config settings for
+        # subsequent tests.
+        self.useFixture(config_fixture.Config())
+
+    @mock.patch('sys.argv', return_value=mock.sentinel.argv)
+    @mock.patch('nova.db.sqlalchemy.api.configure')
+    @mock.patch('nova.api.openstack.wsgi_app._setup_service')
+    @mock.patch('nova.api.openstack.wsgi_app._get_config_files')
+    def test_init_application_called_twice(self, mock_get_files, mock_setup,
+                                           mock_db_configure, mock_argv):
+        """Test that init_application can tolerate being called twice in a
+        single python interpreter instance.
+
+        When nova-api is run via mod_wsgi, if any exception is raised during
+        init_application, mod_wsgi will re-run the WSGI script without
+        restarting the daemon process even when configured for Daemon Mode.
+
+        We access the database as part of init_application, so if nova-api
+        starts up before the database is up, we'll get, for example, a
+        DBConnectionError raised during init_application and our WSGI script
+        will get reloaded/re-run by mod_wsgi.
+        """
+        mock_get_files.return_value = [self.conf.name]
+        mock_setup.side_effect = [test.TestingException, None]
+        # We need to mock the global database configure() method, else we will
+        # be affected by global database state altered by other tests that ran
+        # before this test, causing this test to fail with
+        # oslo_db.sqlalchemy.enginefacade.AlreadyStartedError. We can instead
+        # mock the method to raise an exception if it's called a second time in
+        # this test to simulate the fact that the database does not tolerate
+        # re-init [after a database query has been made].
+        mock_db_configure.side_effect = [None, test.TestingException]
+        # Run init_application the first time, simulating an exception being
+        # raised during it.
+        self.assertRaises(test.TestingException, wsgi_app.init_application,
+                          'nova-api')
+        # Now run init_application a second time, it should succeed since no
+        # exception is being raised (the init of global data should not be
+        # re-attempted).
+        wsgi_app.init_application('nova-api')
+        self.assertIn('Global data already initialized, not re-initializing.',
+                      self.stdlog.logger.output)

nova/tests/unit/test_utils.py

@@ -1294,3 +1294,101 @@ def test_api_db_is_configured_but_the_service_cannot_access_db(
             'not allowed to directly access the database. You should run this '
             'service without the [api_database]/connection config option. The '
             'service version check will only query the local cell.')
+
+
+class RunOnceTests(test.NoDBTestCase):
+
+    fake_logger = mock.MagicMock()
+
+    @utils.run_once("already ran once", fake_logger)
+    def dummy_test_func(self, fail=False):
+        if fail:
+            raise ValueError()
+        return True
+
+    def setUp(self):
+        super(RunOnceTests, self).setUp()
+        self.dummy_test_func.reset()
+        RunOnceTests.fake_logger.reset_mock()
+
+    def test_wrapped_funtions_called_once(self):
+        self.assertFalse(self.dummy_test_func.called)
+        result = self.dummy_test_func()
+        self.assertTrue(result)
+        self.assertTrue(self.dummy_test_func.called)
+
+        # assert that on second invocation no result
+        # is returned and that the logger is invoked.
+        result = self.dummy_test_func()
+        RunOnceTests.fake_logger.assert_called_once()
+        self.assertIsNone(result)
+
+    def test_wrapped_funtions_called_once_raises(self):
+        self.assertFalse(self.dummy_test_func.called)
+        self.assertRaises(ValueError, self.dummy_test_func, fail=True)
+        self.assertTrue(self.dummy_test_func.called)
+
+        # assert that on second invocation no result
+        # is returned and that the logger is invoked.
+        result = self.dummy_test_func()
+        RunOnceTests.fake_logger.assert_called_once()
+        self.assertIsNone(result)
+
+    def test_wrapped_funtions_can_be_reset(self):
+        # assert we start with a clean state
+        self.assertFalse(self.dummy_test_func.called)
+        result = self.dummy_test_func()
+        self.assertTrue(result)
+
+        self.dummy_test_func.reset()
+        # assert we restored a clean state
+        self.assertFalse(self.dummy_test_func.called)
+        result = self.dummy_test_func()
+        self.assertTrue(result)
+
+        # assert that we never called the logger
+        RunOnceTests.fake_logger.assert_not_called()
+
+    def test_reset_calls_cleanup(self):
+        mock_clean = mock.Mock()
+
+        @utils.run_once("already ran once", self.fake_logger,
+                        cleanup=mock_clean)
+        def f():
+            pass
+
+        f()
+        self.assertTrue(f.called)
+
+        f.reset()
+        self.assertFalse(f.called)
+        mock_clean.assert_called_once_with()
+
+    def test_clean_is_not_called_at_reset_if_wrapped_not_called(self):
+        mock_clean = mock.Mock()
+
+        @utils.run_once("already ran once", self.fake_logger,
+                        cleanup=mock_clean)
+        def f():
+            pass
+
+        self.assertFalse(f.called)
+
+        f.reset()
+        self.assertFalse(f.called)
+        self.assertFalse(mock_clean.called)
+
+    def test_reset_works_even_if_cleanup_raises(self):
+        mock_clean = mock.Mock(side_effect=ValueError())
+
+        @utils.run_once("already ran once", self.fake_logger,
+                        cleanup=mock_clean)
+        def f():
+            pass
+
+        f()
+        self.assertTrue(f.called)
+
+        self.assertRaises(ValueError, f.reset)
+        self.assertFalse(f.called)
+        mock_clean.assert_called_once_with()

nova/utils.py

@@ -1103,3 +1103,49 @@ def raise_if_old_compute():
             scope=scope,
             min_service_level=current_service_version,
             oldest_supported_service=oldest_supported_service_level)
+
+
+def run_once(message, logger, cleanup=None):
+    """This is a utility function decorator to ensure a function
+    is run once and only once in an interpreter instance.
+
+    Note: this is copied from the placement repo (placement/util.py)
+
+    The decorated function object can be reset by calling its
+    reset function. All exceptions raised by the wrapped function,
+    logger and cleanup function will be propagated to the caller.
+    """
+    def outer_wrapper(func):
+        @functools.wraps(func)
+        def wrapper(*args, **kwargs):
+            if not wrapper.called:
+                # Note(sean-k-mooney): the called state is always
+                # updated even if the wrapped function completes
+                # by raising an exception. If the caller catches
+                # the exception it is their responsibility to call
+                # reset if they want to re-execute the wrapped function.
+                try:
+                    return func(*args, **kwargs)
+                finally:
+                    wrapper.called = True
+            else:
+                logger(message)
+
+        wrapper.called = False
+
+        def reset(wrapper, *args, **kwargs):
+            # Note(sean-k-mooney): we conditionally call the
+            # cleanup function if one is provided only when the
+            # wrapped function has been called previously. We catch
+            # and reraise any exception that may be raised and update
+            # the called state in a finally block to ensure its
+            # always updated if reset is called.
+            try:
+                if cleanup and wrapper.called:
+                    return cleanup(*args, **kwargs)
+            finally:
+                wrapper.called = False
+
+        wrapper.reset = functools.partial(reset, wrapper)
+        return wrapper
+    return outer_wrapper