From e3085fa6310ddeaafa493c3f718aab0ce64f0994 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Herv=C3=A9=20Beraud?= Date: Thu, 4 Jun 2020 09:49:59 +0200 Subject: [PATCH] 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 Co-Authored-By: melanie witt 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 bc2c19bb2db901af0c48d34fb15a335f4e343361) Change-Id: I2bd360dcc6501feea7baf02d4510b282205fc061 (cherry picked from commit 7c9edc02eda45aafbbb539b759e6b92f7aeb5ea8) --- nova/api/openstack/wsgi_app.py | 24 ++++- nova/test.py | 5 + .../tests/unit/api/openstack/test_wsgi_app.py | 85 ++++++++++++++++ nova/tests/unit/test_utils.py | 98 +++++++++++++++++++ nova/utils.py | 46 +++++++++ 5 files changed, 256 insertions(+), 2 deletions(-) create mode 100644 nova/tests/unit/api/openstack/test_wsgi_app.py diff --git a/nova/api/openstack/wsgi_app.py b/nova/api/openstack/wsgi_app.py index 8e8fbd6eacf3..9039b888cb05 100644 --- a/nova/api/openstack/wsgi_app.py +++ b/nova/api/openstack/wsgi_app.py @@ -29,6 +29,8 @@ CONF = cfg.CONF CONFIG_FILES = ['api-paste.ini', 'nova.conf'] +LOG = logging.getLogger(__name__) + objects.register_all() @@ -77,8 +79,12 @@ def error_application(exc, name): 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] diff --git a/nova/test.py b/nova/test.py index 89e4bed0842a..9bb6e5e032a1 100644 --- a/nova/test.py +++ b/nova/test.py @@ -54,6 +54,7 @@ from six.moves import builtins 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 @@ class TestCase(base.BaseTestCase): 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. diff --git a/nova/tests/unit/api/openstack/test_wsgi_app.py b/nova/tests/unit/api/openstack/test_wsgi_app.py new file mode 100644 index 000000000000..4cb7459c982d --- /dev/null +++ b/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) diff --git a/nova/tests/unit/test_utils.py b/nova/tests/unit/test_utils.py index b64a753aeb23..b7516ef7e827 100644 --- a/nova/tests/unit/test_utils.py +++ b/nova/tests/unit/test_utils.py @@ -1294,3 +1294,101 @@ class TestOldComputeCheck(test.NoDBTestCase): '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() diff --git a/nova/utils.py b/nova/utils.py index 181d1f1affa2..ec5e3e86dc9a 100644 --- a/nova/utils.py +++ b/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