Public bug reported: We're doing policy enforcement wrong somehow, I'm seeing this in the nova-api logs when a server is being deleted:
http://logs.openstack.org/81/606981/4/check/tempest- slow/fafde23/controller/logs/screen-n-api.txt.gz#_Dec_08_01_45_42_745709 Dec 08 01:45:42.745709 ubuntu-xenial-ovh-gra1-0001066161 [email protected][22839]: DEBUG oslo_policy.policy [None req-a0211268-269b-4227-ba65-a680ec13b6e3 tempest- TestMultiAttachVolumeSwap-1803326020 tempest- TestMultiAttachVolumeSwap-1803326020] enforce: rule="context_is_admin" creds={"domain_id": null, "is_admin": null, "is_admin_project": true, "project_domain_id": "default", "project_id": "5db98765c5d94a73bae8aba2f13c7762", "roles": ["reader", "member"], "service_project_domain_id": null, "service_project_id": null, "service_roles": [], "service_user_domain_id": null, "service_user_id": null, "system_scope": null, "user_domain_id": "default", "user_id": "9bc61597b6794ca49c79ce599c26b223"} target=cannot format data, exception: Expected a dictionary, got <class 'oslo_context.context._DeprecatedPolicyValues'> instead. {{(pid=22842) enforce /usr/local/lib/python2.7/dist- packages/oslo_policy/policy.py:902}} I would think that's coming from here but I'm not sure: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/api/openstack/compute/servers.py#L674 But the debug error comes before we get that far because it's logged before this: Dec 08 01:45:42.747544 ubuntu-xenial-ovh-gra1-0001066161 [email protected][22839]: DEBUG nova.api.openstack.wsgi [None req-a0211268-269b-4227-ba65-a680ec13b6e3 tempest- TestMultiAttachVolumeSwap-1803326020 tempest- TestMultiAttachVolumeSwap-1803326020] Calling method '<bound method ServersController.delete of <nova.api.openstack.compute.servers.ServersController object at 0x7f91cdb05c90>>' {{(pid=22842) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:507}} So maybe some kind of middleware? It's probably this: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/context.py#L151 And that eventually calls enforce() in the policy code passing credentials as the target: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/policy.py#L178 And the _DeprecatedPolicyValues comes from oslo.context: https://github.com/openstack/oslo.context/blob/0daf01065d1d51694e06aaecb3dcf4dcc78710fe/oslo_context/context.py#L318 The fix might be here: https://review.openstack.org/#/c/564349/ ** Affects: nova Importance: Medium Assignee: Matt Riedemann (mriedem) Status: Triaged ** Tags: api logging policy -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to OpenStack Compute (nova). https://bugs.launchpad.net/bugs/1807747 Title: "cannot format data, exception: Expected a dictionary, got <class 'oslo_context.context._DeprecatedPolicyValues" all over n-api logs Status in OpenStack Compute (nova): Triaged Bug description: We're doing policy enforcement wrong somehow, I'm seeing this in the nova-api logs when a server is being deleted: http://logs.openstack.org/81/606981/4/check/tempest- slow/fafde23/controller/logs/screen-n-api.txt.gz#_Dec_08_01_45_42_745709 Dec 08 01:45:42.745709 ubuntu-xenial-ovh-gra1-0001066161 [email protected][22839]: DEBUG oslo_policy.policy [None req-a0211268-269b-4227-ba65-a680ec13b6e3 tempest- TestMultiAttachVolumeSwap-1803326020 tempest- TestMultiAttachVolumeSwap-1803326020] enforce: rule="context_is_admin" creds={"domain_id": null, "is_admin": null, "is_admin_project": true, "project_domain_id": "default", "project_id": "5db98765c5d94a73bae8aba2f13c7762", "roles": ["reader", "member"], "service_project_domain_id": null, "service_project_id": null, "service_roles": [], "service_user_domain_id": null, "service_user_id": null, "system_scope": null, "user_domain_id": "default", "user_id": "9bc61597b6794ca49c79ce599c26b223"} target=cannot format data, exception: Expected a dictionary, got <class 'oslo_context.context._DeprecatedPolicyValues'> instead. {{(pid=22842) enforce /usr/local/lib/python2.7/dist- packages/oslo_policy/policy.py:902}} I would think that's coming from here but I'm not sure: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/api/openstack/compute/servers.py#L674 But the debug error comes before we get that far because it's logged before this: Dec 08 01:45:42.747544 ubuntu-xenial-ovh-gra1-0001066161 [email protected][22839]: DEBUG nova.api.openstack.wsgi [None req-a0211268-269b-4227-ba65-a680ec13b6e3 tempest- TestMultiAttachVolumeSwap-1803326020 tempest- TestMultiAttachVolumeSwap-1803326020] Calling method '<bound method ServersController.delete of <nova.api.openstack.compute.servers.ServersController object at 0x7f91cdb05c90>>' {{(pid=22842) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:507}} So maybe some kind of middleware? It's probably this: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/context.py#L151 And that eventually calls enforce() in the policy code passing credentials as the target: https://github.com/openstack/nova/blob/08d617084e5aa69ada0898d674022621d130aef3/nova/policy.py#L178 And the _DeprecatedPolicyValues comes from oslo.context: https://github.com/openstack/oslo.context/blob/0daf01065d1d51694e06aaecb3dcf4dcc78710fe/oslo_context/context.py#L318 The fix might be here: https://review.openstack.org/#/c/564349/ To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1807747/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
