Comment 1 for bug 1914592

Consider an arbitrary failing test from the job linked above, which can be run like so:

  $ tox -e functional-py38 -- \
      -n nova.tests.functional.regressions.test_bug_1522536.TestServerGet.test_id_overlap

Having added a large number of print debugs (patch attached - can be applied to oslo.config tag 3.6.1), we see the following from nova functional tests (at nova commit 726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3):

        File "/home/stephenfin/Development/openstack/nova/nova/tests/functional/regressions/test_bug_1522536.py", line 26, in setUp
  super(TestServerGet, self).setUp()
        File "/home/stephenfin/Development/openstack/nova/nova/test.py", line 264, in setUp
  self.policy = self.useFixture(policy_fixture.PolicyFixture())
        File "/home/stephenfin/Development/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/testtools/testcase.py", line 735, in useFixture
  fixture.setUp()
        File "/home/stephenfin/Development/openstack/nova/nova/tests/unit/policy_fixture.py", line 56, in setUp
  nova.policy.init(suppress_deprecation_warnings=True)
        File "/home/stephenfin/Development/openstack/nova/nova/policy.py", line 93, in init
  _ENFORCER.load_rules()

This is followed shortly thereafter by:

        File "/home/stephenfin/Development/openstack/nova/nova/tests/functional/regressions/test_bug_1522536.py", line 27, in setUp
  self.useFixture(policy_fixture.RealPolicyFixture())
        File "/home/stephenfin/Development/openstack/nova/.tox/functional-py38/lib/python3.8/site-packages/testtools/testcase.py", line 735, in useFixture
  fixture.setUp()
        File "/home/stephenfin/Development/openstack/nova/nova/tests/unit/policy_fixture.py", line 52, in setUp
  nova.policy.reset()
        File "/home/stephenfin/Development/openstack/nova/nova/policy.py", line 54, in reset
  _ENFORCER.clear()

From this we can see there are two fixtures being applied: the legacy 'PolicyFixture', which should really be deprecated and removed by now, and the modern 'RealPolicyFixture'. The sequence of these calls is important.

The call to 'PolicyFixture' attempts to 'reset()' nova's global policy engine instance [1] but isn't able to do so since it hasn't been initialized yet. It then 'init()'s this global policy engine [2]. Since the engine is now initialized, the 'RealPolicyFixture's call to 'reset()' will be permitted. The enforcer is deleted and then later initialized again in the subsequent 'init()' call. However, there is a difference in how we initialized the enforcer the second time around. In the first call from the legacy 'PolicyFixture', we initialized it with a sample file [3] that we created from some fake policy. However, in the second call from the 'RealPolicyFixture' we don't generate a fake policy file but rather point to 'etc/nova/policy.yaml' in tree, which doesn't actually exist [4][5] and therefore has nothing to load from.

This change in how we initialize the enforcer has a knock on effect. For reasons I haven't yet entirely groked - though I suspect it's to ensure the user gets exactly what they asked for without modifications - we only apply the deprecated check string via an OR *if* the rule wasn't loaded from a file (i.e. it's a default from code and not something user-specified). This means the first time we run through the code path, we don't modify the 'check_str' of the affected rule to apply the deprecated rules, even though oslo.policy knows these deprecated rules exist. The second time we run through it, we _should_ apply these since it's a default from code and not a file, however, since we're passing the same rule objects defined in various submodules in 'nova.policies', any attributes previously set are being persisted (bug #1914095) including the '_deprecated_rule_handled' attribute [6]. This results in us skipping the whole '_handle_deprecated_rule' function.

There are a quite a few cleanups needed here. We need to clarify in code why we skip applying the deprecated rules if a rule is loaded from a file. Ideally, we need to stop applying both fixtures in nova or even remove the legacy 'PolicyFixture' entirely. We need to deep copy the policy rules in nova before we call the engine to initialize them and also update oslo.policy to do that for us (tracked via bug #1914095). Finally, we need to find some way to log this in a way that avoids the need for printf-debugging while also not exploding logs. I suspect the last of these tasks will be the most difficult :)

[1] https://github.com/openstack/nova/blob/726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3/nova/tests/unit/policy_fixture.py#L52
[2] https://github.com/openstack/nova/blob/726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3/nova/tests/unit/policy_fixture.py#L56
[3] https://github.com/openstack/nova/blob/726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3/nova/tests/unit/policy_fixture.py#L96-L104
[4] https://github.com/openstack/nova/blob/726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3/nova/tests/unit/policy_fixture.py#L44
[5] https://github.com/openstack/nova/blob/726e2fd03b5dec5d6aa22a12a68a2f8d7c8952b3/nova/tests/unit/policy_fixture.py#L49
[6] https://github.com/openstack/oslo.policy/blob/bd9d47aa36ad6f2f4746f09a267d7ce809a820f4/oslo_policy/policy.py#L774