yahoo-eng-team team mailing list archive

[OpenStack Infra <1807747@xxxxxxxxxxxxxxxxxx>]

Reviewed:  https://review.opendev.org/624185
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=c27af238ad99c0330eb4b55398f44be28e6f0485
Submitter: Zuul
Branch:    master

commit c27af238ad99c0330eb4b55398f44be28e6f0485
Author: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date:   Mon Dec 10 14:58:46 2018 -0500

    Fix target used in nova.policy.check_is_admin
    
    The target passed to Enforcer.authorize should be a dict,
    similar to the target dict to the RequestContext.can method.
    However, we were passing an instance of _DeprecatedPolicyValues
    because that is ultimately what comes out of
    RequestContext.to_policy_values(). As of change
    I4642c57990b145c0e691140970574412682e66a5 in oslo.policy, that
    incorrect type for the target parameter results in an error in
    the debug logs for the policy check:
    
      cannot format data, exception: Expected a dictionary, got
      <class 'oslo_context.context._DeprecatedPolicyValues'> instead.
    
    This resolves the issue by using the same default target dict
    that RequestContext.can uses if a target is not supplied.
    
    Note that we get here from NovaKeystoneContext via API middleware
    before any request handler is invoked in the wsgi stack, so there
    is no context from the request as to what to pass for the target
    besides the user_id/project_id.
    
    Change-Id: I4442a7b95d15233f76f7795d45b18ac440ddb831
    Closes-Bug: #1807747


** Changed in: nova
       Status: In Progress => Fix Released

-- 
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):
  Fix Released

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
  devstack@n-api.service[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
  devstack@n-api.service[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